niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #479
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestPushPathsRefusesUntrustedClosure4--- PASS: TestPushPathsRefusesUntrustedClosure (0.01s)5=== RUN TestDoServerRequestAttachesToken6=== PAUSE TestDoServerRequestAttachesToken7=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry8=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry9=== RUN TestRegisterUploadedObjectReusesConnections10=== PAUSE TestRegisterUploadedObjectReusesConnections11=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica12=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica13=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun14=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun15=== RUN TestCaseHackSuffix16=== PAUSE TestCaseHackSuffix17=== RUN TestFilterOversizedClosures18=== PAUSE TestFilterOversizedClosures19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_ReturnsAfterDroppedBody22=== PAUSE TestUploadMultipart_ReturnsAfterDroppedBody23=== RUN TestPartSizeForNAR24=== PAUSE TestPartSizeForNAR25=== RUN TestDumpPathCaseHackMatchesNix26--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)27=== RUN TestDumpPathCaseHackCollision28--- PASS: TestDumpPathCaseHackCollision (0.00s)29=== RUN TestDumpPathMatchesNix30=== PAUSE TestDumpPathMatchesNix31=== RUN TestDumpPathSingleFile32=== PAUSE TestDumpPathSingleFile33=== RUN TestDumpPathWriterError34=== PAUSE TestDumpPathWriterError35=== RUN TestEncodeNixBase3236=== PAUSE TestEncodeNixBase3237=== RUN TestEncodeNixBase32WithRealHash38=== PAUSE TestEncodeNixBase32WithRealHash39=== RUN TestConvertHashToNix3240=== PAUSE TestConvertHashToNix3241=== RUN TestGetStorePathHash42=== PAUSE TestGetStorePathHash43=== RUN TestPathInfoHashCompatibility44=== PAUSE TestPathInfoHashCompatibility45=== RUN TestParsePathInfoJSON46=== PAUSE TestParsePathInfoJSON47=== RUN TestParsePathInfoJSONMultiplePaths48=== PAUSE TestParsePathInfoJSONMultiplePaths49=== RUN TestPathInfoCACompatibility50=== PAUSE TestPathInfoCACompatibility51=== RUN TestRateLimiterFeedback52=== PAUSE TestRateLimiterFeedback53=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess54=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess55=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer56=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer57=== RUN TestRegisterUploadedObject_OutlivesPush58=== PAUSE TestRegisterUploadedObject_OutlivesPush59=== 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=== RUN TestUntrustedPaths116=== PAUSE TestUntrustedPaths117=== RUN TestUntrustedPathsContentAddressed118=== PAUSE TestUntrustedPathsContentAddressed119=== RUN TestParsePathInfoUltimate120=== PAUSE TestParsePathInfoUltimate121=== CONT TestDoServerRequestAttachesToken122=== CONT TestScriptTokenBadJSON123=== CONT TestResolveStorePath124=== CONT TestScriptTokenEmptyToken125=== CONT TestScriptTokenCachesUntilRefresh126=== CONT TestScriptTokenNoExpiryRerunsEveryCall127--- PASS: TestDoServerRequestAttachesToken (0.00s)128=== CONT TestFileTokenEmpty129=== CONT TestFileTokenReadsAndCaches130=== CONT TestStaticToken131=== CONT TestUploadMultipart_PartsInParallel132=== CONT TestSetClientTLSErrors133=== CONT TestSetClientTLSDoesNotMutateDefaultTransport134=== CONT TestSetClientTLS135=== CONT TestStreamPushStopsWhenCanceled136=== CONT TestClientSignaturesByStorePath137=== CONT TestStreamPushReportsEveryPath138=== CONT TestShellSplitErrors139=== CONT TestShellSplit140=== CONT TestDoWithRetry_FinalResponseBodyReadable141=== CONT TestRetryTimeoutOutlastsMaxRetries142=== CONT TestStreamPushBatchesUnderLoad143=== CONT TestDoWithRetry_BodyReplayedViaGetBody144=== CONT TestStreamPushReportsSkippedPaths145=== CONT TestStreamPushRequestLine146=== CONT TestStreamPushGivesUpOnDeadServer147=== CONT TestFileTokenMissing148--- PASS: TestFileTokenEmpty (0.00s)149=== CONT TestStreamPushReportsSignatures150=== CONT TestStreamPushIsolatesFailures151=== CONT TestEncodeNixBase32152=== RUN TestEncodeNixBase32/test_string_hash153=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer154=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false155=== CONT TestDumpPathSingleFile156=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess157--- PASS: TestResolveStorePath (0.00s)158--- PASS: TestFileTokenReadsAndCaches (0.00s)159--- PASS: TestStaticToken (0.00s)160--- PASS: TestShellSplitErrors (0.00s)161=== PAUSE TestEncodeNixBase32/test_string_hash162=== CONT TestRegisterUploadedObject_OutlivesPush163=== CONT TestRateLimiterFeedback164--- PASS: TestShellSplit (0.00s)165--- PASS: TestScriptTokenEmptyToken (0.00s)166=== CONT TestDumpPathWriterError167=== RUN TestEncodeNixBase32/empty_input168--- PASS: TestScriptTokenBadJSON (0.00s)169--- PASS: TestClientSignaturesByStorePath (0.00s)170--- PASS: TestStreamPushStopsWhenCanceled (0.00s)1712026/11/10 21:11:42 WARN Rate limiter enabled after throttle name=server-test rate=5172--- PASS: TestFileTokenMissing (0.00s)173--- PASS: TestStreamPushReportsSkippedPaths (0.00s)174=== CONT TestPathInfoCACompatibility175=== RUN TestPathInfoCACompatibility/null_ca_field176=== PAUSE TestPathInfoCACompatibility/null_ca_field177=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false178=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true179=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true180=== RUN TestPathInfoCACompatibility/old_string_format_-_text181=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text182=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1832026/11/10 21:11:42 ERROR Upload failed error=boom count=1184=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive185--- PASS: TestStreamPushReportsEveryPath (0.03s)186--- PASS: TestStreamPushReportsSignatures (0.03s)187=== CONT TestParsePathInfoJSONMultiplePaths188=== RUN TestRateLimiterFeedback/429_enables_limiter189=== PAUSE TestRateLimiterFeedback/429_enables_limiter190=== RUN TestRateLimiterFeedback/503_enables_limiter1912026/11/10 21:11:42 ERROR Upload failed error="bad path" count=3192=== PAUSE TestRateLimiterFeedback/503_enables_limiter193=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter194=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter195=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter196--- PASS: TestStreamPushIsolatesFailures (0.03s)197=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths198=== CONT TestParsePathInfoJSON199=== RUN TestParsePathInfoJSON/Nix_format200=== PAUSE TestParsePathInfoJSON/Nix_format201=== RUN TestParsePathInfoJSON/Lix_format202=== PAUSE TestParsePathInfoJSON/Lix_format203=== RUN TestPathInfoCACompatibility/new_structured_format_-_text204=== CONT TestPartSizeForNAR2052026/11/10 21:11:42 ERROR Upload failed error="connection refused" count=202062026/11/10 21:11:42 ERROR Server seems unavailable, giving up on batch untried=17207=== RUN TestPartSizeForNAR/zero_stays_at_minimum208=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter209=== CONT TestUploadMultipart_ReturnsAfterDroppedBody210=== CONT TestScriptTokenEmptyCommand2112026/11/10 21:11:42 ERROR Upload failed error=boom count=1212=== CONT TestDumpPathMatchesNix2132026/11/10 21:11:42 WARN Rate limiter enabled after throttle name=server-test rate=5214=== CONT TestConvertHashToNix322152026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:442252162026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:39851217=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths218=== RUN TestParsePathInfoJSON/empty_input2192026/11/10 21:11:42 WARN Rate limiter backed off name=server-test rate=5220=== PAUSE TestEncodeNixBase32/empty_input2212026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:442252222026/11/10 21:11:42 WARN Rate limiter enabled after throttle name=server-test rate=5223=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text224=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum2252026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:33707226--- PASS: TestStreamPushGivesUpOnDeadServer (0.03s)227--- PASS: TestRegisterUploadedObject_OutlivesPush (0.00s)228=== CONT TestPathInfoHashCompatibility229=== CONT TestScriptTokenScriptFails2302026/11/10 21:11:42 WARN Rate limiter backed off name=server-test rate=5231=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)232=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)233=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths234=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths235=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun236=== CONT TestRegisterUploadedObjectReusesConnections237=== PAUSE TestParsePathInfoJSON/empty_input238=== RUN TestParsePathInfoJSON/whitespace_only239=== RUN TestConvertHashToNix32/SRI_format_to_Nix32240=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32241=== RUN TestConvertHashToNix32/already_Nix32_format242=== PAUSE TestConvertHashToNix32/already_Nix32_format243=== RUN TestConvertHashToNix32/invalid_format244=== PAUSE TestConvertHashToNix32/invalid_format245=== CONT TestEncodeNixBase32WithRealHash246=== CONT TestUntrustedPaths247=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica248=== CONT TestFilterOversizedClosures2492026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:39851250=== RUN TestFilterOversizedClosures/no_limit_keeps_everything251=== RUN TestUntrustedPaths/server_without_policy_accepts_anything252=== PAUSE TestUntrustedPaths/server_without_policy_accepts_anything253=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything254=== RUN TestUntrustedPaths/built_locally255=== PAUSE TestUntrustedPaths/built_locally256=== RUN TestUntrustedPaths/signed_by_the_server_key257=== PAUSE TestUntrustedPaths/signed_by_the_server_key258=== RUN TestUntrustedPaths/signed_by_an_upstream_key259=== PAUSE TestUntrustedPaths/signed_by_an_upstream_key260=== RUN TestUntrustedPaths/unsigned_substitute261=== PAUSE TestUntrustedPaths/unsigned_substitute262=== RUN TestUntrustedPaths/signed_only_by_another_key263=== PAUSE TestUntrustedPaths/signed_only_by_another_key264=== RUN TestUntrustedPaths/another_key's_signature_under_the_server_key_name265=== PAUSE TestUntrustedPaths/another_key's_signature_under_the_server_key_name266=== RUN TestUntrustedPaths/server_signature_over_different_contents267=== PAUSE TestUntrustedPaths/server_signature_over_different_contents268--- PASS: TestScriptTokenEmptyCommand (0.00s)269--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)270--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.03s)271--- PASS: TestEncodeNixBase32WithRealHash (0.00s)272--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.03s)273--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.00s)274=== CONT TestGetStorePathHash275=== RUN TestGetStorePathHash/valid_store_path276=== PAUSE TestGetStorePathHash/valid_store_path277=== RUN TestGetStorePathHash/basename_without_hyphen_should_error278=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error279=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error2802026/11/10 21:11:42 INFO Garbage collection started281=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error282=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error283=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error284=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped285=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped286=== RUN TestFilterOversizedClosures/all_closures_skipped287=== PAUSE TestFilterOversizedClosures/all_closures_skipped288=== CONT TestUntrustedPathsContentAddressed289--- PASS: TestUntrustedPathsContentAddressed (0.00s)290=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false291=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon292=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon293=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI294=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI295=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512296=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512297=== RUN TestSetClientTLS/rejects_connection_without_client_cert298=== RUN TestSetClientTLSErrors/missing_cert_file299=== PAUSE TestSetClientTLSErrors/missing_cert_file300=== RUN TestSetClientTLSErrors/missing_key_file301=== PAUSE TestSetClientTLSErrors/missing_key_file302=== RUN TestSetClientTLSErrors/missing_ca_file303=== PAUSE TestSetClientTLSErrors/missing_ca_file304=== RUN TestSetClientTLSErrors/invalid_ca_file305=== PAUSE TestSetClientTLSErrors/invalid_ca_file306=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry3072026/11/10 21:11:42 INFO Garbage collection started3082026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:39851309--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)310--- PASS: TestScriptTokenScriptFails (0.00s)311=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter312=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true313=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter314--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)315=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method316=== PAUSE TestParsePathInfoJSON/whitespace_only317=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert318=== RUN TestPartSizeForNAR/small_stays_at_minimum319=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method320=== RUN TestParsePathInfoJSON/invalid_JSON321=== PAUSE TestParsePathInfoJSON/invalid_JSON322=== CONT TestCaseHackSuffix323=== CONT TestEncodeNixBase32/empty_input324=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths325=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths326=== PAUSE TestPartSizeForNAR/small_stays_at_minimum327=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum328=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum329=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts330=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts331=== RUN TestPartSizeForNAR/1_TiB332=== CONT TestRateLimiterFeedback/429_enables_limiter3332026/11/10 21:11:42 WARN Rate limiter enabled after throttle name=s3-test rate=5334=== CONT TestConvertHashToNix32/SRI_format_to_Nix323352026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:43437336--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)337 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)338 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)3392026/11/10 21:11:42 WARN Rate limiter enabled after throttle name=server-test rate=5340=== CONT TestParsePathInfoUltimate3412026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:465153422026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:39851343=== CONT TestUntrustedPaths/another_key's_signature_under_the_server_key_name3442026/11/10 21:11:42 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=0345=== CONT TestEncodeNixBase32/test_string_hash3462026/11/10 21:11:42 WARN Rate limiter backed off name=server-test rate=5347=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA348=== CONT TestConvertHashToNix32/invalid_format349=== CONT TestRateLimiterFeedback/503_enables_limiter350=== CONT TestConvertHashToNix32/already_Nix32_format351=== CONT TestGetStorePathHash/valid_store_path352=== CONT TestUntrustedPaths/server_without_policy_accepts_anything353=== PAUSE TestPartSizeForNAR/1_TiB354=== CONT TestFilterOversizedClosures/no_limit_keeps_everything355=== CONT TestUntrustedPaths/server_signature_over_different_contents356--- PASS: TestStreamPushBatchesUnderLoad (0.03s)357 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)358 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)359=== CONT TestUntrustedPaths/built_locally360=== CONT TestSetClientTLSErrors/missing_cert_file361=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI3622026/11/10 21:11:42 WARN Rate limiter enabled after throttle name=server-test rate=5363=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon3642026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:33285365=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error3662026/11/10 21:11:42 WARN Rate limiter backed off name=server-test rate=5367=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA3682026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:39851369=== CONT TestUntrustedPaths/unsigned_substitute3702026/11/10 21:11:42 WARN Garbage collection finished on another replica. Its statistics are not available here371=== CONT TestSetClientTLSErrors/invalid_ca_file372=== CONT TestUntrustedPaths/signed_by_an_upstream_key373=== CONT TestPathInfoCACompatibility/null_ca_field374=== CONT TestParsePathInfoJSON/Nix_format375=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive376=== CONT TestPathInfoCACompatibility/old_string_format_-_text377=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method378--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)379=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)380=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error381=== RUN TestPartSizeForNAR/5_TiB_S3_max_object382=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object383=== RUN TestPartSizeForNAR/capped_at_5_GiB3842026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:39851385=== CONT TestGetStorePathHash/basename_without_hyphen_should_error386=== CONT TestUntrustedPaths/signed_only_by_another_key387=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512388=== CONT TestFilterOversizedClosures/all_closures_skipped389=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3902026/11/10 21:11:42 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50391=== RUN TestSetClientTLS/preserves_debug_logging_transport392=== CONT TestSetClientTLSErrors/missing_ca_file393=== CONT TestUntrustedPaths/signed_by_the_server_key394=== CONT TestPathInfoCACompatibility/new_structured_format_-_text3952026/11/10 21:11:42 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=2000396=== CONT TestSetClientTLSErrors/missing_key_file397=== CONT TestParsePathInfoJSON/whitespace_only398--- PASS: TestParsePathInfoUltimate (0.00s)399=== CONT TestParsePathInfoJSON/invalid_JSON400=== CONT TestParsePathInfoJSON/empty_input401=== PAUSE TestPartSizeForNAR/capped_at_5_GiB402=== CONT TestParsePathInfoJSON/Lix_format403=== PAUSE TestSetClientTLS/preserves_debug_logging_transport404=== CONT TestSetClientTLS/rejects_connection_without_client_cert4052026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:39851406=== CONT TestSetClientTLS/preserves_debug_logging_transport407=== CONT TestPartSizeForNAR/zero_stays_at_minimum408=== CONT TestPartSizeForNAR/5_TiB_S3_max_object409=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum410=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts411=== CONT TestPartSizeForNAR/capped_at_5_GiB412=== CONT TestPartSizeForNAR/small_stays_at_minimum413=== CONT TestPartSizeForNAR/1_TiB414--- PASS: TestEncodeNixBase32 (0.03s)415 --- PASS: TestEncodeNixBase32/empty_input (0.00s)416 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)417--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.00s)418=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA419--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)420--- PASS: TestGetStorePathHash (0.00s)421 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)422 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)423 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)424 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)425--- PASS: TestPartSizeForNAR (0.01s)426 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)427 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)428 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)429 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)430 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)431 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)432 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)4332026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:39851434--- PASS: TestConvertHashToNix32 (0.00s)435 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)436 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)437 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)438--- PASS: TestRateLimiterFeedback (0.00s)439 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)440 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)441 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)442 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)443--- PASS: TestSetClientTLSErrors (0.03s)444 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)445 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)446 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)447 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)448--- PASS: TestFilterOversizedClosures (0.00s)449 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)450 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)451 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)452--- PASS: TestParsePathInfoJSON (0.00s)453 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)454 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)455 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)456 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)457 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)458--- PASS: TestPathInfoCACompatibility (0.01s)459 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)460 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)461 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)462 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)463 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)464--- PASS: TestPathInfoHashCompatibility (0.00s)465 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)466 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)467 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)468 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)469--- PASS: TestUntrustedPaths (0.00s)470 --- PASS: TestUntrustedPaths/server_without_policy_accepts_anything (0.00s)471 --- PASS: TestUntrustedPaths/built_locally (0.00s)472 --- PASS: TestUntrustedPaths/server_signature_over_different_contents (0.00s)473 --- PASS: TestUntrustedPaths/another_key's_signature_under_the_server_key_name (0.00s)474 --- PASS: TestUntrustedPaths/unsigned_substitute (0.00s)475 --- PASS: TestUntrustedPaths/signed_by_an_upstream_key (0.00s)476 --- PASS: TestUntrustedPaths/signed_only_by_another_key (0.00s)477 --- PASS: TestUntrustedPaths/signed_by_the_server_key (0.00s)4782026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:398514792026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:39851480--- PASS: TestStreamPushRequestLine (0.05s)4812026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:398514822026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:398514832026/11/10 21:11:42 http: TLS handshake error from 127.0.0.1:55604: remote error: tls: bad certificate4842026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:39851485--- PASS: TestDumpPathSingleFile (0.06s)486--- PASS: TestSetClientTLS (0.05s)487 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)488 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)489 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)4902026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:398514912026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:398514922026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:398514932026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:398514942026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:39851495--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)4962026/11/10 21:11:42 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:39851497--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.07s)498--- PASS: TestDumpPathWriterError (0.07s)499--- PASS: TestCaseHackSuffix (0.04s)500--- PASS: TestDumpPathMatchesNix (0.10s)5012026/11/10 21:11:42 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:33037/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:33037/api/uploads/complete5022026/11/10 21:11:42 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"5032026/11/10 21:11:42 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:33037/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:33037/api/uploads/complete5042026/11/10 21:11:42 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"5052026/11/10 21:11:42 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:33037/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:33037/api/uploads/complete5062026/11/10 21:11:42 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"507--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.13s)508--- PASS: TestUploadMultipart_PartsInParallel (0.66s)509--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)510PASS511Running server tests...512The files belonging to this database system will be owned by user "nixbld".513This user must also own the server process.514515The database cluster will be initialized with locale "C".516The default database encoding has accordingly been set to "SQL_ASCII".517The default text search configuration will be set to "english".518519Data page checksums are enabled.520521creating directory /build/postgres452874703/data ... ok522creating subdirectories ... ok523selecting dynamic shared memory implementation ... posix524selecting default "max_connections" ... 100525selecting default "shared_buffers" ... 128MB526selecting default time zone ... UTC527creating configuration files ... ok528running bootstrap script ... ok529performing post-bootstrap initialization ... ok530syncing data to disk ... ok531532initdb: warning: enabling "trust" authentication for local connections533initdb: 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.534535Success. You can now start the database server using:536537 pg_ctl -D /build/postgres452874703/data -l logfile start538539/build/postgres452874703:5432 - no response5402026-11-10 21:11:44.652 UTC [130] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5412026-11-10 21:11:44.653 UTC [130] LOG: listening on Unix socket "/build/postgres452874703/.s.PGSQL.5432"5422026-11-10 21:11:44.657 UTC [137] LOG: database system was shut down at 2026-11-10 21:11:44 UTC5432026-11-10 21:11:44.661 UTC [130] LOG: database system is ready to accept connections544/build/postgres452874703:5432 - accepting connections545{"timestamp":"2026-11-10T21:11:45.071729423Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"e2672e95-f1eb-4150-aa56-f134082a4ec9","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":5,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(400)"}546=== RUN TestAbortSucceeded547=== PAUSE TestAbortSucceeded548=== RUN TestService_AuthMiddleware549=== PAUSE TestService_AuthMiddleware550=== RUN TestService_AuthMiddleware_MTLSProxyHeader551=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader552=== RUN TestService_AuthMiddleware_MTLSBoundSubjects553=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects554=== RUN TestService_ReadAuthMiddleware555=== PAUSE TestService_ReadAuthMiddleware556=== RUN TestService_AuthMiddleware_OIDC557=== PAUSE TestService_AuthMiddleware_OIDC558=== RUN TestService_RequireScope_OIDC559=== PAUSE TestService_RequireScope_OIDC560=== RUN TestService_ReadScope_PublicByDefault561=== PAUSE TestService_ReadScope_PublicByDefault562=== RUN TestCacheConfigHandler563=== PAUSE TestCacheConfigHandler564=== RUN TestCacheStatsHandler565=== PAUSE TestCacheStatsHandler566=== RUN TestClientCADerivations567=== PAUSE TestClientCADerivations568=== RUN TestClientErrorHandling569=== PAUSE TestClientErrorHandling570=== RUN TestClientIntegration571=== PAUSE TestClientIntegration572=== RUN TestClientMultipleUploads573=== PAUSE TestClientMultipleUploads574=== RUN TestClientWithDependencies575=== PAUSE TestClientWithDependencies576=== RUN TestClientSharedPathCommittedMidPush577=== PAUSE TestClientSharedPathCommittedMidPush578=== RUN TestPinProtectsFromGC579=== PAUSE TestPinProtectsFromGC580=== RUN TestClientPushesUseOnePush581=== PAUSE TestClientPushesUseOnePush582=== RUN TestClientFallsBackToClosures583=== PAUSE TestClientFallsBackToClosures584=== RUN TestDeleteClosuresRacingPins585=== PAUSE TestDeleteClosuresRacingPins586=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock587=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock588=== RUN TestResolveDBConnectionString589=== PAUSE TestResolveDBConnectionString590=== RUN TestConnectWaitsForAPeerMigration591=== PAUSE TestConnectWaitsForAPeerMigration592=== RUN TestLeadElectsOneAndHandsOver593=== PAUSE TestLeadElectsOneAndHandsOver594=== RUN TestLeadIncumbentWinsAfterRestart5952026/11/10 21:11:45 INFO lead: acquired remote=192.0.2.1:12345962026/11/10 21:11:45 INFO lead: released remote=192.0.2.1:12345972026/11/10 21:11:45 INFO lead: acquired remote=192.0.2.1:12345982026/11/10 21:11:47 INFO lead: released remote=192.0.2.1:1234599--- PASS: TestLeadIncumbentWinsAfterRestart (1.85s)600=== RUN TestLeadIncumbentAnnouncesAtOnce601=== PAUSE TestLeadIncumbentAnnouncesAtOnce602=== RUN TestLeadEndsOnShutdown603=== PAUSE TestLeadEndsOnShutdown604=== RUN TestLeadEndsWhenItsConnectionHangs6052026/11/10 21:11:47 INFO lead: acquired remote=192.0.2.1:12346062026-11-10 21:11:48.547 UTC [578] FATAL: terminating connection due to administrator command6072026/11/10 21:11:48 INFO lead: acquired remote=192.0.2.1:12346082026/11/10 21:11:49 WARN lead: lock connection lost error="timeout: context deadline exceeded"6092026/11/10 21:11:49 INFO lead: released remote=192.0.2.1:12346102026/11/10 21:11:50 INFO lead: released remote=192.0.2.1:1234611--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)612=== RUN TestGCAdvisoryLockBlocksConcurrentRun613=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun614=== RUN TestGCBugBareHashReferences615=== PAUSE TestGCBugBareHashReferences616=== RUN TestGCMetrics617=== PAUSE TestGCMetrics618=== RUN TestPushDedupSurvivesConcurrentGC619=== PAUSE TestPushDedupSurvivesConcurrentGC620=== RUN TestDeduplicatedObjectsRecordedAsPending621=== PAUSE TestDeduplicatedObjectsRecordedAsPending622=== RUN TestGCSweepSkipsPendingObjects623=== PAUSE TestGCSweepSkipsPendingObjects624=== RUN TestTombstonedObjectOfferedWithoutWaiting625=== PAUSE TestTombstonedObjectOfferedWithoutWaiting626=== RUN TestGCSweepDeliversEachKeyOnce627=== PAUSE TestGCSweepDeliversEachKeyOnce628=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection629=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection630=== RUN TestForceGCDuringPushOffersSweptObject631=== PAUSE TestForceGCDuringPushOffersSweptObject632=== RUN TestFailedS3DeleteKeepsTombstone633=== PAUSE TestFailedS3DeleteKeepsTombstone634=== RUN TestSweepSkipsRowsLockedByPush635=== PAUSE TestSweepSkipsRowsLockedByPush636=== RUN TestRegisterCompletedObjectNeedsPendingRow637=== PAUSE TestRegisterCompletedObjectNeedsPendingRow638=== RUN TestGetExistingObjectsLocksRows639=== PAUSE TestGetExistingObjectsLocksRows640=== RUN TestSweepRechecksPendingAfterLocking641=== PAUSE TestSweepRechecksPendingAfterLocking642=== RUN TestPushWaitsForSweepHoldingRow643=== PAUSE TestPushWaitsForSweepHoldingRow644=== RUN TestCommitRacingPendingCleanupKeepsObjects645=== PAUSE TestCommitRacingPendingCleanupKeepsObjects646=== RUN TestGCEndsOnShutdown647=== PAUSE TestGCEndsOnShutdown648=== RUN TestGCTaskStore_StartNew649=== PAUSE TestGCTaskStore_StartNew650=== RUN TestGCTaskStore_DeduplicateSameParams651=== PAUSE TestGCTaskStore_DeduplicateSameParams652=== RUN TestGCTaskStore_ConflictDifferentParams653=== PAUSE TestGCTaskStore_ConflictDifferentParams654=== RUN TestGCTaskStore_GetEmpty655=== PAUSE TestGCTaskStore_GetEmpty656=== RUN TestGCTaskStore_GetReturnsLatest657=== PAUSE TestGCTaskStore_GetReturnsLatest658=== RUN TestGCTaskStore_CompletedAllowsNewTask659=== PAUSE TestGCTaskStore_CompletedAllowsNewTask660=== RUN TestGCTaskStore_PhaseUpdates661=== PAUSE TestGCTaskStore_PhaseUpdates662=== RUN TestGCTaskStore_Fail663=== PAUSE TestGCTaskStore_Fail664=== RUN TestGracefulShutdownDrainsInflight665=== PAUSE TestGracefulShutdownDrainsInflight666=== RUN TestService_healthCheckHandler667=== PAUSE TestService_healthCheckHandler668=== RUN TestService_readinessHandler669=== PAUSE TestService_readinessHandler670=== RUN TestGenerateLandingPage671=== PAUSE TestGenerateLandingPage672=== RUN TestEnsureAbortUploadsRule673=== PAUSE TestEnsureAbortUploadsRule674=== RUN TestCacheConfigHandlerMaxNarSize675=== PAUSE TestCacheConfigHandlerMaxNarSize676=== RUN TestCreatePendingClosureRejectsOversizedNAR677=== PAUSE TestCreatePendingClosureRejectsOversizedNAR678=== RUN TestNARDeduplicationMetadataUploadBug679=== PAUSE TestNARDeduplicationMetadataUploadBug680=== RUN TestMetricsInventory681=== PAUSE TestMetricsInventory682=== RUN TestMetricsCommit683=== PAUSE TestMetricsCommit684=== RUN TestService_NativeMTLS685=== PAUSE TestService_NativeMTLS686=== RUN TestServerTLSConfig687=== PAUSE TestServerTLSConfig688=== RUN TestMultipartCleanup689=== PAUSE TestMultipartCleanup690=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded691=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded692=== RUN TestPendingCleanupUsesOneCutoff693=== PAUSE TestPendingCleanupUsesOneCutoff694=== RUN TestObjectStatsTrigger695=== PAUSE TestObjectStatsTrigger696=== RUN TestObjectStatsUpdatedOncePerCommit697=== PAUSE TestObjectStatsUpdatedOncePerCommit698=== RUN TestOrphanedObjectsGC699=== PAUSE TestOrphanedObjectsGC700=== RUN TestOrphanedObjectsGCStressTest701=== PAUSE TestOrphanedObjectsGCStressTest702=== RUN TestCreatePin_ReservedPins703=== PAUSE TestCreatePin_ReservedPins704=== RUN TestPresentReportsOnlyClosureRoots705=== PAUSE TestPresentReportsOnlyClosureRoots706=== RUN TestPresentRefreshesOnlyStaleClosures707=== PAUSE TestPresentRefreshesOnlyStaleClosures708=== RUN TestPresentNotReportedWhileGCDeletesClosure709=== PAUSE TestPresentNotReportedWhileGCDeletesClosure710=== RUN TestParseSingleRange711=== PAUSE TestParseSingleRange712=== RUN TestProxyHeadersOnlyTrustedOnSocket7132026/11/10 21:11:50 INFO Starting HTTP server address=127.0.0.1:418457142026/11/10 21:11:50 INFO Starting HTTP server address=proxy.sock7152026/11/10 21:11:50 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7162026/11/10 21:11:50 INFO Shutdown signal received, draining in-flight requests timeout=10s717--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.11s)718=== RUN TestIsValidCachePath719=== PAUSE TestIsValidCachePath720=== RUN TestReadProxyNarinfo721=== PAUSE TestReadProxyNarinfo722=== RUN TestReadProxyNarinfoAlreadyDecompressed723=== PAUSE TestReadProxyNarinfoAlreadyDecompressed724=== RUN TestReadProxyContentNegotiation725=== PAUSE TestReadProxyContentNegotiation726=== RUN TestReadProxyNarStreaming727=== PAUSE TestReadProxyNarStreaming728=== RUN TestReadProxy404729=== PAUSE TestReadProxy404730=== RUN TestReadProxyInvalidPath731=== PAUSE TestReadProxyInvalidPath732=== RUN TestReadProxyHead733=== PAUSE TestReadProxyHead734=== RUN TestReadProxyOutlastsServerWriteTimeout735=== PAUSE TestReadProxyOutlastsServerWriteTimeout736=== RUN TestReadProxyConditionalGet737=== PAUSE TestReadProxyConditionalGet738=== RUN TestReadProxyRootRedirectsToIndexHTML739=== PAUSE TestReadProxyRootRedirectsToIndexHTML740=== RUN TestReadProxyDisabled741=== PAUSE TestReadProxyDisabled742=== RUN TestReadRedirectNar743=== PAUSE TestReadRedirectNar744=== RUN TestReadRedirectKeepsNarinfoProxied745=== PAUSE TestReadRedirectKeepsNarinfoProxied746=== RUN TestReadProxyRangeRequest747=== PAUSE TestReadProxyRangeRequest748=== RUN TestReadRedirectUsesPublicS3URL749=== PAUSE TestReadRedirectUsesPublicS3URL750=== RUN TestPush_OverlappingRootsStoreOneRowPerKey751=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey752=== RUN TestPush_CompleteCommitsEveryRoot753=== PAUSE TestPush_CompleteCommitsEveryRoot754=== RUN TestPush_RepeatedRootCommitsOnce755=== PAUSE TestPush_RepeatedRootCommitsOnce756=== RUN TestPush_CompleteWaitsForCleanupOfThePush757=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush758=== RUN TestPush_RootsAreLockedInByteOrder759=== PAUSE TestPush_RootsAreLockedInByteOrder760=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit761=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit762=== RUN TestPush_RejectsBadRequests763=== PAUSE TestPush_RejectsBadRequests764=== RUN TestPush_SignsNarinfosOfItsPendingObjects765=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects766=== RUN TestSharedNarBothUploadsComplete767=== PAUSE TestSharedNarBothUploadsComplete768=== RUN TestCompleteMultipartUpload_ErrorButObjectExists769=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists770=== RUN TestCompletedNarNotReofferedAcrossClosures771=== PAUSE TestCompletedNarNotReofferedAcrossClosures772=== RUN TestPresignedUploadRegisteredBeforeCommit773=== PAUSE TestPresignedUploadRegisteredBeforeCommit774=== RUN TestService_Rustfstest775=== PAUSE TestService_Rustfstest776=== RUN TestParseSize777=== PAUSE TestParseSize778=== RUN TestSkippedUploadsHandler779=== PAUSE TestSkippedUploadsHandler780=== RUN TestSystemdListenerNotActivated781--- PASS: TestSystemdListenerNotActivated (0.00s)782=== RUN TestWatchdogBeatsWhenHealthy783--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)784=== RUN TestWatchdogSkipsWhenUnhealthy7852026/11/10 21:11:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7862026/11/10 21:11:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7872026/11/10 21:11:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7882026/11/10 21:11:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7892026/11/10 21:11:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7902026/11/10 21:11:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7912026/11/10 21:11:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7922026/11/10 21:11:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7932026/11/10 21:11:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"794--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)795=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle796=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle797=== RUN TestProxyWriteTimeout798=== PAUSE TestProxyWriteTimeout799=== RUN TestPendingClosureWriteTimeout800=== PAUSE TestPendingClosureWriteTimeout801=== RUN TestIsValidUploadKey802=== PAUSE TestIsValidUploadKey803=== RUN TestUploadHandlersRejectInvalidKeys804=== PAUSE TestUploadHandlersRejectInvalidKeys805=== RUN TestUploadHandlersRejectOversizedBody806=== PAUSE TestUploadHandlersRejectOversizedBody807=== RUN TestService_cleanupPendingClosuresHandler808=== PAUSE TestService_cleanupPendingClosuresHandler809=== RUN TestService_createPendingClosureHandler810=== PAUSE TestService_createPendingClosureHandler811=== RUN TestService_verifyS3Integrity812=== PAUSE TestService_verifyS3Integrity813=== RUN TestService_verifyS3ReuploadsStaleNarinfo814=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo815=== RUN TestCompleteMultipartUnregistered816=== PAUSE TestCompleteMultipartUnregistered817=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT818=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT819=== CONT TestAbortSucceeded820=== CONT TestProxyWriteTimeout821--- PASS: TestAbortSucceeded (0.00s)822=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT823=== CONT TestCompleteMultipartUnregistered824=== CONT TestService_verifyS3ReuploadsStaleNarinfo825=== CONT TestService_verifyS3Integrity826=== CONT TestService_createPendingClosureHandler827=== CONT TestService_cleanupPendingClosuresHandler828=== CONT TestUploadHandlersRejectOversizedBody829=== CONT TestUploadHandlersRejectInvalidKeys830=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info831=== CONT TestIsValidUploadKey832=== CONT TestPendingClosureWriteTimeout833=== CONT TestParseSingleRange834=== CONT TestSweepSkipsRowsLockedByPush835=== CONT TestRegisterCompletedObjectNeedsPendingRow836=== CONT TestFailedS3DeleteKeepsTombstone837=== CONT TestPresentNotReportedWhileGCDeletesClosure838=== CONT TestForceGCDuringPushOffersSweptObject839=== CONT TestPresentRefreshesOnlyStaleClosures840=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection841=== CONT TestPresentReportsOnlyClosureRoots842=== CONT TestGCSweepDeliversEachKeyOnce843=== CONT TestCreatePin_ReservedPins844=== CONT TestTombstonedObjectOfferedWithoutWaiting845=== CONT TestOrphanedObjectsGCStressTest846=== RUN TestProxyWriteTimeout/narinfo847=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed848=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info849=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal850=== RUN TestPendingClosureWriteTimeout/empty851=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed852=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed853=== PAUSE TestPendingClosureWriteTimeout/empty854=== RUN TestPendingClosureWriteTimeout/400_objects855=== PAUSE TestPendingClosureWriteTimeout/400_objects856=== RUN TestPendingClosureWriteTimeout/670k_objects857=== RUN TestIsValidUploadKey/narinfo858=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale859=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows860=== RUN TestParseSingleRange/none861=== PAUSE TestProxyWriteTimeout/narinfo862=== RUN TestProxyWriteTimeout/1_GiB_nar863=== PAUSE TestPendingClosureWriteTimeout/670k_objects864=== PAUSE TestIsValidUploadKey/narinfo865=== RUN TestIsValidUploadKey/nar_zst866=== PAUSE TestIsValidUploadKey/nar_zst867=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale868=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows869=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check870=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check871=== PAUSE TestParseSingleRange/none872=== PAUSE TestProxyWriteTimeout/1_GiB_nar873=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed874=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal875=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline876=== RUN TestIsValidUploadKey/nar_xz877=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline878=== CONT TestGCSweepSkipsPendingObjects879=== RUN TestParseSingleRange/unknown_unit880=== PAUSE TestParseSingleRange/unknown_unit881=== RUN TestParseSingleRange/multi-range_ignored882=== PAUSE TestParseSingleRange/multi-range_ignored883=== RUN TestParseSingleRange/malformed_no_dash884=== PAUSE TestParseSingleRange/malformed_no_dash885=== RUN TestProxyWriteTimeout/10_GiB_nar886=== PAUSE TestProxyWriteTimeout/10_GiB_nar887=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost888=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key889=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh890=== PAUSE TestIsValidUploadKey/nar_xz891=== CONT TestOrphanedObjectsGC892=== RUN TestParseSingleRange/malformed_both_empty893=== PAUSE TestParseSingleRange/malformed_both_empty894=== RUN TestParseSingleRange/malformed_end_before_start895=== PAUSE TestParseSingleRange/malformed_end_before_start896=== RUN TestParseSingleRange/closed897=== RUN TestIsValidUploadKey/nar_plain898=== PAUSE TestIsValidUploadKey/nar_plain899=== RUN TestIsValidUploadKey/listing900=== PAUSE TestIsValidUploadKey/listing901=== RUN TestIsValidUploadKey/build_log902=== PAUSE TestIsValidUploadKey/build_log903=== RUN TestIsValidUploadKey/build_log_home-manager_file904=== PAUSE TestIsValidUploadKey/build_log_home-manager_file905=== RUN TestIsValidUploadKey/build_log_plus_in_name906=== PAUSE TestIsValidUploadKey/build_log_plus_in_name907=== RUN TestIsValidUploadKey/build_log_question_mark908=== PAUSE TestIsValidUploadKey/build_log_question_mark909=== RUN TestIsValidUploadKey/build_log_equals910=== PAUSE TestIsValidUploadKey/build_log_equals911=== RUN TestIsValidUploadKey/realisation912=== PAUSE TestIsValidUploadKey/realisation913=== RUN TestIsValidUploadKey/realisation_plus_in_output914=== PAUSE TestIsValidUploadKey/realisation_plus_in_output915=== RUN TestIsValidUploadKey/nix-cache-info916=== PAUSE TestParseSingleRange/closed917=== RUN TestProxyWriteTimeout/unknown_size918=== PAUSE TestProxyWriteTimeout/unknown_size919=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost920=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key921=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh922=== PAUSE TestIsValidUploadKey/nix-cache-info923=== RUN TestIsValidUploadKey/index.html924=== PAUSE TestIsValidUploadKey/index.html925=== RUN TestIsValidUploadKey/narinfo_key,_nar_type926=== RUN TestParseSingleRange/open-ended927=== CONT TestDeduplicatedObjectsRecordedAsPending928=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed929=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key930=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key931=== CONT TestObjectStatsUpdatedOncePerCommit932=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type933=== RUN TestIsValidUploadKey/nar_key,_narinfo_type934=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type935=== RUN TestIsValidUploadKey/listing_key,_narinfo_type936=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type937=== RUN TestIsValidUploadKey/traversal938=== PAUSE TestIsValidUploadKey/traversal939=== PAUSE TestParseSingleRange/open-ended940=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed941=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed942=== CONT TestPushDedupSurvivesConcurrentGC943=== RUN TestIsValidUploadKey/traversal_nar944=== PAUSE TestIsValidUploadKey/traversal_nar945=== RUN TestIsValidUploadKey/absolute946=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed947=== PAUSE TestIsValidUploadKey/absolute948=== CONT TestObjectStatsTrigger949=== RUN TestParseSingleRange/end_clamped_to_size950=== PAUSE TestParseSingleRange/end_clamped_to_size951=== RUN TestParseSingleRange/suffix952=== RUN TestIsValidUploadKey/empty_key953=== PAUSE TestIsValidUploadKey/empty_key954=== PAUSE TestParseSingleRange/suffix955=== RUN TestIsValidUploadKey/unknown_type956=== PAUSE TestIsValidUploadKey/unknown_type957=== CONT TestGCMetrics958=== RUN TestParseSingleRange/suffix_exceeds_size959=== PAUSE TestParseSingleRange/suffix_exceeds_size960=== RUN TestParseSingleRange/single_byte961=== PAUSE TestParseSingleRange/single_byte962=== RUN TestParseSingleRange/start_past_EOF963=== PAUSE TestParseSingleRange/start_past_EOF964=== RUN TestParseSingleRange/start_far_past_EOF965=== PAUSE TestParseSingleRange/start_far_past_EOF966=== CONT TestPendingCleanupUsesOneCutoff9672026/11/10 21:11:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33997/oidc968=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure969=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure970=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart971=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart972=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts973=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts974=== CONT TestGCBugBareHashReferences9752026/11/10 21:11:50 INFO Received uploads request method=POST path=/api/pending_closures976--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.40s)977=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded9782026/11/10 21:11:50 INFO Received cleanup request method=DELETE path=/api/pending_closures9792026/11/10 21:11:50 INFO Aborted multipart uploads count=0 kept=09802026/11/10 21:11:50 INFO Received uploads request method=POST path=/api/pending_closures9812026/11/10 21:11:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9822026/11/10 21:11:50 INFO Received cleanup request method=DELETE path=/api/pending_closures9832026/11/10 21:11:50 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst984--- PASS: TestCompleteMultipartUnregistered (0.43s)985=== CONT TestGCAdvisoryLockBlocksConcurrentRun9862026/11/10 21:11:50 INFO Aborted multipart uploads count=1 kept=09872026/11/10 21:11:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9882026-11-10 21:11:50.927 UTC [649] ERROR: Closure does not exist: id=19892026-11-10 21:11:50.927 UTC [649] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9902026-11-10 21:11:50.927 UTC [649] STATEMENT: -- name: CommitPendingClosure :one991 SELECT commit_pending_closure($1::bigint)::bigint992 993--- PASS: TestService_cleanupPendingClosuresHandler (0.44s)994=== CONT TestMultipartCleanup9952026/11/10 21:11:50 INFO Received uploads request method=POST path=/api/pending_closures9962026/11/10 21:11:50 INFO Received uploads request method=POST path=/api/pending_closures9972026/11/10 21:11:50 INFO Received uploads request method=POST path=/api/pending_closures9982026/11/10 21:11:50 INFO Received uploads request method=POST path=/api/pending_closures999--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.51s)1000=== CONT TestLeadEndsOnShutdown10012026/11/10 21:11:51 INFO Received uploads request method=POST path=/api/pending_closures1002--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.55s)1003=== CONT TestServerTLSConfig1004=== RUN TestServerTLSConfig/no_client_CA1005=== PAUSE TestServerTLSConfig/no_client_CA1006=== RUN TestServerTLSConfig/missing_CA_file1007=== PAUSE TestServerTLSConfig/missing_CA_file1008=== RUN TestServerTLSConfig/not_a_PEM_file1009=== PAUSE TestServerTLSConfig/not_a_PEM_file1010=== CONT TestLeadIncumbentAnnouncesAtOnce10112026/11/10 21:11:51 INFO Received uploads request method=POST path=/api/pending_closures1012--- PASS: TestPresentReportsOnlyClosureRoots (0.61s)1013=== CONT TestService_NativeMTLS10142026/11/10 21:11:51 INFO Received uploads request method=POST path=/api/pending_closures10152026/11/10 21:11:51 INFO Aborted multipart uploads count=0 kept=010162026/11/10 21:11:51 WARN Force mode enabled - objects will be deleted immediately without grace period10172026/11/10 21:11:51 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10182026/11/10 21:11:51 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1019--- PASS: TestFailedS3DeleteKeepsTombstone (0.68s)1020=== CONT TestLeadElectsOneAndHandsOver1021--- PASS: TestPresentRefreshesOnlyStaleClosures (0.70s)1022=== CONT TestMetricsCommit10232026/11/10 21:11:51 INFO Aborted multipart uploads count=0 kept=010242026/11/10 21:11:51 WARN Force mode enabled - objects will be deleted immediately without grace period10252026/11/10 21:11:51 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010262026/11/10 21:11:51 INFO Vacuumed table table=pending_closures10272026/11/10 21:11:51 INFO Vacuumed table table=pending_objects10282026/11/10 21:11:51 INFO Vacuumed table table=multipart_uploads10292026/11/10 21:11:51 INFO Vacuumed table table=closures10302026/11/10 21:11:51 INFO Received uploads request method=POST path=/api/pending_closures10312026/11/10 21:11:51 INFO Vacuumed table table=objects10322026/11/10 21:11:51 INFO Aborted multipart uploads count=0 kept=010332026/11/10 21:11:51 WARN Force mode enabled - objects will be deleted immediately without grace period10342026/11/10 21:11:51 INFO Aborted multipart uploads count=0 kept=010352026/11/10 21:11:51 WARN Force mode enabled - objects will be deleted immediately without grace period10362026/11/10 21:11:51 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010372026/11/10 21:11:51 INFO Vacuumed table table=pending_closures10382026/11/10 21:11:51 INFO Vacuumed table table=pending_objects10392026/11/10 21:11:51 INFO Vacuumed table table=multipart_uploads10402026/11/10 21:11:51 INFO Vacuumed table table=closures10412026/11/10 21:11:51 INFO Vacuumed table table=objects1042--- PASS: TestGCSweepSkipsPendingObjects (0.73s)1043=== CONT TestConnectWaitsForAPeerMigration10442026/11/10 21:11:51 INFO Aborted multipart uploads count=0 kept=010452026/11/10 21:11:51 WARN Force mode enabled - objects will be deleted immediately without grace period10462026/11/10 21:11:51 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=010472026/11/10 21:11:51 INFO Vacuumed table table=pending_closures10482026/11/10 21:11:51 INFO Vacuumed table table=pending_objects10492026/11/10 21:11:51 INFO Vacuumed table table=multipart_uploads10502026/11/10 21:11:51 INFO Vacuumed table table=closures10512026/11/10 21:11:51 INFO Vacuumed table table=objects1052--- PASS: TestSweepSkipsRowsLockedByPush (0.82s)1053=== CONT TestMetricsInventory10542026/11/10 21:11:51 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=010552026/11/10 21:11:51 INFO Vacuumed table table=pending_closures10562026/11/10 21:11:51 INFO Vacuumed table table=pending_objects10572026/11/10 21:11:51 INFO Vacuumed table table=multipart_uploads10582026/11/10 21:11:51 INFO Vacuumed table table=closures10592026/11/10 21:11:51 INFO Vacuumed table table=objects1060--- PASS: TestGCSweepDeliversEachKeyOnce (0.86s)1061=== CONT TestResolveDBConnectionString1062=== RUN TestResolveDBConnectionString/flag_wins1063=== PAUSE TestResolveDBConnectionString/flag_wins1064=== RUN TestResolveDBConnectionString/file_when_flag_empty1065=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1066=== RUN TestResolveDBConnectionString/missing_file_is_an_error1067=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1068=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1069=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1070=== RUN TestResolveDBConnectionString/nothing_configured1071=== PAUSE TestResolveDBConnectionString/nothing_configured1072=== CONT TestNARDeduplicationMetadataUploadBug1073--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.87s)1074=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10752026/11/10 21:11:51 INFO Aborted multipart uploads count=0 kept=010762026/11/10 21:11:51 WARN Force mode enabled - objects will be deleted immediately without grace period10772026/11/10 21:11:51 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010782026/11/10 21:11:51 INFO Vacuumed table table=pending_closures10792026/11/10 21:11:51 INFO Vacuumed table table=pending_objects10802026/11/10 21:11:51 INFO Vacuumed table table=multipart_uploads10812026/11/10 21:11:51 INFO Vacuumed table table=closures10822026/11/10 21:11:51 INFO Vacuumed table table=objects1083--- PASS: TestGCMetrics (0.82s)1084=== CONT TestCreatePendingClosureRejectsOversizedNAR10852026/11/10 21:11:51 INFO Received uploads request method=POST path=/api/pending_closures1086--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1087=== CONT TestCacheConfigHandlerMaxNarSize1088--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1089=== CONT TestDeleteClosuresRacingPins10902026/11/10 21:11:51 INFO Received uploads request method=POST path=/api/pending_closures10912026/11/10 21:11:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10922026/11/10 21:11:51 WARN Refused reserved pin name=worker-x86_64-linux10932026/11/10 21:11:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10942026/11/10 21:11:51 INFO Received create pin request method=POST path=/api/pins/my-app10952026/11/10 21:11:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1096--- PASS: TestCreatePin_ReservedPins (0.93s)1097=== CONT TestEnsureAbortUploadsRule10982026/11/10 21:11:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10992026/11/10 21:11:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11002026/11/10 21:11:51 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NjcwYWZhMTItOWMyOS00OGM1LWE0MTktNjE3YzlmMDJjZDRjLmUxZTE0MjBhLWI5NWQtNDMxOS1iYjcwLWM0ZDRiZjIwMmVkMHgxNzk0MzQ1MTEwOTUyMTMyODA4 parts=1011012026/11/10 21:11:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11022026/11/10 21:11:51 INFO Completed upload id=1 objects=2 duration=4.498997ms11032026/11/10 21:11:51 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011042026/11/10 21:11:51 INFO Received uploads request method=POST path=/api/pending_closures11052026/11/10 21:11:51 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NjcwYWZhMTItOWMyOS00OGM1LWE0MTktNjE3YzlmMDJjZDRjLjEwM2U1NjJlLWZmZDgtNDFkZi04NjJkLThiZjk1OTZjODk2YXgxNzk0MzQ1MTEwOTc4NDYyNjQw parts=1011062026/11/10 21:11:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11072026/11/10 21:11:51 INFO Starting cleanup of old closures method=DELETE path=/api/closures11082026/11/10 21:11:51 INFO Completed upload id=1 objects=2 duration=4.374547ms1109--- PASS: TestObjectStatsTrigger (0.90s)1110=== CONT TestClientFallsBackToClosures11112026/11/10 21:11:51 INFO Received uploads request method=POST path=/api/pending_closures11122026/11/10 21:11:51 INFO Received uploads request method=POST path=/api/pending_closures11132026/11/10 21:11:51 INFO Aborted multipart uploads count=0 kept=011142026/11/10 21:11:51 INFO Received uploads request method=POST path=/api/pending_closures11152026/11/10 21:11:51 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11162026/11/10 21:11:51 WARN Found objects in DB but missing from S3, will re-upload count=11117--- PASS: TestService_verifyS3Integrity (1.00s)1118=== CONT TestGenerateLandingPage11192026/11/10 21:11:51 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=01120--- PASS: TestGenerateLandingPage (0.00s)1121=== CONT TestClientPushesUseOnePush11222026/11/10 21:11:51 INFO Vacuumed table table=pending_closures11232026/11/10 21:11:51 INFO Received uploads request method=POST path=/api/pending_closures11242026/11/10 21:11:51 INFO Vacuumed table table=pending_objects11252026/11/10 21:11:51 INFO Aborted multipart uploads count=0 kept=011262026/11/10 21:11:51 INFO Vacuumed table table=multipart_uploads11272026/11/10 21:11:51 INFO Vacuumed table table=closures11282026/11/10 21:11:51 INFO Vacuumed table table=objects11292026/11/10 21:11:51 INFO Received cleanup request method=DELETE path=/api/pending_closures11302026/11/10 21:11:51 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=011312026/11/10 21:11:51 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001132--- PASS: TestService_createPendingClosureHandler (1.03s)1133=== CONT TestService_readinessHandler11342026/11/10 21:11:51 INFO Vacuumed table table=pending_closures11352026/11/10 21:11:51 INFO Vacuumed table table=pending_objects11362026/11/10 21:11:51 INFO Vacuumed table table=multipart_uploads11372026/11/10 21:11:51 INFO Vacuumed table table=closures1138--- PASS: TestGCBugBareHashReferences (0.87s)1139=== CONT TestPinProtectsFromGC11402026/11/10 21:11:51 INFO Vacuumed table table=objects11412026/11/10 21:11:51 INFO Aborted multipart uploads count=0 kept=011422026/11/10 21:11:51 WARN Force mode enabled - objects will be deleted immediately without grace period11432026/11/10 21:11:51 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011442026/11/10 21:11:51 INFO Vacuumed table table=pending_closures11452026/11/10 21:11:51 INFO Received uploads request method=POST path=/api/pending_closures11462026/11/10 21:11:51 INFO Vacuumed table table=pending_objects11472026/11/10 21:11:51 INFO Vacuumed table table=multipart_uploads11482026/11/10 21:11:51 INFO Vacuumed table table=closures11492026/11/10 21:11:51 INFO Vacuumed table table=objects1150--- PASS: TestPushDedupSurvivesConcurrentGC (0.99s)1151--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.00s)1152=== CONT TestGCTaskStore_StartNew1153--- PASS: TestGCTaskStore_StartNew (0.00s)1154=== CONT TestGCTaskStore_DeduplicateSameParams1155--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1156=== CONT TestGCEndsOnShutdown1157=== RUN TestGCEndsOnShutdown/before_the_run1158=== CONT TestClientSharedPathCommittedMidPush1159=== PAUSE TestGCEndsOnShutdown/before_the_run1160=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1161=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1162=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1163=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1164=== CONT TestCommitRacingPendingCleanupKeepsObjects1165--- PASS: TestObjectStatsUpdatedOncePerCommit (1.01s)1166=== CONT TestClientWithDependencies11672026/11/10 21:11:51 INFO Received uploads request method=POST path=/api/pending_closures1168--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.71s)1169=== CONT TestPushWaitsForSweepHoldingRow11702026/11/10 21:11:51 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"1171--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.71s)1172=== CONT TestClientMultipleUploads11732026/11/10 21:11:51 INFO Received uploads request method=POST path=/api/pending_closures11742026/11/10 21:11:51 INFO lead: acquired remote=192.0.2.1:123411752026/11/10 21:11:51 INFO lead: acquired remote=192.0.2.1:123411762026/11/10 21:11:51 INFO lead: released remote=192.0.2.1:12341177--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.67s)1178=== CONT TestSweepRechecksPendingAfterLocking11792026/11/10 21:11:51 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11802026/11/10 21:11:51 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1181--- PASS: TestService_NativeMTLS (0.64s)1182=== CONT TestGetExistingObjectsLocksRows1183=== NAME TestOrphanedObjectsGC1184 orphaned_objects_gc_test.go:287: GC Test Summary:1185 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1186 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1187 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1188 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1189 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1190--- PASS: TestOrphanedObjectsGC (1.19s)1191=== CONT TestClientIntegration11922026/11/10 21:11:51 INFO lead: acquired remote=192.0.2.1:123411932026/11/10 21:11:51 INFO Received cleanup request method=DELETE path=/api/pending_closures11942026/11/10 21:11:51 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket30/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11952026/11/10 21:11:51 INFO Aborted multipart uploads count=0 kept=111962026/11/10 21:11:51 INFO Received cleanup request method=DELETE path=/api/pending_closures11972026/11/10 21:11:51 INFO Aborted multipart uploads count=1 kept=01198--- PASS: TestMultipartCleanup (0.87s)1199=== CONT TestGCTaskStore_PhaseUpdates1200--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1201=== CONT TestClientErrorHandling1202=== RUN TestClientErrorHandling/InvalidStorePath1203=== PAUSE TestClientErrorHandling/InvalidStorePath1204=== RUN TestClientErrorHandling/InvalidAuthToken1205=== PAUSE TestClientErrorHandling/InvalidAuthToken1206=== RUN TestClientErrorHandling/ServerNotAvailable1207=== PAUSE TestClientErrorHandling/ServerNotAvailable1208=== CONT TestGCTaskStore_ConflictDifferentParams1209--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1210=== CONT TestClientCADerivations12112026/11/10 21:11:51 INFO Received push request method=POST path=/api/pushes12122026/11/10 21:11:51 INFO Received complete push request method=POST path=/api/pushes/1/complete12132026/11/10 21:11:51 INFO Completed push id=1 objects=4 duration=10.799783ms12142026/11/10 21:11:51 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12152026/11/10 21:11:51 INFO Completed upload id=2 objects=2 duration=2.320267ms1216--- PASS: TestMetricsCommit (0.66s)1217=== CONT TestService_healthCheckHandler1218--- PASS: TestMetricsInventory (0.55s)1219=== CONT TestCacheStatsHandler1220=== NAME TestNARDeduplicationMetadataUploadBug1221 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2102559795/001/store/3zn4vxq8rysxr9mm31jq22zizr0spy0p-file1.txt12222026/11/10 21:11:52 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket40 days=21223--- PASS: TestEnsureAbortUploadsRule (0.60s)1224=== CONT TestGracefulShutdownDrainsInflight12252026/11/10 21:11:52 INFO Received push request method=POST path=/api/pushes12262026/11/10 21:11:52 INFO Starting HTTP server address=127.0.0.1:4411512272026/11/10 21:11:52 INFO Shutdown signal received, draining in-flight requests timeout=10s12282026/11/10 21:11:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12292026/11/10 21:11:52 INFO Uploading 3zn4vxq8rysxr9mm31jq22zizr0spy0p-file1.txt (160B)12302026/11/10 21:11:52 WARN Failed to register uploaded object key=3zn4vxq8rysxr9mm31jq22zizr0spy0p.ls error="server returned 404: 404 page not found\n"12312026/11/10 21:11:52 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12322026/11/10 21:11:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12332026/11/10 21:11:52 INFO Signed narinfos id=1 count=112342026/11/10 21:11:52 INFO Uploading 1 narinfos12352026/11/10 21:11:52 INFO Received complete push request method=POST path=/api/pushes/1/complete12362026/11/10 21:11:52 WARN Failed to register uploaded object key=3zn4vxq8rysxr9mm31jq22zizr0spy0p.narinfo error="server returned 404: 404 page not found\n"12372026/11/10 21:11:52 INFO Completed push id=1 objects=3 duration=9.585ms12382026/11/10 21:11:52 INFO Upload complete. (71ms)1239=== NAME TestNARDeduplicationMetadataUploadBug1240 metadata_upload_test.go:54: Retrieved narinfo from S3:1241 StorePath: /build/TestNARDeduplicationMetadataUploadBug2102559795/001/store/3zn4vxq8rysxr9mm31jq22zizr0spy0p-file1.txt1242 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1243 Compression: zstd1244 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1245 NarSize: 1601246 References: 1247 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1248 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1249 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1250 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12512026/11/10 21:11:52 WARN readiness check failed error="closed pool"1252--- PASS: TestService_readinessHandler (0.57s)1253=== CONT TestCacheConfigHandler1254=== RUN TestCacheConfigHandler/full_config,_no_issuer1255=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1256=== RUN TestCacheConfigHandler/no_cache_url_configured1257=== PAUSE TestCacheConfigHandler/no_cache_url_configured1258=== RUN TestCacheConfigHandler/no_signing_keys1259=== PAUSE TestCacheConfigHandler/no_signing_keys1260=== RUN TestCacheConfigHandler/upstream_keys_advertised1261=== PAUSE TestCacheConfigHandler/upstream_keys_advertised1262=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1263=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1264=== CONT TestGCTaskStore_Fail1265--- PASS: TestGCTaskStore_Fail (0.00s)1266=== CONT TestService_ReadScope_PublicByDefault1267--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1268=== CONT TestGCTaskStore_CompletedAllowsNewTask1269--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1270=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1271=== NAME TestNARDeduplicationMetadataUploadBug1272 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2102559795/001/store/jj94xsg0gzx4x47qbp6gy3mz59nknvca-file2.txt1273--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.78s)1274=== CONT TestGCTaskStore_GetReturnsLatest1275--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1276=== CONT TestService_RequireScope_OIDC12772026/11/10 21:11:52 INFO Received push request method=POST path=/api/pushes12782026/11/10 21:11:52 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12792026/11/10 21:11:52 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12802026/11/10 21:11:52 WARN Failed to register uploaded object key=jj94xsg0gzx4x47qbp6gy3mz59nknvca.ls error="server returned 404: 404 page not found\n"12812026/11/10 21:11:52 INFO Signed narinfos id=2 count=112822026/11/10 21:11:52 INFO Uploading 1 narinfos12832026/11/10 21:11:52 INFO Received complete push request method=POST path=/api/pushes/2/complete12842026/11/10 21:11:52 WARN Failed to register uploaded object key=jj94xsg0gzx4x47qbp6gy3mz59nknvca.narinfo error="server returned 404: 404 page not found\n"12852026/11/10 21:11:52 INFO Completed push id=2 objects=3 duration=2.312748ms12862026/11/10 21:11:52 INFO Upload complete. (51ms)1287=== NAME TestNARDeduplicationMetadataUploadBug1288 metadata_upload_test.go:76: Retrieved narinfo from S3:1289 StorePath: /build/TestNARDeduplicationMetadataUploadBug2102559795/001/store/jj94xsg0gzx4x47qbp6gy3mz59nknvca-file2.txt1290 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1291 Compression: zstd1292 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1293 NarSize: 1601294 References: 1295 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1296 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1297 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1298 {"version":1,"root":{"type":"regular","size":44}}1299--- PASS: TestNARDeduplicationMetadataUploadBug (0.84s)1300=== CONT TestService_AuthMiddleware_OIDC1301=== NAME TestPinProtectsFromGC1302 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC2289851878/001/store/ng1rahspbgs9avy1b4hkh123fm7m13ap-pinned-file.txt1303 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC2289851878/001/store/3n50cij4a7yqz151qhcl3f1vba2dw8az-unpinned-file.txt13042026/11/10 21:11:52 INFO Aborted multipart uploads count=0 kept=013052026/11/10 21:11:52 INFO Received uploads request method=POST path=/api/pending_closures13062026/11/10 21:11:52 WARN Force mode enabled - objects will be deleted immediately without grace period13072026/11/10 21:11:52 INFO Received uploads request method=POST path=/api/pending_closures13082026/11/10 21:11:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013092026/11/10 21:11:52 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13102026/11/10 21:11:52 INFO Uploading cdvsqm1fs04cna8drxwa7lbndn9c0hls-a (216B)13112026/11/10 21:11:52 INFO Uploading nmbm1x1067pdrh3i22wbwrf7iai81hxq-shared-dep (136B)13122026/11/10 21:11:52 INFO Vacuumed table table=pending_closures13132026/11/10 21:11:52 INFO Vacuumed table table=pending_objects13142026/11/10 21:11:52 INFO Vacuumed table table=multipart_uploads13152026/11/10 21:11:52 INFO Vacuumed table table=closures13162026/11/10 21:11:52 INFO Vacuumed table table=objects13172026/11/10 21:11:52 WARN Failed to register uploaded object key=yycjjdf2z45mr4q7sgjx0dhk6zymg0il.ls error="server returned 404: 404 page not found\n"13182026/11/10 21:11:52 WARN Failed to register uploaded object key=cdvsqm1fs04cna8drxwa7lbndn9c0hls.ls error="server returned 404: 404 page not found\n"13192026/11/10 21:11:52 WARN Failed to register uploaded object key=nmbm1x1067pdrh3i22wbwrf7iai81hxq.ls error="server returned 404: 404 page not found\n"13202026/11/10 21:11:52 INFO Received uploads request method=POST path=/api/pending_closures13212026/11/10 21:11:52 WARN Failed to register uploaded object key=nar/1gk5prqhqpjkp4dr2a89p0a7ml8k2dsz465ymi2k8wzcqc7ycngv.nar.zst error="server returned 404: 404 page not found\n"13222026/11/10 21:11:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13232026/11/10 21:11:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13242026/11/10 21:11:52 INFO Signed narinfos id=1 count=213252026/11/10 21:11:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13262026/11/10 21:11:52 INFO Signed narinfos id=2 count=213272026/11/10 21:11:52 INFO Uploading 4 narinfos13282026/11/10 21:11:52 WARN Failed to register uploaded object key=nmbm1x1067pdrh3i22wbwrf7iai81hxq.narinfo error="server returned 404: 404 page not found\n"13292026/11/10 21:11:52 WARN Failed to register uploaded object key=yycjjdf2z45mr4q7sgjx0dhk6zymg0il.narinfo error="server returned 404: 404 page not found\n"13302026/11/10 21:11:52 WARN Failed to register uploaded object key=cdvsqm1fs04cna8drxwa7lbndn9c0hls.narinfo error="server returned 404: 404 page not found\n"1331--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.68s)1332=== CONT TestGCTaskStore_GetEmpty1333--- PASS: TestGCTaskStore_GetEmpty (0.00s)1334=== CONT TestService_AuthMiddleware_MTLSProxyHeader13352026/11/10 21:11:52 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13362026/11/10 21:11:52 WARN Failed to register uploaded object key=nmbm1x1067pdrh3i22wbwrf7iai81hxq.narinfo error="server returned 404: 404 page not found\n"13372026/11/10 21:11:52 INFO Completed upload id=2 objects=6 duration=5.197043ms13382026/11/10 21:11:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13392026/11/10 21:11:52 INFO Completed upload id=1 objects=6 duration=1.020075ms13402026/11/10 21:11:52 INFO Upload complete. (67ms)1341=== NAME TestClientFallsBackToClosures1342 client_pushes_test.go:112: Retrieved narinfo from S3:1343 StorePath: /build/TestClientFallsBackToClosures1176615973/001/store/nmbm1x1067pdrh3i22wbwrf7iai81hxq-shared-dep1344 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1345 Compression: zstd1346 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821347 NarSize: 1361348 References: 1349 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13502026/11/10 21:11:52 INFO Received push request method=POST path=/api/pushes1351 client_pushes_test.go:112: Retrieved narinfo from S3:1352 StorePath: /build/TestClientFallsBackToClosures1176615973/001/store/cdvsqm1fs04cna8drxwa7lbndn9c0hls-a1353 URL: nar/1gk5prqhqpjkp4dr2a89p0a7ml8k2dsz465ymi2k8wzcqc7ycngv.nar.zst1354 Compression: zstd1355 NarHash: sha256:1gk5prqhqpjkp4dr2a89p0a7ml8k2dsz465ymi2k8wzcqc7ycngv1356 NarSize: 2161357 References: /build/TestClientFallsBackToClosures1176615973/001/store/nmbm1x1067pdrh3i22wbwrf7iai81hxq-shared-dep1358 CA: text:sha256:0k4025i654bg83yk2cw9kzm7wqaf591radl2nz05fvxz5r91imp813592026/11/10 21:11:52 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13602026/11/10 21:11:52 INFO Uploading 6nglvc0a1s1lpnfbi0xwd37677ia9l1n-shared-dep (136B)13612026/11/10 21:11:52 INFO Uploading s8da80b3h5c2ykid1mgx7gbz6qw3c9wh-b (216B)1362 client_pushes_test.go:112: Retrieved narinfo from S3:1363 StorePath: /build/TestClientFallsBackToClosures1176615973/001/store/yycjjdf2z45mr4q7sgjx0dhk6zymg0il-b1364 URL: nar/1gk5prqhqpjkp4dr2a89p0a7ml8k2dsz465ymi2k8wzcqc7ycngv.nar.zst1365 Compression: zstd1366 NarHash: sha256:1gk5prqhqpjkp4dr2a89p0a7ml8k2dsz465ymi2k8wzcqc7ycngv1367 NarSize: 2161368 References: /build/TestClientFallsBackToClosures1176615973/001/store/nmbm1x1067pdrh3i22wbwrf7iai81hxq-shared-dep1369 CA: text:sha256:0k4025i654bg83yk2cw9kzm7wqaf591radl2nz05fvxz5r91imp813702026/11/10 21:11:52 WARN Failed to register uploaded object key=6nglvc0a1s1lpnfbi0xwd37677ia9l1n.ls error="server returned 404: 404 page not found\n"13712026/11/10 21:11:52 WARN Failed to register uploaded object key=nar/0dwhmp3fcvc9j36lvmnxmwfp0xj978ag1m03kk3x4jkd5d8y1av2.nar.zst error="server returned 404: 404 page not found\n"13722026/11/10 21:11:52 WARN Failed to register uploaded object key=s8da80b3h5c2ykid1mgx7gbz6qw3c9wh.ls error="server returned 404: 404 page not found\n"13732026/11/10 21:11:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13742026/11/10 21:11:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13752026/11/10 21:11:52 WARN Failed to register uploaded object key=jir3qwfcf48021p1bj3wbsjyjm7fm4x3.ls error="server returned 404: 404 page not found\n"13762026/11/10 21:11:52 INFO Signed narinfos id=1 count=313772026/11/10 21:11:52 INFO Uploading 3 narinfos1378--- PASS: TestClientFallsBackToClosures (0.79s)13792026/11/10 21:11:52 INFO Received push request method=POST path=/api/pushes1380=== CONT TestService_ReadAuthMiddleware13812026/11/10 21:11:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13822026/11/10 21:11:52 INFO Uploading ng1rahspbgs9avy1b4hkh123fm7m13ap-pinned-file.txt (128B)13832026/11/10 21:11:52 INFO Received complete push request method=POST path=/api/pushes/1/complete13842026/11/10 21:11:52 WARN Failed to register uploaded object key=s8da80b3h5c2ykid1mgx7gbz6qw3c9wh.narinfo error="server returned 404: 404 page not found\n"13852026/11/10 21:11:52 WARN Failed to register uploaded object key=jir3qwfcf48021p1bj3wbsjyjm7fm4x3.narinfo error="server returned 404: 404 page not found\n"13862026/11/10 21:11:52 WARN Failed to register uploaded object key=6nglvc0a1s1lpnfbi0xwd37677ia9l1n.narinfo error="server returned 404: 404 page not found\n"13872026/11/10 21:11:52 WARN Failed to register uploaded object key=ng1rahspbgs9avy1b4hkh123fm7m13ap.ls error="server returned 404: 404 page not found\n"13882026/11/10 21:11:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13892026/11/10 21:11:52 INFO Completed push id=1 objects=8 duration=6.224948ms13902026/11/10 21:11:52 INFO Upload complete. (59ms)13912026/11/10 21:11:52 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13922026/11/10 21:11:52 INFO Signed narinfos id=1 count=113932026/11/10 21:11:52 INFO Uploading 1 narinfos1394=== NAME TestClientPushesUseOnePush1395 client_pushes_test.go:97: Retrieved narinfo from S3:1396 StorePath: /build/TestClientPushesUseOnePush2767391241/001/store/6nglvc0a1s1lpnfbi0xwd37677ia9l1n-shared-dep1397 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1398 Compression: zstd1399 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821400 NarSize: 1361401 References: 1402 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1403 client_pushes_test.go:97: Retrieved narinfo from S3:1404 StorePath: /build/TestClientPushesUseOnePush2767391241/001/store/jir3qwfcf48021p1bj3wbsjyjm7fm4x3-a1405 URL: nar/0dwhmp3fcvc9j36lvmnxmwfp0xj978ag1m03kk3x4jkd5d8y1av2.nar.zst1406 Compression: zstd1407 NarHash: sha256:0dwhmp3fcvc9j36lvmnxmwfp0xj978ag1m03kk3x4jkd5d8y1av21408 NarSize: 2161409 References: /build/TestClientPushesUseOnePush2767391241/001/store/6nglvc0a1s1lpnfbi0xwd37677ia9l1n-shared-dep1410 CA: text:sha256:12jxakpg7gbwxg5sf2p75yrsygynpdfic2z6pcfghl0hj9pc96hr14112026/11/10 21:11:52 INFO Received complete push request method=POST path=/api/pushes/1/complete14122026/11/10 21:11:52 WARN Failed to register uploaded object key=ng1rahspbgs9avy1b4hkh123fm7m13ap.narinfo error="server returned 404: 404 page not found\n"1413 client_pushes_test.go:97: Retrieved narinfo from S3:1414 StorePath: /build/TestClientPushesUseOnePush2767391241/001/store/s8da80b3h5c2ykid1mgx7gbz6qw3c9wh-b1415 URL: nar/0dwhmp3fcvc9j36lvmnxmwfp0xj978ag1m03kk3x4jkd5d8y1av2.nar.zst1416 Compression: zstd1417 NarHash: sha256:0dwhmp3fcvc9j36lvmnxmwfp0xj978ag1m03kk3x4jkd5d8y1av21418 NarSize: 2161419 References: /build/TestClientPushesUseOnePush2767391241/001/store/6nglvc0a1s1lpnfbi0xwd37677ia9l1n-shared-dep1420 CA: text:sha256:12jxakpg7gbwxg5sf2p75yrsygynpdfic2z6pcfghl0hj9pc96hr14212026/11/10 21:11:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39863/oidc14222026/11/10 21:11:52 INFO Completed push id=1 objects=3 duration=5.023533ms14232026/11/10 21:11:52 INFO Upload complete. (57ms)1424--- PASS: TestClientPushesUseOnePush (0.80s)1425=== CONT TestService_AuthMiddleware1426=== NAME TestClientWithDependencies1427 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies666494109/001/store/zym2cwjs8vxv5yfzyldyvr9k08vm3ncw-test-script14282026/11/10 21:11:52 INFO Received push request method=POST path=/api/pushes14292026/11/10 21:11:52 INFO Aborted multipart uploads count=0 kept=01430=== NAME TestClientMultipleUploads1431 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads2957983768/001/store/1gl39kwr1xkviydb24drq7my05hjcdam-test-file-0.txt14322026/11/10 21:11:52 WARN Force mode enabled - objects will be deleted immediately without grace period14332026/11/10 21:11:52 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14342026/11/10 21:11:52 INFO Uploading r9n5ppgy191w19xdhn90pqgpidsg7zfb-top (224B)14352026/11/10 21:11:52 INFO Uploading z1kzjrzl67fbqlf2kbfnmw811skf9qhb-shared-dep (136B)14362026/11/10 21:11:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14372026/11/10 21:11:52 WARN Failed to register uploaded object key=r9n5ppgy191w19xdhn90pqgpidsg7zfb.ls error="server returned 404: 404 page not found\n"14382026/11/10 21:11:52 WARN Failed to register uploaded object key=nar/0pb8p5c0h6dwp1aglqzl7194ahnm2jb21icqwcpinvliy45zwawf.nar.zst error="server returned 404: 404 page not found\n"14392026/11/10 21:11:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14402026/11/10 21:11:52 WARN Failed to register uploaded object key=z1kzjrzl67fbqlf2kbfnmw811skf9qhb.ls error="server returned 404: 404 page not found\n"14412026/11/10 21:11:52 INFO Signed narinfos id=1 count=214422026/11/10 21:11:52 INFO Uploading 2 narinfos14432026/11/10 21:11:52 WARN Failed to register uploaded object key=r9n5ppgy191w19xdhn90pqgpidsg7zfb.narinfo error="server returned 404: 404 page not found\n"14442026/11/10 21:11:52 INFO Received complete push request method=POST path=/api/pushes/1/complete14452026/11/10 21:11:52 WARN Failed to register uploaded object key=z1kzjrzl67fbqlf2kbfnmw811skf9qhb.narinfo error="server returned 404: 404 page not found\n"1446=== NAME TestClientWithDependencies1447 client_integration_test.go:662: Found 1 dependencies (including self)14482026/11/10 21:11:52 INFO Completed push id=1 objects=6 duration=10.210016ms14492026/11/10 21:11:52 INFO Upload complete. (69ms)1450=== NAME TestClientSharedPathCommittedMidPush1451 client_integration_test.go:727: Retrieved narinfo from S3:1452 StorePath: /build/TestClientSharedPathCommittedMidPush4219023999/001/store/z1kzjrzl67fbqlf2kbfnmw811skf9qhb-shared-dep1453 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1454 Compression: zstd1455 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821456 NarSize: 1361457 References: 1458 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14592026/11/10 21:11:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01460 client_integration_test.go:727: Retrieved narinfo from S3:1461 StorePath: /build/TestClientSharedPathCommittedMidPush4219023999/001/store/r9n5ppgy191w19xdhn90pqgpidsg7zfb-top1462 URL: nar/0pb8p5c0h6dwp1aglqzl7194ahnm2jb21icqwcpinvliy45zwawf.nar.zst1463 Compression: zstd1464 NarHash: sha256:0pb8p5c0h6dwp1aglqzl7194ahnm2jb21icqwcpinvliy45zwawf1465 NarSize: 2241466 References: /build/TestClientSharedPathCommittedMidPush4219023999/001/store/z1kzjrzl67fbqlf2kbfnmw811skf9qhb-shared-dep1467 CA: text:sha256:0yg09xdxy6amcba8z14p6jwkp33mpxcb3i66zgq66agclw3c553k1468--- PASS: TestGetExistingObjectsLocksRows (0.59s)1469=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1470=== NAME TestClientMultipleUploads1471 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads2957983768/001/store/xs2yng9nq9bgrp7x2qmd3s5b20ln66rw-test-file-1.txt14722026/11/10 21:11:52 INFO Vacuumed table table=pending_closures14732026/11/10 21:11:52 INFO Vacuumed table table=pending_objects1474--- PASS: TestClientSharedPathCommittedMidPush (0.77s)1475=== CONT TestReadProxyOutlastsServerWriteTimeout14762026/11/10 21:11:52 INFO Vacuumed table table=multipart_uploads14772026/11/10 21:11:52 INFO Vacuumed table table=closures14782026/11/10 21:11:52 INFO Vacuumed table table=objects1479--- PASS: TestSweepRechecksPendingAfterLocking (0.63s)1480=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle14812026/11/10 21:11:52 INFO Received push request method=POST path=/api/pushes14822026/11/10 21:11:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14832026/11/10 21:11:52 INFO Uploading 3n50cij4a7yqz151qhcl3f1vba2dw8az-unpinned-file.txt (128B)14842026/11/10 21:11:52 WARN Failed to register uploaded object key=3n50cij4a7yqz151qhcl3f1vba2dw8az.ls error="server returned 404: 404 page not found\n"14852026/11/10 21:11:52 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14862026/11/10 21:11:52 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14872026/11/10 21:11:52 INFO Signed narinfos id=2 count=114882026/11/10 21:11:52 INFO Uploading 1 narinfos1489=== NAME TestClientMultipleUploads1490 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads2957983768/001/store/lx62p1laqp0lzrxyi6akzg18scnwnq04-test-file-2.txt14912026/11/10 21:11:52 INFO Received complete push request method=POST path=/api/pushes/2/complete14922026/11/10 21:11:52 WARN Failed to register uploaded object key=3n50cij4a7yqz151qhcl3f1vba2dw8az.narinfo error="server returned 404: 404 page not found\n"1493=== NAME TestClientIntegration1494 client_integration_test.go:291: Created store path: /build/TestClientIntegration2432285565/002/store/sd8ijdp5gflqy2rg3jv5il3hphdif7gl-test-file.txt1495--- PASS: TestService_healthCheckHandler (0.53s)1496=== CONT TestReadRedirectUsesPublicS3URL14972026/11/10 21:11:52 INFO Completed push id=2 objects=3 duration=16.692623ms14982026/11/10 21:11:52 INFO Upload complete. (66ms)14992026/11/10 21:11:52 INFO Received push request method=POST path=/api/pushes15002026/11/10 21:11:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15012026/11/10 21:11:52 INFO Uploading zym2cwjs8vxv5yfzyldyvr9k08vm3ncw-test-script (136B)15022026/11/10 21:11:52 WARN Failed to register uploaded object key=zym2cwjs8vxv5yfzyldyvr9k08vm3ncw.ls error="server returned 404: 404 page not found\n"15032026/11/10 21:11:52 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15042026/11/10 21:11:52 WARN Failed to register uploaded object key=log/bsi6rmf2v2304846hiwzkkr3rj1wi445-test-script.drv error="server returned 404: 404 page not found\n"15052026/11/10 21:11:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15062026/11/10 21:11:52 INFO Signed narinfos id=1 count=115072026/11/10 21:11:52 INFO Uploading 1 narinfos15082026/11/10 21:11:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41037/oidc15092026/11/10 21:11:52 INFO Received complete push request method=POST path=/api/pushes/1/complete15102026/11/10 21:11:52 WARN Failed to register uploaded object key=zym2cwjs8vxv5yfzyldyvr9k08vm3ncw.narinfo error="server returned 404: 404 page not found\n"15112026/11/10 21:11:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures15122026/11/10 21:11:52 INFO Garbage collection started15132026/11/10 21:11:52 INFO Completed push id=1 objects=4 duration=9.928968ms15142026/11/10 21:11:52 INFO Upload complete. (71ms)1515--- PASS: TestCacheStatsHandler (0.56s)1516=== CONT TestSkippedUploadsHandler15172026/11/10 21:11:52 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001518=== NAME TestClientWithDependencies1519 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies666494109/001/store) requires matching store prefix1520--- PASS: TestSkippedUploadsHandler (0.00s)1521=== CONT TestReadProxyRangeRequest15222026/11/10 21:11:52 INFO Aborted multipart uploads count=0 kept=015232026/11/10 21:11:52 INFO Received push request method=POST path=/api/pushes1524--- PASS: TestClientWithDependencies (0.86s)1525=== CONT TestParseSize1526--- PASS: TestParseSize (0.00s)1527=== CONT TestReadRedirectKeepsNarinfoProxied1528--- PASS: TestService_ReadScope_PublicByDefault (0.35s)1529=== CONT TestService_Rustfstest15302026/11/10 21:11:52 WARN Force mode enabled - objects will be deleted immediately without grace period15312026/11/10 21:11:52 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15322026/11/10 21:11:52 INFO Uploading xs2yng9nq9bgrp7x2qmd3s5b20ln66rw-test-file-1.txt (160B)15332026/11/10 21:11:52 INFO Uploading 1gl39kwr1xkviydb24drq7my05hjcdam-test-file-0.txt (160B)15342026/11/10 21:11:52 INFO Uploading lx62p1laqp0lzrxyi6akzg18scnwnq04-test-file-2.txt (160B)15352026/11/10 21:11:52 INFO Received push request method=POST path=/api/pushes1536=== NAME TestClientCADerivations1537 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations397668666/001/store/802mw6s8cpvyj50qa0p9nrxzhl5yhk1f-ca-test15382026/11/10 21:11:52 WARN Failed to register uploaded object key=1gl39kwr1xkviydb24drq7my05hjcdam.ls error="server returned 404: 404 page not found\n"15392026/11/10 21:11:52 WARN Failed to register uploaded object key=xs2yng9nq9bgrp7x2qmd3s5b20ln66rw.ls error="server returned 404: 404 page not found\n"15402026/11/10 21:11:52 WARN Failed to register uploaded object key=lx62p1laqp0lzrxyi6akzg18scnwnq04.ls error="server returned 404: 404 page not found\n"15412026/11/10 21:11:52 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15422026/11/10 21:11:52 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15432026/11/10 21:11:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15442026/11/10 21:11:52 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15452026/11/10 21:11:52 INFO Signed narinfos id=1 count=315462026/11/10 21:11:52 INFO Uploading 3 narinfos15472026/11/10 21:11:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15482026/11/10 21:11:52 INFO Uploading sd8ijdp5gflqy2rg3jv5il3hphdif7gl-test-file.txt (152B)15492026/11/10 21:11:52 WARN Failed to register uploaded object key=lx62p1laqp0lzrxyi6akzg18scnwnq04.narinfo error="server returned 404: 404 page not found\n"15502026/11/10 21:11:52 WARN Failed to register uploaded object key=1gl39kwr1xkviydb24drq7my05hjcdam.narinfo error="server returned 404: 404 page not found\n"15512026/11/10 21:11:52 INFO Received complete push request method=POST path=/api/pushes/1/complete15522026/11/10 21:11:52 WARN Failed to register uploaded object key=xs2yng9nq9bgrp7x2qmd3s5b20ln66rw.narinfo error="server returned 404: 404 page not found\n"15532026/11/10 21:11:52 WARN Failed to register uploaded object key=sd8ijdp5gflqy2rg3jv5il3hphdif7gl.ls error="server returned 404: 404 page not found\n"15542026/11/10 21:11:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15552026/11/10 21:11:52 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15562026/11/10 21:11:52 INFO Signed narinfos id=1 count=115572026/11/10 21:11:52 INFO Uploading 1 narinfos15582026/11/10 21:11:52 INFO Received complete push request method=POST path=/api/pushes/1/complete15592026/11/10 21:11:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15602026/11/10 21:11:52 WARN mTLS auth: bound subjects configured but subject DN unavailable15612026/11/10 21:11:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1562--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.37s)15632026/11/10 21:11:52 WARN Failed to register uploaded object key=sd8ijdp5gflqy2rg3jv5il3hphdif7gl.narinfo error="server returned 404: 404 page not found\n"1564=== CONT TestReadRedirectNar15652026/11/10 21:11:52 INFO Completed push id=1 objects=9 duration=10.547834ms15662026/11/10 21:11:52 INFO Upload complete. (77ms)1567=== NAME TestClientMultipleUploads1568 client_integration_test.go:416: Uploaded 3 paths in 106.289303ms1569=== NAME TestClientCADerivations1570 client_ca_test.go:139: Found 1 dependencies (including self)15712026/11/10 21:11:52 INFO Completed push id=1 objects=3 duration=9.995128ms15722026/11/10 21:11:52 INFO Upload complete. (70ms)1573--- PASS: TestClientMultipleUploads (0.85s)1574=== CONT TestPresignedUploadRegisteredBeforeCommit15752026/11/10 21:11:52 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=015762026/11/10 21:11:52 INFO Vacuumed table table=pending_closures1577--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.26s)1578=== CONT TestReadProxyDisabled15792026/11/10 21:11:52 INFO Vacuumed table table=pending_objects15802026/11/10 21:11:52 INFO Vacuumed table table=multipart_uploads15812026/11/10 21:11:52 INFO All 1 paths already cached1582=== NAME TestClientIntegration1583 client_integration_test.go:317: Retrieved narinfo from S3:1584 StorePath: /build/TestClientIntegration2432285565/002/store/sd8ijdp5gflqy2rg3jv5il3hphdif7gl-test-file.txt1585 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1586 Compression: zstd1587 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11588 NarSize: 1521589 References: 1590 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11591 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)15922026/11/10 21:11:52 INFO Vacuumed table table=closures1593 client_integration_test.go:318: Decompressed .ls content (64 bytes):1594 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}15952026/11/10 21:11:52 INFO Vacuumed table table=objects1596--- PASS: TestService_ReadAuthMiddleware (0.26s)1597=== CONT TestCompletedNarNotReofferedAcrossClosures1598=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1599=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1600=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1601=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1602=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1603=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1604=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1605=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1606=== CONT TestReadProxyRootRedirectsToIndexHTML16072026/11/10 21:11:52 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1608--- PASS: TestService_AuthMiddleware (0.29s)1609=== CONT TestCompleteMultipartUpload_ErrorButObjectExists16102026/11/10 21:11:52 INFO Received push request method=POST path=/api/pushes16112026/11/10 21:11:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16122026/11/10 21:11:52 INFO Uploading 802mw6s8cpvyj50qa0p9nrxzhl5yhk1f-ca-test (144B)16132026/11/10 21:11:52 WARN Failed to register uploaded object key=802mw6s8cpvyj50qa0p9nrxzhl5yhk1f.ls error="server returned 404: 404 page not found\n"16142026/11/10 21:11:52 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16152026/11/10 21:11:52 WARN Failed to register uploaded object key=log/48z1b3q5qh4dni7pqw2hj4h56xv415q3-ca-test.drv error="server returned 404: 404 page not found\n"16162026/11/10 21:11:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16172026/11/10 21:11:52 INFO Signed narinfos id=1 count=116182026/11/10 21:11:52 INFO Uploading 1 narinfos16192026/11/10 21:11:52 INFO Received complete push request method=POST path=/api/pushes/1/complete16202026/11/10 21:11:52 WARN Failed to register uploaded object key=802mw6s8cpvyj50qa0p9nrxzhl5yhk1f.narinfo error="server returned 404: 404 page not found\n"16212026/11/10 21:11:52 INFO Received push request method=POST path=/api/pushes16222026/11/10 21:11:52 INFO Object in database but missing from S3 key=sd8ijdp5gflqy2rg3jv5il3hphdif7gl.ls16232026/11/10 21:11:52 WARN Found objects in DB but missing from S3, will re-upload count=116242026/11/10 21:11:52 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16252026/11/10 21:11:52 INFO Completed push id=1 objects=4 duration=10.430285ms16262026/11/10 21:11:52 INFO Upload complete. (109ms)16272026/11/10 21:11:52 INFO Received complete push request method=POST path=/api/pushes/2/complete16282026/11/10 21:11:52 WARN Failed to register uploaded object key=sd8ijdp5gflqy2rg3jv5il3hphdif7gl.ls error="server returned 404: 404 page not found\n"1629=== NAME TestClientCADerivations1630 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations397668666/001/store/802mw6s8cpvyj50qa0p9nrxzhl5yhk1f-ca-test1631 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1632 Compression: zstd1633 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1634 NarSize: 1441635 References: 1636 Deriver: /build/TestClientCADerivations397668666/001/store/48z1b3q5qh4dni7pqw2hj4h56xv415q3-ca-test.drv1637 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1638 client_ca_test.go:185: Checking for realisation files in S3...16392026/11/10 21:11:52 INFO Completed push id=2 objects=3 duration=2.789515ms16402026/11/10 21:11:52 INFO Upload complete. (49ms)1641 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1642 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1643=== NAME TestClientIntegration1644 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1645 client_integration_test.go:335: Decompressed .ls content (49 bytes):1646 {"version":1,"root":{"type":"regular","size":39}}16472026/11/10 21:11:52 INFO Received push request method=POST path=/api/pushes1648--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.34s)1649=== CONT TestSharedNarBothUploadsComplete16502026/11/10 21:11:52 INFO Received uploads request method=POST path=/api/pending_closures16512026/11/10 21:11:52 INFO Received push request method=POST path=/api/pushes1652--- PASS: TestReadRedirectUsesPublicS3URL (0.34s)1653=== CONT TestReadProxyConditionalGet16542026/11/10 21:11:52 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16552026/11/10 21:11:52 INFO lead: released remote=192.0.2.1:123416562026/11/10 21:11:52 INFO Received complete push request method=POST path=/api/pushes/3/complete1657--- PASS: TestLeadEndsOnShutdown (1.73s)1658=== CONT TestPush_SignsNarinfosOfItsPendingObjects16592026/11/10 21:11:52 WARN Failed to register uploaded object key=sd8ijdp5gflqy2rg3jv5il3hphdif7gl.ls error="server returned 404: 404 page not found\n"16602026/11/10 21:11:52 INFO Completed push id=3 objects=3 duration=2.701216ms16612026/11/10 21:11:52 INFO Upload complete. (47ms)1662=== NAME TestClientIntegration1663 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1664 client_integration_test.go:352: Decompressed .ls content (49 bytes):1665 {"version":1,"root":{"type":"regular","size":39}}1666 client_integration_test.go:363: Testing garbage collection...1667--- PASS: TestPushWaitsForSweepHoldingRow (1.14s)1668=== CONT TestPush_RejectsBadRequests1669=== NAME TestClientCADerivations1670 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1671 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1672 error: binary cache 's3://bucket53?endpoint=http://localhost:39623®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations397668666/001/store'1673 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11674--- PASS: TestClientCADerivations (0.95s)1675=== CONT TestPush_CompleteWaitsForCleanupOfThePush1676=== RUN TestService_RequireScope_OIDC/builder_may_write1677=== PAUSE TestService_RequireScope_OIDC/builder_may_write1678=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1679=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1680=== RUN TestService_RequireScope_OIDC/ops_may_admin1681=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1682=== RUN TestService_RequireScope_OIDC/ops_may_not_write1683=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1684=== RUN TestService_RequireScope_OIDC/reader_may_not_write1685=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1686=== RUN TestService_RequireScope_OIDC/static_token_may_admin1687=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1688=== RUN TestService_RequireScope_OIDC/static_token_may_write1689=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1690=== RUN TestService_RequireScope_OIDC/reader_may_read1691=== PAUSE TestService_RequireScope_OIDC/reader_may_read1692=== RUN TestService_RequireScope_OIDC/writer_implies_read1693=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1694=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1695=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1696=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1697=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1698=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1699=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1700=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1701=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1702=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1703=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1704=== CONT TestPush_RepeatedRootCommitsOnce17052026/11/10 21:11:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17062026/11/10 21:11:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures17072026/11/10 21:11:52 INFO Garbage collection started1708--- PASS: TestReadProxyRangeRequest (0.34s)1709=== CONT TestPush_CompleteCommitsEveryRoot17102026/11/10 21:11:52 INFO Aborted multipart uploads count=0 kept=017112026/11/10 21:11:52 WARN Force mode enabled - objects will be deleted immediately without grace period1712--- PASS: TestReadRedirectKeepsNarinfoProxied (0.36s)1713=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1714--- PASS: TestService_Rustfstest (0.37s)1715=== CONT TestReadProxyNarStreaming17162026/11/10 21:11:52 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=017172026/11/10 21:11:52 INFO Vacuumed table table=pending_closures17182026/11/10 21:11:52 INFO Vacuumed table table=pending_objects17192026/11/10 21:11:52 INFO Vacuumed table table=multipart_uploads17202026/11/10 21:11:52 INFO Vacuumed table table=closures1721--- PASS: TestReadRedirectNar (0.38s)1722=== CONT TestPush_RootsAreLockedInByteOrder17232026/11/10 21:11:52 INFO Vacuumed table table=objects17242026/11/10 21:11:52 INFO Received uploads request method=POST path=/api/pending_closures17252026/11/10 21:11:52 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst17262026/11/10 21:11:52 INFO Received uploads request method=POST path=/api/pending_closures1727--- PASS: TestReadProxyDisabled (0.41s)1728=== CONT TestReadProxyHead1729--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.42s)1730=== CONT TestReadProxyInvalidPath17312026/11/10 21:11:52 INFO Received uploads request method=POST path=/api/pending_closures1732--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.41s)1733=== CONT TestReadProxy40417342026/11/10 21:11:52 INFO lead: released remote=192.0.2.1:12341735--- PASS: TestDeleteClosuresRacingPins (1.59s)1736=== CONT TestReadProxyNarinfoAlreadyDecompressed17372026/11/10 21:11:52 INFO Received uploads request method=POST path=/api/pending_closures17382026/11/10 21:11:53 INFO lead: acquired remote=192.0.2.1:123417392026/11/10 21:11:53 INFO Received uploads request method=POST path=/api/pending_closures17402026/11/10 21:11:53 INFO Received uploads request method=POST path=/api/pending_closures17412026/11/10 21:11:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17422026/11/10 21:11:53 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjcwYWZhMTItOWMyOS00OGM1LWE0MTktNjE3YzlmMDJjZDRjLjI1ZDI0ZWQ0LWRhMjMtNGVhNy1iNTE1LTc5MmE3OWY4ZTdmNXgxNzk0MzQ1MTEzMDA3ODQzODQx17432026/11/10 21:11:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjcwYWZhMTItOWMyOS00OGM1LWE0MTktNjE3YzlmMDJjZDRjLjI1ZDI0ZWQ0LWRhMjMtNGVhNy1iNTE1LTc5MmE3OWY4ZTdmNXgxNzk0MzQ1MTEzMDA3ODQzODQx parts=11744--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.48s)1745=== CONT TestReadProxyNarinfo1746--- PASS: TestReadProxyConditionalGet (0.35s)1747=== CONT TestReadProxyContentNegotiation17482026/11/10 21:11:53 INFO Received push request method=POST path=/api/pushes17492026/11/10 21:11:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17502026/11/10 21:11:53 INFO Signed narinfos id=1 count=117512026/11/10 21:11:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17522026/11/10 21:11:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17532026/11/10 21:11:53 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"17542026/11/10 21:11:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17552026/11/10 21:11:53 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"17562026/11/10 21:11:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17572026/11/10 21:11:53 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=117582026/11/10 21:11:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17592026/11/10 21:11:53 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1760--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.38s)1761=== CONT TestIsValidCachePath1762=== RUN TestIsValidCachePath/narinfo1763=== PAUSE TestIsValidCachePath/narinfo1764=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1765=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1766=== RUN TestIsValidCachePath/nar_zst1767=== PAUSE TestIsValidCachePath/nar_zst1768=== RUN TestIsValidCachePath/nar_xz1769=== PAUSE TestIsValidCachePath/nar_xz1770=== RUN TestIsValidCachePath/nar_bz21771=== PAUSE TestIsValidCachePath/nar_bz21772=== RUN TestIsValidCachePath/nar_uncompressed1773=== PAUSE TestIsValidCachePath/nar_uncompressed1774=== RUN TestIsValidCachePath/ls1775=== PAUSE TestIsValidCachePath/ls1776=== RUN TestIsValidCachePath/log1777=== PAUSE TestIsValidCachePath/log1778=== RUN TestIsValidCachePath/realisation1779=== PAUSE TestIsValidCachePath/realisation1780=== RUN TestIsValidCachePath/nix-cache-info1781=== PAUSE TestIsValidCachePath/nix-cache-info1782=== RUN TestIsValidCachePath/index.html1783=== PAUSE TestIsValidCachePath/index.html1784=== RUN TestIsValidCachePath/traversal_parent1785=== PAUSE TestIsValidCachePath/traversal_parent1786=== RUN TestIsValidCachePath/traversal_in_middle1787=== PAUSE TestIsValidCachePath/traversal_in_middle1788=== RUN TestIsValidCachePath/invalid_char_e1789=== PAUSE TestIsValidCachePath/invalid_char_e1790=== RUN TestIsValidCachePath/invalid_char_u1791=== PAUSE TestIsValidCachePath/invalid_char_u1792=== RUN TestIsValidCachePath/random_path1793=== PAUSE TestIsValidCachePath/random_path1794=== RUN TestIsValidCachePath/empty1795=== PAUSE TestIsValidCachePath/empty1796=== RUN TestIsValidCachePath/leading_slash1797=== PAUSE TestIsValidCachePath/leading_slash1798=== RUN TestIsValidCachePath/wrong_extension1799=== PAUSE TestIsValidCachePath/wrong_extension1800=== RUN TestIsValidCachePath/short_hash1801=== PAUSE TestIsValidCachePath/short_hash1802=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1803=== RUN TestPush_RejectsBadRequests/no_roots1804=== PAUSE TestPush_RejectsBadRequests/no_roots1805=== RUN TestPush_RejectsBadRequests/no_objects1806=== PAUSE TestPush_RejectsBadRequests/no_objects1807=== RUN TestPush_RejectsBadRequests/bad_root1808=== PAUSE TestPush_RejectsBadRequests/bad_root1809=== RUN TestPush_RejectsBadRequests/root_not_in_objects1810=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1811=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18122026/11/10 21:11:53 INFO Received push request method=POST path=/api/pushes18132026/11/10 21:11:53 INFO Received push request method=POST path=/api/pushes18142026/11/10 21:11:53 INFO Received complete push request method=POST path=/api/pushes/1/complete18152026/11/10 21:11:53 INFO Completed push id=1 objects=4 duration=7.893298ms1816--- PASS: TestPush_RepeatedRootCommitsOnce (0.46s)1817=== CONT TestPendingClosureWriteTimeout/empty1818=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18192026/11/10 21:11:53 INFO Received push request method=POST path=/api/pushes18202026/11/10 21:11:53 INFO Received complete push request method=POST path=/api/pushes/1/complete18212026/11/10 21:11:53 INFO Completed push id=1 objects=6 duration=7.244412ms1822--- PASS: TestPush_CompleteCommitsEveryRoot (0.48s)1823=== CONT TestPendingClosureWriteTimeout/670k_objects1824=== CONT TestPendingClosureWriteTimeout/400_objects1825=== CONT TestProxyWriteTimeout/narinfo1826=== CONT TestProxyWriteTimeout/10_GiB_nar1827=== CONT TestProxyWriteTimeout/unknown_size1828=== CONT TestProxyWriteTimeout/1_GiB_nar1829--- PASS: TestProxyWriteTimeout (0.08s)1830 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1831 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1832 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1833 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1834=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1835=== NAME TestOrphanedObjectsGCStressTest1836 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains18372026/11/10 21:11:53 INFO Received push request method=POST path=/api/pushes18382026/11/10 21:11:53 INFO Received complete push request method=POST path=/api/pushes/1/complete18392026/11/10 21:11:53 INFO Completed push id=1 objects=4 duration=7.611251ms18402026/11/10 21:11:53 INFO Received push request method=POST path=/api/pushes1841 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1842--- PASS: TestReadProxyNarStreaming (0.49s)1843=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh18442026/11/10 21:11:53 INFO Received push request method=POST path=/api/pushes18452026/11/10 21:11:53 INFO Aborted multipart uploads count=0 kept=01846--- PASS: TestReadProxyInvalidPath (0.45s)1847=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18482026/11/10 21:11:53 INFO Received uploads request method=POST path=/1849=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18502026/11/10 21:11:53 INFO Received complete multipart upload request method=POST path=/1851=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18522026/11/10 21:11:53 INFO Received request for more parts method=POST path=/1853=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18542026/11/10 21:11:53 INFO Received uploads request method=POST path=/1855--- PASS: TestUploadHandlersRejectInvalidKeys (0.08s)1856 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1857 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1858 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1859 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1860=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed18612026/11/10 21:11:53 WARN Force mode enabled - objects will be deleted immediately without grace period18622026-11-10 21:11:53.361 UTC [2084] ERROR: could not obtain lock on row in relation "closures"18632026-11-10 21:11:53.361 UTC [2084] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT18642026-11-10 21:11:53.361 UTC [2084] ERROR: could not obtain lock on row in relation "closures"18652026-11-10 21:11:53.361 UTC [2084] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT18662026-11-10 21:11:53.362 UTC [2084] ERROR: could not obtain lock on row in relation "closures"18672026-11-10 21:11:53.362 UTC [2084] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT18682026-11-10 21:11:53.362 UTC [2084] ERROR: could not obtain lock on row in relation "closures"18692026-11-10 21:11:53.362 UTC [2084] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT18702026-11-10 21:11:53.362 UTC [2084] ERROR: could not obtain lock on row in relation "closures"18712026-11-10 21:11:53.362 UTC [2084] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1872--- PASS: TestPush_RootsAreLockedInByteOrder (0.51s)1873=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed18742026/11/10 21:11:53 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=018752026/11/10 21:11:53 INFO Vacuumed table table=pending_closures18762026/11/10 21:11:53 INFO Vacuumed table table=pending_objects18772026/11/10 21:11:53 INFO Vacuumed table table=multipart_uploads18782026/11/10 21:11:53 INFO Vacuumed table table=closures18792026/11/10 21:11:53 INFO Vacuumed table table=objects18802026/11/10 21:11:53 INFO Received complete push request method=POST path=/api/pushes/2/complete18812026/11/10 21:11:53 INFO Completed push id=2 objects=4 duration=3.567732ms1882--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.61s)1883=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1884--- PASS: TestReadProxyHead (0.52s)1885=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1886--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.48s)1887=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed18882026-11-10 21:11:53.477 UTC [2067] ERROR: Push does not exist: id=118892026-11-10 21:11:53.477 UTC [2067] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE18902026-11-10 21:11:53.477 UTC [2067] STATEMENT: SELECT commit_push($1)1891--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.74s)1892=== CONT TestIsValidUploadKey/narinfo1893=== CONT TestIsValidUploadKey/unknown_type1894=== CONT TestIsValidUploadKey/empty_key1895=== CONT TestIsValidUploadKey/absolute1896=== CONT TestIsValidUploadKey/traversal_nar1897=== CONT TestIsValidUploadKey/traversal1898=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1899=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1900=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1901=== CONT TestIsValidUploadKey/index.html1902=== CONT TestIsValidUploadKey/nix-cache-info1903=== CONT TestIsValidUploadKey/realisation_plus_in_output1904=== CONT TestIsValidUploadKey/realisation1905=== CONT TestIsValidUploadKey/build_log_equals1906=== CONT TestIsValidUploadKey/build_log_question_mark1907=== CONT TestIsValidUploadKey/build_log_plus_in_name1908=== CONT TestIsValidUploadKey/build_log_home-manager_file1909=== CONT TestIsValidUploadKey/build_log1910=== CONT TestIsValidUploadKey/listing1911=== CONT TestIsValidUploadKey/nar_plain1912=== CONT TestIsValidUploadKey/nar_xz1913=== CONT TestIsValidUploadKey/nar_zst1914--- PASS: TestIsValidUploadKey (0.08s)1915 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1916 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1917 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1918 --- PASS: TestIsValidUploadKey/absolute (0.00s)1919 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1920 --- PASS: TestIsValidUploadKey/traversal (0.00s)1921 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1922 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1923 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1924 --- PASS: TestIsValidUploadKey/index.html (0.00s)1925 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1926 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1927 --- PASS: TestIsValidUploadKey/realisation (0.00s)1928 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1929 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1930 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1931 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1932 --- PASS: TestIsValidUploadKey/build_log (0.00s)1933 --- PASS: TestIsValidUploadKey/listing (0.00s)1934 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1935 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1936 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1937=== CONT TestParseSingleRange/none1938=== CONT TestParseSingleRange/open-ended1939=== CONT TestParseSingleRange/start_far_past_EOF1940=== CONT TestParseSingleRange/start_past_EOF1941=== CONT TestParseSingleRange/single_byte1942=== CONT TestParseSingleRange/suffix_exceeds_size1943=== CONT TestParseSingleRange/suffix1944=== CONT TestParseSingleRange/end_clamped_to_size1945=== CONT TestParseSingleRange/multi-range_ignored1946=== CONT TestParseSingleRange/malformed_no_dash1947=== CONT TestParseSingleRange/closed1948=== CONT TestParseSingleRange/unknown_unit1949=== CONT TestParseSingleRange/malformed_end_before_start1950=== CONT TestParseSingleRange/malformed_both_empty1951--- PASS: TestParseSingleRange (0.08s)1952 --- PASS: TestParseSingleRange/none (0.00s)1953 --- PASS: TestParseSingleRange/open-ended (0.00s)1954 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1955 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1956 --- PASS: TestParseSingleRange/single_byte (0.00s)1957 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1958 --- PASS: TestParseSingleRange/suffix (0.00s)1959 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1960 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1961 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1962 --- PASS: TestParseSingleRange/closed (0.00s)1963 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1964 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1965 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1966=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19672026/11/10 21:11:53 INFO Received uploads request method=POST path=/19682026/11/10 21:11:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19692026/11/10 21:11:53 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NjcwYWZhMTItOWMyOS00OGM1LWE0MTktNjE3YzlmMDJjZDRjLmE3NWYzMzM0LTY1YTgtNDJjZC1iYTlhLTJlY2E5MWE2N2Q0YXgxNzk0MzQ1MTEyOTQzNDI3OTA5 parts=1219702026/11/10 21:11:53 INFO Received uploads request method=POST path=/api/pending_closures1971--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.99s)1972=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19732026/11/10 21:11:53 INFO Received request for more parts method=POST path=/1974--- PASS: TestReadProxy404 (0.56s)1975=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19762026/11/10 21:11:53 INFO Received complete multipart upload request method=POST path=/19772026/11/10 21:11:53 INFO Received uploads request method=POST path=/api/pending_closures19782026/11/10 21:11:53 INFO Aborted multipart uploads count=0 kept=019792026/11/10 21:11:53 WARN Force mode enabled - objects will be deleted immediately without grace period1980--- PASS: TestReadProxyContentNegotiation (0.51s)1981=== CONT TestServerTLSConfig/no_client_CA1982=== CONT TestServerTLSConfig/not_a_PEM_file1983=== CONT TestServerTLSConfig/missing_CA_file1984--- PASS: TestServerTLSConfig (0.00s)1985 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1986 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1987 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1988=== CONT TestResolveDBConnectionString/flag_wins1989=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1990=== CONT TestResolveDBConnectionString/nothing_configured1991=== CONT TestResolveDBConnectionString/missing_file_is_an_error1992=== CONT TestResolveDBConnectionString/file_when_flag_empty1993=== CONT TestGCEndsOnShutdown/before_the_run1994--- PASS: TestResolveDBConnectionString (0.00s)1995 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1996 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1997 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1998 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1999 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2000=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark20012026/11/10 21:11:53 INFO Received uploads request method=POST path=/api/pending_closures2002=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete20032026/11/10 21:11:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20042026/11/10 21:11:53 INFO Aborted multipart uploads count=0 kept=020052026/11/10 21:11:53 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=020062026/11/10 21:11:53 INFO Vacuumed table table=pending_closures20072026/11/10 21:11:53 INFO Vacuumed table table=pending_objects20082026/11/10 21:11:53 INFO Vacuumed table table=multipart_uploads20092026/11/10 21:11:53 INFO Vacuumed table table=closures20102026/11/10 21:11:53 WARN Force mode enabled - objects will be deleted immediately without grace period20112026/11/10 21:11:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020122026/11/10 21:11:53 INFO Vacuumed table table=objects20132026/11/10 21:11:53 INFO Received uploads request method=POST path=/api/pending_closures20142026/11/10 21:11:53 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>2015--- PASS: TestReadProxyNarinfo (0.55s)2016=== CONT TestClientErrorHandling/InvalidStorePath20172026/11/10 21:11:53 INFO Vacuumed table table=pending_closures20182026/11/10 21:11:53 INFO Vacuumed table table=pending_objects20192026/11/10 21:11:53 INFO Vacuumed table table=multipart_uploads20202026/11/10 21:11:53 INFO Vacuumed table table=closures20212026/11/10 21:11:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NjcwYWZhMTItOWMyOS00OGM1LWE0MTktNjE3YzlmMDJjZDRjLjMyY2ZlYjc5LTE1MDYtNGY2YS1hNWY0LWVmOWMyYWM3M2I5ZXgxNzk0MzQ1MTEzMDMzODkwOTQ1 parts=1220222026/11/10 21:11:53 INFO Vacuumed table table=objects2023=== CONT TestClientErrorHandling/ServerNotAvailable2024--- PASS: TestForceGCDuringPushOffersSweptObject (0.07s)2025 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.52s)2026 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.53s)2027=== CONT TestClientErrorHandling/InvalidAuthToken20282026/11/10 21:11:53 INFO Received uploads request method=POST path=/api/pending_closures20292026/11/10 21:11:53 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/present20302026/11/10 21:11:53 INFO Received uploads request method=POST path=/api/pending_closures20312026/11/10 21:11:53 INFO Received uploads request method=POST path=/api/pending_closures20322026/11/10 21:11:53 INFO Received uploads request method=POST path=/api/pending_closures20332026/11/10 21:11:53 WARN Request failed, retrying attempt=2 backoff=188.679728ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20342026/11/10 21:11:53 INFO Received uploads request method=POST path=/api/pending_closures20352026/11/10 21:11:53 INFO Aborted multipart uploads count=0 kept=020362026/11/10 21:11:53 WARN Force mode enabled - objects will be deleted immediately without grace period2037=== CONT TestCacheConfigHandler/full_config,_no_issuer2038=== CONT TestCacheConfigHandler/upstream_keys_advertised2039=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2040=== CONT TestCacheConfigHandler/no_signing_keys2041=== CONT TestCacheConfigHandler/no_cache_url_configured2042=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2043--- PASS: TestCacheConfigHandler (0.00s)2044 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2045 --- PASS: TestCacheConfigHandler/upstream_keys_advertised (0.00s)2046 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2047 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2048 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2049=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20502026/11/10 21:11:53 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]2051=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2052=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2053=== CONT TestService_RequireScope_OIDC/builder_may_write2054=== CONT TestService_RequireScope_OIDC/reader_may_read2055=== CONT TestService_RequireScope_OIDC/static_token_may_write2056=== CONT TestService_RequireScope_OIDC/static_token_may_admin2057=== CONT TestService_RequireScope_OIDC/reader_may_not_write20582026/11/10 21:11:53 WARN Authentication failed token_preview=eyJhbGciOi...0S52RTlRGQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2059=== CONT TestService_RequireScope_OIDC/ops_may_not_write2060=== CONT TestService_RequireScope_OIDC/ops_may_admin2061=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2062=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20632026/11/10 21:11:53 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]2064=== CONT TestService_RequireScope_OIDC/writer_implies_read2065=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2066=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2067=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2068=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2069=== CONT TestIsValidCachePath/narinfo2070=== CONT TestIsValidCachePath/index.html2071=== CONT TestIsValidCachePath/short_hash2072=== CONT TestIsValidCachePath/wrong_extension2073=== CONT TestIsValidCachePath/leading_slash2074=== CONT TestIsValidCachePath/empty2075=== CONT TestIsValidCachePath/random_path2076=== CONT TestIsValidCachePath/invalid_char_u2077=== CONT TestIsValidCachePath/invalid_char_e2078=== CONT TestIsValidCachePath/traversal_parent2079=== CONT TestIsValidCachePath/nar_uncompressed2080=== CONT TestIsValidCachePath/realisation2081=== CONT TestIsValidCachePath/log2082=== CONT TestIsValidCachePath/nix-cache-info2083=== CONT TestIsValidCachePath/traversal_in_middle2084=== CONT TestIsValidCachePath/ls2085=== CONT TestIsValidCachePath/nar_bz22086=== CONT TestIsValidCachePath/nar_xz2087--- PASS: TestService_AuthMiddleware_OIDC (0.36s)2088 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2089 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2090 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2091 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2092=== CONT TestIsValidCachePath/nar_zst2093=== CONT TestPush_RejectsBadRequests/no_roots2094=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2095--- PASS: TestIsValidCachePath (0.00s)2096 --- PASS: TestIsValidCachePath/narinfo (0.00s)2097 --- PASS: TestIsValidCachePath/index.html (0.00s)2098 --- PASS: TestIsValidCachePath/short_hash (0.00s)2099 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2100 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2101 --- PASS: TestIsValidCachePath/empty (0.00s)2102 --- PASS: TestIsValidCachePath/random_path (0.00s)2103 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2104 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2105 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2106 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2107 --- PASS: TestIsValidCachePath/realisation (0.00s)2108 --- PASS: TestIsValidCachePath/log (0.00s)2109 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2110 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2111 --- PASS: TestIsValidCachePath/ls (0.00s)2112 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2113 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2114 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2115 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2116=== CONT TestPush_RejectsBadRequests/bad_root21172026/11/10 21:11:53 INFO Received push request method=POST path=/api/pushes21182026/11/10 21:11:53 INFO Received push request method=POST path=/api/pushes2119=== CONT TestPush_RejectsBadRequests/root_not_in_objects21202026/11/10 21:11:53 INFO Received push request method=POST path=/api/pushes2121=== CONT TestPush_RejectsBadRequests/no_objects21222026/11/10 21:11:53 INFO Received push request method=POST path=/api/pushes2123--- PASS: TestPush_RejectsBadRequests (0.38s)2124 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2125 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2126 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2127 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2128--- PASS: TestService_RequireScope_OIDC (0.61s)2129 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2130 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2131 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2132 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2133 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2134 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2135 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2136 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2137 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2138 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2139 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2140 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2141 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2142 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)21432026/11/10 21:11:53 INFO Aborted multipart uploads count=0 kept=021442026/11/10 21:11:53 WARN Force mode enabled - objects will be deleted immediately without grace period21452026/11/10 21:11:53 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:39623/bucket104/?delete=\": context canceled"2146--- PASS: TestGCEndsOnShutdown (0.00s)2147 --- PASS: TestGCEndsOnShutdown/before_the_run (0.31s)2148 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.31s)2149 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.35s)21502026/11/10 21:11:54 WARN Request failed, retrying attempt=3 backoff=429.957103ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21512026/11/10 21:11:54 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21522026/11/10 21:11:54 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21532026/11/10 21:11:54 INFO lead: released remote=192.0.2.1:12342154--- PASS: TestLeadElectsOneAndHandsOver (2.90s)21552026/11/10 21:11:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21562026/11/10 21:11:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NjcwYWZhMTItOWMyOS00OGM1LWE0MTktNjE3YzlmMDJjZDRjLjJhOGZiY2JiLTEwZmUtNGZiNS04OTA5LTRhM2FmYzMzMGZiY3gxNzk0MzQ1MTEzMDQyOTYxNzM3 parts=122157--- PASS: TestSharedNarBothUploadsComplete (1.50s)2158--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)2159 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2160 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2161 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.69s)21622026/11/10 21:11:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21632026/11/10 21:11:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2164--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.08s)2165 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.91s)2166 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.88s)21672026/11/10 21:11:54 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=NjcwYWZhMTItOWMyOS00OGM1LWE0MTktNjE3YzlmMDJjZDRjLjE2ZGY4MzMxLWNlOTUtNDFhMi04MGNkLTMyYjgxZWM2ZmU4OHgxNzk0MzQ1MTEzNzEzMjc1OTg3 parts=1021682026/11/10 21:11:54 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=NjcwYWZhMTItOWMyOS00OGM1LWE0MTktNjE3YzlmMDJjZDRjLjU2MmVjODE4LTMyY2MtNDQxZi05ZGQ3LTYxZmM2YTZmMGIwOXgxNzk0MzQ1MTEzNzQxNDMzNzkw parts=1021692026/11/10 21:11:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21702026/11/10 21:11:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21712026/11/10 21:11:54 INFO Completed upload id=1 objects=3 duration=2.842405ms21722026/11/10 21:11:54 INFO Completed upload id=1 objects=3 duration=2.776755ms21732026/11/10 21:11:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21742026/11/10 21:11:54 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=NjcwYWZhMTItOWMyOS00OGM1LWE0MTktNjE3YzlmMDJjZDRjLmNmMWNjZjRmLWExNGYtNDhlYy05ZGUwLWY2ZTYxMWMzMjQ2MXgxNzk0MzQ1MTEzNzY5Mjk0OTM0 parts=1021752026/11/10 21:11:54 INFO Received uploads request method=POST path=/api/pending_closures21762026/11/10 21:11:54 INFO Received uploads request method=POST path=/api/pending_closures21772026/11/10 21:11:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21782026/11/10 21:11:54 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst21792026/11/10 21:11:54 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo21802026/11/10 21:11:54 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst21812026/11/10 21:11:54 WARN Found objects in DB but missing from S3, will re-upload count=121822026/11/10 21:11:54 INFO Completed upload id=1 objects=3 duration=2.979194ms21832026/11/10 21:11:54 INFO Received uploads request method=POST path=/api/pending_closures21842026/11/10 21:11:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21852026/11/10 21:11:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21862026/11/10 21:11:54 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=NjcwYWZhMTItOWMyOS00OGM1LWE0MTktNjE3YzlmMDJjZDRjLmQ0ODA2YWY4LTI1NDEtNGM0NC1iOGZjLTk1YjlmMTIzYTlhY3gxNzk0MzQ1MTEzNzk4NDE1Mzcy parts=1021872026/11/10 21:11:54 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=NjcwYWZhMTItOWMyOS00OGM1LWE0MTktNjE3YzlmMDJjZDRjLjJmMjgzZjQxLTY1YjctNGNkZi1hOTYzLWRiNWQwNzQ0ZTc0OXgxNzk0MzQ1MTEzODI2MTk0MTc2 parts=1021882026/11/10 21:11:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21892026/11/10 21:11:54 INFO Completed upload id=1 objects=3 duration=2.831096ms21902026/11/10 21:11:54 INFO Received uploads request method=POST path=/api/pending_closures21912026/11/10 21:11:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21922026/11/10 21:11:54 INFO Completed upload id=1 objects=3 duration=3.041434ms21932026/11/10 21:11:54 INFO Received uploads request method=POST path=/api/pending_closures2194--- PASS: TestPendingClosureWriteTimeout (0.07s)2195 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2196 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2197 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2198 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.20s)21992026/11/10 21:11:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022002026/11/10 21:11:54 INFO Received create pin request method=POST path=/api/pins/myapp22012026/11/10 21:11:54 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2289851878/001/store/ng1rahspbgs9avy1b4hkh123fm7m13ap-pinned-file.txt narinfo_key=ng1rahspbgs9avy1b4hkh123fm7m13ap.narinfo22022026/11/10 21:11:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures22032026/11/10 21:11:54 INFO Garbage collection started22042026/11/10 21:11:54 WARN Request failed, retrying attempt=4 backoff=744.092502ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22052026/11/10 21:11:54 INFO Aborted multipart uploads count=0 kept=022062026/11/10 21:11:54 WARN Force mode enabled - objects will be deleted immediately without grace period22072026/11/10 21:11:54 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=022082026/11/10 21:11:54 INFO Vacuumed table table=pending_closures22092026/11/10 21:11:54 INFO Vacuumed table table=pending_objects22102026/11/10 21:11:54 INFO Vacuumed table table=multipart_uploads22112026/11/10 21:11:54 INFO Vacuumed table table=closures22122026/11/10 21:11:54 INFO Vacuumed table table=objects22132026/11/10 21:11:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2214=== NAME TestOrphanedObjectsGCStressTest2215 orphaned_objects_gc_test.go:503: Stress test completed successfully:2216 orphaned_objects_gc_test.go:504: - Active objects preserved: 202217 orphaned_objects_gc_test.go:505: - Objects deleted: 2102218 orphaned_objects_gc_test.go:506: - Total GC'd: 2102219--- PASS: TestOrphanedObjectsGCStressTest (4.19s)22202026/11/10 21:11:54 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=NjcwYWZhMTItOWMyOS00OGM1LWE0MTktNjE3YzlmMDJjZDRjLmMwNmUzODdhLTUzOTctNDJhNy05MzYyLTQxNTQzYzE2MzViYngxNzk0MzQ1MTE0MjUwNTQzNjc2 parts=1022212026/11/10 21:11:54 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22222026/11/10 21:11:54 INFO Completed upload id=2 objects=3 duration=1.398062ms22232026/11/10 21:11:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22242026/11/10 21:11:54 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=NjcwYWZhMTItOWMyOS00OGM1LWE0MTktNjE3YzlmMDJjZDRjLmM4ODQ1ZGFmLWZjNDEtNGQ0OS04NTc0LWE0ZDI4MWRjZGRkZHgxNzk0MzQ1MTE0MjgzNDM5Mzk0 parts=1022252026/11/10 21:11:54 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22262026/11/10 21:11:54 INFO Completed upload id=2 objects=3 duration=1.330843ms22272026/11/10 21:11:54 INFO Received uploads request method=POST path=/api/pending_closures22282026/11/10 21:11:54 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst22292026/11/10 21:11:54 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo22302026/11/10 21:11:54 INFO Received uploads request method=POST path=/api/pending_closures22312026/11/10 21:11:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02232=== NAME TestClientIntegration2233 client_integration_test.go:370: Objects in database after GC:2234 client_integration_test.go:370: Successfully deleted all objects with GC --force22352026/11/10 21:11:54 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst22362026/11/10 21:11:54 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo2237--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.08s)2238 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (0.88s)2239 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (0.89s)2240 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (0.84s)2241 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (1.34s)2242 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (1.36s)2243--- PASS: TestClientIntegration (3.02s)22442026/11/10 21:11:55 WARN Request failed, retrying attempt=5 backoff=1.496355066s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22452026/11/10 21:11:56 WARN Rate limiter enabled after throttle name=s3-test rate=522462026/11/10 21:11:56 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2247=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2248 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102249 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002250--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.84s)2251--- PASS: TestConnectWaitsForAPeerMigration (5.14s)2252=== NAME TestPinProtectsFromGC2253 client_integration_test.go:887: Pin successfully protected closure from garbage collection2254--- PASS: TestPinProtectsFromGC (4.91s)22552026/11/10 21:11:56 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-config22562026/11/10 21:11:56 WARN Request failed, retrying attempt=2 backoff=213.721404ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2257--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.50s)22582026/11/10 21:11:57 WARN Request failed, retrying attempt=3 backoff=407.92586ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22592026/11/10 21:11:57 WARN Request failed, retrying attempt=4 backoff=771.797869ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22602026/11/10 21:11:57 INFO Aborted multipart uploads count=1 kept=022612026/11/10 21:11:57 INFO Received cleanup request method=DELETE path=/api/pending_closures22622026/11/10 21:11:57 INFO Aborted multipart uploads count=1 kept=02263--- PASS: TestPendingCleanupUsesOneCutoff (6.96s)22642026/11/10 21:11:58 WARN Request failed, retrying attempt=5 backoff=1.666872347s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2265--- PASS: TestClientErrorHandling (0.00s)2266 --- PASS: TestClientErrorHandling/InvalidStorePath (0.36s)2267 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.43s)2268 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.25s)2269PASS2270{"timestamp":"2026-11-10T21:11:59.891229724Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:44384","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(395)"}22712026-11-10 21:12:00.227 UTC [130] LOG: received smart shutdown request22722026-11-10 21:12:00.232 UTC [130] LOG: background worker "logical replication launcher" (PID 140) exited with exit code 122732026-11-10 21:12:00.240 UTC [135] LOG: shutting down22742026-11-10 21:12:00.241 UTC [135] LOG: checkpoint starting: shutdown immediate22752026-11-10 21:12:01.837 UTC [135] LOG: checkpoint complete: wrote 12028 buffers (73.4%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.239 s, sync=1.309 s, total=1.598 s; sync files=36061, longest=0.002 s, average=0.001 s; distance=521392 kB, estimate=521392 kB; lsn=0/21491F40, redo lsn=0/21491F4022762026-11-10 21:12:01.916 UTC [130] LOG: database system is shut down2277Running OIDC tests...2278=== RUN TestAudienceForIssuer2279=== PAUSE TestAudienceForIssuer2280=== RUN TestGlobMatch2281=== PAUSE TestGlobMatch2282=== RUN TestValidateToken_ValidToken2283=== PAUSE TestValidateToken_ValidToken2284=== RUN TestValidateToken_WrongAudience2285=== PAUSE TestValidateToken_WrongAudience2286=== RUN TestValidateToken_Expired2287=== PAUSE TestValidateToken_Expired2288=== RUN TestValidateToken_BoundClaimsMismatch2289=== PAUSE TestValidateToken_BoundClaimsMismatch2290=== RUN TestValidateToken_BoundSubjectMismatch2291=== PAUSE TestValidateToken_BoundSubjectMismatch2292=== RUN TestValidateToken_MultipleProviders2293=== PAUSE TestValidateToken_MultipleProviders2294=== RUN TestValidateToken_NoMatchingProvider2295=== PAUSE TestValidateToken_NoMatchingProvider2296=== RUN TestValidateToken_KubernetesServiceAccount2297=== PAUSE TestValidateToken_KubernetesServiceAccount2298=== RUN TestNewValidator_KubernetesRequiresCA2299=== PAUSE TestNewValidator_KubernetesRequiresCA2300=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2301=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2302=== RUN TestPins_ReservedForMatchingRule2303=== PAUSE TestPins_ReservedForMatchingRule2304=== RUN TestPins_TopLevelShorthand2305=== PAUSE TestPins_TopLevelShorthand2306=== RUN TestPins_ConfigValidation2307=== PAUSE TestPins_ConfigValidation2308=== RUN TestScopes_LegacyProviderDefaultsToWrite2309=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2310=== RUN TestScopes_Rules2311=== PAUSE TestScopes_Rules2312=== RUN TestScopes_ConfigValidation2313=== PAUSE TestScopes_ConfigValidation2314=== CONT TestAudienceForIssuer2315=== CONT TestValidateToken_KubernetesServiceAccount2316=== CONT TestValidateToken_ValidToken2317=== CONT TestPins_ConfigValidation2318=== CONT TestValidateToken_BoundClaimsMismatch2319=== CONT TestPins_TopLevelShorthand2320=== CONT TestValidateToken_MultipleProviders2321=== CONT TestScopes_ConfigValidation2322=== CONT TestValidateToken_BoundSubjectMismatch2323=== CONT TestScopes_Rules2324=== CONT TestValidateToken_NoMatchingProvider2325=== CONT TestScopes_LegacyProviderDefaultsToWrite2326=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2327=== CONT TestGlobMatch2328=== RUN TestGlobMatch/foo_foo2329=== PAUSE TestGlobMatch/foo_foo2330=== RUN TestGlobMatch/foo_bar2331=== PAUSE TestGlobMatch/foo_bar2332=== CONT TestPins_ReservedForMatchingRule2333=== CONT TestValidateToken_Expired2334=== CONT TestValidateToken_WrongAudience2335=== RUN TestGlobMatch/*_2336=== PAUSE TestGlobMatch/*_2337=== RUN TestGlobMatch/*_anything2338=== PAUSE TestGlobMatch/*_anything2339=== RUN TestGlobMatch/foo*_foo2340=== PAUSE TestGlobMatch/foo*_foo2341=== RUN TestGlobMatch/foo*_foobar2342=== PAUSE TestGlobMatch/foo*_foobar2343=== RUN TestGlobMatch/foo*_bar2344=== PAUSE TestGlobMatch/foo*_bar2345=== RUN TestGlobMatch/*bar_bar2346=== PAUSE TestGlobMatch/*bar_bar2347=== RUN TestGlobMatch/*bar_foobar2348=== PAUSE TestGlobMatch/*bar_foobar2349=== CONT TestNewValidator_KubernetesRequiresCA2350=== RUN TestGlobMatch/*bar_foo2351=== PAUSE TestGlobMatch/*bar_foo2352=== RUN TestGlobMatch/foo*bar_foobar2353=== PAUSE TestGlobMatch/foo*bar_foobar2354=== RUN TestGlobMatch/foo*bar_foo123bar2355=== PAUSE TestGlobMatch/foo*bar_foo123bar2356=== RUN TestGlobMatch/foo*bar_foobarbaz2357=== PAUSE TestGlobMatch/foo*bar_foobarbaz2358=== RUN TestGlobMatch/*/*_foo/bar2359=== PAUSE TestGlobMatch/*/*_foo/bar2360=== RUN TestGlobMatch/*/*_foo2361=== PAUSE TestGlobMatch/*/*_foo2362=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2363=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2364=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02365=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02366--- PASS: TestAudienceForIssuer (0.00s)2367=== RUN TestGlobMatch/refs/*/main_refs/heads/main2368--- PASS: TestPins_ConfigValidation (0.00s)2369--- PASS: TestScopes_ConfigValidation (0.00s)2370=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2371=== RUN TestGlobMatch/fo?_foo2372=== PAUSE TestGlobMatch/fo?_foo2373=== RUN TestGlobMatch/fo?_fo2374=== PAUSE TestGlobMatch/fo?_fo2375=== RUN TestGlobMatch/fo?_fooo2376=== PAUSE TestGlobMatch/fo?_fooo2377=== RUN TestGlobMatch/?oo_foo2378=== PAUSE TestGlobMatch/?oo_foo2379=== RUN TestGlobMatch/?oo_boo2380=== PAUSE TestGlobMatch/?oo_boo2381=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2382=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2383=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2384=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2385=== CONT TestGlobMatch/foo_foo2386=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2387=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2388=== CONT TestGlobMatch/foo*bar_foo123bar2389=== CONT TestGlobMatch/*/*_foo2390=== CONT TestGlobMatch/foo*bar_foobarbaz2391=== CONT TestGlobMatch/*bar_foo2392=== CONT TestGlobMatch/foo*bar_foobar2393=== CONT TestGlobMatch/*_anything2394=== CONT TestGlobMatch/foo*_foobar2395=== CONT TestGlobMatch/foo*_foo2396=== CONT TestGlobMatch/*bar_foobar2397=== CONT TestGlobMatch/foo_bar2398=== CONT TestGlobMatch/?oo_boo2399=== CONT TestGlobMatch/*bar_bar2400=== CONT TestGlobMatch/foo*_bar2401=== CONT TestGlobMatch/*_2402=== CONT TestGlobMatch/?oo_foo2403=== CONT TestGlobMatch/fo?_fooo2404=== CONT TestGlobMatch/fo?_fo2405=== CONT TestGlobMatch/fo?_foo2406=== CONT TestGlobMatch/refs/*/main_refs/heads/main2407=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02408=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2409=== CONT TestGlobMatch/*/*_foo/bar2410--- PASS: TestGlobMatch (0.00s)2411 --- PASS: TestGlobMatch/foo_foo (0.00s)2412 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2413 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2414 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2415 --- PASS: TestGlobMatch/*/*_foo (0.00s)2416 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2417 --- PASS: TestGlobMatch/*bar_foo (0.00s)2418 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2419 --- PASS: TestGlobMatch/*_anything (0.00s)2420 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2421 --- PASS: TestGlobMatch/foo*_foo (0.00s)2422 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2423 --- PASS: TestGlobMatch/foo_bar (0.00s)2424 --- PASS: TestGlobMatch/?oo_boo (0.00s)2425 --- PASS: TestGlobMatch/*bar_bar (0.00s)2426 --- PASS: TestGlobMatch/foo*_bar (0.00s)2427 --- PASS: TestGlobMatch/*_ (0.00s)2428 --- PASS: TestGlobMatch/?oo_foo (0.00s)2429 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2430 --- PASS: TestGlobMatch/fo?_fo (0.00s)2431 --- PASS: TestGlobMatch/fo?_foo (0.00s)2432 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2433 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2434 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2435 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)24362026/11/10 21:12:04 http: TLS handshake error from 127.0.0.1:39946: remote error: tls: bad certificate2437--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)24382026/11/10 21:12:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34363/oidc2439--- PASS: TestValidateToken_WrongAudience (0.03s)24402026/11/10 21:12:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41029/oidc2441--- PASS: TestPins_TopLevelShorthand (0.04s)24422026/11/10 21:12:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41329/oidc24432026/11/10 21:12:04 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324442026/11/10 21:12:04 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:461032445--- PASS: TestScopes_Rules (0.05s)2446--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)2447--- PASS: TestValidateToken_KubernetesServiceAccount (0.05s)24482026/11/10 21:12:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33219/oidc2449--- PASS: TestValidateToken_BoundClaimsMismatch (0.07s)24502026/11/10 21:12:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42517/oidc24512026/11/10 21:12:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46679/oidc2452--- PASS: TestValidateToken_BoundSubjectMismatch (0.08s)2453--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.08s)24542026/11/10 21:12:04 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40443/oidc24552026/11/10 21:12:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40477/oidc2456--- PASS: TestValidateToken_NoMatchingProvider (0.09s)2457--- PASS: TestPins_ReservedForMatchingRule (0.09s)24582026/11/10 21:12:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41297/oidc2459--- PASS: TestValidateToken_Expired (0.15s)24602026/11/10 21:12:04 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36569/oidc24612026/11/10 21:12:04 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:38619/oidc2462--- PASS: TestValidateToken_MultipleProviders (0.19s)24632026/11/10 21:12:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45185/oidc2464--- PASS: TestValidateToken_ValidToken (0.20s)2465PASS2466Running hook tests...2467=== RUN TestSendPathsEmpty2468=== PAUSE TestSendPathsEmpty2469=== RUN TestQueueEnqueueAndFetch2470=== PAUSE TestQueueEnqueueAndFetch2471=== RUN TestQueueDeduplication2472=== PAUSE TestQueueDeduplication2473=== RUN TestQueueRemove2474=== PAUSE TestQueueRemove2475=== RUN TestQueueFetchBatchLimit2476=== PAUSE TestQueueFetchBatchLimit2477=== RUN TestQueueRetryMovesToBack2478=== PAUSE TestQueueRetryMovesToBack2479=== RUN TestQueueFetchRemoveLifecycle2480=== PAUSE TestQueueFetchRemoveLifecycle2481=== RUN TestQueueConcurrentWriters2482=== PAUSE TestQueueConcurrentWriters2483=== RUN TestQueueRemoveLargeClosure2484=== PAUSE TestQueueRemoveLargeClosure2485=== RUN TestServerClientIntegration2486--- PASS: TestServerClientIntegration (0.00s)2487=== RUN TestServerQueueError24882026/11/10 21:12:04 ERROR Failed to queue paths error="permission denied" count=12489--- PASS: TestServerQueueError (0.00s)2490=== RUN TestGetListenerSocketActivation2491 server_test.go:218: === RUN TestGetListenerSocketActivation2492 --- PASS: TestGetListenerSocketActivation (0.00s)2493 PASS2494 2495--- PASS: TestGetListenerSocketActivation (0.01s)2496=== RUN TestServerStalledClientDoesNotBlockShutdown2497=== PAUSE TestServerStalledClientDoesNotBlockShutdown2498=== RUN TestServerBacksOffOnAcceptErrors2499=== PAUSE TestServerBacksOffOnAcceptErrors2500=== RUN TestDrainIsolatesPoisonPath2501=== PAUSE TestDrainIsolatesPoisonPath2502=== RUN TestRunNotBlockedByPoisonHead2503=== PAUSE TestRunNotBlockedByPoisonHead2504=== RUN TestDrainGivesUpWhenServerDown2505=== PAUSE TestDrainGivesUpWhenServerDown2506=== RUN TestFailedPathPrunedByLaterClosure2507=== PAUSE TestFailedPathPrunedByLaterClosure2508=== RUN TestWorkerUploadsAndRemoves2509=== PAUSE TestWorkerUploadsAndRemoves2510=== RUN TestWorkerSkipsGCdPaths2511=== PAUSE TestWorkerSkipsGCdPaths2512=== RUN TestWorkerPrunesClosureDeps2513=== PAUSE TestWorkerPrunesClosureDeps2514=== RUN TestDrainTimeout2515=== PAUSE TestDrainTimeout2516=== RUN TestWorkerRemoveFailureIsNotProgress2517=== PAUSE TestWorkerRemoveFailureIsNotProgress2518=== RUN TestWorkerKeepsPathItCannotStat2519=== PAUSE TestWorkerKeepsPathItCannotStat2520=== CONT TestSendPathsEmpty2521--- PASS: TestSendPathsEmpty (0.00s)2522=== CONT TestWorkerKeepsPathItCannotStat2523=== CONT TestServerBacksOffOnAcceptErrors2524=== CONT TestWorkerRemoveFailureIsNotProgress25252026/11/10 21:12:04 ERROR Accept failed error="too many open files"2526=== CONT TestDrainTimeout2527=== CONT TestWorkerPrunesClosureDeps2528=== CONT TestWorkerSkipsGCdPaths2529=== CONT TestWorkerUploadsAndRemoves2530=== CONT TestFailedPathPrunedByLaterClosure2531=== CONT TestDrainGivesUpWhenServerDown2532=== CONT TestRunNotBlockedByPoisonHead2533=== CONT TestDrainIsolatesPoisonPath2534=== CONT TestQueueRemove2535=== CONT TestQueueRemoveLargeClosure2536=== CONT TestQueueFetchBatchLimit2537=== CONT TestServerStalledClientDoesNotBlockShutdown2538=== CONT TestQueueDeduplication2539=== CONT TestQueueConcurrentWriters2540=== CONT TestQueueFetchRemoveLifecycle2541=== CONT TestQueueEnqueueAndFetch2542=== CONT TestQueueRetryMovesToBack25432026/11/10 21:12:04 ERROR Accept failed error="too many open files"25442026/11/10 21:12:04 ERROR Accept failed error="too many open files"25452026/11/10 21:12:04 INFO Upload queue status pending=225462026/11/10 21:12:04 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1789606334/002/nonexistent25472026/11/10 21:12:04 INFO Upload queue status pending=225482026/11/10 21:12:04 INFO Uploading batch count=125492026/11/10 21:12:04 ERROR Upload failed error="upload failed" count=125502026/11/10 21:12:04 INFO Upload queue status pending=225512026/11/10 21:12:04 INFO Uploading batch count=125522026/11/10 21:12:04 INFO Uploading batch count=225532026/11/10 21:12:04 INFO Uploading batch count=225542026/11/10 21:12:04 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1569057069/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat1569057069/002/locked/aaa: permission denied"25552026/11/10 21:12:04 INFO Uploading batch count=125562026/11/10 21:12:04 INFO Uploading batch count=425572026/11/10 21:12:04 ERROR Upload failed error="upload failed" count=225582026/11/10 21:12:04 INFO Uploading batch count=225592026/11/10 21:12:04 ERROR Upload failed error="upload failed" count=425602026/11/10 21:12:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1971970048/002/a25612026/11/10 21:12:04 INFO Uploading batch count=12562--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2563--- PASS: TestQueueEnqueueAndFetch (0.02s)25642026/11/10 21:12:04 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1569057069/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat1569057069/002/locked/aaa: permission denied"25652026/11/10 21:12:04 INFO Uploading batch count=125662026/11/10 21:12:04 INFO Upload queue status pending=325672026/11/10 21:12:04 INFO Uploading batch count=125682026/11/10 21:12:04 ERROR Upload failed error="upload failed" count=125692026/11/10 21:12:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath4216309765/002/bbb25702026/11/10 21:12:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1971970048/002/b2571--- PASS: TestQueueFetchBatchLimit (0.02s)25722026/11/10 21:12:04 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1569057069/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat1569057069/002/locked/aaa: permission denied"2573--- PASS: TestQueueRemove (0.03s)25742026/11/10 21:12:04 INFO Uploading batch count=225752026/11/10 21:12:04 ERROR Upload failed error="upload failed" count=225762026/11/10 21:12:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1971970048/002/c2577--- PASS: TestQueueDeduplication (0.03s)25782026/11/10 21:12:04 ERROR Drain finished with paths left in queue remaining=125792026/11/10 21:12:04 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress3674224766/002/nonexistent25802026/11/10 21:12:04 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12581--- PASS: TestQueueRetryMovesToBack (0.02s)25822026/11/10 21:12:04 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress3674224766/002/nonexistent25832026/11/10 21:12:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1971970048/002/d25842026/11/10 21:12:04 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125852026/11/10 21:12:04 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress3674224766/002/nonexistent25862026/11/10 21:12:04 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125872026/11/10 21:12:04 INFO Uploading batch count=12588--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)25892026/11/10 21:12:04 ERROR Upload failed error="upload failed" count=125902026/11/10 21:12:04 ERROR Drain finished with paths left in queue remaining=125912026/11/10 21:12:04 INFO Uploading batch count=225922026/11/10 21:12:04 ERROR Upload failed error="upload failed" count=225932026/11/10 21:12:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1971970048/002/e25942026/11/10 21:12:04 INFO Uploading batch count=125952026/11/10 21:12:04 ERROR Upload failed error="upload failed" count=125962026/11/10 21:12:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1971970048/002/f2597--- PASS: TestWorkerRemoveFailureIsNotProgress (0.03s)2598--- PASS: TestWorkerKeepsPathItCannotStat (0.03s)25992026/11/10 21:12:04 INFO Uploading batch count=126002026/11/10 21:12:04 ERROR Upload failed error="upload failed" count=126012026/11/10 21:12:04 ERROR Drain finished with paths left in queue remaining=1026022026/11/10 21:12:04 ERROR Drain finished with paths left in queue remaining=12603--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2604--- PASS: TestDrainIsolatesPoisonPath (0.03s)26052026/11/10 21:12:04 ERROR Accept failed error="too many open files"2606--- PASS: TestWorkerSkipsGCdPaths (0.04s)2607--- PASS: TestWorkerPrunesClosureDeps (0.04s)2608--- PASS: TestWorkerUploadsAndRemoves (0.04s)2609--- PASS: TestQueueRemoveLargeClosure (0.07s)26102026/11/10 21:12:04 ERROR Accept failed error="too many open files"26112026/11/10 21:12:04 ERROR Accept failed error="too many open files"26122026/11/10 21:12:04 ERROR Failed to decode request error="read unix /build/hook683056284/test.sock->@: i/o timeout"26132026/11/10 21:12:04 ERROR Failed to write response error="write unix /build/hook683056284/test.sock->@: i/o timeout"2614--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)2615--- PASS: TestQueueConcurrentWriters (0.22s)26162026/11/10 21:12:04 ERROR Upload failed error="context deadline exceeded" count=226172026/11/10 21:12:04 ERROR Drain finished with paths left in queue remaining=42618--- PASS: TestDrainTimeout (0.23s)26192026/11/10 21:12:04 ERROR Accept failed error="too many open files"26202026/11/10 21:12:04 ERROR Accept failed error="too many open files"2621--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)26222026/11/10 21:12:05 INFO Uploading batch count=126232026/11/10 21:12:05 INFO Uploading batch count=126242026/11/10 21:12:05 INFO Uploading batch count=126252026/11/10 21:12:05 ERROR Upload failed error="upload failed" count=126262026/11/10 21:12:05 INFO Uploading batch count=126272026/11/10 21:12:05 ERROR Upload failed error="upload failed" count=126282026/11/10 21:12:05 INFO Uploading batch count=126292026/11/10 21:12:05 ERROR Upload failed error="upload failed" count=126302026/11/10 21:12:05 INFO Uploading batch count=126312026/11/10 21:12:05 ERROR Upload failed error="upload failed" count=126322026/11/10 21:12:05 ERROR Drain finished with paths left in queue remaining=12633--- PASS: TestRunNotBlockedByPoisonHead (1.05s)2634PASS2635Running signing tests...2636=== RUN TestExternalSigner2637=== PAUSE TestExternalSigner2638=== RUN TestExternalSignerWrongPublicKey2639=== PAUSE TestExternalSignerWrongPublicKey2640=== RUN TestExternalSignerErrors2641=== PAUSE TestExternalSignerErrors2642=== RUN TestExternalSignerRestartsAfterCrash2643=== PAUSE TestExternalSignerRestartsAfterCrash2644=== RUN TestExternalSignerProgramErrorKeepsProcess2645=== PAUSE TestExternalSignerProgramErrorKeepsProcess2646=== RUN TestExternalSignerClose2647=== PAUSE TestExternalSignerClose2648=== RUN TestExternalSignerRejectsInvalidPublicKey2649=== PAUSE TestExternalSignerRejectsInvalidPublicKey2650=== RUN TestExternalSignerCancellation2651=== PAUSE TestExternalSignerCancellation2652=== RUN TestGenerateFingerprint2653=== PAUSE TestGenerateFingerprint2654=== RUN TestParseSigningKey2655=== PAUSE TestParseSigningKey2656=== RUN TestSign2657=== PAUSE TestSign2658=== RUN TestSignBatch2659=== PAUSE TestSignBatch2660=== RUN TestNilKeyPublicKey2661=== PAUSE TestNilKeyPublicKey2662=== RUN TestSignErrors2663=== PAUSE TestSignErrors2664=== RUN TestParsePublicKeysRejectsMalformed2665=== PAUSE TestParsePublicKeysRejectsMalformed2666=== CONT TestExternalSigner2667=== CONT TestGenerateFingerprint2668=== CONT TestParsePublicKeysRejectsMalformed2669=== CONT TestExternalSignerProgramErrorKeepsProcess2670=== CONT TestExternalSignerClose2671=== CONT TestSignBatch2672=== CONT TestSignErrors2673=== CONT TestNilKeyPublicKey2674=== CONT TestExternalSignerErrors2675=== RUN TestExternalSignerErrors/exit_on_request2676=== PAUSE TestExternalSignerErrors/exit_on_request2677=== RUN TestExternalSignerErrors/wrong_shape2678=== PAUSE TestExternalSignerErrors/wrong_shape2679=== RUN TestExternalSignerErrors/wrong_id2680=== CONT TestExternalSignerRestartsAfterCrash2681=== CONT TestSign2682=== CONT TestExternalSignerWrongPublicKey2683=== CONT TestParseSigningKey2684=== CONT TestExternalSignerCancellation2685=== CONT TestExternalSignerRejectsInvalidPublicKey2686=== RUN TestGenerateFingerprint/basic_with_references2687--- PASS: TestParsePublicKeysRejectsMalformed (0.00s)2688--- PASS: TestNilKeyPublicKey (0.00s)2689=== PAUSE TestExternalSignerErrors/wrong_id2690=== RUN TestExternalSignerRejectsInvalidPublicKey/#002691=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002692=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2693=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2694=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2695=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2696=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2697--- PASS: TestSign (0.00s)2698=== PAUSE TestGenerateFingerprint/basic_with_references2699=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2700=== RUN TestParseSigningKey/valid_32-byte_key2701=== PAUSE TestParseSigningKey/valid_32-byte_key2702=== RUN TestExternalSignerErrors/missing_signatures2703=== PAUSE TestExternalSignerErrors/missing_signatures2704=== RUN TestSignErrors/nil_key2705=== PAUSE TestSignErrors/nil_key2706=== RUN TestGenerateFingerprint/no_references2707=== RUN TestSignErrors/nil_narinfo2708=== PAUSE TestSignErrors/nil_narinfo2709=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2710=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2711=== CONT TestExternalSignerRejectsInvalidPublicKey/#002712=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2713=== PAUSE TestGenerateFingerprint/no_references2714=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2715=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2716=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2717=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2718=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2719=== RUN TestParseSigningKey/no_colon2720=== RUN TestExternalSignerErrors/wrong_signatures_shape2721=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2722=== RUN TestExternalSignerErrors/too_few_signatures2723=== RUN TestSignErrors/invalid_narinfo2724--- PASS: TestSignBatch (0.00s)2725=== PAUSE TestSignErrors/invalid_narinfo2726=== RUN TestSignErrors/canceled2727=== PAUSE TestSignErrors/canceled2728=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2729=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2730=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2731=== RUN TestGenerateFingerprint/invalid_nar_hash_length2732=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2733=== PAUSE TestParseSigningKey/no_colon2734=== PAUSE TestExternalSignerErrors/too_few_signatures2735=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2736--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2737 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2738 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2739 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2740 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2741 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2742=== CONT TestSignErrors/nil_key2743=== CONT TestSignErrors/invalid_narinfo2744=== CONT TestSignErrors/nil_narinfo2745=== CONT TestSignErrors/canceled2746--- PASS: TestSignErrors (0.00s)2747 --- PASS: TestSignErrors/nil_key (0.00s)2748 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2749 --- PASS: TestSignErrors/nil_narinfo (0.00s)2750 --- PASS: TestSignErrors/canceled (0.00s)2751=== RUN TestGenerateFingerprint/invalid_store_path_prefix2752=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2753=== RUN TestGenerateFingerprint/invalid_reference_prefix2754=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2755=== CONT TestGenerateFingerprint/basic_with_references2756=== RUN TestParseSigningKey/empty_name2757=== PAUSE TestParseSigningKey/empty_name2758=== RUN TestParseSigningKey/invalid_base642759=== PAUSE TestParseSigningKey/invalid_base642760=== CONT TestGenerateFingerprint/invalid_nar_hash_length2761=== RUN TestExternalSignerErrors/wrong_signature_length2762=== PAUSE TestExternalSignerErrors/wrong_signature_length2763=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2764=== CONT TestGenerateFingerprint/no_references2765=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2766=== CONT TestGenerateFingerprint/invalid_store_path_prefix2767=== CONT TestGenerateFingerprint/invalid_reference_prefix2768--- PASS: TestGenerateFingerprint (0.00s)2769 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2770 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2771 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2772 --- PASS: TestGenerateFingerprint/no_references (0.00s)2773 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2774 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2775 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2776=== RUN TestParseSigningKey/wrong_length2777=== PAUSE TestParseSigningKey/wrong_length2778=== RUN TestExternalSignerErrors/exit_at_startup2779=== PAUSE TestExternalSignerErrors/exit_at_startup2780=== CONT TestParseSigningKey/valid_32-byte_key2781=== CONT TestParseSigningKey/invalid_base642782=== CONT TestParseSigningKey/empty_name2783=== CONT TestParseSigningKey/no_colon2784=== CONT TestParseSigningKey/wrong_length2785=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2786--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2787=== RUN TestExternalSignerErrors/null_signatures2788=== PAUSE TestExternalSignerErrors/null_signatures2789=== RUN TestExternalSignerErrors/unrequested_key2790=== PAUSE TestExternalSignerErrors/unrequested_key2791--- PASS: TestParseSigningKey (0.00s)2792 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2793 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2794 --- PASS: TestParseSigningKey/empty_name (0.00s)2795 --- PASS: TestParseSigningKey/no_colon (0.00s)2796 --- PASS: TestParseSigningKey/wrong_length (0.00s)2797 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2798=== RUN TestExternalSignerErrors/missing_signature_name2799=== PAUSE TestExternalSignerErrors/missing_signature_name2800=== RUN TestExternalSignerErrors/wrong_signature_name2801=== PAUSE TestExternalSignerErrors/wrong_signature_name2802=== RUN TestExternalSignerErrors/invalid_signature_base642803=== PAUSE TestExternalSignerErrors/invalid_signature_base642804=== RUN TestExternalSignerErrors/program_error2805=== PAUSE TestExternalSignerErrors/program_error2806=== RUN TestExternalSignerErrors/invalid_JSON2807=== PAUSE TestExternalSignerErrors/invalid_JSON2808=== RUN TestExternalSignerErrors/null2809=== PAUSE TestExternalSignerErrors/null2810--- PASS: TestExternalSignerClose (0.00s)2811=== CONT TestExternalSignerErrors/wrong_signature_name2812=== CONT TestExternalSignerErrors/exit_on_request2813=== CONT TestExternalSignerErrors/exit_at_startup2814=== CONT TestExternalSignerErrors/wrong_signature_length2815=== CONT TestExternalSignerErrors/null_signatures2816=== CONT TestExternalSignerErrors/too_few_signatures2817=== CONT TestExternalSignerErrors/null2818=== CONT TestExternalSignerErrors/wrong_signatures_shape2819=== CONT TestExternalSignerErrors/missing_signatures2820=== CONT TestExternalSignerErrors/invalid_JSON2821=== CONT TestExternalSignerErrors/program_error2822=== CONT TestExternalSignerErrors/wrong_shape2823=== CONT TestExternalSignerErrors/invalid_signature_base642824=== CONT TestExternalSignerErrors/wrong_id2825=== CONT TestExternalSignerErrors/missing_signature_name2826=== CONT TestExternalSignerErrors/unrequested_key2827--- PASS: TestExternalSignerWrongPublicKey (0.00s)2828--- PASS: TestExternalSigner (0.01s)2829--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2830--- PASS: TestExternalSignerErrors (0.00s)2831 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2832 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2833 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2834 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2835 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2836 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2837 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2838 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2839 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2840 --- PASS: TestExternalSignerErrors/null (0.01s)2841 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2842 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2843 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2844 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2845 --- PASS: TestExternalSignerErrors/program_error (0.01s)2846 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2847--- PASS: TestExternalSignerCancellation (0.02s)2848PASS2849Running OpenBao signer tests...2850=== RUN TestSign2851=== PAUSE TestSign2852=== RUN TestSignErrors2853=== PAUSE TestSignErrors2854=== RUN TestServe2855=== PAUSE TestServe2856=== RUN TestServeRejectsGarbage2857=== PAUSE TestServeRejectsGarbage2858=== CONT TestSign2859=== CONT TestServe2860=== CONT TestServeRejectsGarbage2861=== CONT TestSignErrors2862--- PASS: TestServeRejectsGarbage (0.00s)2863=== RUN TestSignErrors/no_prefix2864=== PAUSE TestSignErrors/no_prefix2865=== RUN TestSignErrors/invalid_base642866=== PAUSE TestSignErrors/invalid_base642867=== RUN TestSignErrors/http_error2868=== PAUSE TestSignErrors/http_error2869=== RUN TestSignErrors/invalid_json2870=== PAUSE TestSignErrors/invalid_json2871=== CONT TestSignErrors/no_prefix2872=== CONT TestSignErrors/invalid_base642873--- PASS: TestServe (0.00s)2874=== CONT TestSignErrors/http_error2875=== CONT TestSignErrors/invalid_json2876--- PASS: TestSign (0.00s)2877--- PASS: TestSignErrors (0.00s)2878 --- PASS: TestSignErrors/invalid_json (0.00s)2879 --- PASS: TestSignErrors/http_error (0.00s)2880 --- PASS: TestSignErrors/invalid_base64 (0.00s)2881 --- PASS: TestSignErrors/no_prefix (0.00s)2882PASS