niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #406
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestRetryTimeoutOutlastsMaxRetries56=== PAUSE TestRetryTimeoutOutlastsMaxRetries57=== RUN TestShellSplit58=== PAUSE TestShellSplit59=== RUN TestShellSplitErrors60=== PAUSE TestShellSplitErrors61=== RUN TestStreamPushReportsEveryPath62=== PAUSE TestStreamPushReportsEveryPath63=== RUN TestStreamPushBatchesUnderLoad64=== PAUSE TestStreamPushBatchesUnderLoad65=== RUN TestStreamPushIsolatesFailures66=== PAUSE TestStreamPushIsolatesFailures67=== RUN TestStreamPushGivesUpOnDeadServer68=== PAUSE TestStreamPushGivesUpOnDeadServer69=== RUN TestStreamPushRequestLine70=== PAUSE TestStreamPushRequestLine71=== RUN TestStreamPushReportsSignatures72=== PAUSE TestStreamPushReportsSignatures73=== RUN TestStreamPushReportsSkippedPaths74=== PAUSE TestStreamPushReportsSkippedPaths75=== RUN TestClientSignaturesByStorePath76=== PAUSE TestClientSignaturesByStorePath77=== RUN TestStreamPushStopsWhenCanceled78=== PAUSE TestStreamPushStopsWhenCanceled79=== RUN TestSetClientTLS80=== PAUSE TestSetClientTLS81=== RUN TestSetClientTLSDoesNotMutateDefaultTransport82=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport83=== RUN TestSetClientTLSErrors84=== PAUSE TestSetClientTLSErrors85=== RUN TestStaticToken86=== PAUSE TestStaticToken87=== RUN TestFileTokenReadsAndCaches88=== PAUSE TestFileTokenReadsAndCaches89=== RUN TestFileTokenMissing90=== PAUSE TestFileTokenMissing91=== RUN TestFileTokenEmpty92=== PAUSE TestFileTokenEmpty93=== RUN TestScriptTokenNoExpiryRerunsEveryCall94=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall95=== RUN TestScriptTokenCachesUntilRefresh96=== PAUSE TestScriptTokenCachesUntilRefresh97=== RUN TestScriptTokenEmptyToken98=== PAUSE TestScriptTokenEmptyToken99=== RUN TestScriptTokenBadJSON100=== PAUSE TestScriptTokenBadJSON101=== RUN TestScriptTokenScriptFails102=== PAUSE TestScriptTokenScriptFails103=== RUN TestScriptTokenEmptyCommand104=== PAUSE TestScriptTokenEmptyCommand105=== CONT TestDoServerRequestAttachesToken106=== CONT TestShellSplit107=== CONT TestEncodeNixBase32WithRealHash108--- PASS: TestShellSplit (0.00s)109--- PASS: TestEncodeNixBase32WithRealHash (0.00s)110=== CONT TestScriptTokenNoExpiryRerunsEveryCall111=== CONT TestRetryTimeoutOutlastsMaxRetries112=== CONT TestEncodeNixBase32113=== RUN TestEncodeNixBase32/test_string_hash114=== PAUSE TestEncodeNixBase32/test_string_hash115=== RUN TestEncodeNixBase32/empty_input116=== PAUSE TestEncodeNixBase32/empty_input117=== CONT TestDoWithRetry_BodyReplayedViaGetBody118=== CONT TestDumpPathWriterError119=== CONT TestResolveStorePath120=== CONT TestDumpPathSingleFile121=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess122=== CONT TestDumpPathMatchesNix123=== CONT TestRateLimiterFeedback124=== RUN TestRateLimiterFeedback/429_enables_limiter125=== PAUSE TestRateLimiterFeedback/429_enables_limiter126=== RUN TestRateLimiterFeedback/503_enables_limiter127=== PAUSE TestRateLimiterFeedback/503_enables_limiter128=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter129=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter130=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter131=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter132=== CONT TestPathInfoCACompatibility133=== RUN TestPathInfoCACompatibility/null_ca_field134=== CONT TestParsePathInfoJSONMultiplePaths135=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths136=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths137=== CONT TestUploadMultipart_SupersededByPeer138=== CONT TestParsePathInfoJSON139=== CONT TestGetStorePathHash140=== CONT TestConvertHashToNix32141=== CONT TestPathInfoHashCompatibility142=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica143=== CONT TestCaseHackSuffix144=== CONT TestUploadMultipart_PartsInParallel145=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun146=== CONT TestPartSizeForNAR147=== CONT TestFilterOversizedClosures148=== CONT TestStreamPushRequestLine149=== CONT TestScriptTokenEmptyCommand1502026/10/10 19:01:43 WARN Rate limiter enabled after throttle name=server-test rate=5151=== PAUSE TestPathInfoCACompatibility/null_ca_field152=== RUN TestGetStorePathHash/valid_store_path153=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)154=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths155=== PAUSE TestGetStorePathHash/valid_store_path156=== CONT TestScriptTokenScriptFails157--- PASS: TestResolveStorePath (0.01s)158=== RUN TestPathInfoCACompatibility/old_string_format_-_text159=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)160=== RUN TestGetStorePathHash/basename_without_hyphen_should_error161=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1622026/10/10 19:01:43 WARN Rate limiter enabled after throttle name=server-test rate=5163=== CONT TestSetClientTLS1642026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:38315165=== RUN TestPartSizeForNAR/zero_stays_at_minimum166=== RUN TestUploadMultipart_SupersededByPeer/exists167=== PAUSE TestUploadMultipart_SupersededByPeer/exists168--- PASS: TestScriptTokenEmptyCommand (0.00s)169=== RUN TestUploadMultipart_SupersededByPeer/missing170=== RUN TestConvertHashToNix32/SRI_format_to_Nix321712026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:39143172=== PAUSE TestUploadMultipart_SupersededByPeer/missing173=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32174--- PASS: TestScriptTokenScriptFails (0.00s)175=== RUN TestParsePathInfoJSON/Nix_format176=== CONT TestScriptTokenBadJSON177=== CONT TestStreamPushStopsWhenCanceled178=== RUN TestConvertHashToNix32/already_Nix32_format179=== RUN TestFilterOversizedClosures/no_limit_keeps_everything180=== PAUSE TestParsePathInfoJSON/Nix_format181--- PASS: TestCaseHackSuffix (0.04s)182=== CONT TestClientSignaturesByStorePath183--- PASS: TestClientSignaturesByStorePath (0.00s)184=== CONT TestScriptTokenCachesUntilRefresh185=== CONT TestScriptTokenEmptyToken186=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything187--- PASS: TestStreamPushStopsWhenCanceled (0.07s)188=== PAUSE TestConvertHashToNix32/already_Nix32_format189=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text190=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error191=== CONT TestStreamPushReportsSkippedPaths192--- PASS: TestDoServerRequestAttachesToken (0.08s)193=== CONT TestRegisterUploadedObjectReusesConnections1942026/10/10 19:01:43 ERROR Upload failed error=boom count=1195=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon196=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon197--- PASS: TestStreamPushReportsSkippedPaths (0.00s)198=== RUN TestParsePathInfoJSON/Lix_format199=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive200=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive201=== RUN TestPathInfoCACompatibility/new_structured_format_-_text2022026/10/10 19:01:43 WARN Rate limiter backed off name=server-test rate=5203=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text2042026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:38315205=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method2062026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:39143207=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method2082026/10/10 19:01:43 INFO Garbage collection started2092026/10/10 19:01:43 INFO Garbage collection started210=== PAUSE TestParsePathInfoJSON/Lix_format211=== RUN TestParsePathInfoJSON/empty_input212=== PAUSE TestParsePathInfoJSON/empty_input213=== RUN TestParsePathInfoJSON/whitespace_only214=== PAUSE TestParsePathInfoJSON/whitespace_only215=== RUN TestParsePathInfoJSON/invalid_JSON216=== PAUSE TestParsePathInfoJSON/invalid_JSON217=== CONT TestStreamPushReportsEveryPath218=== CONT TestStreamPushIsolatesFailures219--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.08s)220--- PASS: TestScriptTokenBadJSON (0.07s)221--- PASS: TestStreamPushReportsEveryPath (0.00s)222=== CONT TestShellSplitErrors223--- PASS: TestShellSplitErrors (0.00s)224=== CONT TestFileTokenReadsAndCaches2252026/10/10 19:01:43 ERROR Upload failed error="bad path" count=3226--- PASS: TestStreamPushIsolatesFailures (0.00s)227=== CONT TestFileTokenEmpty228--- PASS: TestDumpPathSingleFile (0.08s)229=== CONT TestFileTokenMissing2302026/10/10 19:01:43 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=0231=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum2322026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:39143233=== RUN TestPartSizeForNAR/small_stays_at_minimum234=== PAUSE TestPartSizeForNAR/small_stays_at_minimum235=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum236=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum237=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts238=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts239=== RUN TestPartSizeForNAR/1_TiB240=== PAUSE TestPartSizeForNAR/1_TiB241=== RUN TestPartSizeForNAR/5_TiB_S3_max_object242=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object243=== RUN TestPartSizeForNAR/capped_at_5_GiB244=== PAUSE TestPartSizeForNAR/capped_at_5_GiB245=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped246=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped247=== RUN TestFilterOversizedClosures/all_closures_skipped248=== PAUSE TestFilterOversizedClosures/all_closures_skipped249--- PASS: TestFileTokenMissing (0.00s)250--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.07s)251--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.08s)252=== CONT TestSetClientTLSErrors253--- PASS: TestFileTokenReadsAndCaches (0.00s)254=== CONT TestRateLimiterFeedback/429_enables_limiter255--- PASS: TestFileTokenEmpty (0.00s)256=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter257=== CONT TestEncodeNixBase32/test_string_hash258=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter259--- PASS: TestScriptTokenEmptyToken (0.00s)2602026/10/10 19:01:43 WARN Garbage collection finished on another replica. Its statistics are not available here261=== CONT TestRateLimiterFeedback/503_enables_limiter262--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.07s)263=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths264=== RUN TestSetClientTLSErrors/missing_cert_file2652026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:39143266=== PAUSE TestSetClientTLSErrors/missing_cert_file267=== RUN TestSetClientTLSErrors/missing_key_file268=== PAUSE TestSetClientTLSErrors/missing_key_file269=== RUN TestSetClientTLSErrors/missing_ca_file270=== PAUSE TestSetClientTLSErrors/missing_ca_file271=== RUN TestSetClientTLSErrors/invalid_ca_file272=== PAUSE TestSetClientTLSErrors/invalid_ca_file273=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2742026/10/10 19:01:43 WARN Rate limiter enabled after throttle name=server-test rate=5275=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2762026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:38071277=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512278=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512279=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths280=== CONT TestUploadMultipart_SupersededByPeer/missing2812026/10/10 19:01:43 WARN Rate limiter backed off name=server-test rate=5282--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)283 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)284 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)285=== CONT TestStreamPushReportsSignatures2862026/10/10 19:01:43 WARN Rate limiter enabled after throttle name=server-test rate=5287=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method2882026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:45883289=== CONT TestStreamPushGivesUpOnDeadServer290=== CONT TestPathInfoCACompatibility/new_structured_format_-_text291=== CONT TestStaticToken292=== CONT TestSetClientTLSDoesNotMutateDefaultTransport293=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error294=== CONT TestEncodeNixBase32/empty_input295=== CONT TestUploadMultipart_SupersededByPeer/exists2962026/10/10 19:01:43 ERROR Upload failed error="connection refused" count=202972026/10/10 19:01:43 WARN Rate limiter backed off name=server-test rate=5298=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error299=== RUN TestConvertHashToNix32/invalid_format3002026/10/10 19:01:43 ERROR Server seems unavailable, giving up on batch untried=17301--- PASS: TestEncodeNixBase32 (0.00s)302 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)303 --- PASS: TestEncodeNixBase32/empty_input (0.00s)304=== CONT TestParsePathInfoJSON/Nix_format305=== CONT TestParsePathInfoJSON/invalid_JSON306=== CONT TestParsePathInfoJSON/whitespace_only3072026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:39143308=== CONT TestPartSizeForNAR/zero_stays_at_minimum309=== CONT TestFilterOversizedClosures/no_limit_keeps_everything310=== CONT TestPartSizeForNAR/1_TiB311=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts312=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum313=== CONT TestPartSizeForNAR/small_stays_at_minimum3142026/10/10 19:01:43 ERROR Upload failed error=boom count=1315=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped316=== CONT TestPartSizeForNAR/capped_at_5_GiB3172026/10/10 19:01:43 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000318=== CONT TestSetClientTLSErrors/missing_cert_file319=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)320=== CONT TestSetClientTLSErrors/missing_key_file321--- PASS: TestStaticToken (0.00s)322=== CONT TestSetClientTLSErrors/invalid_ca_file3232026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:39143324=== CONT TestFilterOversizedClosures/all_closures_skipped3252026/10/10 19:01:43 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=50326=== CONT TestPartSizeForNAR/5_TiB_S3_max_object327=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive328=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error329=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error330=== CONT TestPathInfoCACompatibility/old_string_format_-_text331=== PAUSE TestConvertHashToNix32/invalid_format332=== CONT TestPathInfoCACompatibility/null_ca_field333=== CONT TestParsePathInfoJSON/empty_input3342026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:39143335=== CONT TestParsePathInfoJSON/Lix_format336=== RUN TestSetClientTLS/rejects_connection_without_client_cert337=== CONT TestStreamPushBatchesUnderLoad338=== CONT TestSetClientTLSErrors/missing_ca_file339=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512340=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon341--- PASS: TestRateLimiterFeedback (0.00s)342 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)343 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)344 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)345 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)346=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI347=== CONT TestGetStorePathHash/valid_store_path348=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error349--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)350--- PASS: TestStreamPushReportsSignatures (0.00s)351=== CONT TestGetStorePathHash/basename_without_hyphen_should_error352=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error353=== CONT TestConvertHashToNix32/SRI_format_to_Nix32354=== CONT TestConvertHashToNix32/invalid_format355=== CONT TestConvertHashToNix32/already_Nix32_format356=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert357--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)358--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)359=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA3602026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:39143361--- PASS: TestPartSizeForNAR (0.07s)362 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)363 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)364 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)365 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)366 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)367 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)368 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)369--- PASS: TestFilterOversizedClosures (0.07s)370 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)371 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)372 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)373=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA374--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)375 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)376 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)377=== RUN TestSetClientTLS/preserves_debug_logging_transport3782026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:39143379--- PASS: TestConvertHashToNix32 (0.07s)380 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)381 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)382 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)383--- PASS: TestPathInfoCACompatibility (0.07s)384 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)385 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)386 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)387 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)388 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)389--- PASS: TestGetStorePathHash (0.09s)390 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)391 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)392 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)393 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)394--- PASS: TestPathInfoHashCompatibility (0.09s)395 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)396 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)397 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)398 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)399--- PASS: TestSetClientTLSErrors (0.02s)400 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)401 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)402 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)403 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)404--- PASS: TestParsePathInfoJSON (0.07s)405 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)406 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)407 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)408 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)409 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)410=== PAUSE TestSetClientTLS/preserves_debug_logging_transport411=== CONT TestSetClientTLS/rejects_connection_without_client_cert412=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA413=== CONT TestSetClientTLS/preserves_debug_logging_transport4142026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:391434152026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:391434162026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:391434172026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:391434182026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:391434192026/10/10 19:01:43 http: TLS handshake error from 127.0.0.1:34748: remote error: tls: bad certificate420--- PASS: TestStreamPushRequestLine (0.10s)4212026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:39143422--- PASS: TestSetClientTLS (0.03s)423 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)424 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)425 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)4262026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:391434272026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:391434282026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:391434292026/10/10 19:01:43 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:39143430--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.12s)431--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)432--- PASS: TestDumpPathWriterError (0.13s)433--- PASS: TestDumpPathMatchesNix (0.18s)434--- PASS: TestStreamPushBatchesUnderLoad (0.10s)435--- PASS: TestUploadMultipart_PartsInParallel (0.70s)436--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)437PASS438Running server tests...439The files belonging to this database system will be owned by user "nixbld".440This user must also own the server process.441442The database cluster will be initialized with locale "C".443The default database encoding has accordingly been set to "SQL_ASCII".444The default text search configuration will be set to "english".445446Data page checksums are enabled.447448creating directory /build/postgres4185851385/data ... ok449creating subdirectories ... ok450selecting dynamic shared memory implementation ... posix451selecting default "max_connections" ... 100452selecting default "shared_buffers" ... 128MB453selecting default time zone ... UTC454creating configuration files ... ok455running bootstrap script ... ok456performing post-bootstrap initialization ... ok457syncing data to disk ... ok458459initdb: warning: enabling "trust" authentication for local connections460initdb: 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.461462Success. You can now start the database server using:463464 pg_ctl -D /build/postgres4185851385/data -l logfile start465466/build/postgres4185851385:5432 - no response4672026-10-10 19:01:45.600 UTC [127] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4682026-10-10 19:01:45.600 UTC [127] LOG: listening on Unix socket "/build/postgres4185851385/.s.PGSQL.5432"4692026-10-10 19:01:45.606 UTC [134] LOG: database system was shut down at 2026-10-10 19:01:45 UTC4702026-10-10 19:01:45.610 UTC [127] LOG: database system is ready to accept connections471/build/postgres4185851385:5432 - accepting connections472{"timestamp":"2026-10-10T19:01:45.906510761Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"8e8ed1bd-ea81-45f5-8896-3c743d7a44b2","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(400)"}473=== RUN TestService_AuthMiddleware474=== PAUSE TestService_AuthMiddleware475=== RUN TestService_AuthMiddleware_MTLSProxyHeader476=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader477=== RUN TestService_AuthMiddleware_MTLSBoundSubjects478=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects479=== RUN TestService_ReadAuthMiddleware480=== PAUSE TestService_ReadAuthMiddleware481=== RUN TestService_AuthMiddleware_OIDC482=== PAUSE TestService_AuthMiddleware_OIDC483=== RUN TestService_RequireScope_OIDC484=== PAUSE TestService_RequireScope_OIDC485=== RUN TestService_ReadScope_PublicByDefault486=== PAUSE TestService_ReadScope_PublicByDefault487=== RUN TestCacheConfigHandler488=== PAUSE TestCacheConfigHandler489=== RUN TestCacheStatsHandler490=== PAUSE TestCacheStatsHandler491=== RUN TestClientCADerivations492=== PAUSE TestClientCADerivations493=== RUN TestClientErrorHandling494=== PAUSE TestClientErrorHandling495=== RUN TestClientIntegration496=== PAUSE TestClientIntegration497=== RUN TestClientMultipleUploads498=== PAUSE TestClientMultipleUploads499=== RUN TestClientWithDependencies500=== PAUSE TestClientWithDependencies501=== RUN TestClientSharedPathCommittedMidPush502=== PAUSE TestClientSharedPathCommittedMidPush503=== RUN TestPinProtectsFromGC504=== PAUSE TestPinProtectsFromGC505=== RUN TestClientPushesUseOnePush506=== PAUSE TestClientPushesUseOnePush507=== RUN TestClientFallsBackToClosures508=== PAUSE TestClientFallsBackToClosures509=== RUN TestDeleteClosuresRacingPins510=== PAUSE TestDeleteClosuresRacingPins511=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock512=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock513=== RUN TestResolveDBConnectionString514=== PAUSE TestResolveDBConnectionString515=== RUN TestConnectWaitsForAPeerMigration516=== PAUSE TestConnectWaitsForAPeerMigration517=== RUN TestLeadElectsOneAndHandsOver518=== PAUSE TestLeadElectsOneAndHandsOver519=== RUN TestLeadIncumbentWinsAfterRestart5202026/10/10 19:01:46 INFO lead: acquired remote=192.0.2.1:12345212026/10/10 19:01:46 INFO lead: released remote=192.0.2.1:12345222026/10/10 19:01:46 INFO lead: acquired remote=192.0.2.1:12345232026/10/10 19:01:47 INFO lead: released remote=192.0.2.1:1234524--- PASS: TestLeadIncumbentWinsAfterRestart (1.91s)525=== RUN TestLeadIncumbentAnnouncesAtOnce526=== PAUSE TestLeadIncumbentAnnouncesAtOnce527=== RUN TestLeadEndsOnShutdown528=== PAUSE TestLeadEndsOnShutdown529=== RUN TestLeadEndsWhenItsConnectionHangs5302026/10/10 19:01:48 INFO lead: acquired remote=192.0.2.1:12345312026-10-10 19:01:49.440 UTC [573] FATAL: terminating connection due to administrator command5322026/10/10 19:01:49 INFO lead: acquired remote=192.0.2.1:12345332026/10/10 19:01:50 WARN lead: lock connection lost error="timeout: context deadline exceeded"5342026/10/10 19:01:50 INFO lead: released remote=192.0.2.1:12345352026/10/10 19:01:51 INFO lead: released remote=192.0.2.1:1234536--- PASS: TestLeadEndsWhenItsConnectionHangs (3.12s)537=== RUN TestGCAdvisoryLockBlocksConcurrentRun538=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun539=== RUN TestGCBugBareHashReferences540=== PAUSE TestGCBugBareHashReferences541=== RUN TestGCMetrics542=== PAUSE TestGCMetrics543=== RUN TestPushDedupSurvivesConcurrentGC544=== PAUSE TestPushDedupSurvivesConcurrentGC545=== RUN TestDeduplicatedObjectsRecordedAsPending546=== PAUSE TestDeduplicatedObjectsRecordedAsPending547=== RUN TestGCSweepSkipsPendingObjects548=== PAUSE TestGCSweepSkipsPendingObjects549=== RUN TestTombstonedObjectOfferedWithoutWaiting550=== PAUSE TestTombstonedObjectOfferedWithoutWaiting551=== RUN TestGCSweepDeliversEachKeyOnce552=== PAUSE TestGCSweepDeliversEachKeyOnce553=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection554=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection555=== RUN TestForceGCDuringPushOffersSweptObject556=== PAUSE TestForceGCDuringPushOffersSweptObject557=== RUN TestFailedS3DeleteKeepsTombstone558=== PAUSE TestFailedS3DeleteKeepsTombstone559=== RUN TestSweepSkipsRowsLockedByPush560=== PAUSE TestSweepSkipsRowsLockedByPush561=== RUN TestRegisterCompletedObjectNeedsPendingRow562=== PAUSE TestRegisterCompletedObjectNeedsPendingRow563=== RUN TestGetExistingObjectsLocksRows564=== PAUSE TestGetExistingObjectsLocksRows565=== RUN TestSweepRechecksPendingAfterLocking566=== PAUSE TestSweepRechecksPendingAfterLocking567=== RUN TestPushWaitsForSweepHoldingRow568=== PAUSE TestPushWaitsForSweepHoldingRow569=== RUN TestCommitRacingPendingCleanupKeepsObjects570=== PAUSE TestCommitRacingPendingCleanupKeepsObjects571=== RUN TestGCEndsOnShutdown572=== PAUSE TestGCEndsOnShutdown573=== RUN TestGCTaskStore_StartNew574=== PAUSE TestGCTaskStore_StartNew575=== RUN TestGCTaskStore_DeduplicateSameParams576=== PAUSE TestGCTaskStore_DeduplicateSameParams577=== RUN TestGCTaskStore_ConflictDifferentParams578=== PAUSE TestGCTaskStore_ConflictDifferentParams579=== RUN TestGCTaskStore_GetEmpty580=== PAUSE TestGCTaskStore_GetEmpty581=== RUN TestGCTaskStore_GetReturnsLatest582=== PAUSE TestGCTaskStore_GetReturnsLatest583=== RUN TestGCTaskStore_CompletedAllowsNewTask584=== PAUSE TestGCTaskStore_CompletedAllowsNewTask585=== RUN TestGCTaskStore_PhaseUpdates586=== PAUSE TestGCTaskStore_PhaseUpdates587=== RUN TestGCTaskStore_Fail588=== PAUSE TestGCTaskStore_Fail589=== RUN TestGracefulShutdownDrainsInflight590=== PAUSE TestGracefulShutdownDrainsInflight591=== RUN TestService_healthCheckHandler592=== PAUSE TestService_healthCheckHandler593=== RUN TestService_readinessHandler594=== PAUSE TestService_readinessHandler595=== RUN TestGenerateLandingPage596=== PAUSE TestGenerateLandingPage597=== RUN TestCacheConfigHandlerMaxNarSize598=== PAUSE TestCacheConfigHandlerMaxNarSize599=== RUN TestCreatePendingClosureRejectsOversizedNAR600=== PAUSE TestCreatePendingClosureRejectsOversizedNAR601=== RUN TestNARDeduplicationMetadataUploadBug602=== PAUSE TestNARDeduplicationMetadataUploadBug603=== RUN TestMetricsInventory604=== PAUSE TestMetricsInventory605=== RUN TestMetricsCommit606=== PAUSE TestMetricsCommit607=== RUN TestService_NativeMTLS608=== PAUSE TestService_NativeMTLS609=== RUN TestServerTLSConfig610=== PAUSE TestServerTLSConfig611=== RUN TestMultipartCleanup612=== PAUSE TestMultipartCleanup613=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded614=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded615=== RUN TestPendingCleanupUsesOneCutoff616=== PAUSE TestPendingCleanupUsesOneCutoff617=== RUN TestObjectStatsTrigger618=== PAUSE TestObjectStatsTrigger619=== RUN TestObjectStatsLargeCommit620=== PAUSE TestObjectStatsLargeCommit621=== RUN TestOrphanedObjectsGC622=== PAUSE TestOrphanedObjectsGC623=== RUN TestOrphanedObjectsGCStressTest624=== PAUSE TestOrphanedObjectsGCStressTest625=== RUN TestCreatePin_ReservedPins626=== PAUSE TestCreatePin_ReservedPins627=== RUN TestPresentReportsOnlyClosureRoots628=== PAUSE TestPresentReportsOnlyClosureRoots629=== RUN TestPresentRefreshesOnlyStaleClosures630=== PAUSE TestPresentRefreshesOnlyStaleClosures631=== RUN TestPresentNotReportedWhileGCDeletesClosure632=== PAUSE TestPresentNotReportedWhileGCDeletesClosure633=== RUN TestParseSingleRange634=== PAUSE TestParseSingleRange635=== RUN TestProxyHeadersOnlyTrustedOnSocket6362026/10/10 19:01:51 INFO Starting HTTP server address=proxy.sock6372026/10/10 19:01:51 INFO Starting HTTP server address=127.0.0.1:465056382026/10/10 19:01:51 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6392026/10/10 19:01:51 INFO Shutdown signal received, draining in-flight requests timeout=10s640--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.12s)641=== RUN TestIsValidCachePath642=== PAUSE TestIsValidCachePath643=== RUN TestReadProxyNarinfo644=== PAUSE TestReadProxyNarinfo645=== RUN TestReadProxyNarinfoAlreadyDecompressed646=== PAUSE TestReadProxyNarinfoAlreadyDecompressed647=== RUN TestReadProxyContentNegotiation648=== PAUSE TestReadProxyContentNegotiation649=== RUN TestReadProxyNarStreaming650=== PAUSE TestReadProxyNarStreaming651=== RUN TestReadProxy404652=== PAUSE TestReadProxy404653=== RUN TestReadProxyInvalidPath654=== PAUSE TestReadProxyInvalidPath655=== RUN TestReadProxyHead656=== PAUSE TestReadProxyHead657=== RUN TestReadProxyOutlastsServerWriteTimeout658=== PAUSE TestReadProxyOutlastsServerWriteTimeout659=== RUN TestReadProxyConditionalGet660=== PAUSE TestReadProxyConditionalGet661=== RUN TestReadProxyRootRedirectsToIndexHTML662=== PAUSE TestReadProxyRootRedirectsToIndexHTML663=== RUN TestReadProxyDisabled664=== PAUSE TestReadProxyDisabled665=== RUN TestReadRedirectNar666=== PAUSE TestReadRedirectNar667=== RUN TestReadRedirectKeepsNarinfoProxied668=== PAUSE TestReadRedirectKeepsNarinfoProxied669=== RUN TestReadProxyRangeRequest670=== PAUSE TestReadProxyRangeRequest671=== RUN TestReadRedirectUsesPublicS3URL672=== PAUSE TestReadRedirectUsesPublicS3URL673=== RUN TestPush_OverlappingRootsStoreOneRowPerKey674=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey675=== RUN TestPush_CompleteCommitsEveryRoot676=== PAUSE TestPush_CompleteCommitsEveryRoot677=== RUN TestPush_RepeatedRootCommitsOnce678=== PAUSE TestPush_RepeatedRootCommitsOnce679=== RUN TestPush_CompleteWaitsForCleanupOfThePush680=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush681=== RUN TestPush_RootsAreLockedInByteOrder682=== PAUSE TestPush_RootsAreLockedInByteOrder683=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit684=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit685=== RUN TestPush_RejectsBadRequests686=== PAUSE TestPush_RejectsBadRequests687=== RUN TestPush_SignsNarinfosOfItsPendingObjects688=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects689=== RUN TestRedundantMultipartUpload690=== PAUSE TestRedundantMultipartUpload691=== RUN TestCompleteMultipartUpload_ErrorButObjectExists692=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists693=== RUN TestCompletedNarNotReofferedAcrossClosures694=== PAUSE TestCompletedNarNotReofferedAcrossClosures695=== RUN TestPresignedUploadRegisteredBeforeCommit696=== PAUSE TestPresignedUploadRegisteredBeforeCommit697=== RUN TestService_Rustfstest698=== PAUSE TestService_Rustfstest699=== RUN TestParseSize700=== PAUSE TestParseSize701=== RUN TestSkippedUploadsHandler702=== PAUSE TestSkippedUploadsHandler703=== RUN TestSystemdListenerNotActivated704--- PASS: TestSystemdListenerNotActivated (0.00s)705=== RUN TestWatchdogBeatsWhenHealthy706--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)707=== RUN TestWatchdogSkipsWhenUnhealthy7082026/10/10 19:01:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7092026/10/10 19:01:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7102026/10/10 19:01:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7112026/10/10 19:01:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7122026/10/10 19:01:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7132026/10/10 19:01:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7142026/10/10 19:01:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7152026/10/10 19:01:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7162026/10/10 19:01:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7172026/10/10 19:01:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"718--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)719=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle720=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle721=== RUN TestProxyWriteTimeout722=== PAUSE TestProxyWriteTimeout723=== RUN TestPendingClosureWriteTimeout724=== PAUSE TestPendingClosureWriteTimeout725=== RUN TestIsValidUploadKey726=== PAUSE TestIsValidUploadKey727=== RUN TestUploadHandlersRejectInvalidKeys728=== PAUSE TestUploadHandlersRejectInvalidKeys729=== RUN TestUploadHandlersRejectOversizedBody730=== PAUSE TestUploadHandlersRejectOversizedBody731=== RUN TestService_cleanupPendingClosuresHandler732=== PAUSE TestService_cleanupPendingClosuresHandler733=== RUN TestService_createPendingClosureHandler734=== PAUSE TestService_createPendingClosureHandler735=== RUN TestService_verifyS3Integrity736=== PAUSE TestService_verifyS3Integrity737=== RUN TestCompleteMultipartUnregistered738=== PAUSE TestCompleteMultipartUnregistered739=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT740=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT741=== CONT TestService_AuthMiddleware742=== CONT TestProxyWriteTimeout743=== CONT TestParseSingleRange744=== RUN TestParseSingleRange/none745=== PAUSE TestParseSingleRange/none746=== RUN TestParseSingleRange/unknown_unit747=== PAUSE TestParseSingleRange/unknown_unit748=== RUN TestParseSingleRange/multi-range_ignored749=== PAUSE TestParseSingleRange/multi-range_ignored750=== RUN TestParseSingleRange/malformed_no_dash751=== PAUSE TestParseSingleRange/malformed_no_dash752=== CONT TestPush_OverlappingRootsStoreOneRowPerKey753=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT754=== CONT TestCompleteMultipartUnregistered755=== CONT TestService_verifyS3Integrity756=== CONT TestService_createPendingClosureHandler757=== CONT TestService_cleanupPendingClosuresHandler758=== CONT TestUploadHandlersRejectOversizedBody759=== CONT TestUploadHandlersRejectInvalidKeys760=== CONT TestIsValidUploadKey761=== CONT TestPendingClosureWriteTimeout762=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle763=== CONT TestSkippedUploadsHandler764=== CONT TestParseSize765--- PASS: TestParseSize (0.00s)7662026/10/10 19:01:51 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000767=== CONT TestPresignedUploadRegisteredBeforeCommit768=== CONT TestService_Rustfstest769=== CONT TestCompletedNarNotReofferedAcrossClosures770=== CONT TestCompleteMultipartUpload_ErrorButObjectExists771=== CONT TestRedundantMultipartUpload772=== CONT TestPush_SignsNarinfosOfItsPendingObjects773=== CONT TestPush_RejectsBadRequests774=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit775=== RUN TestProxyWriteTimeout/narinfo776=== RUN TestParseSingleRange/malformed_both_empty777=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info778=== RUN TestPendingClosureWriteTimeout/empty779=== RUN TestIsValidUploadKey/narinfo780=== CONT TestPush_RootsAreLockedInByteOrder781=== PAUSE TestParseSingleRange/malformed_both_empty782=== PAUSE TestPendingClosureWriteTimeout/empty783=== RUN TestPendingClosureWriteTimeout/400_objects784=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info785=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal786=== PAUSE TestIsValidUploadKey/narinfo787=== RUN TestParseSingleRange/malformed_end_before_start788=== RUN TestIsValidUploadKey/nar_zst789=== PAUSE TestIsValidUploadKey/nar_zst790=== PAUSE TestProxyWriteTimeout/narinfo791=== PAUSE TestPendingClosureWriteTimeout/400_objects792=== RUN TestProxyWriteTimeout/1_GiB_nar793=== PAUSE TestProxyWriteTimeout/1_GiB_nar794=== RUN TestProxyWriteTimeout/10_GiB_nar795=== PAUSE TestProxyWriteTimeout/10_GiB_nar796=== RUN TestProxyWriteTimeout/unknown_size797=== PAUSE TestProxyWriteTimeout/unknown_size798=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal799=== PAUSE TestParseSingleRange/malformed_end_before_start800=== RUN TestParseSingleRange/closed801=== PAUSE TestParseSingleRange/closed802=== RUN TestParseSingleRange/open-ended803=== PAUSE TestParseSingleRange/open-ended804=== RUN TestParseSingleRange/end_clamped_to_size805=== PAUSE TestParseSingleRange/end_clamped_to_size806=== RUN TestParseSingleRange/suffix807=== PAUSE TestParseSingleRange/suffix808=== RUN TestParseSingleRange/suffix_exceeds_size809=== PAUSE TestParseSingleRange/suffix_exceeds_size810=== RUN TestParseSingleRange/single_byte811=== PAUSE TestParseSingleRange/single_byte812=== RUN TestParseSingleRange/start_past_EOF813=== PAUSE TestParseSingleRange/start_past_EOF814=== RUN TestParseSingleRange/start_far_past_EOF815=== PAUSE TestParseSingleRange/start_far_past_EOF816=== RUN TestIsValidUploadKey/nar_xz817=== PAUSE TestIsValidUploadKey/nar_xz818=== RUN TestPendingClosureWriteTimeout/670k_objects819=== PAUSE TestPendingClosureWriteTimeout/670k_objects820=== CONT TestPush_CompleteWaitsForCleanupOfThePush821=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline822=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline823=== CONT TestPush_CompleteCommitsEveryRoot824=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key825=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key826=== CONT TestPush_RepeatedRootCommitsOnce827=== RUN TestIsValidUploadKey/nar_plain828=== PAUSE TestIsValidUploadKey/nar_plain829=== RUN TestIsValidUploadKey/listing830=== PAUSE TestIsValidUploadKey/listing831=== RUN TestIsValidUploadKey/build_log832=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key833=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key834=== CONT TestRegisterCompletedObjectNeedsPendingRow835=== PAUSE TestIsValidUploadKey/build_log836=== RUN TestIsValidUploadKey/build_log_home-manager_file837=== PAUSE TestIsValidUploadKey/build_log_home-manager_file838=== RUN TestIsValidUploadKey/build_log_plus_in_name839=== PAUSE TestIsValidUploadKey/build_log_plus_in_name840=== RUN TestIsValidUploadKey/build_log_question_mark841=== PAUSE TestIsValidUploadKey/build_log_question_mark842=== RUN TestIsValidUploadKey/build_log_equals843=== PAUSE TestIsValidUploadKey/build_log_equals844=== RUN TestIsValidUploadKey/realisation845=== PAUSE TestIsValidUploadKey/realisation846=== RUN TestIsValidUploadKey/realisation_plus_in_output847=== PAUSE TestIsValidUploadKey/realisation_plus_in_output848=== RUN TestIsValidUploadKey/nix-cache-info849=== PAUSE TestIsValidUploadKey/nix-cache-info850=== RUN TestIsValidUploadKey/index.html851=== PAUSE TestIsValidUploadKey/index.html852=== RUN TestIsValidUploadKey/narinfo_key,_nar_type853=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type854=== RUN TestIsValidUploadKey/nar_key,_narinfo_type855=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type856=== RUN TestIsValidUploadKey/listing_key,_narinfo_type857=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type858=== RUN TestIsValidUploadKey/traversal859=== PAUSE TestIsValidUploadKey/traversal860=== RUN TestIsValidUploadKey/traversal_nar861=== PAUSE TestIsValidUploadKey/traversal_nar862=== RUN TestIsValidUploadKey/absolute863--- PASS: TestSkippedUploadsHandler (0.01s)864=== CONT TestPresentNotReportedWhileGCDeletesClosure865=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale866=== PAUSE TestIsValidUploadKey/absolute867=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale868=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh869=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh870=== RUN TestIsValidUploadKey/empty_key871=== PAUSE TestIsValidUploadKey/empty_key872=== CONT TestPresentRefreshesOnlyStaleClosures873=== RUN TestIsValidUploadKey/unknown_type874=== PAUSE TestIsValidUploadKey/unknown_type875=== CONT TestPresentReportsOnlyClosureRoots876=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart877=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart878=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts879=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts880=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure881=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure882=== CONT TestCreatePin_ReservedPins8832026/10/10 19:01:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46261/oidc8842026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures8852026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures8862026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures8872026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures8882026/10/10 19:01:51 INFO Received push request method=POST path=/api/pushes8892026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures890--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.38s)891=== CONT TestOrphanedObjectsGCStressTest892--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.39s)893=== CONT TestOrphanedObjectsGC8942026/10/10 19:01:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8952026/10/10 19:01:51 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst896--- PASS: TestCompleteMultipartUnregistered (0.41s)897=== CONT TestObjectStatsLargeCommit8982026/10/10 19:01:51 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"899--- PASS: TestService_AuthMiddleware (0.44s)900=== CONT TestObjectStatsTrigger9012026/10/10 19:01:51 INFO Received cleanup request method=DELETE path=/api/pending_closures9022026/10/10 19:01:51 INFO Aborted multipart uploads count=0 kept=09032026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures9042026/10/10 19:01:51 INFO Received cleanup request method=DELETE path=/api/pending_closures9052026/10/10 19:01:51 INFO Aborted multipart uploads count=1 kept=09062026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures9072026/10/10 19:01:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9082026-10-10 19:01:51.899 UTC [644] ERROR: Closure does not exist: id=19092026-10-10 19:01:51.899 UTC [644] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9102026-10-10 19:01:51.899 UTC [644] STATEMENT: -- name: CommitPendingClosure :one911 SELECT commit_pending_closure($1::bigint)::bigint912 913--- PASS: TestService_cleanupPendingClosuresHandler (0.50s)914=== CONT TestPendingCleanupUsesOneCutoff9152026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures9162026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures9172026/10/10 19:01:51 INFO Received uploads request method=POST path=/api/pending_closures9182026/10/10 19:01:51 INFO Received push request method=POST path=/api/pushes9192026/10/10 19:01:52 INFO Received complete push request method=POST path=/api/pushes/1/complete920--- PASS: TestService_Rustfstest (0.52s)921=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded9222026/10/10 19:01:52 INFO Completed push id=1 objects=4 duration=6.992326ms923--- PASS: TestPush_RepeatedRootCommitsOnce (0.52s)924=== CONT TestMultipartCleanup9252026/10/10 19:01:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9262026/10/10 19:01:52 INFO Received push request method=POST path=/api/pushes9272026/10/10 19:01:52 INFO Received complete push request method=POST path=/api/pushes/1/complete9282026/10/10 19:01:52 INFO Completed push id=1 objects=6 duration=10.03343ms929--- PASS: TestPush_CompleteCommitsEveryRoot (0.58s)930=== CONT TestServerTLSConfig931=== RUN TestServerTLSConfig/no_client_CA932=== PAUSE TestServerTLSConfig/no_client_CA933=== RUN TestServerTLSConfig/missing_CA_file934=== PAUSE TestServerTLSConfig/missing_CA_file935=== RUN TestServerTLSConfig/not_a_PEM_file936=== PAUSE TestServerTLSConfig/not_a_PEM_file937=== CONT TestService_NativeMTLS938--- PASS: TestPresentRefreshesOnlyStaleClosures (0.59s)939=== CONT TestMetricsCommit9402026/10/10 19:01:52 INFO Received push request method=POST path=/api/pushes9412026/10/10 19:01:52 INFO Received complete push request method=POST path=/api/pushes/1/complete942--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.64s)943=== CONT TestMetricsInventory9442026/10/10 19:01:52 INFO Completed push id=1 objects=4 duration=8.874553ms9452026/10/10 19:01:52 INFO Received push request method=POST path=/api/pushes9462026/10/10 19:01:52 INFO Received push request method=POST path=/api/pushes9472026/10/10 19:01:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9482026/10/10 19:01:52 INFO Signed narinfos id=1 count=19492026/10/10 19:01:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9502026/10/10 19:01:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9512026/10/10 19:01:52 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9522026/10/10 19:01:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9532026/10/10 19:01:52 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9542026/10/10 19:01:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9552026/10/10 19:01:52 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19562026/10/10 19:01:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9572026/10/10 19:01:52 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo958--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.69s)959=== CONT TestNARDeduplicationMetadataUploadBug9602026/10/10 19:01:52 INFO Received uploads request method=POST path=/api/pending_closures9612026/10/10 19:01:52 INFO Aborted multipart uploads count=0 kept=09622026/10/10 19:01:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9632026/10/10 19:01:52 WARN Force mode enabled - objects will be deleted immediately without grace period9642026/10/10 19:01:52 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=09652026/10/10 19:01:52 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OGI4NDExZDAtOGFkZi00NDA1LTljMjgtZjAxOGVjZTIzNWU1LmJhZWVhMWFkLWY0ZWYtNGQzYS1iM2Y3LWUyYWZkMDBiOWJmY3gxNzkxNjU4OTExNzIwNDM5MzEy parts=109662026/10/10 19:01:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9672026/10/10 19:01:52 INFO Vacuumed table table=pending_closures9682026/10/10 19:01:52 INFO Completed upload id=1 objects=2 duration=2.576965ms9692026/10/10 19:01:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9702026/10/10 19:01:52 INFO Vacuumed table table=pending_objects9712026/10/10 19:01:52 INFO Received uploads request method=POST path=/api/pending_closures9722026/10/10 19:01:52 INFO Vacuumed table table=multipart_uploads9732026/10/10 19:01:52 INFO Received uploads request method=POST path=/api/pending_closures9742026/10/10 19:01:52 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGI4NDExZDAtOGFkZi00NDA1LTljMjgtZjAxOGVjZTIzNWU1Ljk1NzI4ZjYzLTZmNjUtNDU4NS05MmU5LTU3MTJhOTEwMTBjMHgxNzkxNjU4OTEyMjA3ODgxMzg0975--- PASS: TestPresentReportsOnlyClosureRoots (0.75s)976=== CONT TestReadProxyOutlastsServerWriteTimeout9772026/10/10 19:01:52 INFO Vacuumed table table=closures9782026/10/10 19:01:52 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9792026/10/10 19:01:52 WARN Found objects in DB but missing from S3, will re-upload count=19802026/10/10 19:01:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete981--- PASS: TestService_verifyS3Integrity (0.85s)982=== CONT TestCreatePendingClosureRejectsOversizedNAR9832026/10/10 19:01:52 INFO Received uploads request method=POST path=/api/pending_closures984--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)985=== CONT TestCacheConfigHandlerMaxNarSize986--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)987=== CONT TestReadRedirectUsesPublicS3URL9882026/10/10 19:01:52 INFO Vacuumed table table=objects9892026/10/10 19:01:52 INFO Received complete push request method=POST path=/api/pushes/2/complete9902026/10/10 19:01:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGI4NDExZDAtOGFkZi00NDA1LTljMjgtZjAxOGVjZTIzNWU1Ljk1NzI4ZjYzLTZmNjUtNDU4NS05MmU5LTU3MTJhOTEwMTBjMHgxNzkxNjU4OTEyMjA3ODgxMzg0 parts=19912026/10/10 19:01:52 INFO Completed push id=2 objects=4 duration=3.221144ms992--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.76s)993=== CONT TestGenerateLandingPage9942026/10/10 19:01:52 INFO Received uploads request method=POST path=/api/pending_closures995--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.76s)996=== CONT TestReadProxyRangeRequest997--- PASS: TestGenerateLandingPage (0.00s)998=== CONT TestReadRedirectKeepsNarinfoProxied9992026/10/10 19:01:52 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OGI4NDExZDAtOGFkZi00NDA1LTljMjgtZjAxOGVjZTIzNWU1LjI3ZmMzZTQxLWVmODQtNGZjNC1hOTAwLTdjZmMwNzM1ZmUzMHgxNzkxNjU4OTExNzQ1NDI1MjEz parts=1010002026/10/10 19:01:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10012026/10/10 19:01:52 INFO Completed upload id=1 objects=2 duration=5.756569ms10022026/10/10 19:01:52 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010032026/10/10 19:01:52 INFO Received uploads request method=POST path=/api/pending_closures10042026/10/10 19:01:52 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10052026/10/10 19:01:52 INFO Received uploads request method=POST path=/api/pending_closures1006--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.80s)1007=== CONT TestReadRedirectNar1008=== RUN TestPush_RejectsBadRequests/no_roots1009=== PAUSE TestPush_RejectsBadRequests/no_roots1010=== RUN TestPush_RejectsBadRequests/no_objects1011=== PAUSE TestPush_RejectsBadRequests/no_objects1012=== RUN TestPush_RejectsBadRequests/bad_root10132026/10/10 19:01:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures1014=== PAUSE TestPush_RejectsBadRequests/bad_root1015=== RUN TestPush_RejectsBadRequests/root_not_in_objects1016=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1017=== CONT TestService_readinessHandler10182026/10/10 19:01:52 INFO Aborted multipart uploads count=0 kept=010192026/10/10 19:01:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010202026/10/10 19:01:52 INFO Vacuumed table table=pending_closures10212026/10/10 19:01:52 INFO Vacuumed table table=pending_objects10222026/10/10 19:01:52 INFO Received push request method=POST path=/api/pushes10232026/10/10 19:01:52 INFO Vacuumed table table=multipart_uploads10242026/10/10 19:01:52 INFO Vacuumed table table=closures10252026/10/10 19:01:52 INFO Vacuumed table table=objects10262026/10/10 19:01:52 INFO Received push request method=POST path=/api/pushes10272026/10/10 19:01:52 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001028--- PASS: TestService_createPendingClosureHandler (0.99s)1029=== CONT TestService_healthCheckHandler10302026/10/10 19:01:52 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10312026/10/10 19:01:52 WARN Refused reserved pin name=worker-x86_64-linux10322026/10/10 19:01:52 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10332026/10/10 19:01:52 INFO Received create pin request method=POST path=/api/pins/my-app10342026/10/10 19:01:52 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1035--- PASS: TestCreatePin_ReservedPins (0.82s)1036=== CONT TestReadProxyDisabled10372026-10-10 19:01:52.406 UTC [751] ERROR: could not obtain lock on row in relation "closures"10382026-10-10 19:01:52.406 UTC [751] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10392026-10-10 19:01:52.407 UTC [751] ERROR: could not obtain lock on row in relation "closures"10402026-10-10 19:01:52.407 UTC [751] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10412026-10-10 19:01:52.407 UTC [751] ERROR: could not obtain lock on row in relation "closures"10422026-10-10 19:01:52.407 UTC [751] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10432026-10-10 19:01:52.407 UTC [751] ERROR: could not obtain lock on row in relation "closures"10442026-10-10 19:01:52.407 UTC [751] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10452026-10-10 19:01:52.408 UTC [751] ERROR: could not obtain lock on row in relation "closures"10462026-10-10 19:01:52.408 UTC [751] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1047--- PASS: TestPush_RootsAreLockedInByteOrder (0.92s)1048=== CONT TestReadProxyRootRedirectsToIndexHTML10492026/10/10 19:01:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10502026/10/10 19:01:52 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OGI4NDExZDAtOGFkZi00NDA1LTljMjgtZjAxOGVjZTIzNWU1LjY3MDEyZDM1LWRlYWEtNGQwZS1hN2NjLTQzNTQwZDRjYThlZngxNzkxNjU4OTExOTA2NjY5MTcy parts=1210512026/10/10 19:01:52 INFO Received uploads request method=POST path=/api/pending_closures1052--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.03s)1053=== CONT TestReadProxyConditionalGet1054--- PASS: TestObjectStatsTrigger (0.70s)1055=== CONT TestGracefulShutdownDrainsInflight10562026/10/10 19:01:52 INFO Starting HTTP server address=127.0.0.1:3622110572026/10/10 19:01:52 INFO Shutdown signal received, draining in-flight requests timeout=10s10582026/10/10 19:01:52 INFO Received uploads request method=POST path=/api/pending_closures10592026/10/10 19:01:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10602026/10/10 19:01:52 INFO Received uploads request method=POST path=/api/pending_closures10612026/10/10 19:01:52 INFO Received cleanup request method=DELETE path=/api/pending_closures10622026/10/10 19:01:52 INFO Received uploads request method=POST path=/api/pending_closures10632026/10/10 19:01:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OGI4NDExZDAtOGFkZi00NDA1LTljMjgtZjAxOGVjZTIzNWU1LmRiODE2Y2FkLTFlYzEtNDg2NC04N2UzLTM5MDk1YWY3YWQ2N3gxNzkxNjU4OTExOTY2MjU1MTk0 parts=121064--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1065=== CONT TestGCTaskStore_StartNew1066--- PASS: TestGCTaskStore_StartNew (0.00s)1067=== CONT TestGCEndsOnShutdown1068=== RUN TestGCEndsOnShutdown/before_the_run1069=== PAUSE TestGCEndsOnShutdown/before_the_run1070=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete10712026/10/10 19:01:52 INFO Received uploads request method=POST path=/api/pending_closures1072=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1073=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1074=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1075=== CONT TestGCTaskStore_DeduplicateSameParams1076--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1077=== CONT TestCommitRacingPendingCleanupKeepsObjects10782026/10/10 19:01:52 INFO Received uploads request method=POST path=/api/pending_closures1079--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.62s)1080=== CONT TestGCTaskStore_Fail1081--- PASS: TestGCTaskStore_Fail (0.00s)1082=== CONT TestPushWaitsForSweepHoldingRow10832026/10/10 19:01:52 INFO Received uploads request method=POST path=/api/pending_closures10842026-10-10 19:01:52.661 UTC [745] ERROR: Push does not exist: id=110852026-10-10 19:01:52.661 UTC [745] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10862026-10-10 19:01:52.661 UTC [745] STATEMENT: SELECT commit_push($1)1087--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.16s)1088=== CONT TestGCTaskStore_PhaseUpdates1089--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1090=== CONT TestGCTaskStore_CompletedAllowsNewTask1091--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1092=== CONT TestSweepRechecksPendingAfterLocking10932026/10/10 19:01:52 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10942026/10/10 19:01:52 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1095--- PASS: TestService_NativeMTLS (0.59s)1096=== CONT TestGCTaskStore_GetReturnsLatest1097--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1098=== CONT TestGetExistingObjectsLocksRows10992026/10/10 19:01:52 INFO Received push request method=POST path=/api/pushes11002026/10/10 19:01:52 INFO Received complete push request method=POST path=/api/pushes/1/complete11012026/10/10 19:01:52 INFO Completed push id=1 objects=4 duration=10.742679ms11022026/10/10 19:01:52 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11032026/10/10 19:01:52 INFO Completed upload id=2 objects=2 duration=2.334535ms1104--- PASS: TestMetricsCommit (0.67s)1105=== CONT TestGCTaskStore_GetEmpty1106--- PASS: TestGCTaskStore_GetEmpty (0.00s)1107=== CONT TestReadProxyNarStreaming1108--- PASS: TestMetricsInventory (0.62s)1109=== CONT TestGCTaskStore_ConflictDifferentParams1110--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1111=== CONT TestReadProxyHead11122026/10/10 19:01:52 INFO Received cleanup request method=DELETE path=/api/pending_closures11132026/10/10 19:01:52 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket34/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11142026/10/10 19:01:52 INFO Aborted multipart uploads count=0 kept=111152026/10/10 19:01:52 INFO Received cleanup request method=DELETE path=/api/pending_closures11162026/10/10 19:01:52 INFO Aborted multipart uploads count=1 kept=01117--- PASS: TestMultipartCleanup (0.76s)1118=== CONT TestReadProxyNarinfo1119=== NAME TestNARDeduplicationMetadataUploadBug1120 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1016035587/001/store/kfhmrrhaqilfh05hd1gqd4jalr3r2zdh-file1.txt1121=== NAME TestOrphanedObjectsGC1122 orphaned_objects_gc_test.go:287: GC Test Summary:1123 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1124 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1125 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1126 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1127 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1128--- PASS: TestOrphanedObjectsGC (1.04s)1129=== CONT TestReadProxyInvalidPath1130--- PASS: TestReadRedirectUsesPublicS3URL (0.60s)1131=== CONT TestReadProxyNarinfoAlreadyDecompressed1132--- PASS: TestReadRedirectKeepsNarinfoProxied (0.61s)1133=== CONT TestReadProxy40411342026/10/10 19:01:52 INFO Received push request method=POST path=/api/pushes1135--- PASS: TestReadProxyRangeRequest (0.64s)1136=== CONT TestIsValidCachePath1137=== RUN TestIsValidCachePath/narinfo1138=== PAUSE TestIsValidCachePath/narinfo1139=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1140=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1141=== RUN TestIsValidCachePath/nar_zst1142=== PAUSE TestIsValidCachePath/nar_zst1143=== RUN TestIsValidCachePath/nar_xz1144=== PAUSE TestIsValidCachePath/nar_xz1145=== RUN TestIsValidCachePath/nar_bz21146=== PAUSE TestIsValidCachePath/nar_bz21147=== RUN TestIsValidCachePath/nar_uncompressed1148=== PAUSE TestIsValidCachePath/nar_uncompressed1149=== RUN TestIsValidCachePath/ls1150=== PAUSE TestIsValidCachePath/ls1151=== RUN TestIsValidCachePath/log1152=== PAUSE TestIsValidCachePath/log1153=== RUN TestIsValidCachePath/realisation1154=== PAUSE TestIsValidCachePath/realisation1155=== RUN TestIsValidCachePath/nix-cache-info1156=== PAUSE TestIsValidCachePath/nix-cache-info1157=== RUN TestIsValidCachePath/index.html1158=== PAUSE TestIsValidCachePath/index.html1159=== RUN TestIsValidCachePath/traversal_parent1160=== PAUSE TestIsValidCachePath/traversal_parent1161=== RUN TestIsValidCachePath/traversal_in_middle1162=== PAUSE TestIsValidCachePath/traversal_in_middle1163=== RUN TestIsValidCachePath/invalid_char_e1164=== PAUSE TestIsValidCachePath/invalid_char_e1165=== RUN TestIsValidCachePath/invalid_char_u1166=== PAUSE TestIsValidCachePath/invalid_char_u1167=== RUN TestIsValidCachePath/random_path1168=== PAUSE TestIsValidCachePath/random_path1169=== RUN TestIsValidCachePath/empty1170=== PAUSE TestIsValidCachePath/empty1171=== RUN TestIsValidCachePath/leading_slash1172=== PAUSE TestIsValidCachePath/leading_slash1173=== RUN TestIsValidCachePath/wrong_extension1174=== PAUSE TestIsValidCachePath/wrong_extension1175=== RUN TestIsValidCachePath/short_hash1176=== PAUSE TestIsValidCachePath/short_hash1177=== CONT TestReadProxyContentNegotiation11782026/10/10 19:01:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11792026/10/10 19:01:52 INFO Uploading kfhmrrhaqilfh05hd1gqd4jalr3r2zdh-file1.txt (160B)11802026/10/10 19:01:52 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11812026/10/10 19:01:52 WARN Failed to register uploaded object key=kfhmrrhaqilfh05hd1gqd4jalr3r2zdh.ls error="server returned 404: 404 page not found\n"11822026/10/10 19:01:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11832026/10/10 19:01:52 INFO Signed narinfos id=1 count=111842026/10/10 19:01:52 INFO Uploading 1 narinfos11852026/10/10 19:01:52 INFO Received complete push request method=POST path=/api/pushes/1/complete11862026/10/10 19:01:52 WARN Failed to register uploaded object key=kfhmrrhaqilfh05hd1gqd4jalr3r2zdh.narinfo error="server returned 404: 404 page not found\n"1187--- PASS: TestReadRedirectNar (0.64s)1188=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11892026/10/10 19:01:52 INFO Completed push id=1 objects=3 duration=11.128578ms11902026/10/10 19:01:52 INFO Upload complete. (80ms)1191=== NAME TestNARDeduplicationMetadataUploadBug1192 metadata_upload_test.go:54: Retrieved narinfo from S3:1193 StorePath: /build/TestNARDeduplicationMetadataUploadBug1016035587/001/store/kfhmrrhaqilfh05hd1gqd4jalr3r2zdh-file1.txt1194 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1195 Compression: zstd1196 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1197 NarSize: 1601198 References: 1199 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1200 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1201 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1202 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12032026/10/10 19:01:52 WARN readiness check failed error="closed pool"1204--- PASS: TestService_readinessHandler (0.66s)1205=== CONT TestClientErrorHandling1206=== RUN TestClientErrorHandling/InvalidStorePath1207=== PAUSE TestClientErrorHandling/InvalidStorePath1208=== RUN TestClientErrorHandling/InvalidAuthToken1209=== PAUSE TestClientErrorHandling/InvalidAuthToken1210=== RUN TestClientErrorHandling/ServerNotAvailable1211=== PAUSE TestClientErrorHandling/ServerNotAvailable1212=== CONT TestSweepSkipsRowsLockedByPush1213=== NAME TestNARDeduplicationMetadataUploadBug1214 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1016035587/001/store/dims1iibdbcjqc0p1fwwl8diy5hl09iy-file2.txt1215--- PASS: TestService_healthCheckHandler (0.59s)1216=== CONT TestDeleteClosuresRacingPins1217--- PASS: TestReadProxyDisabled (0.61s)1218=== CONT TestService_RequireScope_OIDC12192026/10/10 19:01:53 INFO Received push request method=POST path=/api/pushes12202026/10/10 19:01:53 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12212026/10/10 19:01:53 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12222026/10/10 19:01:53 WARN Failed to register uploaded object key=dims1iibdbcjqc0p1fwwl8diy5hl09iy.ls error="server returned 404: 404 page not found\n"12232026/10/10 19:01:53 INFO Signed narinfos id=2 count=112242026/10/10 19:01:53 INFO Uploading 1 narinfos12252026/10/10 19:01:53 INFO Received complete push request method=POST path=/api/pushes/2/complete12262026/10/10 19:01:53 WARN Failed to register uploaded object key=dims1iibdbcjqc0p1fwwl8diy5hl09iy.narinfo error="server returned 404: 404 page not found\n"12272026/10/10 19:01:53 INFO Completed push id=2 objects=3 duration=2.837214ms1228--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.64s)12292026/10/10 19:01:53 INFO Upload complete. (51ms)1230=== CONT TestClientFallsBackToClosures1231=== NAME TestNARDeduplicationMetadataUploadBug1232 metadata_upload_test.go:76: Retrieved narinfo from S3:1233 StorePath: /build/TestNARDeduplicationMetadataUploadBug1016035587/001/store/dims1iibdbcjqc0p1fwwl8diy5hl09iy-file2.txt1234 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1235 Compression: zstd1236 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1237 NarSize: 1601238 References: 1239 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1240 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1241 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1242 {"version":1,"root":{"type":"regular","size":44}}1243--- PASS: TestNARDeduplicationMetadataUploadBug (0.88s)1244=== CONT TestClientPushesUseOnePush1245--- PASS: TestReadProxyConditionalGet (0.56s)1246=== CONT TestFailedS3DeleteKeepsTombstone12472026/10/10 19:01:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46635/oidc12482026/10/10 19:01:53 INFO Aborted multipart uploads count=0 kept=012492026/10/10 19:01:53 INFO Received uploads request method=POST path=/api/pending_closures12502026/10/10 19:01:53 WARN Force mode enabled - objects will be deleted immediately without grace period12512026/10/10 19:01: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=012522026/10/10 19:01:53 INFO Vacuumed table table=pending_closures12532026/10/10 19:01:53 INFO Vacuumed table table=pending_objects12542026/10/10 19:01:53 INFO Vacuumed table table=multipart_uploads12552026/10/10 19:01:53 INFO Vacuumed table table=closures12562026/10/10 19:01:53 INFO Vacuumed table table=objects1257--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.57s)1258=== CONT TestPinProtectsFromGC12592026/10/10 19:01:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12602026/10/10 19:01:53 INFO Aborted multipart uploads count=0 kept=012612026/10/10 19:01:53 WARN Force mode enabled - objects will be deleted immediately without grace period12622026/10/10 19:01:53 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OGI4NDExZDAtOGFkZi00NDA1LTljMjgtZjAxOGVjZTIzNWU1Ljk4YTUwYWVjLWJmMzQtNGNmMi1hNTE0LTA2MmRjMWZiNTIyNXgxNzkxNjU4OTEyNjIyNzA5OTQ5 error="Get \"http://127.0.0.1:1/bucket13/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12632026/10/10 19:01:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OGI4NDExZDAtOGFkZi00NDA1LTljMjgtZjAxOGVjZTIzNWU1LjJiNTdkZWE4LWE1ZTctNGM1NS1hMjM5LWJmZmY4MWNjMWY0N3gxNzkxNjU4OTEyNjE1MDYwMjA0 parts=1212642026/10/10 19:01:53 INFO Received cleanup request method=DELETE path=/api/pending_closures12652026/10/10 19:01:53 INFO Aborted multipart uploads count=1 kept=012662026/10/10 19:01: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=01267--- PASS: TestRedundantMultipartUpload (1.72s)1268=== CONT TestClientCADerivations1269--- PASS: TestGetExistingObjectsLocksRows (0.55s)1270=== CONT TestClientSharedPathCommittedMidPush12712026/10/10 19:01:53 INFO Vacuumed table table=pending_closures12722026/10/10 19:01:53 INFO Vacuumed table table=pending_objects12732026/10/10 19:01:53 INFO Vacuumed table table=multipart_uploads12742026/10/10 19:01:53 INFO Vacuumed table table=closures12752026/10/10 19:01:53 INFO Vacuumed table table=objects1276--- PASS: TestSweepRechecksPendingAfterLocking (0.56s)1277=== CONT TestClientWithDependencies1278--- PASS: TestReadProxyHead (0.48s)1279=== CONT TestCacheStatsHandler1280--- PASS: TestReadProxyNarStreaming (0.51s)1281=== CONT TestClientMultipleUploads1282--- PASS: TestReadProxyInvalidPath (0.49s)1283=== CONT TestService_ReadScope_PublicByDefault1284--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.51s)1285=== CONT TestForceGCDuringPushOffersSweptObject1286=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1287=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1288=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1289=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1290=== CONT TestClientIntegration12912026/10/10 19:01:53 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1292--- PASS: TestReadProxyNarinfo (0.62s)1293=== CONT TestGCBugBareHashReferences1294--- PASS: TestReadProxy404 (0.54s)1295=== CONT TestGCMetrics1296--- PASS: TestObjectStatsLargeCommit (1.61s)1297=== CONT TestLeadElectsOneAndHandsOver1298--- PASS: TestReadProxyContentNegotiation (0.57s)1299=== CONT TestGCAdvisoryLockBlocksConcurrentRun13002026/10/10 19:01:53 INFO Aborted multipart uploads count=0 kept=013012026/10/10 19:01:53 WARN Force mode enabled - objects will be deleted immediately without grace period13022026/10/10 19:01: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=013032026/10/10 19:01:53 INFO Vacuumed table table=pending_closures13042026/10/10 19:01:53 INFO Vacuumed table table=pending_objects13052026/10/10 19:01:53 INFO Vacuumed table table=multipart_uploads13062026/10/10 19:01:53 INFO Vacuumed table table=closures13072026/10/10 19:01:53 INFO Vacuumed table table=objects13082026/10/10 19:01:53 INFO Aborted multipart uploads count=0 kept=013092026/10/10 19:01:53 WARN Force mode enabled - objects will be deleted immediately without grace period13102026/10/10 19:01:53 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=013112026/10/10 19:01:53 INFO Vacuumed table table=pending_closures13122026/10/10 19:01:53 INFO Vacuumed table table=pending_objects13132026/10/10 19:01:53 INFO Vacuumed table table=multipart_uploads13142026/10/10 19:01:53 INFO Vacuumed table table=closures13152026/10/10 19:01:53 INFO Vacuumed table table=objects1316--- PASS: TestSweepSkipsRowsLockedByPush (0.61s)1317=== CONT TestLeadEndsOnShutdown13182026/10/10 19:01:53 INFO Received uploads request method=POST path=/api/pending_closures1319=== RUN TestService_RequireScope_OIDC/builder_may_write1320=== PAUSE TestService_RequireScope_OIDC/builder_may_write1321=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1322=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1323=== RUN TestService_RequireScope_OIDC/ops_may_admin1324=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1325=== RUN TestService_RequireScope_OIDC/ops_may_not_write1326=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1327=== RUN TestService_RequireScope_OIDC/reader_may_not_write1328=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1329=== RUN TestService_RequireScope_OIDC/static_token_may_admin1330=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1331=== RUN TestService_RequireScope_OIDC/static_token_may_write1332=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1333=== RUN TestService_RequireScope_OIDC/reader_may_read1334=== PAUSE TestService_RequireScope_OIDC/reader_may_read1335=== RUN TestService_RequireScope_OIDC/writer_implies_read1336=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1337=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1338=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1339=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1340=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1341=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1342=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1343=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1344=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1345=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1346=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1347=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1348--- PASS: TestPushWaitsForSweepHoldingRow (1.03s)1349=== CONT TestConnectWaitsForAPeerMigration1350--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.75s)1351=== CONT TestLeadIncumbentAnnouncesAtOnce13522026/10/10 19:01:53 INFO Aborted multipart uploads count=0 kept=013532026/10/10 19:01:53 WARN Force mode enabled - objects will be deleted immediately without grace period13542026/10/10 19:01:53 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13552026/10/10 19:01:53 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1356--- PASS: TestFailedS3DeleteKeepsTombstone (0.64s)1357=== CONT TestResolveDBConnectionString1358=== RUN TestResolveDBConnectionString/flag_wins1359=== PAUSE TestResolveDBConnectionString/flag_wins1360=== RUN TestResolveDBConnectionString/file_when_flag_empty1361=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1362=== RUN TestResolveDBConnectionString/missing_file_is_an_error1363=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1364=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1365=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1366=== RUN TestResolveDBConnectionString/nothing_configured1367=== PAUSE TestResolveDBConnectionString/nothing_configured1368=== CONT TestGCSweepDeliversEachKeyOnce13692026/10/10 19:01:53 INFO Received uploads request method=POST path=/api/pending_closures1370=== NAME TestPinProtectsFromGC1371 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC21755984/001/store/ymgy3y615d32w1mk2pwkryj7jzgrac4b-pinned-file.txt1372 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC21755984/001/store/css6mvp24k1qmfyfjnv2ipl2wbcqa3a4-unpinned-file.txt13732026/10/10 19:01:53 INFO Received uploads request method=POST path=/api/pending_closures13742026/10/10 19:01:53 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13752026/10/10 19:01:53 INFO Uploading 4cssl97lhf97lnbjfazm8rcn8zb0478a-shared-dep (136B)13762026/10/10 19:01:53 INFO Uploading fk7l3i3746mdbhl10r33kzbapq6rryj5-a (216B)13772026/10/10 19:01:53 WARN Failed to register uploaded object key=7p0fm76wmvmww7a9qwn1p28rdvzkvqxh.ls error="server returned 404: 404 page not found\n"13782026/10/10 19:01:53 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13792026/10/10 19:01:53 WARN Failed to register uploaded object key=nar/1l43lgl9fn3hwn1xxhh79yzq2r0blcasjm3r0477c4m136gyxxxb.nar.zst error="server returned 404: 404 page not found\n"13802026/10/10 19:01:53 WARN Failed to register uploaded object key=4cssl97lhf97lnbjfazm8rcn8zb0478a.ls error="server returned 404: 404 page not found\n"13812026/10/10 19:01:53 WARN Failed to register uploaded object key=fk7l3i3746mdbhl10r33kzbapq6rryj5.ls error="server returned 404: 404 page not found\n"13822026/10/10 19:01:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13832026/10/10 19:01:53 INFO Signed narinfos id=1 count=213842026/10/10 19:01:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13852026/10/10 19:01:53 INFO Signed narinfos id=2 count=213862026/10/10 19:01:53 INFO Uploading 4 narinfos13872026/10/10 19:01:53 WARN Failed to register uploaded object key=7p0fm76wmvmww7a9qwn1p28rdvzkvqxh.narinfo error="server returned 404: 404 page not found\n"13882026/10/10 19:01:53 WARN Failed to register uploaded object key=4cssl97lhf97lnbjfazm8rcn8zb0478a.narinfo error="server returned 404: 404 page not found\n"13892026/10/10 19:01:53 WARN Failed to register uploaded object key=fk7l3i3746mdbhl10r33kzbapq6rryj5.narinfo error="server returned 404: 404 page not found\n"13902026/10/10 19:01:53 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13912026/10/10 19:01:53 WARN Failed to register uploaded object key=4cssl97lhf97lnbjfazm8rcn8zb0478a.narinfo error="server returned 404: 404 page not found\n"13922026/10/10 19:01:53 INFO Received push request method=POST path=/api/pushes13932026/10/10 19:01:53 INFO Completed upload id=2 objects=6 duration=9.149532ms13942026/10/10 19:01:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13952026/10/10 19:01:53 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13962026/10/10 19:01:53 INFO Uploading k0i782ql2xf61s0rnf06r1fckn32bnay-b (216B)13972026/10/10 19:01:53 INFO Uploading gj06y10p7dvk58dwsbl23qs9jg0775fd-shared-dep (136B)13982026/10/10 19:01:53 INFO Completed upload id=1 objects=6 duration=2.052496ms13992026/10/10 19:01:53 INFO Upload complete. (80ms)1400=== NAME TestClientFallsBackToClosures1401 client_pushes_test.go:112: Retrieved narinfo from S3:1402 StorePath: /build/TestClientFallsBackToClosures4146082806/001/store/4cssl97lhf97lnbjfazm8rcn8zb0478a-shared-dep1403 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1404 Compression: zstd1405 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821406 NarSize: 1361407 References: 1408 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1409=== CONT TestGCSweepSkipsPendingObjects1410--- PASS: TestCacheStatsHandler (0.55s)1411=== NAME TestClientFallsBackToClosures1412 client_pushes_test.go:112: Retrieved narinfo from S3:1413 StorePath: /build/TestClientFallsBackToClosures4146082806/001/store/fk7l3i3746mdbhl10r33kzbapq6rryj5-a1414 URL: nar/1l43lgl9fn3hwn1xxhh79yzq2r0blcasjm3r0477c4m136gyxxxb.nar.zst1415 Compression: zstd1416 NarHash: sha256:1l43lgl9fn3hwn1xxhh79yzq2r0blcasjm3r0477c4m136gyxxxb1417 NarSize: 2161418 References: /build/TestClientFallsBackToClosures4146082806/001/store/4cssl97lhf97lnbjfazm8rcn8zb0478a-shared-dep1419 CA: text:sha256:1wji0c5qx98a05yn65zanb67w4szyc981vmdraj3l3zncwli9wa714202026/10/10 19:01:53 WARN Failed to register uploaded object key=gj06y10p7dvk58dwsbl23qs9jg0775fd.ls error="server returned 404: 404 page not found\n"14212026/10/10 19:01:53 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14222026/10/10 19:01:53 WARN Failed to register uploaded object key=ac51n37zadky0y9bwz7sfkjzfxd9837p.ls error="server returned 404: 404 page not found\n"14232026/10/10 19:01:53 WARN Failed to register uploaded object key=nar/1slq1i0a2ln4i7v3nmngk9qz7kba6mzwqxx5s06sa5vjnbbk8q5m.nar.zst error="server returned 404: 404 page not found\n"1424 client_pushes_test.go:112: Retrieved narinfo from S3:1425 StorePath: /build/TestClientFallsBackToClosures4146082806/001/store/7p0fm76wmvmww7a9qwn1p28rdvzkvqxh-b1426 URL: nar/1l43lgl9fn3hwn1xxhh79yzq2r0blcasjm3r0477c4m136gyxxxb.nar.zst1427 Compression: zstd1428 NarHash: sha256:1l43lgl9fn3hwn1xxhh79yzq2r0blcasjm3r0477c4m136gyxxxb1429 NarSize: 2161430 References: /build/TestClientFallsBackToClosures4146082806/001/store/4cssl97lhf97lnbjfazm8rcn8zb0478a-shared-dep1431 CA: text:sha256:1wji0c5qx98a05yn65zanb67w4szyc981vmdraj3l3zncwli9wa714322026/10/10 19:01:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14332026/10/10 19:01:53 WARN Failed to register uploaded object key=k0i782ql2xf61s0rnf06r1fckn32bnay.ls error="server returned 404: 404 page not found\n"14342026/10/10 19:01:53 INFO Signed narinfos id=1 count=314352026/10/10 19:01:53 INFO Uploading 3 narinfos14362026/10/10 19:01:53 WARN Failed to register uploaded object key=ac51n37zadky0y9bwz7sfkjzfxd9837p.narinfo error="server returned 404: 404 page not found\n"1437--- PASS: TestClientFallsBackToClosures (0.74s)14382026/10/10 19:01:53 WARN Failed to register uploaded object key=k0i782ql2xf61s0rnf06r1fckn32bnay.narinfo error="server returned 404: 404 page not found\n"1439=== CONT TestDeduplicatedObjectsRecordedAsPending14402026/10/10 19:01:53 INFO Received complete push request method=POST path=/api/pushes/1/complete14412026/10/10 19:01:53 WARN Failed to register uploaded object key=gj06y10p7dvk58dwsbl23qs9jg0775fd.narinfo error="server returned 404: 404 page not found\n"1442=== NAME TestClientCADerivations1443 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations19195735/001/store/0jvgy2wllcz9qdz3jjfwxscy4v5akr6v-ca-test14442026/10/10 19:01:53 INFO Completed push id=1 objects=8 duration=5.667128ms14452026/10/10 19:01:53 INFO Upload complete. (69ms)1446=== NAME TestClientPushesUseOnePush1447 client_pushes_test.go:97: Retrieved narinfo from S3:1448 StorePath: /build/TestClientPushesUseOnePush1533090230/001/store/gj06y10p7dvk58dwsbl23qs9jg0775fd-shared-dep1449 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1450 Compression: zstd1451 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821452 NarSize: 1361453 References: 1454 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1455 client_pushes_test.go:97: Retrieved narinfo from S3:1456 StorePath: /build/TestClientPushesUseOnePush1533090230/001/store/ac51n37zadky0y9bwz7sfkjzfxd9837p-a1457 URL: nar/1slq1i0a2ln4i7v3nmngk9qz7kba6mzwqxx5s06sa5vjnbbk8q5m.nar.zst1458 Compression: zstd1459 NarHash: sha256:1slq1i0a2ln4i7v3nmngk9qz7kba6mzwqxx5s06sa5vjnbbk8q5m1460 NarSize: 2161461 References: /build/TestClientPushesUseOnePush1533090230/001/store/gj06y10p7dvk58dwsbl23qs9jg0775fd-shared-dep1462 CA: text:sha256:15s2bi2dq8nil1l2iv3hl93g4jzhj73g20bi3vk21jjldkl4ag061463 client_pushes_test.go:97: Retrieved narinfo from S3:1464 StorePath: /build/TestClientPushesUseOnePush1533090230/001/store/k0i782ql2xf61s0rnf06r1fckn32bnay-b1465 URL: nar/1slq1i0a2ln4i7v3nmngk9qz7kba6mzwqxx5s06sa5vjnbbk8q5m.nar.zst1466 Compression: zstd1467 NarHash: sha256:1slq1i0a2ln4i7v3nmngk9qz7kba6mzwqxx5s06sa5vjnbbk8q5m1468 NarSize: 2161469 References: /build/TestClientPushesUseOnePush1533090230/001/store/gj06y10p7dvk58dwsbl23qs9jg0775fd-shared-dep1470 CA: text:sha256:15s2bi2dq8nil1l2iv3hl93g4jzhj73g20bi3vk21jjldkl4ag061471--- PASS: TestClientPushesUseOnePush (0.75s)1472=== CONT TestTombstonedObjectOfferedWithoutWaiting1473--- PASS: TestService_ReadScope_PublicByDefault (0.50s)1474=== CONT TestPushDedupSurvivesConcurrentGC1475=== NAME TestClientCADerivations1476 client_ca_test.go:139: Found 1 dependencies (including self)1477=== NAME TestClientWithDependencies1478 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3181107765/001/store/5q3nd7997ncknx70jxip98jcvl0nn4ij-test-script14792026/10/10 19:01:53 INFO Received push request method=POST path=/api/pushes1480=== NAME TestClientMultipleUploads1481 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads36134264/001/store/l50nk8s6lwfgi075rpscdfsvwkqf6p24-test-file-0.txt14822026/10/10 19:01:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14832026/10/10 19:01:53 INFO Uploading ymgy3y615d32w1mk2pwkryj7jzgrac4b-pinned-file.txt (128B)14842026/10/10 19:01:53 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14852026/10/10 19:01:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14862026/10/10 19:01:53 WARN Failed to register uploaded object key=ymgy3y615d32w1mk2pwkryj7jzgrac4b.ls error="server returned 404: 404 page not found\n"14872026/10/10 19:01:53 INFO Signed narinfos id=1 count=114882026/10/10 19:01:53 INFO Uploading 1 narinfos14892026/10/10 19:01:53 WARN Failed to register uploaded object key=ymgy3y615d32w1mk2pwkryj7jzgrac4b.narinfo error="server returned 404: 404 page not found\n"14902026/10/10 19:01:53 INFO Received complete push request method=POST path=/api/pushes/1/complete1491=== NAME TestClientWithDependencies1492 client_integration_test.go:615: Found 1 dependencies (including self)14932026/10/10 19:01:53 INFO Completed push id=1 objects=3 duration=10.829099ms14942026/10/10 19:01:53 INFO Upload complete. (86ms)14952026/10/10 19:01:53 INFO Received push request method=POST path=/api/pushes14962026/10/10 19:01:53 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14972026/10/10 19:01:53 INFO Uploading 59b026vmwfv1jir9ydp60cdsryb7hvbi-shared-dep (136B)14982026/10/10 19:01:53 INFO Uploading 8indfskv8srmb8vz24zm80l5prshs8yx-top (224B)1499=== NAME TestClientMultipleUploads1500 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads36134264/001/store/x19vq07lnrc5236qi5j6z521ra5klhpq-test-file-1.txt15012026/10/10 19:01:53 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15022026/10/10 19:01:53 WARN Failed to register uploaded object key=nar/1qmdvq451fyjhhn1ic4s3maanx54zny9y17vp4y0zjm8irqm6bxj.nar.zst error="server returned 404: 404 page not found\n"15032026/10/10 19:01:53 WARN Failed to register uploaded object key=8indfskv8srmb8vz24zm80l5prshs8yx.ls error="server returned 404: 404 page not found\n"15042026/10/10 19:01:53 WARN Failed to register uploaded object key=59b026vmwfv1jir9ydp60cdsryb7hvbi.ls error="server returned 404: 404 page not found\n"15052026/10/10 19:01:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15062026/10/10 19:01:53 INFO Signed narinfos id=1 count=215072026/10/10 19:01:53 INFO Uploading 2 narinfos1508=== NAME TestClientIntegration1509 client_integration_test.go:286: Created store path: /build/TestClientIntegration4030071466/002/store/m52vbaw7d8s36wqwan0mpvvi57vcprzl-test-file.txt15102026/10/10 19:01:53 WARN Failed to register uploaded object key=59b026vmwfv1jir9ydp60cdsryb7hvbi.narinfo error="server returned 404: 404 page not found\n"15112026/10/10 19:01:53 INFO Received complete push request method=POST path=/api/pushes/1/complete15122026/10/10 19:01:53 WARN Failed to register uploaded object key=8indfskv8srmb8vz24zm80l5prshs8yx.narinfo error="server returned 404: 404 page not found\n"15132026/10/10 19:01:53 INFO Aborted multipart uploads count=0 kept=015142026/10/10 19:01:53 INFO Completed push id=1 objects=6 duration=13.037884ms15152026/10/10 19:01:53 INFO Upload complete. (75ms)1516=== NAME TestClientSharedPathCommittedMidPush1517 client_integration_test.go:680: Retrieved narinfo from S3:1518 StorePath: /build/TestClientSharedPathCommittedMidPush3159525353/001/store/59b026vmwfv1jir9ydp60cdsryb7hvbi-shared-dep1519 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1520 Compression: zstd1521 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821522 NarSize: 1361523 References: 1524 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1525 client_integration_test.go:680: Retrieved narinfo from S3:1526 StorePath: /build/TestClientSharedPathCommittedMidPush3159525353/001/store/8indfskv8srmb8vz24zm80l5prshs8yx-top1527 URL: nar/1qmdvq451fyjhhn1ic4s3maanx54zny9y17vp4y0zjm8irqm6bxj.nar.zst1528 Compression: zstd1529 NarHash: sha256:1qmdvq451fyjhhn1ic4s3maanx54zny9y17vp4y0zjm8irqm6bxj1530 NarSize: 2241531 References: /build/TestClientSharedPathCommittedMidPush3159525353/001/store/59b026vmwfv1jir9ydp60cdsryb7hvbi-shared-dep1532 CA: text:sha256:02sb8dasflrqwl33vfy2x9146qy203xdw0mz34wv9q1nsaxszz9d15332026/10/10 19:01:53 WARN Force mode enabled - objects will be deleted immediately without grace period1534--- PASS: TestClientSharedPathCommittedMidPush (0.70s)1535=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15362026/10/10 19:01: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=015372026/10/10 19:01:53 INFO Vacuumed table table=pending_closures15382026/10/10 19:01:53 INFO Vacuumed table table=pending_objects15392026/10/10 19:01:53 INFO Vacuumed table table=multipart_uploads15402026/10/10 19:01:53 INFO Vacuumed table table=closures15412026/10/10 19:01:53 INFO Vacuumed table table=objects15422026/10/10 19:01:53 INFO lead: acquired remote=192.0.2.1:12341543=== NAME TestClientMultipleUploads1544 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads36134264/001/store/rxb6ykim7g2s07kvdji3rmpgsdpnb9xr-test-file-2.txt1545--- PASS: TestGCMetrics (0.51s)1546=== CONT TestService_ReadAuthMiddleware15472026/10/10 19:01:53 INFO Received push request method=POST path=/api/pushes15482026/10/10 19:01:53 INFO Received push request method=POST path=/api/pushes15492026/10/10 19:01:53 INFO Received push request method=POST path=/api/pushes15502026/10/10 19:01:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15512026/10/10 19:01:53 INFO Uploading css6mvp24k1qmfyfjnv2ipl2wbcqa3a4-unpinned-file.txt (128B)15522026/10/10 19:01:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15532026/10/10 19:01:53 INFO Uploading 5q3nd7997ncknx70jxip98jcvl0nn4ij-test-script (136B)15542026/10/10 19:01:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15552026/10/10 19:01:53 INFO Uploading 0jvgy2wllcz9qdz3jjfwxscy4v5akr6v-ca-test (144B)15562026/10/10 19:01:53 WARN Failed to register uploaded object key=css6mvp24k1qmfyfjnv2ipl2wbcqa3a4.ls error="server returned 404: 404 page not found\n"15572026/10/10 19:01:53 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15582026/10/10 19:01:53 INFO Signed narinfos id=2 count=115592026/10/10 19:01:53 INFO Uploading 1 narinfos15602026/10/10 19:01:53 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15612026/10/10 19:01:53 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15622026/10/10 19:01:53 WARN Failed to register uploaded object key=log/sr5p9rkrx0kh5km249fbbc9zg6jhgw3g-test-script.drv error="server returned 404: 404 page not found\n"15632026/10/10 19:01:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15642026/10/10 19:01:53 WARN Failed to register uploaded object key=5q3nd7997ncknx70jxip98jcvl0nn4ij.ls error="server returned 404: 404 page not found\n"15652026/10/10 19:01:53 INFO Signed narinfos id=1 count=115662026/10/10 19:01:53 INFO Uploading 1 narinfos15672026/10/10 19:01:53 WARN Failed to register uploaded object key=0jvgy2wllcz9qdz3jjfwxscy4v5akr6v.ls error="server returned 404: 404 page not found\n"15682026/10/10 19:01:53 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15692026/10/10 19:01:53 WARN Failed to register uploaded object key=log/dwfjsp0i67jl6z79rajqkla9mbqrc5nw-ca-test.drv error="server returned 404: 404 page not found\n"15702026/10/10 19:01:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15712026/10/10 19:01:53 INFO Received complete push request method=POST path=/api/pushes/2/complete15722026/10/10 19:01:53 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"15732026/10/10 19:01:53 WARN Failed to register uploaded object key=css6mvp24k1qmfyfjnv2ipl2wbcqa3a4.narinfo error="server returned 404: 404 page not found\n"15742026/10/10 19:01:53 INFO Signed narinfos id=1 count=11575--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.48s)15762026/10/10 19:01:53 INFO Uploading 1 narinfos1577=== CONT TestService_AuthMiddleware_OIDC15782026/10/10 19:01:53 INFO Received complete push request method=POST path=/api/pushes/1/complete15792026/10/10 19:01:53 WARN Failed to register uploaded object key=5q3nd7997ncknx70jxip98jcvl0nn4ij.narinfo error="server returned 404: 404 page not found\n"15802026/10/10 19:01:53 INFO Completed push id=2 objects=3 duration=2.805444ms15812026/10/10 19:01:53 INFO Upload complete. (49ms)15822026/10/10 19:01:53 INFO Received complete push request method=POST path=/api/pushes/1/complete15832026/10/10 19:01:53 WARN Failed to register uploaded object key=0jvgy2wllcz9qdz3jjfwxscy4v5akr6v.narinfo error="server returned 404: 404 page not found\n"15842026/10/10 19:01:53 INFO Completed push id=1 objects=4 duration=6.431517ms15852026/10/10 19:01:53 INFO Upload complete. (61ms)1586=== NAME TestClientWithDependencies1587 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3181107765/001/store) requires matching store prefix1588--- PASS: TestClientWithDependencies (0.74s)1589=== CONT TestService_AuthMiddleware_MTLSProxyHeader15902026/10/10 19:01:53 INFO Received push request method=POST path=/api/pushes15912026/10/10 19:01:53 INFO Completed push id=1 objects=4 duration=10.323299ms15922026/10/10 19:01:53 INFO Upload complete. (104ms)15932026/10/10 19:01:53 INFO lead: acquired remote=192.0.2.1:12341594=== NAME TestClientCADerivations1595 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations19195735/001/store/0jvgy2wllcz9qdz3jjfwxscy4v5akr6v-ca-test1596 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1597 Compression: zstd1598 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1599 NarSize: 1441600 References: 1601 Deriver: /build/TestClientCADerivations19195735/001/store/dwfjsp0i67jl6z79rajqkla9mbqrc5nw-ca-test.drv1602 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1603 client_ca_test.go:185: Checking for realisation files in S3...1604 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1605 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16062026/10/10 19:01:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16072026/10/10 19:01:53 INFO Uploading m52vbaw7d8s36wqwan0mpvvi57vcprzl-test-file.txt (152B)16082026/10/10 19:01:53 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16092026/10/10 19:01:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16102026/10/10 19:01:53 WARN Failed to register uploaded object key=m52vbaw7d8s36wqwan0mpvvi57vcprzl.ls error="server returned 404: 404 page not found\n"16112026/10/10 19:01:53 INFO Signed narinfos id=1 count=116122026/10/10 19:01:53 INFO Uploading 1 narinfos16132026/10/10 19:01:53 INFO Received complete push request method=POST path=/api/pushes/1/complete16142026/10/10 19:01:53 WARN Failed to register uploaded object key=m52vbaw7d8s36wqwan0mpvvi57vcprzl.narinfo error="server returned 404: 404 page not found\n"16152026/10/10 19:01:53 INFO Completed push id=1 objects=3 duration=7.281966ms16162026/10/10 19:01:53 INFO Upload complete. (64ms)16172026/10/10 19:01:53 INFO Starting cleanup of old closures method=DELETE path=/api/closures16182026/10/10 19:01:53 INFO Garbage collection started16192026/10/10 19:01:53 INFO Received uploads request method=POST path=/api/pending_closures16202026/10/10 19:01:53 INFO Received push request method=POST path=/api/pushes16212026/10/10 19:01:54 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16222026/10/10 19:01:54 INFO Uploading rxb6ykim7g2s07kvdji3rmpgsdpnb9xr-test-file-2.txt (160B)16232026/10/10 19:01:54 INFO Uploading l50nk8s6lwfgi075rpscdfsvwkqf6p24-test-file-0.txt (160B)16242026/10/10 19:01:54 INFO Uploading x19vq07lnrc5236qi5j6z521ra5klhpq-test-file-1.txt (160B)16252026/10/10 19:01:54 INFO Aborted multipart uploads count=0 kept=016262026/10/10 19:01:54 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16272026/10/10 19:01:54 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16282026/10/10 19:01:54 WARN Failed to register uploaded object key=rxb6ykim7g2s07kvdji3rmpgsdpnb9xr.ls error="server returned 404: 404 page not found\n"16292026/10/10 19:01:54 WARN Failed to register uploaded object key=l50nk8s6lwfgi075rpscdfsvwkqf6p24.ls error="server returned 404: 404 page not found\n"16302026/10/10 19:01:54 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16312026/10/10 19:01:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16322026/10/10 19:01:54 WARN Failed to register uploaded object key=x19vq07lnrc5236qi5j6z521ra5klhpq.ls error="server returned 404: 404 page not found\n"16332026/10/10 19:01:54 INFO Signed narinfos id=1 count=316342026/10/10 19:01:54 INFO Uploading 3 narinfos16352026/10/10 19:01:54 WARN Force mode enabled - objects will be deleted immediately without grace period16362026/10/10 19:01:54 WARN Failed to register uploaded object key=l50nk8s6lwfgi075rpscdfsvwkqf6p24.narinfo error="server returned 404: 404 page not found\n"16372026/10/10 19:01:54 INFO Received complete push request method=POST path=/api/pushes/1/complete16382026/10/10 19:01:54 WARN Failed to register uploaded object key=x19vq07lnrc5236qi5j6z521ra5klhpq.narinfo error="server returned 404: 404 page not found\n"16392026/10/10 19:01:54 WARN Failed to register uploaded object key=rxb6ykim7g2s07kvdji3rmpgsdpnb9xr.narinfo error="server returned 404: 404 page not found\n"16402026/10/10 19:01:54 INFO lead: acquired remote=192.0.2.1:123416412026/10/10 19:01:54 INFO lead: released remote=192.0.2.1:12341642--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.34s)1643=== CONT TestCacheConfigHandler1644=== RUN TestCacheConfigHandler/full_config,_no_issuer1645=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1646=== RUN TestCacheConfigHandler/no_cache_url_configured1647=== PAUSE TestCacheConfigHandler/no_cache_url_configured1648=== RUN TestCacheConfigHandler/no_signing_keys1649=== PAUSE TestCacheConfigHandler/no_signing_keys1650=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1651=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1652=== CONT TestProxyWriteTimeout/narinfo1653=== CONT TestProxyWriteTimeout/1_GiB_nar1654=== CONT TestProxyWriteTimeout/unknown_size1655=== CONT TestProxyWriteTimeout/10_GiB_nar1656=== CONT TestParseSingleRange/none1657--- PASS: TestProxyWriteTimeout (0.10s)1658 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1659 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1660 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1661 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1662=== CONT TestParseSingleRange/open-ended1663=== CONT TestParseSingleRange/closed1664=== CONT TestParseSingleRange/malformed_end_before_start1665=== CONT TestParseSingleRange/malformed_both_empty1666=== CONT TestParseSingleRange/malformed_no_dash1667=== CONT TestParseSingleRange/multi-range_ignored1668=== CONT TestParseSingleRange/end_clamped_to_size1669=== CONT TestParseSingleRange/unknown_unit1670=== CONT TestParseSingleRange/start_past_EOF1671=== CONT TestParseSingleRange/start_far_past_EOF1672=== CONT TestParseSingleRange/suffix_exceeds_size1673=== CONT TestParseSingleRange/single_byte1674=== CONT TestParseSingleRange/suffix1675--- PASS: TestParseSingleRange (0.10s)1676 --- PASS: TestParseSingleRange/none (0.00s)1677 --- PASS: TestParseSingleRange/open-ended (0.00s)1678 --- PASS: TestParseSingleRange/closed (0.00s)1679 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1680 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1681 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1682 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1683 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1684 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1685 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1686 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1687 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1688 --- PASS: TestParseSingleRange/single_byte (0.00s)1689 --- PASS: TestParseSingleRange/suffix (0.00s)1690=== CONT TestPendingClosureWriteTimeout/empty1691=== CONT TestPendingClosureWriteTimeout/670k_objects1692=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline16932026/10/10 19:01:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44681/oidc16942026/10/10 19:01:54 INFO Completed push id=1 objects=9 duration=32.367986ms16952026/10/10 19:01:54 INFO All 1 paths already cached16962026/10/10 19:01:54 INFO Upload complete. (91ms)1697=== NAME TestClientMultipleUploads16982026/10/10 19:01:54 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=01699 client_integration_test.go:369: Uploaded 3 paths in 123.831064ms1700=== NAME TestClientIntegration1701 client_integration_test.go:312: Retrieved narinfo from S3:1702 StorePath: /build/TestClientIntegration4030071466/002/store/m52vbaw7d8s36wqwan0mpvvi57vcprzl-test-file.txt1703 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1704 Compression: zstd1705 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11706 NarSize: 1521707 References: 1708 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11709 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1710 client_integration_test.go:313: Decompressed .ls content (64 bytes):1711 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1712 client_integration_test.go:316: Testing garbage collection...17132026/10/10 19:01:54 INFO Vacuumed table table=pending_closures17142026/10/10 19:01:54 INFO Vacuumed table table=pending_objects17152026/10/10 19:01:54 INFO Received uploads request method=POST path=/api/pending_closures17162026/10/10 19:01:54 INFO Vacuumed table table=multipart_uploads1717--- PASS: TestClientMultipleUploads (0.79s)1718=== CONT TestPendingClosureWriteTimeout/400_objects1719=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17202026/10/10 19:01:54 INFO Received uploads request method=POST path=/1721=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17222026/10/10 19:01:54 INFO Received request for more parts method=POST path=/1723=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17242026/10/10 19:01:54 INFO Received uploads request method=POST path=/1725=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17262026/10/10 19:01:54 INFO Received complete multipart upload request method=POST path=/1727--- PASS: TestUploadHandlersRejectInvalidKeys (0.09s)1728 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1729 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1730 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1731 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1732=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale17332026/10/10 19:01:54 INFO Vacuumed table table=closures17342026/10/10 19:01:54 INFO Aborted multipart uploads count=0 kept=017352026/10/10 19:01:54 INFO Vacuumed table table=objects17362026/10/10 19:01:54 WARN Force mode enabled - objects will be deleted immediately without grace period17372026/10/10 19:01:54 INFO Aborted multipart uploads count=0 kept=017382026/10/10 19:01:54 WARN Force mode enabled - objects will be deleted immediately without grace period17392026/10/10 19:01: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=01740=== NAME TestClientCADerivations1741 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features17422026/10/10 19:01:54 INFO Received uploads request method=POST path=/api/pending_closures1743 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1744 error: binary cache 's3://bucket68?endpoint=http://localhost:36137®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations19195735/001/store'1745 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117462026/10/10 19:01:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures17472026/10/10 19:01:54 INFO Garbage collection started17482026/10/10 19:01:54 INFO Vacuumed table table=pending_closures17492026/10/10 19:01:54 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=017502026/10/10 19:01:54 INFO Vacuumed table table=pending_closures17512026/10/10 19:01:54 INFO Vacuumed table table=pending_objects17522026/10/10 19:01:54 INFO Vacuumed table table=multipart_uploads17532026/10/10 19:01:54 INFO Vacuumed table table=closures17542026/10/10 19:01:54 INFO Vacuumed table table=pending_objects17552026/10/10 19:01:54 INFO Vacuumed table table=multipart_uploads17562026/10/10 19:01:54 INFO Vacuumed table table=closures1757--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.29s)1758=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1759--- PASS: TestClientCADerivations (0.87s)1760=== CONT TestIsValidUploadKey/narinfo1761=== CONT TestIsValidUploadKey/empty_key17622026/10/10 19:01:54 INFO Vacuumed table table=objects1763=== CONT TestIsValidUploadKey/unknown_type1764=== CONT TestIsValidUploadKey/absolute1765=== CONT TestIsValidUploadKey/traversal_nar1766=== CONT TestIsValidUploadKey/traversal1767=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1768=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1769=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1770=== CONT TestIsValidUploadKey/index.html1771=== CONT TestIsValidUploadKey/nix-cache-info1772=== CONT TestIsValidUploadKey/build_log1773=== CONT TestIsValidUploadKey/listing1774=== CONT TestIsValidUploadKey/nar_plain17752026/10/10 19:01:54 INFO Aborted multipart uploads count=0 kept=01776=== CONT TestIsValidUploadKey/nar_xz1777=== CONT TestIsValidUploadKey/nar_zst1778=== CONT TestIsValidUploadKey/build_log_equals1779=== CONT TestIsValidUploadKey/build_log_home-manager_file1780=== CONT TestIsValidUploadKey/realisation_plus_in_output17812026/10/10 19:01:54 INFO Vacuumed table table=objects1782=== CONT TestIsValidUploadKey/realisation1783=== CONT TestIsValidUploadKey/build_log_question_mark1784=== CONT TestIsValidUploadKey/build_log_plus_in_name1785--- PASS: TestIsValidUploadKey (0.09s)1786 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1787 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1788 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1789 --- PASS: TestIsValidUploadKey/absolute (0.00s)1790 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1791 --- PASS: TestIsValidUploadKey/traversal (0.00s)1792 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1793 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1794 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1795 --- PASS: TestIsValidUploadKey/index.html (0.00s)1796 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1797 --- PASS: TestIsValidUploadKey/build_log (0.00s)1798 --- PASS: TestIsValidUploadKey/listing (0.00s)1799 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1800 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1801 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1802 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1803 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1804 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1805 --- PASS: TestIsValidUploadKey/realisation (0.00s)1806 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1807 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1808=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18092026/10/10 19:01:54 INFO Received complete multipart upload request method=POST path=/1810--- PASS: TestGCSweepDeliversEachKeyOnce (0.37s)1811=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18122026/10/10 19:01:54 INFO Received uploads request method=POST path=/18132026/10/10 19:01:54 WARN Force mode enabled - objects will be deleted immediately without grace period1814--- PASS: TestGCSweepSkipsPendingObjects (0.31s)1815=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18162026/10/10 19:01:54 INFO Received request for more parts method=POST path=/18172026/10/10 19:01:54 INFO Received uploads request method=POST path=/api/pending_closures18182026/10/10 19:01:54 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=01819--- PASS: TestGCBugBareHashReferences (0.71s)1820=== CONT TestServerTLSConfig/no_client_CA1821=== CONT TestServerTLSConfig/missing_CA_file1822--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.30s)1823=== CONT TestServerTLSConfig/not_a_PEM_file1824=== CONT TestPush_RejectsBadRequests/no_roots18252026/10/10 19:01:54 INFO Received push request method=POST path=/api/pushes1826=== CONT TestPush_RejectsBadRequests/bad_root18272026/10/10 19:01:54 INFO Received push request method=POST path=/api/pushes1828=== CONT TestPush_RejectsBadRequests/root_not_in_objects18292026/10/10 19:01:54 INFO Received push request method=POST path=/api/pushes1830=== CONT TestPush_RejectsBadRequests/no_objects18312026/10/10 19:01:54 INFO Received push request method=POST path=/api/pushes1832--- PASS: TestServerTLSConfig (0.00s)1833 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1834 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1835 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1836=== CONT TestGCEndsOnShutdown/before_the_run1837--- PASS: TestPush_RejectsBadRequests (0.80s)1838 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1839 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1840 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1841 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1842=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark18432026/10/10 19:01:54 INFO Vacuumed table table=pending_closures1844=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18452026/10/10 19:01:54 INFO Vacuumed table table=pending_objects18462026/10/10 19:01:54 INFO Vacuumed table table=multipart_uploads18472026/10/10 19:01:54 INFO Vacuumed table table=closures18482026/10/10 19:01:54 INFO Vacuumed table table=objects1849--- PASS: TestService_ReadAuthMiddleware (0.23s)1850=== CONT TestIsValidCachePath/narinfo1851=== CONT TestIsValidCachePath/index.html1852=== CONT TestIsValidCachePath/short_hash1853=== CONT TestIsValidCachePath/wrong_extension1854=== CONT TestIsValidCachePath/leading_slash1855=== CONT TestIsValidCachePath/empty1856=== CONT TestIsValidCachePath/random_path1857=== CONT TestIsValidCachePath/invalid_char_u1858=== CONT TestIsValidCachePath/invalid_char_e1859=== CONT TestIsValidCachePath/nar_uncompressed1860=== CONT TestIsValidCachePath/traversal_in_middle1861=== CONT TestIsValidCachePath/nix-cache-info1862=== CONT TestIsValidCachePath/realisation1863=== CONT TestIsValidCachePath/traversal_parent1864=== CONT TestIsValidCachePath/log1865=== CONT TestIsValidCachePath/ls1866=== CONT TestIsValidCachePath/nar_xz1867=== CONT TestIsValidCachePath/nar_bz21868=== CONT TestIsValidCachePath/nar_zst1869=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1870--- PASS: TestIsValidCachePath (0.00s)1871 --- PASS: TestIsValidCachePath/narinfo (0.00s)1872 --- PASS: TestIsValidCachePath/index.html (0.00s)1873 --- PASS: TestIsValidCachePath/short_hash (0.00s)1874 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1875 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1876 --- PASS: TestIsValidCachePath/empty (0.00s)1877 --- PASS: TestIsValidCachePath/random_path (0.00s)1878 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1879 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1880 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1881 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1882 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1883 --- PASS: TestIsValidCachePath/realisation (0.00s)1884 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1885 --- PASS: TestIsValidCachePath/log (0.00s)1886 --- PASS: TestIsValidCachePath/ls (0.00s)1887 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1888 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1889 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1890 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1891=== CONT TestClientErrorHandling/InvalidStorePath18922026/10/10 19:01:54 INFO Received uploads request method=POST path=/api/pending_closures1893=== CONT TestClientErrorHandling/ServerNotAvailable18942026/10/10 19:01:54 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18952026/10/10 19:01:54 WARN mTLS auth: bound subjects configured but subject DN unavailable18962026/10/10 19:01:54 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1897--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.27s)1898=== CONT TestClientErrorHandling/InvalidAuthToken1899--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.56s)1900=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1901--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.25s)1902=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19032026/10/10 19:01:54 INFO Aborted multipart uploads count=0 kept=019042026/10/10 19:01:54 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=019052026/10/10 19:01:54 INFO Vacuumed table table=pending_closures19062026/10/10 19:01:54 INFO Vacuumed table table=pending_objects19072026/10/10 19:01:54 INFO Vacuumed table table=multipart_uploads19082026/10/10 19:01:54 INFO Vacuumed table table=closures19092026/10/10 19:01:54 INFO Vacuumed table table=objects19102026/10/10 19:01:54 INFO Aborted multipart uploads count=0 kept=019112026/10/10 19:01:54 WARN Force mode enabled - objects will be deleted immediately without grace period19122026/10/10 19:01: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=019132026/10/10 19:01:54 INFO Vacuumed table table=pending_closures19142026/10/10 19:01:54 INFO Vacuumed table table=pending_objects19152026/10/10 19:01:54 INFO Vacuumed table table=multipart_uploads19162026/10/10 19:01:54 INFO Vacuumed table table=closures19172026/10/10 19:01:54 INFO Vacuumed table table=objects19182026/10/10 19:01:54 INFO Received uploads request method=POST path=/api/pending_closures19192026/10/10 19:01:54 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/present1920--- PASS: TestPushDedupSurvivesConcurrentGC (0.48s)1921=== CONT TestService_RequireScope_OIDC/builder_may_write1922=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1923=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19242026/10/10 19:01:54 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]1925=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1926=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1927=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1928=== CONT TestService_RequireScope_OIDC/writer_implies_read1929=== CONT TestService_RequireScope_OIDC/reader_may_read1930=== CONT TestService_RequireScope_OIDC/static_token_may_write1931=== CONT TestService_RequireScope_OIDC/static_token_may_admin1932=== CONT TestService_RequireScope_OIDC/reader_may_not_write1933=== CONT TestService_RequireScope_OIDC/ops_may_not_write1934=== CONT TestService_RequireScope_OIDC/ops_may_admin1935=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1936=== CONT TestResolveDBConnectionString/flag_wins1937=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1938=== CONT TestResolveDBConnectionString/nothing_configured1939=== CONT TestResolveDBConnectionString/missing_file_is_an_error1940=== CONT TestResolveDBConnectionString/file_when_flag_empty1941=== CONT TestCacheConfigHandler/full_config,_no_issuer1942--- PASS: TestService_RequireScope_OIDC (0.64s)1943 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1944 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1945 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1946 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1947 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1948 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1949 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1950 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1951 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1952 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1953 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1954 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1955 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1956 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1957=== CONT TestCacheConfigHandler/no_signing_keys1958=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1959=== CONT TestCacheConfigHandler/no_cache_url_configured1960--- PASS: TestResolveDBConnectionString (0.00s)1961 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1962 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1963 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1964 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1965 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1966--- PASS: TestCacheConfigHandler (0.00s)1967 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1968 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1969 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1970 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1971=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1972=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1973=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1974=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1975=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1976=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1977=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1978=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1979=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1980=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19812026/10/10 19:01:54 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]1982=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1983=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19842026/10/10 19:01:54 WARN Authentication failed token_preview=eyJhbGciOi...ay3k-RvTjw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1985--- PASS: TestService_AuthMiddleware_OIDC (0.38s)1986 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1987 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1988 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1989 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1990=== NAME TestOrphanedObjectsGCStressTest1991 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1992 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion19932026/10/10 19:01:54 WARN Request failed, retrying attempt=2 backoff=182.174304ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19942026/10/10 19:01:54 INFO Aborted multipart uploads count=0 kept=019952026/10/10 19:01:54 WARN Force mode enabled - objects will be deleted immediately without grace period19962026/10/10 19:01:54 INFO Received uploads request method=POST path=/api/pending_closures19972026/10/10 19:01:54 INFO Aborted multipart uploads count=0 kept=019982026/10/10 19:01:54 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19992026/10/10 19:01:54 WARN Force mode enabled - objects will be deleted immediately without grace period20002026/10/10 19:01: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=020012026/10/10 19:01:54 INFO Vacuumed table table=pending_closures20022026/10/10 19:01:54 INFO Vacuumed table table=pending_objects20032026/10/10 19:01:54 INFO Vacuumed table table=multipart_uploads20042026/10/10 19:01:54 INFO Vacuumed table table=closures20052026/10/10 19:01:54 INFO Vacuumed table table=objects20062026/10/10 19:01:54 INFO Aborted multipart uploads count=0 kept=020072026/10/10 19:01:54 WARN Force mode enabled - objects will be deleted immediately without grace period20082026/10/10 19:01:54 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20092026/10/10 19:01:54 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:36137/bucket99/?delete=\": context canceled"2010--- PASS: TestGCEndsOnShutdown (0.00s)2011 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.37s)2012 --- PASS: TestGCEndsOnShutdown/before_the_run (0.39s)2013 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.43s)20142026/10/10 19:01:54 INFO Received uploads request method=POST path=/api/pending_closures20152026/10/10 19:01:54 INFO Aborted multipart uploads count=0 kept=020162026/10/10 19:01:54 WARN Force mode enabled - objects will be deleted immediately without grace period20172026/10/10 19:01:54 WARN Request failed, retrying attempt=3 backoff=405.654221ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20182026/10/10 19:01:54 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=020192026/10/10 19:01:54 INFO Vacuumed table table=pending_closures20202026/10/10 19:01:54 INFO Vacuumed table table=pending_objects20212026/10/10 19:01:54 INFO Vacuumed table table=multipart_uploads20222026/10/10 19:01:54 INFO Vacuumed table table=closures20232026/10/10 19:01:54 INFO Vacuumed table table=objects2024--- PASS: TestDeleteClosuresRacingPins (1.62s)2025--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2026 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.34s)2027 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.40s)2028=== NAME TestOrphanedObjectsGCStressTest2029 orphaned_objects_gc_test.go:503: Stress test completed successfully:2030 orphaned_objects_gc_test.go:504: - Active objects preserved: 202031 orphaned_objects_gc_test.go:505: - Objects deleted: 2102032 orphaned_objects_gc_test.go:506: - Total GC'd: 2102033--- PASS: TestOrphanedObjectsGCStressTest (2.97s)2034--- PASS: TestUploadHandlersRejectOversizedBody (0.18s)2035 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)2036 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2037 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.72s)2038--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2039 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.81s)2040 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.81s)20412026/10/10 19:01:54 WARN Request failed, retrying attempt=4 backoff=745.269087ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20422026/10/10 19:01:55 INFO lead: released remote=192.0.2.1:12342043--- PASS: TestLeadEndsOnShutdown (1.46s)2044--- PASS: TestPendingClosureWriteTimeout (0.09s)2045 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2046 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2047 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2048 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.09s)20492026/10/10 19:01:55 INFO lead: released remote=192.0.2.1:123420502026/10/10 19:01:55 INFO lead: acquired remote=192.0.2.1:123420512026/10/10 19:01:55 WARN Request failed, retrying attempt=5 backoff=1.497293454s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20522026/10/10 19:01:55 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020532026/10/10 19:01:55 INFO Received create pin request method=POST path=/api/pins/myapp20542026/10/10 19:01:56 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC21755984/001/store/ymgy3y615d32w1mk2pwkryj7jzgrac4b-pinned-file.txt narinfo_key=ymgy3y615d32w1mk2pwkryj7jzgrac4b.narinfo20552026/10/10 19:01:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures20562026/10/10 19:01:56 INFO Garbage collection started20572026/10/10 19:01:56 INFO Aborted multipart uploads count=0 kept=020582026/10/10 19:01:56 WARN Force mode enabled - objects will be deleted immediately without grace period20592026/10/10 19:01:56 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=020602026/10/10 19:01:56 INFO Vacuumed table table=pending_closures20612026/10/10 19:01:56 INFO Vacuumed table table=pending_objects20622026/10/10 19:01:56 INFO Vacuumed table table=multipart_uploads20632026/10/10 19:01:56 INFO Vacuumed table table=closures20642026/10/10 19:01:56 INFO Vacuumed table table=objects20652026/10/10 19:01:56 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02066=== NAME TestClientIntegration2067 client_integration_test.go:323: Objects in database after GC:2068 client_integration_test.go:323: Successfully deleted all objects with GC --force2069--- PASS: TestClientIntegration (2.74s)20702026/10/10 19:01:56 WARN Rate limiter enabled after throttle name=s3-test rate=520712026/10/10 19:01:56 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2072=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2073 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102074 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002075--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.66s)20762026/10/10 19:01:56 INFO lead: released remote=192.0.2.1:12342077--- PASS: TestLeadElectsOneAndHandsOver (2.81s)2078--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.76s)20792026/10/10 19:01:57 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-config20802026/10/10 19:01:57 WARN Request failed, retrying attempt=2 backoff=202.265891ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20812026/10/10 19:01:57 WARN Request failed, retrying attempt=3 backoff=437.978655ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2082=== NAME TestPinProtectsFromGC2083 client_integration_test.go:840: Pin successfully protected closure from garbage collection20842026/10/10 19:01:58 WARN Request failed, retrying attempt=4 backoff=839.437537ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2085--- PASS: TestPinProtectsFromGC (4.84s)20862026/10/10 19:01:58 INFO Aborted multipart uploads count=1 kept=020872026/10/10 19:01:58 INFO Received cleanup request method=DELETE path=/api/pending_closures20882026/10/10 19:01:58 INFO Aborted multipart uploads count=1 kept=02089--- PASS: TestPendingCleanupUsesOneCutoff (6.71s)2090--- PASS: TestConnectWaitsForAPeerMigration (5.17s)20912026/10/10 19:01:58 WARN Request failed, retrying attempt=5 backoff=1.641729168s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20922026/10/10 19:02:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"20932026/10/10 19:02:00 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-config20942026/10/10 19:02:00 WARN Request failed, retrying attempt=2 backoff=191.148471ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20952026/10/10 19:02:00 WARN Request failed, retrying attempt=3 backoff=380.343406ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20962026/10/10 19:02:01 WARN Request failed, retrying attempt=4 backoff=755.317268ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20972026/10/10 19:02:01 WARN Request failed, retrying attempt=5 backoff=1.524767499s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20982026/10/10 19:02:03 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20992026/10/10 19:02:03 WARN Request failed, retrying attempt=2 backoff=181.324844ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21002026/10/10 19:02:03 WARN Request failed, retrying attempt=3 backoff=422.213436ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21012026/10/10 19:02:04 WARN Request failed, retrying attempt=4 backoff=755.216031ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21022026/10/10 19:02:04 WARN Request failed, retrying attempt=5 backoff=1.734298755s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2103--- PASS: TestClientErrorHandling (0.00s)2104 --- PASS: TestClientErrorHandling/InvalidStorePath (0.29s)2105 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.39s)2106 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.51s)2107PASS21082026-10-10 19:02:07.072 UTC [127] LOG: received smart shutdown request21092026-10-10 19:02:07.077 UTC [127] LOG: background worker "logical replication launcher" (PID 137) exited with exit code 121102026-10-10 19:02:07.085 UTC [132] LOG: shutting down21112026-10-10 19:02:07.085 UTC [132] LOG: checkpoint starting: shutdown immediate21122026-10-10 19:02:08.704 UTC [132] LOG: checkpoint complete: wrote 10843 buffers (66.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.285 s, sync=1.276 s, total=1.619 s; sync files=34045, longest=0.009 s, average=0.001 s; distance=531533 kB, estimate=531533 kB; lsn=0/21E792C8, redo lsn=0/21E792C821132026-10-10 19:02:08.788 UTC [127] LOG: database system is shut down2114Running OIDC tests...2115=== RUN TestAudienceForIssuer2116=== PAUSE TestAudienceForIssuer2117=== RUN TestGlobMatch2118=== PAUSE TestGlobMatch2119=== RUN TestValidateToken_ValidToken2120=== PAUSE TestValidateToken_ValidToken2121=== RUN TestValidateToken_WrongAudience2122=== PAUSE TestValidateToken_WrongAudience2123=== RUN TestValidateToken_Expired2124=== PAUSE TestValidateToken_Expired2125=== RUN TestValidateToken_BoundClaimsMismatch2126=== PAUSE TestValidateToken_BoundClaimsMismatch2127=== RUN TestValidateToken_BoundSubjectMismatch2128=== PAUSE TestValidateToken_BoundSubjectMismatch2129=== RUN TestValidateToken_MultipleProviders2130=== PAUSE TestValidateToken_MultipleProviders2131=== RUN TestValidateToken_NoMatchingProvider2132=== PAUSE TestValidateToken_NoMatchingProvider2133=== RUN TestValidateToken_KubernetesServiceAccount2134=== PAUSE TestValidateToken_KubernetesServiceAccount2135=== RUN TestNewValidator_KubernetesRequiresCA2136=== PAUSE TestNewValidator_KubernetesRequiresCA2137=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2138=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2139=== RUN TestPins_ReservedForMatchingRule2140=== PAUSE TestPins_ReservedForMatchingRule2141=== RUN TestPins_TopLevelShorthand2142=== PAUSE TestPins_TopLevelShorthand2143=== RUN TestPins_ConfigValidation2144=== PAUSE TestPins_ConfigValidation2145=== RUN TestScopes_LegacyProviderDefaultsToWrite2146=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2147=== RUN TestScopes_Rules2148=== PAUSE TestScopes_Rules2149=== RUN TestScopes_ConfigValidation2150=== PAUSE TestScopes_ConfigValidation2151=== CONT TestAudienceForIssuer2152=== CONT TestPins_ConfigValidation2153--- PASS: TestAudienceForIssuer (0.00s)2154=== CONT TestValidateToken_Expired2155=== CONT TestValidateToken_WrongAudience2156=== CONT TestValidateToken_ValidToken2157=== CONT TestGlobMatch2158=== RUN TestGlobMatch/foo_foo2159=== PAUSE TestGlobMatch/foo_foo2160=== RUN TestGlobMatch/foo_bar2161--- PASS: TestPins_ConfigValidation (0.00s)2162=== PAUSE TestGlobMatch/foo_bar2163=== RUN TestGlobMatch/*_2164=== PAUSE TestGlobMatch/*_2165=== RUN TestGlobMatch/*_anything2166=== PAUSE TestGlobMatch/*_anything2167=== RUN TestGlobMatch/foo*_foo2168=== PAUSE TestGlobMatch/foo*_foo2169=== RUN TestGlobMatch/foo*_foobar2170=== PAUSE TestGlobMatch/foo*_foobar2171=== RUN TestGlobMatch/foo*_bar2172=== PAUSE TestGlobMatch/foo*_bar2173=== RUN TestGlobMatch/*bar_bar2174=== PAUSE TestGlobMatch/*bar_bar2175=== RUN TestGlobMatch/*bar_foobar2176=== PAUSE TestGlobMatch/*bar_foobar2177=== RUN TestGlobMatch/*bar_foo2178=== PAUSE TestGlobMatch/*bar_foo2179=== RUN TestGlobMatch/foo*bar_foobar2180=== PAUSE TestGlobMatch/foo*bar_foobar2181=== RUN TestGlobMatch/foo*bar_foo123bar2182=== PAUSE TestGlobMatch/foo*bar_foo123bar2183=== RUN TestGlobMatch/foo*bar_foobarbaz2184=== PAUSE TestGlobMatch/foo*bar_foobarbaz2185=== RUN TestGlobMatch/*/*_foo/bar2186=== PAUSE TestGlobMatch/*/*_foo/bar2187=== RUN TestGlobMatch/*/*_foo2188=== PAUSE TestGlobMatch/*/*_foo2189=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2190=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2191=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02192=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02193=== RUN TestGlobMatch/refs/*/main_refs/heads/main2194=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2195=== RUN TestGlobMatch/fo?_foo2196=== PAUSE TestGlobMatch/fo?_foo2197=== RUN TestGlobMatch/fo?_fo2198=== PAUSE TestGlobMatch/fo?_fo2199=== RUN TestGlobMatch/fo?_fooo2200=== PAUSE TestGlobMatch/fo?_fooo2201=== RUN TestGlobMatch/?oo_foo2202=== PAUSE TestGlobMatch/?oo_foo2203=== RUN TestGlobMatch/?oo_boo2204=== PAUSE TestGlobMatch/?oo_boo2205=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2206=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2207=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2208=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2209=== CONT TestGlobMatch/foo_foo2210=== CONT TestPins_TopLevelShorthand2211=== CONT TestGlobMatch/*bar_bar2212=== CONT TestGlobMatch/foo*bar_foobarbaz2213=== CONT TestGlobMatch/*/*_foo/bar2214=== CONT TestValidateToken_NoMatchingProvider2215=== CONT TestNewValidator_KubernetesRequiresCA2216=== CONT TestValidateToken_BoundSubjectMismatch2217=== CONT TestScopes_Rules2218=== CONT TestScopes_ConfigValidation2219=== CONT TestScopes_LegacyProviderDefaultsToWrite2220=== CONT TestValidateToken_KubernetesServiceAccount2221=== CONT TestValidateToken_BoundClaimsMismatch2222--- PASS: TestScopes_ConfigValidation (0.00s)2223=== CONT TestGlobMatch/fo?_fo2224=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2225=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2226=== CONT TestGlobMatch/?oo_boo2227=== CONT TestGlobMatch/?oo_foo2228=== CONT TestPins_ReservedForMatchingRule2229=== CONT TestValidateToken_MultipleProviders2230=== CONT TestGlobMatch/foo*bar_foo123bar2231=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02232=== CONT TestGlobMatch/fo?_foo2233=== CONT TestGlobMatch/refs/*/main_refs/heads/main2234=== CONT TestGlobMatch/foo_bar2235=== CONT TestGlobMatch/foo*bar_foobar2236=== CONT TestGlobMatch/*/*_foo2237=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2238=== CONT TestGlobMatch/*bar_foo2239=== CONT TestGlobMatch/*bar_foobar2240=== CONT TestGlobMatch/foo*_foo2241=== CONT TestGlobMatch/foo*_bar2242=== CONT TestGlobMatch/foo*_foobar2243=== CONT TestGlobMatch/*_2244=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2245=== CONT TestGlobMatch/*_anything2246=== CONT TestGlobMatch/fo?_fooo2247--- PASS: TestGlobMatch (0.00s)2248 --- PASS: TestGlobMatch/foo_foo (0.00s)2249 --- PASS: TestGlobMatch/*bar_bar (0.00s)2250 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2251 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2252 --- PASS: TestGlobMatch/fo?_fo (0.00s)2253 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2254 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2255 --- PASS: TestGlobMatch/?oo_boo (0.00s)2256 --- PASS: TestGlobMatch/?oo_foo (0.00s)2257 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2258 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2259 --- PASS: TestGlobMatch/fo?_foo (0.00s)2260 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2261 --- PASS: TestGlobMatch/foo_bar (0.00s)2262 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2263 --- PASS: TestGlobMatch/*/*_foo (0.00s)2264 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2265 --- PASS: TestGlobMatch/*bar_foo (0.00s)2266 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2267 --- PASS: TestGlobMatch/foo*_foo (0.00s)2268 --- PASS: TestGlobMatch/foo*_bar (0.00s)2269 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2270 --- PASS: TestGlobMatch/*_ (0.00s)2271 --- PASS: TestGlobMatch/*_anything (0.00s)2272 --- PASS: TestGlobMatch/fo?_fooo (0.00s)22732026/10/10 19:02:11 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12322742026/10/10 19:02:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46705/oidc2275--- PASS: TestValidateToken_BoundClaimsMismatch (0.03s)22762026/10/10 19:02:11 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:443752277--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.03s)2278--- PASS: TestValidateToken_KubernetesServiceAccount (0.03s)22792026/10/10 19:02:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41123/oidc22802026/10/10 19:02:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36903/oidc22812026/10/10 19:02:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40577/oidc22822026/10/10 19:02:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42069/oidc22832026/10/10 19:02:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32823/oidc2284--- PASS: TestPins_ReservedForMatchingRule (0.04s)2285--- PASS: TestValidateToken_Expired (0.05s)2286--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.04s)2287--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)2288--- PASS: TestScopes_Rules (0.05s)22892026/10/10 19:02:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43477/oidc22902026/10/10 19:02:11 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:42643/oidc2291--- PASS: TestValidateToken_MultipleProviders (0.05s)22922026/10/10 19:02:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44577/oidc2293--- PASS: TestValidateToken_ValidToken (0.07s)22942026/10/10 19:02:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42555/oidc2295--- PASS: TestPins_TopLevelShorthand (0.08s)22962026/10/10 19:02:11 http: TLS handshake error from 127.0.0.1:54218: remote error: tls: bad certificate2297--- PASS: TestNewValidator_KubernetesRequiresCA (0.11s)22982026/10/10 19:02:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38445/oidc2299--- PASS: TestValidateToken_WrongAudience (0.12s)23002026/10/10 19:02:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:44907/oidc2301--- PASS: TestValidateToken_NoMatchingProvider (0.18s)2302PASS2303Running hook tests...2304=== RUN TestSendPathsEmpty2305=== PAUSE TestSendPathsEmpty2306=== RUN TestQueueEnqueueAndFetch2307=== PAUSE TestQueueEnqueueAndFetch2308=== RUN TestQueueDeduplication2309=== PAUSE TestQueueDeduplication2310=== RUN TestQueueRemove2311=== PAUSE TestQueueRemove2312=== RUN TestQueueFetchBatchLimit2313=== PAUSE TestQueueFetchBatchLimit2314=== RUN TestQueueRetryMovesToBack2315=== PAUSE TestQueueRetryMovesToBack2316=== RUN TestQueueFetchRemoveLifecycle2317=== PAUSE TestQueueFetchRemoveLifecycle2318=== RUN TestQueueConcurrentWriters2319=== PAUSE TestQueueConcurrentWriters2320=== RUN TestQueueRemoveLargeClosure2321=== PAUSE TestQueueRemoveLargeClosure2322=== RUN TestServerClientIntegration2323--- PASS: TestServerClientIntegration (0.00s)2324=== RUN TestServerQueueError23252026/10/10 19:02:11 ERROR Failed to queue paths error="permission denied" count=12326--- PASS: TestServerQueueError (0.00s)2327=== RUN TestGetListenerSocketActivation2328 server_test.go:219: === RUN TestGetListenerSocketActivation2329 --- PASS: TestGetListenerSocketActivation (0.00s)2330 PASS2331 2332--- PASS: TestGetListenerSocketActivation (0.01s)2333=== RUN TestDrainIsolatesPoisonPath2334=== PAUSE TestDrainIsolatesPoisonPath2335=== RUN TestRunNotBlockedByPoisonHead2336=== PAUSE TestRunNotBlockedByPoisonHead2337=== RUN TestDrainGivesUpWhenServerDown2338=== PAUSE TestDrainGivesUpWhenServerDown2339=== RUN TestFailedPathPrunedByLaterClosure2340=== PAUSE TestFailedPathPrunedByLaterClosure2341=== RUN TestWorkerUploadsAndRemoves2342=== PAUSE TestWorkerUploadsAndRemoves2343=== RUN TestWorkerSkipsGCdPaths2344=== PAUSE TestWorkerSkipsGCdPaths2345=== RUN TestWorkerPrunesClosureDeps2346=== PAUSE TestWorkerPrunesClosureDeps2347=== RUN TestDrainTimeout2348=== PAUSE TestDrainTimeout2349=== CONT TestSendPathsEmpty2350=== CONT TestFailedPathPrunedByLaterClosure2351=== CONT TestDrainGivesUpWhenServerDown2352=== CONT TestRunNotBlockedByPoisonHead2353=== CONT TestDrainIsolatesPoisonPath2354--- PASS: TestSendPathsEmpty (0.00s)2355=== CONT TestQueueRemoveLargeClosure2356=== CONT TestQueueFetchRemoveLifecycle2357=== CONT TestQueueDeduplication2358=== CONT TestQueueConcurrentWriters2359=== CONT TestWorkerPrunesClosureDeps2360=== CONT TestQueueRemove2361=== CONT TestQueueEnqueueAndFetch2362=== CONT TestQueueRetryMovesToBack2363=== CONT TestDrainTimeout2364=== CONT TestQueueFetchBatchLimit2365=== CONT TestWorkerUploadsAndRemoves2366=== CONT TestWorkerSkipsGCdPaths23672026/10/10 19:02:11 INFO Uploading batch count=423682026/10/10 19:02:11 ERROR Upload failed error="upload failed" count=423692026/10/10 19:02:11 INFO Upload queue status pending=223702026/10/10 19:02:11 INFO Upload queue status pending=223712026/10/10 19:02:11 INFO Upload queue status pending=323722026/10/10 19:02:11 INFO Uploading batch count=123732026/10/10 19:02:11 ERROR Upload failed error="upload failed" count=123742026/10/10 19:02:11 INFO Uploading batch count=123752026/10/10 19:02:11 ERROR Upload failed error="upload failed" count=123762026/10/10 19:02:11 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1415281818/002/nonexistent23772026/10/10 19:02:11 INFO Uploading batch count=223782026/10/10 19:02:11 ERROR Upload failed error="upload failed" count=223792026/10/10 19:02:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2808983862/002/a23802026/10/10 19:02:11 INFO Uploading batch count=223812026/10/10 19:02:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1612604333/002/bbb23822026/10/10 19:02:11 INFO Upload queue status pending=223832026/10/10 19:02:11 INFO Uploading batch count=123842026/10/10 19:02:11 INFO Uploading batch count=22385--- PASS: TestQueueEnqueueAndFetch (0.02s)23862026/10/10 19:02:11 INFO Uploading batch count=123872026/10/10 19:02:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2808983862/002/b2388--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2389--- PASS: TestQueueFetchBatchLimit (0.02s)23902026/10/10 19:02:11 INFO Uploading batch count=12391--- PASS: TestQueueRetryMovesToBack (0.02s)2392--- PASS: TestQueueRemove (0.02s)2393--- PASS: TestQueueDeduplication (0.02s)23942026/10/10 19:02:11 INFO Uploading batch count=123952026/10/10 19:02:11 INFO Uploading batch count=223962026/10/10 19:02:11 ERROR Upload failed error="upload failed" count=223972026/10/10 19:02:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2808983862/002/c23982026/10/10 19:02:11 INFO Uploading batch count=123992026/10/10 19:02:11 ERROR Upload failed error="upload failed" count=124002026/10/10 19:02:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2808983862/002/d24012026/10/10 19:02:11 INFO Uploading batch count=124022026/10/10 19:02:11 ERROR Upload failed error="upload failed" count=124032026/10/10 19:02:11 INFO Uploading batch count=224042026/10/10 19:02:11 ERROR Upload failed error="upload failed" count=224052026/10/10 19:02:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2808983862/002/e24062026/10/10 19:02:11 INFO Uploading batch count=124072026/10/10 19:02:11 ERROR Upload failed error="upload failed" count=12408--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)24092026/10/10 19:02:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2808983862/002/f24102026/10/10 19:02:11 ERROR Drain finished with paths left in queue remaining=124112026/10/10 19:02:11 ERROR Drain finished with paths left in queue remaining=102412--- PASS: TestDrainIsolatesPoisonPath (0.03s)2413--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2414--- PASS: TestWorkerPrunesClosureDeps (0.04s)2415--- PASS: TestWorkerSkipsGCdPaths (0.04s)2416--- PASS: TestWorkerUploadsAndRemoves (0.04s)2417--- PASS: TestQueueRemoveLargeClosure (0.07s)24182026/10/10 19:02:11 ERROR Upload failed error="context deadline exceeded" count=224192026/10/10 19:02:11 ERROR Drain finished with paths left in queue remaining=42420--- PASS: TestDrainTimeout (0.22s)2421--- PASS: TestQueueConcurrentWriters (0.38s)24222026/10/10 19:02:12 INFO Uploading batch count=124232026/10/10 19:02:12 INFO Uploading batch count=124242026/10/10 19:02:12 INFO Uploading batch count=124252026/10/10 19:02:12 ERROR Upload failed error="upload failed" count=124262026/10/10 19:02:12 INFO Uploading batch count=124272026/10/10 19:02:12 ERROR Upload failed error="upload failed" count=124282026/10/10 19:02:12 INFO Uploading batch count=124292026/10/10 19:02:12 ERROR Upload failed error="upload failed" count=124302026/10/10 19:02:12 INFO Uploading batch count=124312026/10/10 19:02:12 ERROR Upload failed error="upload failed" count=124322026/10/10 19:02:12 ERROR Drain finished with paths left in queue remaining=12433--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2434PASS2435Running signing tests...2436=== RUN TestExternalSigner2437=== PAUSE TestExternalSigner2438=== RUN TestExternalSignerWrongPublicKey2439=== PAUSE TestExternalSignerWrongPublicKey2440=== RUN TestExternalSignerErrors2441=== PAUSE TestExternalSignerErrors2442=== RUN TestExternalSignerRestartsAfterCrash2443=== PAUSE TestExternalSignerRestartsAfterCrash2444=== RUN TestExternalSignerProgramErrorKeepsProcess2445=== PAUSE TestExternalSignerProgramErrorKeepsProcess2446=== RUN TestExternalSignerClose2447=== PAUSE TestExternalSignerClose2448=== RUN TestExternalSignerRejectsInvalidPublicKey2449=== PAUSE TestExternalSignerRejectsInvalidPublicKey2450=== RUN TestExternalSignerCancellation2451=== PAUSE TestExternalSignerCancellation2452=== RUN TestGenerateFingerprint2453=== PAUSE TestGenerateFingerprint2454=== RUN TestParseSigningKey2455=== PAUSE TestParseSigningKey2456=== RUN TestSign2457=== PAUSE TestSign2458=== RUN TestSignBatch2459=== PAUSE TestSignBatch2460=== RUN TestNilKeyPublicKey2461=== PAUSE TestNilKeyPublicKey2462=== RUN TestSignErrors2463=== PAUSE TestSignErrors2464=== CONT TestExternalSigner2465=== CONT TestExternalSignerCancellation2466=== CONT TestExternalSignerRejectsInvalidPublicKey2467=== CONT TestSign2468=== CONT TestParseSigningKey2469=== RUN TestParseSigningKey/valid_32-byte_key2470=== CONT TestGenerateFingerprint2471=== CONT TestSignErrors2472=== CONT TestExternalSignerErrors2473=== RUN TestExternalSignerErrors/wrong_signature_name2474=== PAUSE TestExternalSignerErrors/wrong_signature_name2475=== CONT TestExternalSignerRestartsAfterCrash2476=== CONT TestNilKeyPublicKey2477=== CONT TestExternalSignerWrongPublicKey2478--- PASS: TestNilKeyPublicKey (0.00s)2479=== CONT TestExternalSignerClose2480=== CONT TestSignBatch2481=== CONT TestExternalSignerProgramErrorKeepsProcess2482=== RUN TestExternalSignerRejectsInvalidPublicKey/#002483=== PAUSE TestParseSigningKey/valid_32-byte_key2484=== RUN TestGenerateFingerprint/basic_with_references2485=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2486=== PAUSE TestGenerateFingerprint/basic_with_references2487=== RUN TestGenerateFingerprint/no_references2488=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2489=== RUN TestParseSigningKey/no_colon2490=== PAUSE TestParseSigningKey/no_colon2491=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002492--- PASS: TestSign (0.00s)2493--- PASS: TestSignBatch (0.00s)2494=== RUN TestExternalSignerErrors/program_error2495=== PAUSE TestGenerateFingerprint/no_references2496=== PAUSE TestExternalSignerErrors/program_error2497=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2498=== RUN TestParseSigningKey/empty_name2499=== PAUSE TestParseSigningKey/empty_name2500=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2501=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2502=== RUN TestSignErrors/nil_key2503=== RUN TestExternalSignerErrors/exit_at_startup2504=== PAUSE TestSignErrors/nil_key2505=== PAUSE TestExternalSignerErrors/exit_at_startup2506=== RUN TestExternalSignerErrors/null_signatures2507=== RUN TestParseSigningKey/invalid_base642508=== PAUSE TestParseSigningKey/invalid_base642509=== RUN TestParseSigningKey/wrong_length2510=== PAUSE TestParseSigningKey/wrong_length2511=== CONT TestParseSigningKey/valid_32-byte_key2512=== CONT TestParseSigningKey/wrong_length2513=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2514=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2515=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2516=== RUN TestSignErrors/nil_narinfo2517=== PAUSE TestExternalSignerErrors/null_signatures2518=== RUN TestExternalSignerErrors/wrong_signatures_shape2519=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2520=== RUN TestExternalSignerErrors/missing_signature_name2521=== PAUSE TestExternalSignerErrors/missing_signature_name2522=== RUN TestExternalSignerErrors/invalid_signature_base642523=== PAUSE TestExternalSignerErrors/invalid_signature_base642524=== CONT TestParseSigningKey/empty_name2525=== CONT TestParseSigningKey/invalid_base642526=== CONT TestParseSigningKey/no_colon2527=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2528--- PASS: TestParseSigningKey (0.00s)2529 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2530 --- PASS: TestParseSigningKey/wrong_length (0.00s)2531 --- PASS: TestParseSigningKey/empty_name (0.00s)2532 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2533 --- PASS: TestParseSigningKey/no_colon (0.00s)2534 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2535=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2536=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2537=== PAUSE TestSignErrors/nil_narinfo2538=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2539=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2540=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2541=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2542=== CONT TestExternalSignerRejectsInvalidPublicKey/#002543=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2544=== RUN TestSignErrors/invalid_narinfo2545=== PAUSE TestSignErrors/invalid_narinfo2546=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2547=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2548=== RUN TestGenerateFingerprint/invalid_nar_hash_length2549=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2550=== RUN TestGenerateFingerprint/invalid_store_path_prefix2551=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2552=== RUN TestGenerateFingerprint/invalid_reference_prefix2553=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2554=== CONT TestGenerateFingerprint/basic_with_references2555=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2556=== RUN TestExternalSignerErrors/wrong_shape2557=== PAUSE TestExternalSignerErrors/wrong_shape2558=== RUN TestExternalSignerErrors/exit_on_request2559=== CONT TestGenerateFingerprint/invalid_reference_prefix2560=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2561--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2562 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2563 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2564 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2565 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2566 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2567=== RUN TestSignErrors/canceled2568=== PAUSE TestSignErrors/canceled2569=== CONT TestSignErrors/nil_key2570=== CONT TestSignErrors/nil_narinfo2571=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2572=== CONT TestGenerateFingerprint/invalid_store_path_prefix2573=== CONT TestGenerateFingerprint/invalid_nar_hash_length2574=== CONT TestGenerateFingerprint/no_references2575--- PASS: TestGenerateFingerprint (0.00s)2576 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2577 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2578 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2579 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2580 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2581 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2582 --- PASS: TestGenerateFingerprint/no_references (0.00s)2583=== PAUSE TestExternalSignerErrors/exit_on_request2584=== CONT TestSignErrors/invalid_narinfo2585=== CONT TestSignErrors/canceled2586--- PASS: TestSignErrors (0.00s)2587 --- PASS: TestSignErrors/nil_key (0.00s)2588 --- PASS: TestSignErrors/nil_narinfo (0.00s)2589 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2590 --- PASS: TestSignErrors/canceled (0.00s)2591=== RUN TestExternalSignerErrors/invalid_JSON2592=== PAUSE TestExternalSignerErrors/invalid_JSON2593=== RUN TestExternalSignerErrors/null2594=== PAUSE TestExternalSignerErrors/null2595=== RUN TestExternalSignerErrors/unrequested_key2596=== PAUSE TestExternalSignerErrors/unrequested_key2597=== RUN TestExternalSignerErrors/wrong_signature_length2598=== PAUSE TestExternalSignerErrors/wrong_signature_length2599=== RUN TestExternalSignerErrors/wrong_id2600=== PAUSE TestExternalSignerErrors/wrong_id2601=== RUN TestExternalSignerErrors/missing_signatures2602=== PAUSE TestExternalSignerErrors/missing_signatures2603=== RUN TestExternalSignerErrors/too_few_signatures2604=== PAUSE TestExternalSignerErrors/too_few_signatures2605=== CONT TestExternalSignerErrors/wrong_signature_name2606=== CONT TestExternalSignerErrors/wrong_signature_length2607=== CONT TestExternalSignerErrors/invalid_signature_base642608=== CONT TestExternalSignerErrors/null2609=== CONT TestExternalSignerErrors/exit_on_request2610=== CONT TestExternalSignerErrors/too_few_signatures2611=== CONT TestExternalSignerErrors/missing_signatures2612=== CONT TestExternalSignerErrors/wrong_id2613=== CONT TestExternalSignerErrors/unrequested_key2614=== CONT TestExternalSignerErrors/wrong_signatures_shape2615=== CONT TestExternalSignerErrors/wrong_shape2616=== CONT TestExternalSignerErrors/missing_signature_name2617=== CONT TestExternalSignerErrors/exit_at_startup2618=== CONT TestExternalSignerErrors/null_signatures2619=== CONT TestExternalSignerErrors/program_error2620=== CONT TestExternalSignerErrors/invalid_JSON2621--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2622--- PASS: TestExternalSignerClose (0.01s)2623--- PASS: TestExternalSignerWrongPublicKey (0.01s)2624--- PASS: TestExternalSigner (0.01s)2625--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2626--- PASS: TestExternalSignerErrors (0.00s)2627 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2628 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2629 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2630 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2631 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2632 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2633 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2634 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2635 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2636 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2637 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2638 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2639 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2640 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2641 --- PASS: TestExternalSignerErrors/null (0.01s)2642 --- PASS: TestExternalSignerErrors/program_error (0.01s)2643--- PASS: TestExternalSignerCancellation (0.02s)2644PASS2645Running OpenBao signer tests...2646=== RUN TestSign2647=== PAUSE TestSign2648=== RUN TestSignErrors2649=== PAUSE TestSignErrors2650=== RUN TestServe2651=== PAUSE TestServe2652=== RUN TestServeRejectsGarbage2653=== PAUSE TestServeRejectsGarbage2654=== CONT TestSign2655=== CONT TestServe2656=== CONT TestServeRejectsGarbage2657=== CONT TestSignErrors2658=== RUN TestSignErrors/http_error2659--- PASS: TestServeRejectsGarbage (0.00s)2660--- PASS: TestServe (0.00s)2661=== PAUSE TestSignErrors/http_error2662=== RUN TestSignErrors/invalid_json2663=== PAUSE TestSignErrors/invalid_json2664=== RUN TestSignErrors/no_prefix2665=== PAUSE TestSignErrors/no_prefix2666=== RUN TestSignErrors/invalid_base642667=== PAUSE TestSignErrors/invalid_base642668=== CONT TestSignErrors/http_error2669=== CONT TestSignErrors/no_prefix2670=== CONT TestSignErrors/invalid_base642671=== CONT TestSignErrors/invalid_json2672--- PASS: TestSign (0.00s)2673--- PASS: TestSignErrors (0.00s)2674 --- PASS: TestSignErrors/invalid_json (0.00s)2675 --- PASS: TestSignErrors/invalid_base64 (0.00s)2676 --- PASS: TestSignErrors/http_error (0.00s)2677 --- PASS: TestSignErrors/no_prefix (0.00s)2678PASS