niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #399
· 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 TestSetClientTLSDoesNotMutateDefaultTransport108--- PASS: TestShellSplit (0.00s)109=== CONT TestScriptTokenEmptyCommand110=== CONT TestFileTokenEmpty111=== CONT TestScriptTokenNoExpiryRerunsEveryCall112=== CONT TestFileTokenMissing113=== CONT TestScriptTokenEmptyToken114=== CONT TestFileTokenReadsAndCaches115=== CONT TestStaticToken116=== CONT TestPartSizeForNAR117=== CONT TestStreamPushRequestLine118=== CONT TestEncodeNixBase32119=== CONT TestSetClientTLSErrors120=== CONT TestEncodeNixBase32WithRealHash121=== CONT TestPathInfoCACompatibility122=== CONT TestParsePathInfoJSONMultiplePaths123=== CONT TestRetryTimeoutOutlastsMaxRetries124=== CONT TestParsePathInfoJSON125=== CONT TestDoWithRetry_BodyReplayedViaGetBody126=== CONT TestPathInfoHashCompatibility127=== CONT TestResolveStorePath128=== CONT TestGetStorePathHash129=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess130=== CONT TestScriptTokenBadJSON131=== CONT TestConvertHashToNix32132=== CONT TestRateLimiterFeedback133--- PASS: TestScriptTokenEmptyCommand (0.00s)134=== CONT TestScriptTokenScriptFails135=== CONT TestScriptTokenCachesUntilRefresh136=== RUN TestEncodeNixBase32/test_string_hash137=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths138=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths139=== PAUSE TestEncodeNixBase32/test_string_hash140--- PASS: TestFileTokenMissing (0.00s)141--- PASS: TestStaticToken (0.00s)142--- PASS: TestFileTokenEmpty (0.00s)143--- PASS: TestEncodeNixBase32WithRealHash (0.00s)144=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths145=== RUN TestEncodeNixBase32/empty_input146=== CONT TestSetClientTLS147=== RUN TestPartSizeForNAR/zero_stays_at_minimum148=== RUN TestRateLimiterFeedback/429_enables_limiter149=== RUN TestGetStorePathHash/valid_store_path150=== RUN TestConvertHashToNix32/SRI_format_to_Nix32151=== RUN TestPathInfoCACompatibility/null_ca_field152=== RUN TestParsePathInfoJSON/Nix_format153=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)154=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1552026/10/08 12:58:00 WARN Rate limiter enabled after throttle name=server-test rate=5156=== PAUSE TestEncodeNixBase32/empty_input157--- PASS: TestFileTokenReadsAndCaches (0.01s)158=== PAUSE TestGetStorePathHash/valid_store_path159=== RUN TestGetStorePathHash/basename_without_hyphen_should_error160--- PASS: TestScriptTokenScriptFails (0.00s)161--- PASS: TestResolveStorePath (0.00s)162=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error163=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum164=== RUN TestPartSizeForNAR/small_stays_at_minimum165=== PAUSE TestPartSizeForNAR/small_stays_at_minimum166=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error167=== PAUSE TestRateLimiterFeedback/429_enables_limiter168=== CONT TestDumpPathWriterError169=== PAUSE TestPathInfoCACompatibility/null_ca_field170=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32171=== RUN TestPathInfoCACompatibility/old_string_format_-_text172=== RUN TestConvertHashToNix32/already_Nix32_format1732026/10/08 12:58:00 ERROR Upload failed error=boom count=1174=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text175=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum176=== CONT TestDumpPathMatchesNix177=== RUN TestRateLimiterFeedback/503_enables_limiter178=== PAUSE TestRateLimiterFeedback/503_enables_limiter179=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error180=== PAUSE TestParsePathInfoJSON/Nix_format1812026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:39959182=== PAUSE TestConvertHashToNix32/already_Nix32_format1832026/10/08 12:58:00 WARN Rate limiter enabled after throttle name=server-test rate=5184=== RUN TestConvertHashToNix32/invalid_format1852026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:36775186=== PAUSE TestConvertHashToNix32/invalid_format187=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)188=== CONT TestStreamPushStopsWhenCanceled189=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon190=== CONT TestDumpPathSingleFile191=== CONT TestClientSignaturesByStorePath192=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum193=== RUN TestSetClientTLSErrors/missing_cert_file194=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter195=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive196--- PASS: TestScriptTokenBadJSON (0.00s)197=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error198=== CONT TestStreamPushGivesUpOnDeadServer1992026/10/08 12:58:00 WARN Rate limiter backed off name=server-test rate=5200=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive2012026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:36775202=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error203=== RUN TestPathInfoCACompatibility/new_structured_format_-_text204=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts2052026/10/08 12:58:00 ERROR Upload failed error="connection refused" count=202062026/10/08 12:58:00 ERROR Server seems unavailable, giving up on batch untried=17207=== PAUSE TestSetClientTLSErrors/missing_cert_file208=== CONT TestStreamPushBatchesUnderLoad209=== CONT TestCaseHackSuffix210=== CONT TestUploadMultipart_SupersededByPeer211=== CONT TestStreamPushReportsSignatures212=== CONT TestStreamPushReportsSkippedPaths213--- PASS: TestScriptTokenEmptyToken (0.00s)214=== RUN TestParsePathInfoJSON/Lix_format215=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter216=== RUN TestSetClientTLSErrors/missing_key_file217=== CONT TestUploadMultipart_PartsInParallel218=== PAUSE TestSetClientTLSErrors/missing_key_file2192026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:39959220--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)221--- PASS: TestStreamPushStopsWhenCanceled (0.00s)222--- PASS: TestClientSignaturesByStorePath (0.00s)223=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts224=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text225=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter226=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter227--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)228=== CONT TestStreamPushIsolatesFailures229=== RUN TestSetClientTLSErrors/missing_ca_file2302026/10/08 12:58:00 ERROR Upload failed error="bad path" count=3231=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon232=== RUN TestPartSizeForNAR/1_TiB233=== PAUSE TestPartSizeForNAR/1_TiB234=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method235=== PAUSE TestParsePathInfoJSON/Lix_format236=== PAUSE TestSetClientTLSErrors/missing_ca_file237=== CONT TestRegisterUploadedObjectReusesConnections238--- PASS: TestStreamPushIsolatesFailures (0.00s)239--- PASS: TestStreamPushReportsSkippedPaths (0.00s)240--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)241--- PASS: TestDoServerRequestAttachesToken (0.01s)242=== CONT TestStreamPushReportsEveryPath243=== CONT TestShellSplitErrors244=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica245=== CONT TestFilterOversizedClosures246=== RUN TestUploadMultipart_SupersededByPeer/exists247--- PASS: TestShellSplitErrors (0.00s)248=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun249--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)250=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths251--- PASS: TestStreamPushReportsEveryPath (0.00s)252=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths253=== CONT TestEncodeNixBase32/test_string_hash254=== CONT TestEncodeNixBase32/empty_input255=== CONT TestConvertHashToNix32/SRI_format_to_Nix32256--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)257 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)258 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)259--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)260--- PASS: TestEncodeNixBase32 (0.01s)261 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)262 --- PASS: TestEncodeNixBase32/empty_input (0.00s)263=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI264=== RUN TestParsePathInfoJSON/empty_input2652026/10/08 12:58:00 ERROR Upload failed error=boom count=1266=== PAUSE TestParsePathInfoJSON/empty_input267=== RUN TestParsePathInfoJSON/whitespace_only268=== PAUSE TestParsePathInfoJSON/whitespace_only269=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI270=== CONT TestConvertHashToNix32/invalid_format271=== CONT TestGetStorePathHash/basename_without_hyphen_should_error272=== RUN TestSetClientTLSErrors/invalid_ca_file273=== CONT TestGetStorePathHash/valid_store_path274=== CONT TestRateLimiterFeedback/429_enables_limiter275=== RUN TestFilterOversizedClosures/no_limit_keeps_everything276=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything277=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped278=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped279=== RUN TestFilterOversizedClosures/all_closures_skipped280=== PAUSE TestFilterOversizedClosures/all_closures_skipped281=== PAUSE TestUploadMultipart_SupersededByPeer/exists2822026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:39959283=== RUN TestUploadMultipart_SupersededByPeer/missing284=== PAUSE TestUploadMultipart_SupersededByPeer/missing285=== RUN TestSetClientTLS/rejects_connection_without_client_cert286=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert287=== RUN TestParsePathInfoJSON/invalid_JSON2882026/10/08 12:58:00 WARN Rate limiter enabled after throttle name=server-test rate=5289=== PAUSE TestParsePathInfoJSON/invalid_JSON290=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512291=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha5122922026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:43117293=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method294=== PAUSE TestSetClientTLSErrors/invalid_ca_file295=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter296=== CONT TestUploadMultipart_SupersededByPeer/exists297=== CONT TestUploadMultipart_SupersededByPeer/missing2982026/10/08 12:58:00 WARN Rate limiter backed off name=server-test rate=5299=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped300=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA3012026/10/08 12:58:00 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=2000302=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA303=== CONT TestFilterOversizedClosures/all_closures_skipped3042026/10/08 12:58:00 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=50305=== CONT TestParsePathInfoJSON/Nix_format3062026/10/08 12:58:00 INFO Garbage collection started307=== CONT TestParsePathInfoJSON/invalid_JSON308--- PASS: TestStreamPushReportsSignatures (0.03s)309=== RUN TestSetClientTLS/preserves_debug_logging_transport310=== PAUSE TestSetClientTLS/preserves_debug_logging_transport311=== RUN TestPartSizeForNAR/5_TiB_S3_max_object312=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error313=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error314=== CONT TestConvertHashToNix32/already_Nix32_format315=== CONT TestRateLimiterFeedback/503_enables_limiter316=== CONT TestFilterOversizedClosures/no_limit_keeps_everything317=== CONT TestParsePathInfoJSON/whitespace_only318=== CONT TestParsePathInfoJSON/empty_input319=== CONT TestParsePathInfoJSON/Lix_format320=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)321--- PASS: TestParsePathInfoJSON (0.04s)322 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)323 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)324 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)325 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)326 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)3272026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:39959328=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3292026/10/08 12:58:00 INFO Garbage collection started330=== CONT TestSetClientTLSErrors/missing_cert_file3312026/10/08 12:58:00 WARN Rate limiter enabled after throttle name=server-test rate=5332=== CONT TestSetClientTLSErrors/invalid_ca_file3332026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:37335334=== CONT TestSetClientTLSErrors/missing_key_file3352026/10/08 12:58:00 WARN Rate limiter backed off name=server-test rate=5336=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI337=== CONT TestSetClientTLS/preserves_debug_logging_transport338=== CONT TestSetClientTLSErrors/missing_ca_file339=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object3402026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:39959341=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon3422026/10/08 12:58:00 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=0343=== CONT TestPathInfoCACompatibility/null_ca_field344--- PASS: TestFilterOversizedClosures (0.03s)345 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)346 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)347 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)348=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method349=== CONT TestPathInfoCACompatibility/new_structured_format_-_text350=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512351=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive352=== CONT TestPathInfoCACompatibility/old_string_format_-_text353=== CONT TestSetClientTLS/rejects_connection_without_client_cert3542026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:39959355=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA356=== RUN TestPartSizeForNAR/capped_at_5_GiB3572026/10/08 12:58:00 WARN Garbage collection finished on another replica. Its statistics are not available here358=== PAUSE TestPartSizeForNAR/capped_at_5_GiB359--- PASS: TestGetStorePathHash (0.01s)360 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)361 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)362 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)363 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)364=== CONT TestPartSizeForNAR/small_stays_at_minimum365=== CONT TestPartSizeForNAR/zero_stays_at_minimum366=== CONT TestPartSizeForNAR/capped_at_5_GiB367=== CONT TestPartSizeForNAR/5_TiB_S3_max_object368=== CONT TestPartSizeForNAR/1_TiB369=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts370=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum3712026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:39959372--- PASS: TestDumpPathSingleFile (0.04s)373--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)374--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)375--- PASS: TestConvertHashToNix32 (0.01s)376 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)377 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)378 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)379--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)380 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)381 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)382--- PASS: TestPathInfoCACompatibility (0.04s)383 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)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: TestPartSizeForNAR (0.05s)389 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)390 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)391 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)392 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)393 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)394 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)395 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)396--- PASS: TestRateLimiterFeedback (0.01s)397 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)398 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)399 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)400 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)401--- PASS: TestPathInfoHashCompatibility (0.04s)402 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)403 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)404 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)405 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)406--- PASS: TestSetClientTLSErrors (0.04s)407 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)408 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)409 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)410 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)4112026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:399594122026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:399594132026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:399594142026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:39959415--- PASS: TestStreamPushRequestLine (0.06s)4162026/10/08 12:58:00 http: TLS handshake error from 127.0.0.1:53676: remote error: tls: bad certificate4172026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:39959418--- PASS: TestSetClientTLS (0.04s)419 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)420 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)421 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)4222026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:399594232026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:399594242026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:399594252026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:399594262026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:39959427--- PASS: TestRegisterUploadedObjectReusesConnections (0.06s)4282026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:399594292026/10/08 12:58:00 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:39959430--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.07s)431--- PASS: TestCaseHackSuffix (0.06s)432--- PASS: TestDumpPathWriterError (0.07s)433--- PASS: TestStreamPushBatchesUnderLoad (0.10s)434--- PASS: TestDumpPathMatchesNix (0.13s)435--- PASS: TestUploadMultipart_PartsInParallel (0.65s)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/postgres1124863726/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/postgres1124863726/data -l logfile start465466/build/postgres1124863726:5432 - no response4672026-10-08 12:58:02.203 UTC [128] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4682026-10-08 12:58:02.204 UTC [128] LOG: listening on Unix socket "/build/postgres1124863726/.s.PGSQL.5432"4692026-10-08 12:58:02.209 UTC [135] LOG: database system was shut down at 2026-10-08 12:58:01 UTC4702026-10-08 12:58:02.213 UTC [128] LOG: database system is ready to accept connections471/build/postgres1124863726:5432 - accepting connections472=== RUN TestService_AuthMiddleware473=== PAUSE TestService_AuthMiddleware474=== RUN TestService_AuthMiddleware_MTLSProxyHeader475=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader476=== RUN TestService_AuthMiddleware_MTLSBoundSubjects477=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects478=== RUN TestService_ReadAuthMiddleware479=== PAUSE TestService_ReadAuthMiddleware480=== RUN TestService_AuthMiddleware_OIDC481=== PAUSE TestService_AuthMiddleware_OIDC482=== RUN TestService_RequireScope_OIDC483=== PAUSE TestService_RequireScope_OIDC484=== RUN TestService_ReadScope_PublicByDefault485=== PAUSE TestService_ReadScope_PublicByDefault486=== RUN TestCacheConfigHandler487=== PAUSE TestCacheConfigHandler488=== RUN TestCacheStatsHandler489=== PAUSE TestCacheStatsHandler490=== RUN TestClientCADerivations491=== PAUSE TestClientCADerivations492=== RUN TestClientErrorHandling493=== PAUSE TestClientErrorHandling494=== RUN TestClientIntegration495=== PAUSE TestClientIntegration496=== RUN TestClientMultipleUploads497=== PAUSE TestClientMultipleUploads498=== RUN TestClientWithDependencies499=== PAUSE TestClientWithDependencies500=== RUN TestClientSharedPathCommittedMidPush501=== PAUSE TestClientSharedPathCommittedMidPush502=== RUN TestPinProtectsFromGC503=== PAUSE TestPinProtectsFromGC504=== RUN TestClientPushesUseOnePush505=== PAUSE TestClientPushesUseOnePush506=== RUN TestClientFallsBackToClosures507=== PAUSE TestClientFallsBackToClosures508=== RUN TestDeleteClosuresRacingPins509=== PAUSE TestDeleteClosuresRacingPins510=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock511=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock512=== RUN TestResolveDBConnectionString513=== PAUSE TestResolveDBConnectionString514=== RUN TestConnectWaitsForAPeerMigration515=== PAUSE TestConnectWaitsForAPeerMigration516=== RUN TestLeadElectsOneAndHandsOver517=== PAUSE TestLeadElectsOneAndHandsOver518=== RUN TestLeadIncumbentWinsAfterRestart5192026/10/08 12:58:02 INFO lead: acquired remote=192.0.2.1:12345202026/10/08 12:58:03 INFO lead: released remote=192.0.2.1:12345212026/10/08 12:58:03 INFO lead: acquired remote=192.0.2.1:12345222026/10/08 12:58:04 INFO lead: released remote=192.0.2.1:1234523--- PASS: TestLeadIncumbentWinsAfterRestart (1.91s)524=== RUN TestLeadIncumbentAnnouncesAtOnce525=== PAUSE TestLeadIncumbentAnnouncesAtOnce526=== RUN TestLeadEndsOnShutdown527=== PAUSE TestLeadEndsOnShutdown528=== RUN TestLeadEndsWhenItsConnectionHangs5292026/10/08 12:58:04 INFO lead: acquired remote=192.0.2.1:12345302026-10-08 12:58:06.046 UTC [576] FATAL: terminating connection due to administrator command5312026/10/08 12:58:06 INFO lead: acquired remote=192.0.2.1:12345322026/10/08 12:58:07 WARN lead: lock connection lost error="timeout: context deadline exceeded"5332026/10/08 12:58:07 INFO lead: released remote=192.0.2.1:12345342026/10/08 12:58:07 INFO lead: released remote=192.0.2.1:1234535--- PASS: TestLeadEndsWhenItsConnectionHangs (3.12s)536=== RUN TestGCAdvisoryLockBlocksConcurrentRun537=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun538=== RUN TestGCBugBareHashReferences539=== PAUSE TestGCBugBareHashReferences540=== RUN TestGCMetrics541=== PAUSE TestGCMetrics542=== RUN TestPushDedupSurvivesConcurrentGC543=== PAUSE TestPushDedupSurvivesConcurrentGC544=== RUN TestDeduplicatedObjectsRecordedAsPending545=== PAUSE TestDeduplicatedObjectsRecordedAsPending546=== RUN TestGCSweepSkipsPendingObjects547=== PAUSE TestGCSweepSkipsPendingObjects548=== RUN TestTombstonedObjectOfferedWithoutWaiting549=== PAUSE TestTombstonedObjectOfferedWithoutWaiting550=== RUN TestGCSweepDeliversEachKeyOnce551=== PAUSE TestGCSweepDeliversEachKeyOnce552=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection553=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection554=== RUN TestForceGCDuringPushOffersSweptObject555=== PAUSE TestForceGCDuringPushOffersSweptObject556=== RUN TestFailedS3DeleteKeepsTombstone557=== PAUSE TestFailedS3DeleteKeepsTombstone558=== RUN TestSweepSkipsRowsLockedByPush559=== PAUSE TestSweepSkipsRowsLockedByPush560=== RUN TestRegisterCompletedObjectNeedsPendingRow561=== PAUSE TestRegisterCompletedObjectNeedsPendingRow562=== RUN TestGetExistingObjectsLocksRows563=== PAUSE TestGetExistingObjectsLocksRows564=== RUN TestSweepRechecksPendingAfterLocking565=== PAUSE TestSweepRechecksPendingAfterLocking566=== RUN TestPushWaitsForSweepHoldingRow567=== PAUSE TestPushWaitsForSweepHoldingRow568=== RUN TestCommitRacingPendingCleanupKeepsObjects569=== PAUSE TestCommitRacingPendingCleanupKeepsObjects570=== RUN TestGCEndsOnShutdown571=== PAUSE TestGCEndsOnShutdown572=== RUN TestGCTaskStore_StartNew573=== PAUSE TestGCTaskStore_StartNew574=== RUN TestGCTaskStore_DeduplicateSameParams575=== PAUSE TestGCTaskStore_DeduplicateSameParams576=== RUN TestGCTaskStore_ConflictDifferentParams577=== PAUSE TestGCTaskStore_ConflictDifferentParams578=== RUN TestGCTaskStore_GetEmpty579=== PAUSE TestGCTaskStore_GetEmpty580=== RUN TestGCTaskStore_GetReturnsLatest581=== PAUSE TestGCTaskStore_GetReturnsLatest582=== RUN TestGCTaskStore_CompletedAllowsNewTask583=== PAUSE TestGCTaskStore_CompletedAllowsNewTask584=== RUN TestGCTaskStore_PhaseUpdates585=== PAUSE TestGCTaskStore_PhaseUpdates586=== RUN TestGCTaskStore_Fail587=== PAUSE TestGCTaskStore_Fail588=== RUN TestGracefulShutdownDrainsInflight589=== PAUSE TestGracefulShutdownDrainsInflight590=== RUN TestService_healthCheckHandler591=== PAUSE TestService_healthCheckHandler592=== RUN TestService_readinessHandler593=== PAUSE TestService_readinessHandler594=== RUN TestGenerateLandingPage595=== PAUSE TestGenerateLandingPage596=== RUN TestCacheConfigHandlerMaxNarSize597=== PAUSE TestCacheConfigHandlerMaxNarSize598=== RUN TestCreatePendingClosureRejectsOversizedNAR599=== PAUSE TestCreatePendingClosureRejectsOversizedNAR600=== RUN TestNARDeduplicationMetadataUploadBug601=== PAUSE TestNARDeduplicationMetadataUploadBug602=== RUN TestMetricsInventory603=== PAUSE TestMetricsInventory604=== RUN TestMetricsCommit605=== PAUSE TestMetricsCommit606=== RUN TestService_NativeMTLS607=== PAUSE TestService_NativeMTLS608=== RUN TestServerTLSConfig609=== PAUSE TestServerTLSConfig610=== RUN TestMultipartCleanup611=== PAUSE TestMultipartCleanup612=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded613=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded614=== RUN TestPendingCleanupUsesOneCutoff615=== PAUSE TestPendingCleanupUsesOneCutoff616=== RUN TestObjectStatsTrigger617=== PAUSE TestObjectStatsTrigger618=== RUN TestObjectStatsLargeCommit619=== PAUSE TestObjectStatsLargeCommit620=== RUN TestOrphanedObjectsGC621=== PAUSE TestOrphanedObjectsGC622=== RUN TestOrphanedObjectsGCStressTest623=== PAUSE TestOrphanedObjectsGCStressTest624=== RUN TestCreatePin_ReservedPins625=== PAUSE TestCreatePin_ReservedPins626=== RUN TestPresentReportsOnlyClosureRoots627=== PAUSE TestPresentReportsOnlyClosureRoots628=== RUN TestPresentRefreshesOnlyStaleClosures629=== PAUSE TestPresentRefreshesOnlyStaleClosures630=== RUN TestPresentNotReportedWhileGCDeletesClosure631=== PAUSE TestPresentNotReportedWhileGCDeletesClosure632=== RUN TestParseSingleRange633=== PAUSE TestParseSingleRange634=== RUN TestProxyHeadersOnlyTrustedOnSocket6352026/10/08 12:58:07 INFO Starting HTTP server address=127.0.0.1:462436362026/10/08 12:58:07 INFO Starting HTTP server address=proxy.sock6372026/10/08 12:58:07 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6382026/10/08 12:58:07 INFO Shutdown signal received, draining in-flight requests timeout=10s639--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.12s)640=== RUN TestIsValidCachePath641=== PAUSE TestIsValidCachePath642=== RUN TestReadProxyNarinfo643=== PAUSE TestReadProxyNarinfo644=== RUN TestReadProxyNarinfoAlreadyDecompressed645=== PAUSE TestReadProxyNarinfoAlreadyDecompressed646=== RUN TestReadProxyContentNegotiation647=== PAUSE TestReadProxyContentNegotiation648=== RUN TestReadProxyNarStreaming649=== PAUSE TestReadProxyNarStreaming650=== RUN TestReadProxy404651=== PAUSE TestReadProxy404652=== RUN TestReadProxyInvalidPath653=== PAUSE TestReadProxyInvalidPath654=== RUN TestReadProxyHead655=== PAUSE TestReadProxyHead656=== RUN TestReadProxyOutlastsServerWriteTimeout657=== PAUSE TestReadProxyOutlastsServerWriteTimeout658=== RUN TestReadProxyConditionalGet659=== PAUSE TestReadProxyConditionalGet660=== RUN TestReadProxyRootRedirectsToIndexHTML661=== PAUSE TestReadProxyRootRedirectsToIndexHTML662=== RUN TestReadProxyDisabled663=== PAUSE TestReadProxyDisabled664=== RUN TestReadRedirectNar665=== PAUSE TestReadRedirectNar666=== RUN TestReadRedirectKeepsNarinfoProxied667=== PAUSE TestReadRedirectKeepsNarinfoProxied668=== RUN TestReadProxyRangeRequest669=== PAUSE TestReadProxyRangeRequest670=== RUN TestReadRedirectUsesPublicS3URL671=== PAUSE TestReadRedirectUsesPublicS3URL672=== RUN TestPush_OverlappingRootsStoreOneRowPerKey673=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey674=== RUN TestPush_CompleteCommitsEveryRoot675=== PAUSE TestPush_CompleteCommitsEveryRoot676=== RUN TestPush_RepeatedRootCommitsOnce677=== PAUSE TestPush_RepeatedRootCommitsOnce678=== RUN TestPush_CompleteWaitsForCleanupOfThePush679=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush680=== RUN TestPush_RootsAreLockedInByteOrder681=== PAUSE TestPush_RootsAreLockedInByteOrder682=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit683=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit684=== RUN TestPush_RejectsBadRequests685=== PAUSE TestPush_RejectsBadRequests686=== RUN TestPush_SignsNarinfosOfItsPendingObjects687=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects688=== RUN TestRedundantMultipartUpload689=== PAUSE TestRedundantMultipartUpload690=== RUN TestCompleteMultipartUpload_ErrorButObjectExists691=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists692=== RUN TestCompletedNarNotReofferedAcrossClosures693=== PAUSE TestCompletedNarNotReofferedAcrossClosures694=== RUN TestPresignedUploadRegisteredBeforeCommit695=== PAUSE TestPresignedUploadRegisteredBeforeCommit696=== RUN TestService_Rustfstest697=== PAUSE TestService_Rustfstest698=== RUN TestParseSize699=== PAUSE TestParseSize700=== RUN TestSkippedUploadsHandler701=== PAUSE TestSkippedUploadsHandler702=== RUN TestSystemdListenerNotActivated703--- PASS: TestSystemdListenerNotActivated (0.00s)704=== RUN TestWatchdogBeatsWhenHealthy705--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)706=== RUN TestWatchdogSkipsWhenUnhealthy7072026/10/08 12:58:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7082026/10/08 12:58:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7092026/10/08 12:58:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7102026/10/08 12:58:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7112026/10/08 12:58:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7122026/10/08 12:58:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7132026/10/08 12:58:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7142026/10/08 12:58:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7152026/10/08 12:58:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7162026/10/08 12:58:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"717--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)718=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle719=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle720=== RUN TestProxyWriteTimeout721=== PAUSE TestProxyWriteTimeout722=== RUN TestPendingClosureWriteTimeout723=== PAUSE TestPendingClosureWriteTimeout724=== RUN TestIsValidUploadKey725=== PAUSE TestIsValidUploadKey726=== RUN TestUploadHandlersRejectInvalidKeys727=== PAUSE TestUploadHandlersRejectInvalidKeys728=== RUN TestUploadHandlersRejectOversizedBody729=== PAUSE TestUploadHandlersRejectOversizedBody730=== RUN TestService_cleanupPendingClosuresHandler731=== PAUSE TestService_cleanupPendingClosuresHandler732=== RUN TestService_createPendingClosureHandler733=== PAUSE TestService_createPendingClosureHandler734=== RUN TestService_verifyS3Integrity735=== PAUSE TestService_verifyS3Integrity736=== RUN TestCompleteMultipartUnregistered737=== PAUSE TestCompleteMultipartUnregistered738=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT739=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT740=== CONT TestCompleteMultipartUnregistered741=== CONT TestService_AuthMiddleware742=== CONT TestService_verifyS3Integrity743=== CONT TestService_createPendingClosureHandler744=== CONT TestService_cleanupPendingClosuresHandler745=== CONT TestUploadHandlersRejectOversizedBody746=== CONT TestUploadHandlersRejectInvalidKeys747=== CONT TestIsValidUploadKey748=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info749=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info750=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal751=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal752=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key753=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key754=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key755=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key756=== RUN TestIsValidUploadKey/narinfo757=== PAUSE TestIsValidUploadKey/narinfo758=== RUN TestIsValidUploadKey/nar_zst759=== CONT TestProxyWriteTimeout760=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle761=== CONT TestSkippedUploadsHandler762=== CONT TestParseSize763=== CONT TestService_Rustfstest764=== CONT TestPresignedUploadRegisteredBeforeCommit765=== CONT TestCompletedNarNotReofferedAcrossClosures766=== CONT TestCompleteMultipartUpload_ErrorButObjectExists767=== CONT TestRedundantMultipartUpload768=== CONT TestPush_SignsNarinfosOfItsPendingObjects769=== CONT TestPush_RejectsBadRequests770=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit771=== CONT TestPush_RootsAreLockedInByteOrder772=== CONT TestPush_CompleteWaitsForCleanupOfThePush773=== CONT TestPush_RepeatedRootCommitsOnce774=== CONT TestPendingClosureWriteTimeout7752026/10/08 12:58:08 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000776=== CONT TestPush_CompleteCommitsEveryRoot777=== PAUSE TestIsValidUploadKey/nar_zst778=== RUN TestProxyWriteTimeout/narinfo779=== RUN TestIsValidUploadKey/nar_xz780=== PAUSE TestIsValidUploadKey/nar_xz781--- PASS: TestParseSize (0.17s)782=== CONT TestPush_OverlappingRootsStoreOneRowPerKey783=== PAUSE TestProxyWriteTimeout/narinfo784=== RUN TestProxyWriteTimeout/1_GiB_nar785=== PAUSE TestProxyWriteTimeout/1_GiB_nar786=== RUN TestProxyWriteTimeout/10_GiB_nar787=== PAUSE TestProxyWriteTimeout/10_GiB_nar788=== RUN TestProxyWriteTimeout/unknown_size789=== PAUSE TestProxyWriteTimeout/unknown_size790=== RUN TestIsValidUploadKey/nar_plain791=== PAUSE TestIsValidUploadKey/nar_plain792=== RUN TestPendingClosureWriteTimeout/empty793=== CONT TestReadRedirectUsesPublicS3URL794=== RUN TestIsValidUploadKey/listing795=== PAUSE TestPendingClosureWriteTimeout/empty796=== PAUSE TestIsValidUploadKey/listing797=== RUN TestPendingClosureWriteTimeout/400_objects798=== PAUSE TestPendingClosureWriteTimeout/400_objects799=== RUN TestPendingClosureWriteTimeout/670k_objects800=== PAUSE TestPendingClosureWriteTimeout/670k_objects801=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline802=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline803=== RUN TestIsValidUploadKey/build_log804=== PAUSE TestIsValidUploadKey/build_log805=== CONT TestReadProxyRangeRequest806=== RUN TestIsValidUploadKey/build_log_home-manager_file807=== PAUSE TestIsValidUploadKey/build_log_home-manager_file808=== RUN TestIsValidUploadKey/build_log_plus_in_name809=== PAUSE TestIsValidUploadKey/build_log_plus_in_name810=== RUN TestIsValidUploadKey/build_log_question_mark811=== PAUSE TestIsValidUploadKey/build_log_question_mark812=== RUN TestIsValidUploadKey/build_log_equals813=== PAUSE TestIsValidUploadKey/build_log_equals814=== RUN TestIsValidUploadKey/realisation815=== PAUSE TestIsValidUploadKey/realisation816=== RUN TestIsValidUploadKey/realisation_plus_in_output817=== PAUSE TestIsValidUploadKey/realisation_plus_in_output818=== RUN TestIsValidUploadKey/nix-cache-info819=== PAUSE TestIsValidUploadKey/nix-cache-info820=== RUN TestIsValidUploadKey/index.html821=== PAUSE TestIsValidUploadKey/index.html822=== RUN TestIsValidUploadKey/narinfo_key,_nar_type823=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type824=== RUN TestIsValidUploadKey/nar_key,_narinfo_type825=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type826=== RUN TestIsValidUploadKey/listing_key,_narinfo_type827=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type828=== RUN TestIsValidUploadKey/traversal829=== PAUSE TestIsValidUploadKey/traversal830=== RUN TestIsValidUploadKey/traversal_nar831=== PAUSE TestIsValidUploadKey/traversal_nar832=== RUN TestIsValidUploadKey/absolute833=== PAUSE TestIsValidUploadKey/absolute834=== RUN TestIsValidUploadKey/empty_key835=== PAUSE TestIsValidUploadKey/empty_key836=== RUN TestIsValidUploadKey/unknown_type837=== PAUSE TestIsValidUploadKey/unknown_type838--- PASS: TestSkippedUploadsHandler (0.18s)839=== CONT TestReadRedirectKeepsNarinfoProxied840=== CONT TestReadRedirectNar841=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure842=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure843=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart844=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart845=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts846=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts847=== CONT TestReadProxyDisabled8482026/10/08 12:58:08 INFO Received cleanup request method=DELETE path=/api/pending_closures8492026/10/08 12:58:08 INFO Aborted multipart uploads count=0 kept=08502026/10/08 12:58:08 INFO Received uploads request method=POST path=/api/pending_closures8512026/10/08 12:58:08 INFO Received push request method=POST path=/api/pushes8522026/10/08 12:58:08 INFO Received cleanup request method=DELETE path=/api/pending_closures8532026/10/08 12:58:08 INFO Aborted multipart uploads count=1 kept=08542026/10/08 12:58:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8552026-10-08 12:58:08.455 UTC [623] ERROR: Closure does not exist: id=18562026-10-08 12:58:08.455 UTC [623] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE8572026-10-08 12:58:08.455 UTC [623] STATEMENT: -- name: CommitPendingClosure :one858 SELECT commit_pending_closure($1::bigint)::bigint859 860--- PASS: TestService_cleanupPendingClosuresHandler (0.46s)861=== CONT TestReadProxyRootRedirectsToIndexHTML8622026/10/08 12:58:08 INFO Received push request method=POST path=/api/pushes8632026/10/08 12:58:08 INFO Received complete push request method=POST path=/api/pushes/1/complete8642026/10/08 12:58:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8652026-10-08 12:58:08.487 UTC [678] ERROR: could not obtain lock on row in relation "closures"8662026-10-08 12:58:08.487 UTC [678] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8672026/10/08 12:58:08 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst868--- PASS: TestCompleteMultipartUnregistered (0.49s)8692026-10-08 12:58:08.488 UTC [678] ERROR: could not obtain lock on row in relation "closures"8702026-10-08 12:58:08.488 UTC [678] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT871=== CONT TestReadProxyConditionalGet8722026-10-08 12:58:08.488 UTC [678] ERROR: could not obtain lock on row in relation "closures"8732026-10-08 12:58:08.488 UTC [678] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8742026-10-08 12:58:08.488 UTC [678] ERROR: could not obtain lock on row in relation "closures"8752026-10-08 12:58:08.488 UTC [678] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8762026-10-08 12:58:08.489 UTC [678] ERROR: could not obtain lock on row in relation "closures"8772026-10-08 12:58:08.489 UTC [678] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8782026/10/08 12:58:08 INFO Completed push id=1 objects=4 duration=10.65796ms8792026/10/08 12:58:08 INFO Received push request method=POST path=/api/pushes880--- PASS: TestPush_RootsAreLockedInByteOrder (0.48s)881=== CONT TestReadProxyOutlastsServerWriteTimeout8822026/10/08 12:58:08 INFO Received uploads request method=POST path=/api/pending_closures8832026/10/08 12:58:08 INFO Received uploads request method=POST path=/api/pending_closures8842026/10/08 12:58:08 INFO Received uploads request method=POST path=/api/pending_closures8852026/10/08 12:58:08 INFO Aborted multipart uploads count=0 kept=08862026/10/08 12:58:08 WARN Force mode enabled - objects will be deleted immediately without grace period8872026/10/08 12:58:08 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=08882026/10/08 12:58:08 INFO Received uploads request method=POST path=/api/pending_closures8892026/10/08 12:58:08 INFO Received uploads request method=POST path=/api/pending_closures8902026/10/08 12:58:08 INFO Received uploads request method=POST path=/api/pending_closures8912026/10/08 12:58:08 INFO Vacuumed table table=pending_closures8922026/10/08 12:58:08 INFO Vacuumed table table=pending_objects8932026/10/08 12:58:08 INFO Vacuumed table table=multipart_uploads8942026/10/08 12:58:08 INFO Vacuumed table table=closures8952026/10/08 12:58:08 INFO Vacuumed table table=objects8962026/10/08 12:58:08 INFO Received complete push request method=POST path=/api/pushes/2/complete8972026/10/08 12:58:08 INFO Completed push id=2 objects=4 duration=3.000074ms898--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.58s)899=== CONT TestReadProxyHead9002026/10/08 12:58:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9012026/10/08 12:58:08 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"902--- PASS: TestService_AuthMiddleware (0.62s)903=== CONT TestReadProxyInvalidPath904--- PASS: TestService_Rustfstest (0.45s)905=== CONT TestReadProxy4049062026/10/08 12:58:08 INFO Received uploads request method=POST path=/api/pending_closures9072026/10/08 12:58:08 INFO Received push request method=POST path=/api/pushes9082026/10/08 12:58:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9092026/10/08 12:58:08 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YmE0NGE2YmYtOGZiNi00MTE2LTljYjctMTAzMmU3ZTdlNTNiLjIzOGRiNGJkLWQyYWItNDFmYS1iZjBhLTlmYWIzMzZiZDZhNHgxNzkxNDY0Mjg4Njg2NjYxNjc09102026/10/08 12:58:08 INFO Received complete push request method=POST path=/api/pushes/1/complete9112026/10/08 12:58:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YmE0NGE2YmYtOGZiNi00MTE2LTljYjctMTAzMmU3ZTdlNTNiLjIzOGRiNGJkLWQyYWItNDFmYS1iZjBhLTlmYWIzMzZiZDZhNHgxNzkxNDY0Mjg4Njg2NjYxNjc0 parts=1912--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.54s)9132026/10/08 12:58:08 INFO Completed push id=1 objects=6 duration=10.639201ms914=== CONT TestReadProxyNarStreaming915--- PASS: TestPush_CompleteCommitsEveryRoot (0.54s)916=== CONT TestReadProxyContentNegotiation917--- PASS: TestReadRedirectKeepsNarinfoProxied (0.54s)918=== CONT TestReadProxyNarinfoAlreadyDecompressed9192026/10/08 12:58:08 INFO Received push request method=POST path=/api/pushes9202026/10/08 12:58:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9212026/10/08 12:58:08 INFO Signed narinfos id=1 count=19222026/10/08 12:58:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9232026/10/08 12:58:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9242026/10/08 12:58:08 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9252026/10/08 12:58:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9262026/10/08 12:58:08 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9272026/10/08 12:58:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9282026/10/08 12:58:08 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19292026/10/08 12:58:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9302026/10/08 12:58:08 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo931--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.59s)932=== CONT TestReadProxyNarinfo933--- PASS: TestReadProxyRangeRequest (0.60s)934=== CONT TestIsValidCachePath935=== RUN TestIsValidCachePath/narinfo936=== PAUSE TestIsValidCachePath/narinfo937=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars938=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars939=== RUN TestIsValidCachePath/nar_zst940=== PAUSE TestIsValidCachePath/nar_zst941=== RUN TestIsValidCachePath/nar_xz942=== PAUSE TestIsValidCachePath/nar_xz943=== RUN TestIsValidCachePath/nar_bz2944=== PAUSE TestIsValidCachePath/nar_bz2945=== RUN TestIsValidCachePath/nar_uncompressed946=== PAUSE TestIsValidCachePath/nar_uncompressed947=== RUN TestIsValidCachePath/ls948=== PAUSE TestIsValidCachePath/ls949=== RUN TestIsValidCachePath/log950=== PAUSE TestIsValidCachePath/log951=== RUN TestIsValidCachePath/realisation952=== PAUSE TestIsValidCachePath/realisation953=== RUN TestIsValidCachePath/nix-cache-info954=== PAUSE TestIsValidCachePath/nix-cache-info955=== RUN TestIsValidCachePath/index.html956=== PAUSE TestIsValidCachePath/index.html957=== RUN TestIsValidCachePath/traversal_parent958=== PAUSE TestIsValidCachePath/traversal_parent959=== RUN TestIsValidCachePath/traversal_in_middle960=== PAUSE TestIsValidCachePath/traversal_in_middle961=== RUN TestIsValidCachePath/invalid_char_e962=== PAUSE TestIsValidCachePath/invalid_char_e963=== RUN TestIsValidCachePath/invalid_char_u964=== PAUSE TestIsValidCachePath/invalid_char_u965=== RUN TestIsValidCachePath/random_path966=== PAUSE TestIsValidCachePath/random_path967=== RUN TestIsValidCachePath/empty968=== PAUSE TestIsValidCachePath/empty969=== RUN TestIsValidCachePath/leading_slash970=== PAUSE TestIsValidCachePath/leading_slash971=== RUN TestIsValidCachePath/wrong_extension972=== PAUSE TestIsValidCachePath/wrong_extension973=== RUN TestIsValidCachePath/short_hash974=== PAUSE TestIsValidCachePath/short_hash975=== CONT TestParseSingleRange976=== RUN TestParseSingleRange/none977=== PAUSE TestParseSingleRange/none978=== RUN TestParseSingleRange/unknown_unit979=== PAUSE TestParseSingleRange/unknown_unit980=== RUN TestParseSingleRange/multi-range_ignored981=== PAUSE TestParseSingleRange/multi-range_ignored982=== RUN TestParseSingleRange/malformed_no_dash983=== PAUSE TestParseSingleRange/malformed_no_dash984=== RUN TestParseSingleRange/malformed_both_empty985=== PAUSE TestParseSingleRange/malformed_both_empty986=== RUN TestParseSingleRange/malformed_end_before_start987=== PAUSE TestParseSingleRange/malformed_end_before_start988=== RUN TestParseSingleRange/closed989=== PAUSE TestParseSingleRange/closed990=== RUN TestParseSingleRange/open-ended991=== PAUSE TestParseSingleRange/open-ended992=== RUN TestParseSingleRange/end_clamped_to_size993=== PAUSE TestParseSingleRange/end_clamped_to_size994=== RUN TestParseSingleRange/suffix995=== PAUSE TestParseSingleRange/suffix996=== RUN TestParseSingleRange/suffix_exceeds_size997=== PAUSE TestParseSingleRange/suffix_exceeds_size998=== RUN TestParseSingleRange/single_byte999=== PAUSE TestParseSingleRange/single_byte1000=== RUN TestParseSingleRange/start_past_EOF1001=== PAUSE TestParseSingleRange/start_past_EOF1002=== RUN TestParseSingleRange/start_far_past_EOF1003=== PAUSE TestParseSingleRange/start_far_past_EOF1004=== CONT TestPresentNotReportedWhileGCDeletesClosure1005=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1006=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1007=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1008=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1009=== CONT TestPresentRefreshesOnlyStaleClosures10102026/10/08 12:58:08 INFO Received push request method=POST path=/api/pushes10112026/10/08 12:58:08 INFO Received complete push request method=POST path=/api/pushes/1/complete10122026/10/08 12:58:08 INFO Completed push id=1 objects=4 duration=9.106654ms1013--- PASS: TestPush_RepeatedRootCommitsOnce (0.83s)1014=== CONT TestPresentReportsOnlyClosureRoots1015--- PASS: TestReadRedirectUsesPublicS3URL (0.68s)1016=== CONT TestCreatePin_ReservedPins1017--- PASS: TestReadRedirectNar (0.69s)1018=== CONT TestOrphanedObjectsGCStressTest1019--- PASS: TestReadProxyDisabled (0.62s)1020=== CONT TestOrphanedObjectsGC10212026/10/08 12:58:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41663/oidc10222026/10/08 12:58:08 INFO Received push request method=POST path=/api/pushes10232026/10/08 12:58:08 INFO Received push request method=POST path=/api/pushes10242026/10/08 12:58:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1025--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.95s)1026=== CONT TestObjectStatsLargeCommit1027=== RUN TestPush_RejectsBadRequests/no_roots1028=== PAUSE TestPush_RejectsBadRequests/no_roots1029=== RUN TestPush_RejectsBadRequests/no_objects1030=== PAUSE TestPush_RejectsBadRequests/no_objects1031=== RUN TestPush_RejectsBadRequests/bad_root1032=== PAUSE TestPush_RejectsBadRequests/bad_root1033=== RUN TestPush_RejectsBadRequests/root_not_in_objects1034=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1035=== CONT TestObjectStatsTrigger10362026/10/08 12:58:09 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YmE0NGE2YmYtOGZiNi00MTE2LTljYjctMTAzMmU3ZTdlNTNiLmNjMGM4YTA4LWUxZGEtNGYzYy04NWY4LTQ5NjM3MDI1YzFkZHgxNzkxNDY0Mjg4NTQ2MDI5Njkx parts=1010372026/10/08 12:58:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10382026/10/08 12:58:09 INFO Completed upload id=1 objects=2 duration=5.29542ms10392026/10/08 12:58:09 INFO Received uploads request method=POST path=/api/pending_closures10402026/10/08 12:58:09 INFO Received uploads request method=POST path=/api/pending_closures10412026/10/08 12:58:09 INFO Received uploads request method=POST path=/api/pending_closures10422026/10/08 12:58:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10432026/10/08 12:58:09 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10442026/10/08 12:58:09 WARN Found objects in DB but missing from S3, will re-upload count=11045--- PASS: TestService_verifyS3Integrity (1.20s)1046=== CONT TestPendingCleanupUsesOneCutoff10472026/10/08 12:58:09 INFO Received uploads request method=POST path=/api/pending_closures10482026/10/08 12:58:09 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YmE0NGE2YmYtOGZiNi00MTE2LTljYjctMTAzMmU3ZTdlNTNiLjE0ODc4YTQ0LWQ4ZTUtNDRhNy05NDRlLWE5NTlhYWFlZDFjYngxNzkxNDY0Mjg4NTk1MjQ3MjEx parts=1010492026/10/08 12:58:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10502026/10/08 12:58:09 INFO Received uploads request method=POST path=/api/pending_closures10512026/10/08 12:58:09 INFO Completed upload id=1 objects=2 duration=5.651389ms10522026/10/08 12:58:09 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010532026/10/08 12:58:09 INFO Received uploads request method=POST path=/api/pending_closures10542026/10/08 12:58:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures10552026/10/08 12:58:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10562026/10/08 12:58:09 INFO Aborted multipart uploads count=0 kept=010572026/10/08 12:58:09 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10582026/10/08 12:58:09 INFO Received uploads request method=POST path=/api/pending_closures1059--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.05s)1060=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1061--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.79s)1062=== CONT TestMultipartCleanup10632026/10/08 12:58:09 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=010642026/10/08 12:58:09 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YmE0NGE2YmYtOGZiNi00MTE2LTljYjctMTAzMmU3ZTdlNTNiLmY5ZDEwNzkyLWRmZWEtNDM4Ni04YTg3LWEyODc3NGJjMTA2MXgxNzkxNDY0Mjg4NTczMjg2ODcx parts=1210652026/10/08 12:58:09 INFO Vacuumed table table=pending_closures10662026/10/08 12:58:09 INFO Received uploads request method=POST path=/api/pending_closures10672026/10/08 12:58:09 INFO Vacuumed table table=pending_objects1068--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.24s)1069=== CONT TestServerTLSConfig1070=== RUN TestServerTLSConfig/no_client_CA1071=== PAUSE TestServerTLSConfig/no_client_CA1072=== RUN TestServerTLSConfig/missing_CA_file1073=== PAUSE TestServerTLSConfig/missing_CA_file1074=== RUN TestServerTLSConfig/not_a_PEM_file1075=== PAUSE TestServerTLSConfig/not_a_PEM_file1076=== CONT TestService_NativeMTLS10772026/10/08 12:58:09 INFO Vacuumed table table=multipart_uploads10782026/10/08 12:58:09 INFO Vacuumed table table=closures10792026/10/08 12:58:09 INFO Vacuumed table table=objects10802026/10/08 12:58:09 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001081--- PASS: TestService_createPendingClosureHandler (1.28s)1082=== CONT TestMetricsCommit1083=== CONT TestMetricsInventory1084--- PASS: TestReadProxyConditionalGet (0.79s)10852026-10-08 12:58:09.287 UTC [732] ERROR: Push does not exist: id=110862026-10-08 12:58:09.287 UTC [732] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10872026-10-08 12:58:09.287 UTC [732] STATEMENT: SELECT commit_push($1)1088--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.26s)1089=== CONT TestNARDeduplicationMetadataUploadBug1090--- PASS: TestReadProxyHead (0.74s)1091=== CONT TestCreatePendingClosureRejectsOversizedNAR10922026/10/08 12:58:09 INFO Received uploads request method=POST path=/api/pending_closures1093--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1094=== CONT TestCacheConfigHandlerMaxNarSize1095--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1096=== CONT TestGenerateLandingPage1097--- PASS: TestGenerateLandingPage (0.00s)1098=== CONT TestService_readinessHandler1099--- PASS: TestReadProxyInvalidPath (0.74s)1100=== CONT TestService_healthCheckHandler1101--- PASS: TestReadProxy404 (0.88s)1102=== CONT TestGracefulShutdownDrainsInflight11032026/10/08 12:58:09 INFO Starting HTTP server address=127.0.0.1:4442911042026/10/08 12:58:09 INFO Shutdown signal received, draining in-flight requests timeout=10s1105--- PASS: TestReadProxyNarStreaming (0.83s)1106=== CONT TestGCTaskStore_Fail1107--- PASS: TestGCTaskStore_Fail (0.00s)1108=== CONT TestGCTaskStore_PhaseUpdates1109--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1110=== CONT TestGCTaskStore_CompletedAllowsNewTask1111--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1112=== CONT TestGCTaskStore_GetReturnsLatest1113--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1114=== CONT TestGCTaskStore_GetEmpty1115--- PASS: TestGCTaskStore_GetEmpty (0.00s)1116=== CONT TestGCTaskStore_ConflictDifferentParams1117--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1118=== CONT TestGCTaskStore_DeduplicateSameParams1119--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1120=== CONT TestGCTaskStore_StartNew1121--- PASS: TestGCTaskStore_StartNew (0.00s)1122=== CONT TestGCEndsOnShutdown1123=== RUN TestGCEndsOnShutdown/before_the_run1124=== PAUSE TestGCEndsOnShutdown/before_the_run1125=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1126=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1127=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1128=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1129=== CONT TestCommitRacingPendingCleanupKeepsObjects1130--- PASS: TestReadProxyContentNegotiation (0.85s)1131=== CONT TestPushWaitsForSweepHoldingRow1132--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1133=== CONT TestSweepRechecksPendingAfterLocking1134--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.85s)1135=== CONT TestGetExistingObjectsLocksRows1136--- PASS: TestPresentRefreshesOnlyStaleClosures (0.84s)1137=== CONT TestRegisterCompletedObjectNeedsPendingRow1138--- PASS: TestPresentReportsOnlyClosureRoots (0.85s)1139=== CONT TestSweepSkipsRowsLockedByPush11402026/10/08 12:58:09 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1141--- PASS: TestReadProxyNarinfo (0.97s)1142=== CONT TestFailedS3DeleteKeepsTombstone11432026/10/08 12:58:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11442026/10/08 12:58:09 WARN Refused reserved pin name=worker-x86_64-linux11452026/10/08 12:58:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11462026/10/08 12:58:09 INFO Received create pin request method=POST path=/api/pins/my-app11472026/10/08 12:58:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1148--- PASS: TestCreatePin_ReservedPins (0.92s)1149=== CONT TestForceGCDuringPushOffersSweptObject1150=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1151=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1152=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1153=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1154=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection11552026/10/08 12:58:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1156--- PASS: TestObjectStatsTrigger (0.73s)1157=== CONT TestGCSweepDeliversEachKeyOnce11582026/10/08 12:58:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YmE0NGE2YmYtOGZiNi00MTE2LTljYjctMTAzMmU3ZTdlNTNiLjJkZmEzYzc2LWZiZjEtNDQ2Yy1hYjgzLWQ1NzBiYmY1Mzg3NXgxNzkxNDY0Mjg5MTk1MjIyOTE0 parts=1211592026/10/08 12:58:09 INFO Received uploads request method=POST path=/api/pending_closures11602026/10/08 12:58:09 INFO Received uploads request method=POST path=/api/pending_closures11612026/10/08 12:58:09 INFO Received uploads request method=POST path=/api/pending_closures11622026/10/08 12:58:09 INFO Received uploads request method=POST path=/api/pending_closures11632026/10/08 12:58:09 INFO Received cleanup request method=DELETE path=/api/pending_closures11642026/10/08 12:58:09 INFO Received uploads request method=POST path=/api/pending_closures1165--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.74s)1166=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT11672026/10/08 12:58:09 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11682026/10/08 12:58:09 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1169--- PASS: TestService_NativeMTLS (0.73s)1170=== CONT TestTombstonedObjectOfferedWithoutWaiting11712026/10/08 12:58:10 INFO Received push request method=POST path=/api/pushes11722026/10/08 12:58:10 INFO Received uploads request method=POST path=/api/pending_closures11732026/10/08 12:58:10 INFO Received complete push request method=POST path=/api/pushes/1/complete11742026/10/08 12:58:10 INFO Completed push id=1 objects=4 duration=11.03682ms11752026/10/08 12:58:10 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11762026/10/08 12:58:10 INFO Completed upload id=2 objects=2 duration=1.385888ms1177--- PASS: TestMetricsCommit (0.81s)1178=== CONT TestPinProtectsFromGC1179=== NAME TestOrphanedObjectsGC1180 orphaned_objects_gc_test.go:287: GC Test Summary:1181 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1182 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1183 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1184 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1185 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1186--- PASS: TestOrphanedObjectsGC (1.18s)1187=== CONT TestClientPushesUseOnePush1188--- PASS: TestMetricsInventory (0.85s)1189=== CONT TestClientSharedPathCommittedMidPush1190=== NAME TestNARDeduplicationMetadataUploadBug1191 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3196704825/001/store/35rrqpnh1h07h9486x7270bsvmmvnqqs-file1.txt11922026/10/08 12:58:10 WARN readiness check failed error="closed pool"1193--- PASS: TestService_readinessHandler (0.80s)1194=== CONT TestClientWithDependencies1195--- PASS: TestService_healthCheckHandler (0.81s)1196=== CONT TestGCSweepSkipsPendingObjects11972026/10/08 12:58:10 INFO Received cleanup request method=DELETE path=/api/pending_closures11982026/10/08 12:58:10 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket49/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11992026/10/08 12:58:10 INFO Aborted multipart uploads count=0 kept=112002026/10/08 12:58:10 INFO Received cleanup request method=DELETE path=/api/pending_closures12012026/10/08 12:58:10 INFO Aborted multipart uploads count=1 kept=01202--- PASS: TestMultipartCleanup (0.95s)1203=== CONT TestDeduplicatedObjectsRecordedAsPending12042026/10/08 12:58:10 INFO Received push request method=POST path=/api/pushes12052026/10/08 12:58:10 INFO Received uploads request method=POST path=/api/pending_closures12062026/10/08 12:58:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12072026/10/08 12:58:10 INFO Uploading 35rrqpnh1h07h9486x7270bsvmmvnqqs-file1.txt (160B)12082026/10/08 12:58:10 INFO Aborted multipart uploads count=0 kept=012092026/10/08 12:58:10 WARN Failed to register uploaded object key=35rrqpnh1h07h9486x7270bsvmmvnqqs.ls error="server returned 404: 404 page not found\n"12102026/10/08 12:58:10 WARN Force mode enabled - objects will be deleted immediately without grace period12112026/10/08 12:58:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12122026/10/08 12:58:10 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12132026/10/08 12:58:10 INFO Signed narinfos id=1 count=112142026/10/08 12:58:10 INFO Uploading 1 narinfos12152026/10/08 12:58:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012162026/10/08 12:58:10 INFO Received complete push request method=POST path=/api/pushes/1/complete12172026/10/08 12:58:10 WARN Failed to register uploaded object key=35rrqpnh1h07h9486x7270bsvmmvnqqs.narinfo error="server returned 404: 404 page not found\n"12182026/10/08 12:58:10 INFO Completed push id=1 objects=3 duration=227.460125ms12192026/10/08 12:58:10 INFO Upload complete. (302ms)12202026/10/08 12:58:10 INFO Vacuumed table table=pending_closures1221=== NAME TestNARDeduplicationMetadataUploadBug1222 metadata_upload_test.go:54: Retrieved narinfo from S3:1223 StorePath: /build/TestNARDeduplicationMetadataUploadBug3196704825/001/store/35rrqpnh1h07h9486x7270bsvmmvnqqs-file1.txt1224 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1225 Compression: zstd1226 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1227 NarSize: 1601228 References: 1229 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1230 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1231 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1232 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12332026/10/08 12:58:10 INFO Vacuumed table table=pending_objects12342026/10/08 12:58:10 INFO Vacuumed table table=multipart_uploads12352026/10/08 12:58:10 INFO Vacuumed table table=closures12362026/10/08 12:58:10 INFO Vacuumed table table=objects1237--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.96s)1238=== CONT TestPushDedupSurvivesConcurrentGC1239=== NAME TestNARDeduplicationMetadataUploadBug1240 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3196704825/001/store/248jk3z7q6l5mzy8dca1p16ll9sdvkd8-file2.txt1241--- PASS: TestGetExistingObjectsLocksRows (0.95s)1242=== CONT TestClientMultipleUploads12432026/10/08 12:58:10 INFO Aborted multipart uploads count=0 kept=012442026/10/08 12:58:10 WARN Force mode enabled - objects will be deleted immediately without grace period1245--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.96s)1246=== CONT TestGCMetrics12472026/10/08 12:58:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012482026/10/08 12:58:10 INFO Vacuumed table table=pending_closures12492026/10/08 12:58:10 INFO Vacuumed table table=pending_objects12502026/10/08 12:58:10 INFO Vacuumed table table=multipart_uploads12512026/10/08 12:58:10 INFO Vacuumed table table=closures12522026/10/08 12:58:10 INFO Received push request method=POST path=/api/pushes12532026/10/08 12:58:10 INFO Vacuumed table table=objects1254--- PASS: TestSweepRechecksPendingAfterLocking (1.02s)1255=== CONT TestClientIntegration12562026/10/08 12:58:10 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12572026/10/08 12:58:10 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12582026/10/08 12:58:10 WARN Failed to register uploaded object key=248jk3z7q6l5mzy8dca1p16ll9sdvkd8.ls error="server returned 404: 404 page not found\n"12592026/10/08 12:58:10 INFO Signed narinfos id=2 count=112602026/10/08 12:58:10 INFO Uploading 1 narinfos12612026/10/08 12:58:10 INFO Received complete push request method=POST path=/api/pushes/2/complete12622026/10/08 12:58:10 WARN Failed to register uploaded object key=248jk3z7q6l5mzy8dca1p16ll9sdvkd8.narinfo error="server returned 404: 404 page not found\n"12632026/10/08 12:58:10 INFO Completed push id=2 objects=3 duration=3.349674ms12642026/10/08 12:58:10 INFO Upload complete. (56ms)1265=== NAME TestNARDeduplicationMetadataUploadBug1266 metadata_upload_test.go:76: Retrieved narinfo from S3:1267 StorePath: /build/TestNARDeduplicationMetadataUploadBug3196704825/001/store/248jk3z7q6l5mzy8dca1p16ll9sdvkd8-file2.txt1268 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1269 Compression: zstd1270 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1271 NarSize: 1601272 References: 1273 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1274 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1275 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1276 {"version":1,"root":{"type":"regular","size":44}}12772026/10/08 12:58:10 INFO Received uploads request method=POST path=/api/pending_closures1278--- PASS: TestNARDeduplicationMetadataUploadBug (1.36s)1279=== CONT TestClientErrorHandling1280=== RUN TestClientErrorHandling/InvalidStorePath1281=== PAUSE TestClientErrorHandling/InvalidStorePath1282=== RUN TestClientErrorHandling/InvalidAuthToken12832026/10/08 12:58:10 INFO Aborted multipart uploads count=0 kept=01284=== PAUSE TestClientErrorHandling/InvalidAuthToken1285=== RUN TestClientErrorHandling/ServerNotAvailable1286=== PAUSE TestClientErrorHandling/ServerNotAvailable1287=== CONT TestGCBugBareHashReferences12882026/10/08 12:58:10 WARN Force mode enabled - objects will be deleted immediately without grace period12892026/10/08 12:58:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012902026/10/08 12:58:10 INFO Vacuumed table table=pending_closures12912026/10/08 12:58:10 INFO Vacuumed table table=pending_objects12922026/10/08 12:58:10 INFO Vacuumed table table=multipart_uploads12932026/10/08 12:58:10 INFO Vacuumed table table=closures12942026/10/08 12:58:10 INFO Vacuumed table table=objects12952026/10/08 12:58:10 INFO Aborted multipart uploads count=0 kept=012962026/10/08 12:58:10 WARN Force mode enabled - objects will be deleted immediately without grace period12972026/10/08 12:58:10 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=012982026/10/08 12:58:10 INFO Vacuumed table table=pending_closures12992026/10/08 12:58:10 INFO Vacuumed table table=pending_objects13002026/10/08 12:58:10 INFO Vacuumed table table=multipart_uploads13012026/10/08 12:58:10 INFO Vacuumed table table=closures13022026/10/08 12:58:10 INFO Vacuumed table table=objects1303--- PASS: TestSweepSkipsRowsLockedByPush (0.98s)13042026/10/08 12:58:10 INFO Received uploads request method=POST path=/api/pending_closures1305=== CONT TestGCAdvisoryLockBlocksConcurrentRun13062026/10/08 12:58:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13072026/10/08 12:58:10 INFO Aborted multipart uploads count=0 kept=013082026/10/08 12:58:10 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YmE0NGE2YmYtOGZiNi00MTE2LTljYjctMTAzMmU3ZTdlNTNiLmU2ZTYyMGVmLTZiZjAtNDQ1Ni1hNTg5LTQxOWM5NjRhNzVjOHgxNzkxNDY0Mjg5OTExMjE4Mjg1 error="Get \"http://127.0.0.1:1/bucket26/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13092026/10/08 12:58:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YmE0NGE2YmYtOGZiNi00MTE2LTljYjctMTAzMmU3ZTdlNTNiLmM0MmU1MmQ3LWMzYTgtNGJmZS1hOGQ4LWRlYjg4NDI3ZDBlNXgxNzkxNDY0Mjg5OTAzNDczMTI5 parts=121310--- PASS: TestPushWaitsForSweepHoldingRow (1.15s)1311=== CONT TestClientCADerivations13122026/10/08 12:58:10 WARN Force mode enabled - objects will be deleted immediately without grace period13132026/10/08 12:58:10 INFO Received cleanup request method=DELETE path=/api/pending_closures13142026/10/08 12:58:10 INFO Received uploads request method=POST path=/api/pending_closures13152026/10/08 12:58:10 INFO Aborted multipart uploads count=1 kept=013162026/10/08 12:58:10 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13172026/10/08 12:58:10 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1318--- PASS: TestFailedS3DeleteKeepsTombstone (0.99s)1319=== CONT TestCacheStatsHandler13202026/10/08 12:58:10 INFO Aborted multipart uploads count=0 kept=01321--- PASS: TestRedundantMultipartUpload (2.56s)1322=== CONT TestCacheConfigHandler1323=== RUN TestCacheConfigHandler/full_config,_no_issuer1324=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1325=== RUN TestCacheConfigHandler/no_cache_url_configured1326=== PAUSE TestCacheConfigHandler/no_cache_url_configured1327=== RUN TestCacheConfigHandler/no_signing_keys1328=== PAUSE TestCacheConfigHandler/no_signing_keys1329=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1330=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1331=== CONT TestService_ReadScope_PublicByDefault13322026/10/08 12:58:10 WARN Force mode enabled - objects will be deleted immediately without grace period1333--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.78s)1334=== CONT TestLeadEndsOnShutdown13352026/10/08 12:58:10 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=013362026/10/08 12:58:10 INFO Vacuumed table table=pending_closures13372026/10/08 12:58:10 INFO Vacuumed table table=pending_objects13382026/10/08 12:58:10 INFO Vacuumed table table=multipart_uploads13392026/10/08 12:58:10 INFO Vacuumed table table=closures13402026/10/08 12:58:10 INFO Received uploads request method=POST path=/api/pending_closures13412026/10/08 12:58:10 INFO Vacuumed table table=objects1342--- PASS: TestGCSweepDeliversEachKeyOnce (0.91s)1343=== CONT TestService_RequireScope_OIDC1344--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.80s)1345=== CONT TestService_AuthMiddleware_OIDC13462026/10/08 12:58:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33389/oidc13472026/10/08 12:58:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40455/oidc1348--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.11s)1349=== CONT TestLeadIncumbentAnnouncesAtOnce1350=== NAME TestPinProtectsFromGC1351 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3883093520/001/store/h1ipxwwg4jzljjqr8wdd78x3rrr33y0m-pinned-file.txt1352 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3883093520/001/store/2y2hckgkfaf0b3rks9y1lvbg8qrvl5yh-unpinned-file.txt13532026/10/08 12:58:10 INFO Received uploads request method=POST path=/api/pending_closures1354--- PASS: TestObjectStatsLargeCommit (1.80s)1355=== CONT TestService_ReadAuthMiddleware13562026/10/08 12:58:10 INFO Aborted multipart uploads count=0 kept=013572026/10/08 12:58:10 INFO Received uploads request method=POST path=/api/pending_closures13582026/10/08 12:58:10 WARN Force mode enabled - objects will be deleted immediately without grace period1359--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.77s)1360=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13612026/10/08 12:58:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013622026/10/08 12:58:10 INFO Vacuumed table table=pending_closures13632026/10/08 12:58:10 INFO Vacuumed table table=pending_objects13642026/10/08 12:58:10 INFO Vacuumed table table=multipart_uploads13652026/10/08 12:58:10 INFO Vacuumed table table=closures13662026/10/08 12:58:10 INFO Vacuumed table table=objects1367--- PASS: TestGCSweepSkipsPendingObjects (0.83s)1368=== CONT TestLeadElectsOneAndHandsOver13692026/10/08 12:58:11 INFO Received push request method=POST path=/api/pushes1370=== NAME TestClientWithDependencies1371 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2472298107/001/store/nw88s5xc492jn0ky0v4h0qzgc1x772x8-test-script13722026/10/08 12:58:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13732026/10/08 12:58:11 INFO Uploading h1ipxwwg4jzljjqr8wdd78x3rrr33y0m-pinned-file.txt (128B)13742026/10/08 12:58:11 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13752026/10/08 12:58:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1376=== NAME TestClientMultipleUploads13772026/10/08 12:58:11 WARN Failed to register uploaded object key=h1ipxwwg4jzljjqr8wdd78x3rrr33y0m.ls error="server returned 404: 404 page not found\n"1378 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1424842401/001/store/vrd02crvzrrqjv79r8dlhchjmqg7rrj0-test-file-0.txt13792026/10/08 12:58:11 INFO Signed narinfos id=1 count=113802026/10/08 12:58:11 INFO Uploading 1 narinfos13812026/10/08 12:58:11 INFO Received complete push request method=POST path=/api/pushes/1/complete13822026/10/08 12:58:11 WARN Failed to register uploaded object key=h1ipxwwg4jzljjqr8wdd78x3rrr33y0m.narinfo error="server returned 404: 404 page not found\n"13832026/10/08 12:58:11 INFO Completed push id=1 objects=3 duration=165.209468ms13842026/10/08 12:58:11 INFO Received uploads request method=POST path=/api/pending_closures13852026/10/08 12:58:11 INFO Upload complete. (245ms)1386=== NAME TestClientWithDependencies1387 client_integration_test.go:615: Found 1 dependencies (including self)13882026/10/08 12:58:11 INFO Received push request method=POST path=/api/pushes13892026/10/08 12:58:11 INFO Received push request method=POST path=/api/pushes1390=== NAME TestClientMultipleUploads1391 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1424842401/001/store/ajcaqql8jsrxrsn6703871csldmgxzfg-test-file-1.txt13922026/10/08 12:58:11 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13932026/10/08 12:58:11 INFO Uploading fdvv1b2cgi3gk6ch66lw9pndcwa3wp6m-shared-dep (136B)13942026/10/08 12:58:11 INFO Uploading 60d25sb2i678iwn80vvdivh2a8rpbp6w-top (224B)13952026/10/08 12:58:11 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13962026/10/08 12:58:11 INFO Uploading x40hxhzy1gn8bs3avfbwlqy3g5cn8xwd-a (216B)13972026/10/08 12:58:11 INFO Uploading 8vw5nxsyaz2p0j1j45nil7z18dhgknb5-shared-dep (136B)13982026/10/08 12:58:11 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13992026/10/08 12:58:11 WARN Failed to register uploaded object key=nar/0224a0zfhwq820dngrddznxm5wr5592g4950kk33jr49hmbzyckq.nar.zst error="server returned 404: 404 page not found\n"14002026/10/08 12:58:11 WARN Failed to register uploaded object key=1hbqx7nfqnngm48d6z57c06mxp4zbip4.ls error="server returned 404: 404 page not found\n"14012026/10/08 12:58:11 WARN Failed to register uploaded object key=60d25sb2i678iwn80vvdivh2a8rpbp6w.ls error="server returned 404: 404 page not found\n"14022026/10/08 12:58:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14032026/10/08 12:58:11 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14042026/10/08 12:58:11 WARN Failed to register uploaded object key=fdvv1b2cgi3gk6ch66lw9pndcwa3wp6m.ls error="server returned 404: 404 page not found\n"14052026/10/08 12:58:11 WARN Failed to register uploaded object key=x40hxhzy1gn8bs3avfbwlqy3g5cn8xwd.ls error="server returned 404: 404 page not found\n"14062026/10/08 12:58:11 INFO Signed narinfos id=1 count=214072026/10/08 12:58:11 WARN Failed to register uploaded object key=nar/19xn9vpzvgmz0bsvsaf01yjhrb8fiysr87kb8aa4ldmdryx4y011.nar.zst error="server returned 404: 404 page not found\n"14082026/10/08 12:58:11 INFO Uploading 2 narinfos14092026/10/08 12:58:11 WARN Failed to register uploaded object key=8vw5nxsyaz2p0j1j45nil7z18dhgknb5.ls error="server returned 404: 404 page not found\n"14102026/10/08 12:58:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14112026/10/08 12:58:11 INFO Signed narinfos id=1 count=314122026/10/08 12:58:11 INFO Uploading 3 narinfos14132026/10/08 12:58:11 WARN Failed to register uploaded object key=fdvv1b2cgi3gk6ch66lw9pndcwa3wp6m.narinfo error="server returned 404: 404 page not found\n"14142026/10/08 12:58:11 INFO Received complete push request method=POST path=/api/pushes/1/complete14152026/10/08 12:58:11 WARN Failed to register uploaded object key=60d25sb2i678iwn80vvdivh2a8rpbp6w.narinfo error="server returned 404: 404 page not found\n"14162026/10/08 12:58:11 WARN Failed to register uploaded object key=1hbqx7nfqnngm48d6z57c06mxp4zbip4.narinfo error="server returned 404: 404 page not found\n"14172026/10/08 12:58:11 WARN Failed to register uploaded object key=x40hxhzy1gn8bs3avfbwlqy3g5cn8xwd.narinfo error="server returned 404: 404 page not found\n"14182026/10/08 12:58:11 INFO Received complete push request method=POST path=/api/pushes/1/complete14192026/10/08 12:58:11 WARN Failed to register uploaded object key=8vw5nxsyaz2p0j1j45nil7z18dhgknb5.narinfo error="server returned 404: 404 page not found\n"14202026/10/08 12:58:11 INFO Completed push id=1 objects=6 duration=5.83531ms14212026/10/08 12:58:11 INFO Upload complete. (262ms)1422=== NAME TestClientSharedPathCommittedMidPush1423 client_integration_test.go:680: Retrieved narinfo from S3:1424 StorePath: /build/TestClientSharedPathCommittedMidPush3883668260/001/store/fdvv1b2cgi3gk6ch66lw9pndcwa3wp6m-shared-dep1425 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1426 Compression: zstd1427 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821428 NarSize: 1361429 References: 1430 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1431=== NAME TestClientMultipleUploads1432 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1424842401/001/store/s44z9n5pyih47hlpq7qrmczy261ja637-test-file-2.txt14332026/10/08 12:58:11 INFO Aborted multipart uploads count=0 kept=01434=== NAME TestClientSharedPathCommittedMidPush1435 client_integration_test.go:680: Retrieved narinfo from S3:1436 StorePath: /build/TestClientSharedPathCommittedMidPush3883668260/001/store/60d25sb2i678iwn80vvdivh2a8rpbp6w-top1437 URL: nar/0224a0zfhwq820dngrddznxm5wr5592g4950kk33jr49hmbzyckq.nar.zst1438 Compression: zstd1439 NarHash: sha256:0224a0zfhwq820dngrddznxm5wr5592g4950kk33jr49hmbzyckq1440 NarSize: 2241441 References: /build/TestClientSharedPathCommittedMidPush3883668260/001/store/fdvv1b2cgi3gk6ch66lw9pndcwa3wp6m-shared-dep1442 CA: text:sha256:139sfg962n2mfph5kaj0l6w7v42f1aqwhfs3rgf72n97ripxi0zb14432026/10/08 12:58:11 INFO Completed push id=1 objects=8 duration=9.604693ms14442026/10/08 12:58:11 INFO Upload complete. (267ms)1445=== NAME TestClientPushesUseOnePush1446 client_pushes_test.go:97: Retrieved narinfo from S3:1447 StorePath: /build/TestClientPushesUseOnePush1657607529/001/store/8vw5nxsyaz2p0j1j45nil7z18dhgknb5-shared-dep1448 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1449 Compression: zstd1450 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821451 NarSize: 1361452 References: 1453 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1454 client_pushes_test.go:97: Retrieved narinfo from S3:1455 StorePath: /build/TestClientPushesUseOnePush1657607529/001/store/x40hxhzy1gn8bs3avfbwlqy3g5cn8xwd-a1456 URL: nar/19xn9vpzvgmz0bsvsaf01yjhrb8fiysr87kb8aa4ldmdryx4y011.nar.zst1457 Compression: zstd1458 NarHash: sha256:19xn9vpzvgmz0bsvsaf01yjhrb8fiysr87kb8aa4ldmdryx4y0111459 NarSize: 2161460 References: /build/TestClientPushesUseOnePush1657607529/001/store/8vw5nxsyaz2p0j1j45nil7z18dhgknb5-shared-dep1461 CA: text:sha256:11pa5rsw9zmxs95yaaxf0i09hxl86d8w9c9626ydxv5wzq35db9v1462 client_pushes_test.go:97: Retrieved narinfo from S3:1463 StorePath: /build/TestClientPushesUseOnePush1657607529/001/store/1hbqx7nfqnngm48d6z57c06mxp4zbip4-b1464 URL: nar/19xn9vpzvgmz0bsvsaf01yjhrb8fiysr87kb8aa4ldmdryx4y011.nar.zst1465 Compression: zstd1466 NarHash: sha256:19xn9vpzvgmz0bsvsaf01yjhrb8fiysr87kb8aa4ldmdryx4y0111467 NarSize: 2161468 References: /build/TestClientPushesUseOnePush1657607529/001/store/8vw5nxsyaz2p0j1j45nil7z18dhgknb5-shared-dep1469 CA: text:sha256:11pa5rsw9zmxs95yaaxf0i09hxl86d8w9c9626ydxv5wzq35db9v1470--- PASS: TestClientSharedPathCommittedMidPush (1.15s)1471=== CONT TestService_AuthMiddleware_MTLSProxyHeader14722026/10/08 12:58:11 WARN Force mode enabled - objects will be deleted immediately without grace period1473--- PASS: TestClientPushesUseOnePush (1.19s)1474=== CONT TestConnectWaitsForAPeerMigration14752026/10/08 12:58:11 INFO Aborted multipart uploads count=0 kept=014762026/10/08 12:58:11 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=014772026/10/08 12:58:11 INFO Vacuumed table table=pending_closures14782026/10/08 12:58:11 INFO Vacuumed table table=pending_objects14792026/10/08 12:58:11 INFO Vacuumed table table=multipart_uploads14802026/10/08 12:58:11 INFO Vacuumed table table=closures14812026/10/08 12:58:11 INFO Vacuumed table table=objects14822026/10/08 12:58:11 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=01483--- PASS: TestGCMetrics (0.71s)14842026/10/08 12:58:11 INFO Received push request method=POST path=/api/pushes1485=== CONT TestResolveDBConnectionString14862026/10/08 12:58:11 INFO Vacuumed table table=pending_closures1487=== RUN TestResolveDBConnectionString/flag_wins1488=== PAUSE TestResolveDBConnectionString/flag_wins1489=== RUN TestResolveDBConnectionString/file_when_flag_empty1490=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1491=== RUN TestResolveDBConnectionString/missing_file_is_an_error1492=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1493=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1494=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1495=== RUN TestResolveDBConnectionString/nothing_configured1496=== PAUSE TestResolveDBConnectionString/nothing_configured1497=== CONT TestDeleteClosuresRacingPins14982026/10/08 12:58:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14992026/10/08 12:58:11 INFO Uploading 2y2hckgkfaf0b3rks9y1lvbg8qrvl5yh-unpinned-file.txt (128B)15002026/10/08 12:58:11 INFO Vacuumed table table=pending_objects15012026/10/08 12:58:11 INFO Vacuumed table table=multipart_uploads15022026/10/08 12:58:11 INFO Received push request method=POST path=/api/pushes15032026/10/08 12:58:11 INFO Vacuumed table table=closures15042026/10/08 12:58:11 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15052026/10/08 12:58:11 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15062026/10/08 12:58:11 INFO Signed narinfos id=2 count=115072026/10/08 12:58:11 WARN Failed to register uploaded object key=2y2hckgkfaf0b3rks9y1lvbg8qrvl5yh.ls error="server returned 404: 404 page not found\n"15082026/10/08 12:58:11 INFO Uploading 1 narinfos15092026/10/08 12:58:11 INFO Vacuumed table table=objects15102026/10/08 12:58:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15112026/10/08 12:58:11 INFO Uploading nw88s5xc492jn0ky0v4h0qzgc1x772x8-test-script (136B)15122026/10/08 12:58:11 INFO Received complete push request method=POST path=/api/pushes/2/complete15132026/10/08 12:58:11 WARN Failed to register uploaded object key=2y2hckgkfaf0b3rks9y1lvbg8qrvl5yh.narinfo error="server returned 404: 404 page not found\n"15142026/10/08 12:58:11 INFO Completed push id=2 objects=3 duration=1.929286ms15152026/10/08 12:58:11 INFO Aborted multipart uploads count=0 kept=015162026/10/08 12:58:11 INFO Upload complete. (53ms)15172026/10/08 12:58:11 WARN Force mode enabled - objects will be deleted immediately without grace period15182026/10/08 12:58:11 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15192026/10/08 12:58:11 WARN Failed to register uploaded object key=nw88s5xc492jn0ky0v4h0qzgc1x772x8.ls error="server returned 404: 404 page not found\n"15202026/10/08 12:58:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15212026/10/08 12:58:11 WARN Failed to register uploaded object key=log/dk8sz4ibn82lqkfb3yn8yzgyfmm7f2vs-test-script.drv error="server returned 404: 404 page not found\n"15222026/10/08 12:58:11 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=015232026/10/08 12:58:11 INFO Signed narinfos id=1 count=115242026/10/08 12:58:11 INFO Uploading 1 narinfos15252026/10/08 12:58:11 INFO Received complete push request method=POST path=/api/pushes/1/complete15262026/10/08 12:58:11 WARN Failed to register uploaded object key=nw88s5xc492jn0ky0v4h0qzgc1x772x8.narinfo error="server returned 404: 404 page not found\n"15272026/10/08 12:58:11 INFO Vacuumed table table=pending_closures15282026/10/08 12:58:11 INFO Completed push id=1 objects=4 duration=11.35368ms15292026/10/08 12:58:11 INFO Upload complete. (77ms)1530=== NAME TestClientIntegration1531 client_integration_test.go:286: Created store path: /build/TestClientIntegration675611705/002/store/26ijl8brcijqj061z11rvgrqdvk0yzpv-test-file.txt1532=== NAME TestClientWithDependencies1533 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2472298107/001/store) requires matching store prefix15342026/10/08 12:58:11 INFO Vacuumed table table=pending_objects15352026/10/08 12:58:11 INFO Vacuumed table table=multipart_uploads15362026/10/08 12:58:11 INFO Vacuumed table table=closures15372026/10/08 12:58:11 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"1538--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.66s)15392026/10/08 12:58:11 INFO Vacuumed table table=objects1540=== CONT TestClientFallsBackToClosures1541--- PASS: TestPushDedupSurvivesConcurrentGC (0.81s)1542=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1543--- PASS: TestClientWithDependencies (1.21s)1544=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15452026/10/08 12:58:11 INFO Received uploads request method=POST path=/1546=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15472026/10/08 12:58:11 INFO Received request for more parts method=POST path=/1548=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15492026/10/08 12:58:11 INFO Received complete multipart upload request method=POST path=/1550=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15512026/10/08 12:58:11 INFO Received uploads request method=POST path=/1552=== CONT TestProxyWriteTimeout/narinfo1553--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1554 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1555 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1556 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1557 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1558=== CONT TestProxyWriteTimeout/unknown_size1559=== CONT TestProxyWriteTimeout/10_GiB_nar1560=== CONT TestProxyWriteTimeout/1_GiB_nar1561=== CONT TestPendingClosureWriteTimeout/empty1562--- PASS: TestProxyWriteTimeout (0.17s)1563 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1564 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1565 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1566 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1567=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline15682026/10/08 12:58:11 INFO Received push request method=POST path=/api/pushes15692026/10/08 12:58:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures15702026/10/08 12:58:11 INFO Garbage collection started15712026/10/08 12:58:11 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15722026/10/08 12:58:11 INFO Uploading ajcaqql8jsrxrsn6703871csldmgxzfg-test-file-1.txt (160B)15732026/10/08 12:58:11 INFO Uploading s44z9n5pyih47hlpq7qrmczy261ja637-test-file-2.txt (160B)15742026/10/08 12:58:11 INFO Uploading vrd02crvzrrqjv79r8dlhchjmqg7rrj0-test-file-0.txt (160B)15752026/10/08 12:58:11 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15762026/10/08 12:58:11 WARN Failed to register uploaded object key=ajcaqql8jsrxrsn6703871csldmgxzfg.ls error="server returned 404: 404 page not found\n"15772026/10/08 12:58:11 WARN Failed to register uploaded object key=vrd02crvzrrqjv79r8dlhchjmqg7rrj0.ls error="server returned 404: 404 page not found\n"15782026/10/08 12:58:11 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15792026/10/08 12:58:11 WARN Failed to register uploaded object key=s44z9n5pyih47hlpq7qrmczy261ja637.ls error="server returned 404: 404 page not found\n"15802026/10/08 12:58:11 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15812026/10/08 12:58:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15822026/10/08 12:58:11 INFO Signed narinfos id=1 count=315832026/10/08 12:58:11 INFO Uploading 3 narinfos15842026/10/08 12:58:11 WARN Failed to register uploaded object key=vrd02crvzrrqjv79r8dlhchjmqg7rrj0.narinfo error="server returned 404: 404 page not found\n"15852026/10/08 12:58:11 WARN Failed to register uploaded object key=s44z9n5pyih47hlpq7qrmczy261ja637.narinfo error="server returned 404: 404 page not found\n"15862026/10/08 12:58:11 INFO Received complete push request method=POST path=/api/pushes/1/complete15872026/10/08 12:58:11 WARN Failed to register uploaded object key=ajcaqql8jsrxrsn6703871csldmgxzfg.narinfo error="server returned 404: 404 page not found\n"15882026/10/08 12:58:11 INFO Aborted multipart uploads count=0 kept=015892026/10/08 12:58:11 WARN Force mode enabled - objects will be deleted immediately without grace period15902026/10/08 12:58:11 INFO Completed push id=1 objects=9 duration=10.79016ms15912026/10/08 12:58:11 INFO Upload complete. (119ms)1592=== NAME TestClientMultipleUploads1593 client_integration_test.go:369: Uploaded 3 paths in 158.59895ms15942026/10/08 12:58:11 INFO Received push request method=POST path=/api/pushes1595--- PASS: TestClientMultipleUploads (0.89s)1596=== CONT TestPendingClosureWriteTimeout/400_objects1597=== CONT TestPendingClosureWriteTimeout/670k_objects1598=== CONT TestIsValidUploadKey/narinfo1599=== CONT TestIsValidUploadKey/unknown_type1600=== CONT TestIsValidUploadKey/empty_key1601=== CONT TestIsValidUploadKey/absolute1602=== CONT TestIsValidUploadKey/traversal_nar1603=== CONT TestIsValidUploadKey/traversal1604=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1605=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1606=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1607=== CONT TestIsValidUploadKey/index.html1608=== CONT TestIsValidUploadKey/nix-cache-info1609=== CONT TestIsValidUploadKey/realisation_plus_in_output1610=== CONT TestIsValidUploadKey/realisation1611=== CONT TestIsValidUploadKey/build_log_equals1612=== CONT TestIsValidUploadKey/build_log_question_mark1613=== CONT TestIsValidUploadKey/build_log_plus_in_name1614=== CONT TestIsValidUploadKey/build_log_home-manager_file1615=== CONT TestIsValidUploadKey/build_log1616=== CONT TestIsValidUploadKey/listing1617=== CONT TestIsValidUploadKey/nar_zst1618=== CONT TestIsValidUploadKey/nar_plain1619=== CONT TestIsValidUploadKey/nar_xz1620--- PASS: TestIsValidUploadKey (0.20s)1621 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1622 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1623 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1624 --- PASS: TestIsValidUploadKey/absolute (0.00s)1625 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1626 --- PASS: TestIsValidUploadKey/traversal (0.00s)1627 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1628 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1629 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1630 --- PASS: TestIsValidUploadKey/index.html (0.00s)1631 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1632 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1633 --- PASS: TestIsValidUploadKey/realisation (0.00s)1634 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1635 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1636 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1637 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1638 --- PASS: TestIsValidUploadKey/build_log (0.00s)1639 --- PASS: TestIsValidUploadKey/listing (0.00s)1640 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1641 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1642 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1643=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16442026/10/08 12:58:11 INFO Received uploads request method=POST path=/16452026/10/08 12:58:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=016462026/10/08 12:58:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16472026/10/08 12:58:11 INFO Uploading 26ijl8brcijqj061z11rvgrqdvk0yzpv-test-file.txt (152B)16482026/10/08 12:58:11 INFO Vacuumed table table=pending_closures16492026/10/08 12:58:11 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16502026/10/08 12:58:11 WARN Failed to register uploaded object key=26ijl8brcijqj061z11rvgrqdvk0yzpv.ls error="server returned 404: 404 page not found\n"16512026/10/08 12:58:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16522026/10/08 12:58:11 INFO Signed narinfos id=1 count=116532026/10/08 12:58:11 INFO Uploading 1 narinfos16542026/10/08 12:58:11 INFO Vacuumed table table=pending_objects16552026/10/08 12:58:11 INFO Vacuumed table table=multipart_uploads16562026/10/08 12:58:11 INFO Received complete push request method=POST path=/api/pushes/1/complete16572026/10/08 12:58:11 WARN Failed to register uploaded object key=26ijl8brcijqj061z11rvgrqdvk0yzpv.narinfo error="server returned 404: 404 page not found\n"16582026/10/08 12:58:11 INFO Vacuumed table table=closures1659--- PASS: TestService_ReadScope_PublicByDefault (0.71s)1660=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16612026/10/08 12:58:11 INFO Received request for more parts method=POST path=/16622026/10/08 12:58:11 INFO Completed push id=1 objects=3 duration=12.639056ms16632026/10/08 12:58:11 INFO Upload complete. (72ms)1664--- PASS: TestCacheStatsHandler (0.72s)1665=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16662026/10/08 12:58:11 INFO Received complete multipart upload request method=POST path=/16672026/10/08 12:58:11 INFO Vacuumed table table=objects16682026/10/08 12:58:11 INFO lead: acquired remote=192.0.2.1:12341669=== NAME TestClientCADerivations1670 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations654294824/001/store/8iy1rk3qwq1a0jg22s9zfcspxikgssi0-ca-test16712026/10/08 12:58:11 INFO All 1 paths already cached1672=== NAME TestClientIntegration1673 client_integration_test.go:312: Retrieved narinfo from S3:1674 StorePath: /build/TestClientIntegration675611705/002/store/26ijl8brcijqj061z11rvgrqdvk0yzpv-test-file.txt1675 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1676 Compression: zstd1677 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11678 NarSize: 1521679 References: 1680 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11681 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1682 client_integration_test.go:313: Decompressed .ls content (64 bytes):1683 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1684 client_integration_test.go:316: Testing garbage collection...1685=== CONT TestIsValidCachePath/narinfo1686=== CONT TestIsValidCachePath/short_hash1687=== CONT TestIsValidCachePath/wrong_extension1688=== CONT TestIsValidCachePath/leading_slash1689=== CONT TestIsValidCachePath/empty1690=== CONT TestIsValidCachePath/random_path1691=== CONT TestIsValidCachePath/invalid_char_u1692=== CONT TestIsValidCachePath/invalid_char_e1693=== CONT TestIsValidCachePath/traversal_in_middle1694=== CONT TestIsValidCachePath/traversal_parent1695=== CONT TestIsValidCachePath/index.html1696=== CONT TestIsValidCachePath/nix-cache-info1697=== CONT TestIsValidCachePath/realisation1698=== CONT TestIsValidCachePath/log1699=== CONT TestIsValidCachePath/ls1700=== CONT TestIsValidCachePath/nar_uncompressed1701=== CONT TestIsValidCachePath/nar_bz21702=== CONT TestIsValidCachePath/nar_xz1703=== CONT TestIsValidCachePath/nar_zst1704=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1705--- PASS: TestIsValidCachePath (0.00s)1706 --- PASS: TestIsValidCachePath/narinfo (0.00s)1707 --- PASS: TestIsValidCachePath/short_hash (0.00s)1708 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1709 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1710 --- PASS: TestIsValidCachePath/empty (0.00s)1711 --- PASS: TestIsValidCachePath/random_path (0.00s)1712 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1713 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1714 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1715 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1716 --- PASS: TestIsValidCachePath/index.html (0.00s)1717 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1718 --- PASS: TestIsValidCachePath/realisation (0.00s)1719 --- PASS: TestIsValidCachePath/log (0.00s)1720 --- PASS: TestIsValidCachePath/ls (0.00s)1721 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1722 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1723 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1724 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1725 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1726=== CONT TestParseSingleRange/none1727=== CONT TestParseSingleRange/open-ended1728=== CONT TestParseSingleRange/start_far_past_EOF1729=== CONT TestParseSingleRange/start_past_EOF1730=== CONT TestParseSingleRange/single_byte1731=== CONT TestParseSingleRange/suffix_exceeds_size1732=== CONT TestParseSingleRange/suffix1733=== CONT TestParseSingleRange/end_clamped_to_size1734=== CONT TestParseSingleRange/malformed_both_empty1735=== CONT TestParseSingleRange/closed1736=== CONT TestParseSingleRange/malformed_end_before_start1737=== CONT TestParseSingleRange/multi-range_ignored1738=== CONT TestParseSingleRange/malformed_no_dash1739=== CONT TestParseSingleRange/unknown_unit1740--- PASS: TestParseSingleRange (0.00s)1741 --- PASS: TestParseSingleRange/none (0.00s)1742 --- PASS: TestParseSingleRange/open-ended (0.00s)1743 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1744 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1745 --- PASS: TestParseSingleRange/single_byte (0.00s)1746 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1747 --- PASS: TestParseSingleRange/suffix (0.00s)1748 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1749 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1750 --- PASS: TestParseSingleRange/closed (0.00s)1751 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1752 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1753 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1754 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1755=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1756=== RUN TestService_RequireScope_OIDC/builder_may_write1757=== PAUSE TestService_RequireScope_OIDC/builder_may_write1758=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1759=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1760=== RUN TestService_RequireScope_OIDC/ops_may_admin1761=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1762=== RUN TestService_RequireScope_OIDC/ops_may_not_write1763=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1764=== RUN TestService_RequireScope_OIDC/reader_may_not_write1765=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1766=== RUN TestService_RequireScope_OIDC/static_token_may_admin1767=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1768=== RUN TestService_RequireScope_OIDC/static_token_may_write1769=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1770=== RUN TestService_RequireScope_OIDC/reader_may_read1771=== PAUSE TestService_RequireScope_OIDC/reader_may_read1772=== RUN TestService_RequireScope_OIDC/writer_implies_read1773=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1774=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1775=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1776=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1777=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1778=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1779=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1780=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1781=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1782=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1783=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1784=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1785=== CONT TestPush_RejectsBadRequests/no_roots17862026/10/08 12:58:11 INFO Received push request method=POST path=/api/pushes1787=== CONT TestPush_RejectsBadRequests/bad_root17882026/10/08 12:58:11 INFO Received push request method=POST path=/api/pushes1789=== CONT TestPush_RejectsBadRequests/root_not_in_objects17902026/10/08 12:58:11 INFO Received push request method=POST path=/api/pushes1791=== CONT TestPush_RejectsBadRequests/no_objects17922026/10/08 12:58:11 INFO Received push request method=POST path=/api/pushes1793=== CONT TestServerTLSConfig/no_client_CA1794--- PASS: TestPush_RejectsBadRequests (0.96s)1795 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1796 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1797 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1798 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1799=== CONT TestServerTLSConfig/not_a_PEM_file1800=== CONT TestServerTLSConfig/missing_CA_file1801=== CONT TestGCEndsOnShutdown/before_the_run1802--- PASS: TestServerTLSConfig (0.00s)1803 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1804 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1805 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)18062026/10/08 12:58:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures18072026/10/08 12:58:11 INFO Garbage collection started1808=== NAME TestClientCADerivations1809 client_ca_test.go:139: Found 1 dependencies (including self)1810--- PASS: TestGCBugBareHashReferences (0.91s)1811=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1812=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1813=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1814=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1815=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1816=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1817=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1818=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1819=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1820=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18212026/10/08 12:58:11 INFO Aborted multipart uploads count=0 kept=018222026/10/08 12:58:11 WARN Force mode enabled - objects will be deleted immediately without grace period18232026/10/08 12:58:11 INFO lead: acquired remote=192.0.2.1:123418242026/10/08 12:58:11 INFO lead: released remote=192.0.2.1:12341825--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.68s)1826=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows18272026/10/08 12:58:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=018282026/10/08 12:58:11 INFO Vacuumed table table=pending_closures18292026/10/08 12:58:11 INFO Vacuumed table table=pending_objects18302026/10/08 12:58:11 INFO Vacuumed table table=multipart_uploads1831--- PASS: TestService_ReadAuthMiddleware (0.65s)1832=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18332026/10/08 12:58:11 INFO Vacuumed table table=closures18342026/10/08 12:58:11 INFO Vacuumed table table=objects18352026/10/08 12:58:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18362026/10/08 12:58:11 WARN mTLS auth: bound subjects configured but subject DN unavailable18372026/10/08 12:58:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1838--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.66s)1839=== CONT TestClientErrorHandling/InvalidStorePath18402026/10/08 12:58:11 INFO lead: acquired remote=192.0.2.1:123418412026/10/08 12:58:11 INFO Received push request method=POST path=/api/pushes18422026/10/08 12:58:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18432026/10/08 12:58:11 INFO Uploading 8iy1rk3qwq1a0jg22s9zfcspxikgssi0-ca-test (144B)18442026/10/08 12:58:11 WARN Failed to register uploaded object key=log/rgp44mn8w3zzv8lkj0irhk4dy3s61n6c-ca-test.drv error="server returned 404: 404 page not found\n"18452026/10/08 12:58:11 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18462026/10/08 12:58:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18472026/10/08 12:58:11 WARN Failed to register uploaded object key=8iy1rk3qwq1a0jg22s9zfcspxikgssi0.ls error="server returned 404: 404 page not found\n"18482026/10/08 12:58:11 INFO Signed narinfos id=1 count=118492026/10/08 12:58:11 INFO Uploading 1 narinfos18502026/10/08 12:58:11 INFO Received complete push request method=POST path=/api/pushes/1/complete18512026/10/08 12:58:11 WARN Failed to register uploaded object key=8iy1rk3qwq1a0jg22s9zfcspxikgssi0.narinfo error="server returned 404: 404 page not found\n"1852--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.41s)1853=== CONT TestClientErrorHandling/ServerNotAvailable18542026/10/08 12:58:11 INFO Completed push id=1 objects=4 duration=6.956927ms18552026/10/08 12:58:11 INFO Upload complete. (105ms)1856=== NAME TestClientCADerivations1857 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations654294824/001/store/8iy1rk3qwq1a0jg22s9zfcspxikgssi0-ca-test1858 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1859 Compression: zstd1860 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1861 NarSize: 1441862 References: 1863 Deriver: /build/TestClientCADerivations654294824/001/store/rgp44mn8w3zzv8lkj0irhk4dy3s61n6c-ca-test.drv1864 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1865 client_ca_test.go:185: Checking for realisation files in S3...1866 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1867 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1868 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1869 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1870 error: binary cache 's3://bucket77?endpoint=http://localhost:42815®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations654294824/001/store'18712026/10/08 12:58:11 INFO Received uploads request method=POST path=/api/pending_closures18722026/10/08 12:58:11 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/present1873 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11874--- PASS: TestClientCADerivations (1.15s)1875=== CONT TestClientErrorHandling/InvalidAuthToken18762026/10/08 12:58:11 WARN Request failed, retrying attempt=2 backoff=189.742771ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18772026/10/08 12:58:11 INFO Aborted multipart uploads count=0 kept=01878=== CONT TestCacheConfigHandler/full_config,_no_issuer1879=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1880=== CONT TestCacheConfigHandler/no_cache_url_configured1881=== CONT TestCacheConfigHandler/no_signing_keys18822026/10/08 12:58:11 WARN Force mode enabled - objects will be deleted immediately without grace period1883--- PASS: TestCacheConfigHandler (0.00s)1884 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1885 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1886 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1887 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1888=== CONT TestResolveDBConnectionString/flag_wins1889=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1890=== CONT TestResolveDBConnectionString/nothing_configured1891=== CONT TestResolveDBConnectionString/file_when_flag_empty1892=== CONT TestResolveDBConnectionString/missing_file_is_an_error1893=== CONT TestService_RequireScope_OIDC/builder_may_write1894--- PASS: TestResolveDBConnectionString (0.00s)1895 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1896 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1897 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1898 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1899 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1900=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1901=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1902=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1903=== CONT TestService_RequireScope_OIDC/writer_implies_read1904=== CONT TestService_RequireScope_OIDC/reader_may_read1905=== CONT TestService_RequireScope_OIDC/static_token_may_write1906=== CONT TestService_RequireScope_OIDC/static_token_may_admin1907=== CONT TestService_RequireScope_OIDC/reader_may_not_write1908=== CONT TestService_RequireScope_OIDC/ops_may_not_write1909=== CONT TestService_RequireScope_OIDC/ops_may_admin1910=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1911=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19122026/10/08 12:58:11 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]1913=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1914=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1915--- PASS: TestService_RequireScope_OIDC (0.74s)1916 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1917 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1918 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1919 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1920 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1921 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1922 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1923 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1924 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1925 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1926 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1927 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1928 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1929 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1930=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19312026/10/08 12:58:11 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]1932=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1933=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19342026/10/08 12:58:11 WARN Authentication failed token_preview=eyJhbGciOi...4oqnJpymjA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1935--- PASS: TestService_AuthMiddleware_OIDC (0.76s)1936 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1937 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1938 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1939 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19402026/10/08 12:58:12 INFO Aborted multipart uploads count=0 kept=019412026/10/08 12:58:12 WARN Force mode enabled - objects will be deleted immediately without grace period19422026/10/08 12:58:12 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:42815/bucket96/?delete=\": context canceled"1943--- PASS: TestGCEndsOnShutdown (0.00s)1944 --- PASS: TestGCEndsOnShutdown/before_the_run (0.44s)1945 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.44s)1946 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.47s)19472026/10/08 12:58:12 INFO Received uploads request method=POST path=/api/pending_closures19482026/10/08 12:58:12 INFO Aborted multipart uploads count=0 kept=019492026/10/08 12:58:12 INFO Received uploads request method=POST path=/api/pending_closures19502026/10/08 12:58:12 INFO Received uploads request method=POST path=/api/pending_closures19512026/10/08 12:58:12 WARN Force mode enabled - objects will be deleted immediately without grace period19522026/10/08 12:58:12 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)19532026/10/08 12:58:12 INFO Uploading px0dy2zajx9d2q2dwimn1fkli1gd4c4w-shared-dep (136B)19542026/10/08 12:58:12 INFO Uploading apmy2r3aamvzym2j577j9qa25c2fnf70-a (216B)19552026/10/08 12:58:12 WARN Failed to register uploaded object key=px0dy2zajx9d2q2dwimn1fkli1gd4c4w.ls error="server returned 404: 404 page not found\n"19562026/10/08 12:58:12 WARN Failed to register uploaded object key=2xk45nqcw8yidljdg6kjc4y0fvscpzmz.ls error="server returned 404: 404 page not found\n"19572026/10/08 12:58:12 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19582026/10/08 12:58:12 WARN Failed to register uploaded object key=nar/0acqklaaswcz2hbhs7ll9yqf97dllkz5wyj9qxsmj3al0f2ypyil.nar.zst error="server returned 404: 404 page not found\n"19592026/10/08 12:58:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19602026/10/08 12:58:12 WARN Failed to register uploaded object key=apmy2r3aamvzym2j577j9qa25c2fnf70.ls error="server returned 404: 404 page not found\n"19612026/10/08 12:58:12 INFO Signed narinfos id=2 count=219622026/10/08 12:58:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19632026/10/08 12:58:12 INFO Signed narinfos id=1 count=219642026/10/08 12:58:12 INFO Uploading 4 narinfos19652026/10/08 12:58:12 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=019662026/10/08 12:58:12 WARN Failed to register uploaded object key=apmy2r3aamvzym2j577j9qa25c2fnf70.narinfo error="server returned 404: 404 page not found\n"19672026/10/08 12:58:12 WARN Failed to register uploaded object key=px0dy2zajx9d2q2dwimn1fkli1gd4c4w.narinfo error="server returned 404: 404 page not found\n"19682026/10/08 12:58:12 INFO Vacuumed table table=pending_closures19692026/10/08 12:58:12 WARN Failed to register uploaded object key=2xk45nqcw8yidljdg6kjc4y0fvscpzmz.narinfo error="server returned 404: 404 page not found\n"19702026/10/08 12:58:12 INFO Vacuumed table table=pending_objects19712026/10/08 12:58:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19722026/10/08 12:58:12 WARN Failed to register uploaded object key=px0dy2zajx9d2q2dwimn1fkli1gd4c4w.narinfo error="server returned 404: 404 page not found\n"19732026/10/08 12:58:12 INFO Vacuumed table table=multipart_uploads19742026/10/08 12:58:12 INFO Vacuumed table table=closures19752026/10/08 12:58:12 INFO Received uploads request method=POST path=/api/pending_closures19762026/10/08 12:58:12 INFO Vacuumed table table=objects19772026/10/08 12:58:12 INFO Completed upload id=1 objects=6 duration=6.308809ms19782026/10/08 12:58:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19792026/10/08 12:58:12 INFO Completed upload id=2 objects=6 duration=1.279058ms19802026/10/08 12:58:12 INFO Upload complete. (67ms)1981=== NAME TestClientFallsBackToClosures1982 client_pushes_test.go:112: Retrieved narinfo from S3:1983 StorePath: /build/TestClientFallsBackToClosures332778980/001/store/px0dy2zajx9d2q2dwimn1fkli1gd4c4w-shared-dep1984 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1985 Compression: zstd1986 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821987 NarSize: 1361988 References: 1989 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1990=== NAME TestOrphanedObjectsGCStressTest1991 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1992=== NAME TestClientFallsBackToClosures1993 client_pushes_test.go:112: Retrieved narinfo from S3:1994 StorePath: /build/TestClientFallsBackToClosures332778980/001/store/apmy2r3aamvzym2j577j9qa25c2fnf70-a1995 URL: nar/0acqklaaswcz2hbhs7ll9yqf97dllkz5wyj9qxsmj3al0f2ypyil.nar.zst1996 Compression: zstd1997 NarHash: sha256:0acqklaaswcz2hbhs7ll9yqf97dllkz5wyj9qxsmj3al0f2ypyil1998 NarSize: 2161999 References: /build/TestClientFallsBackToClosures332778980/001/store/px0dy2zajx9d2q2dwimn1fkli1gd4c4w-shared-dep2000 CA: text:sha256:04qab7kgc9c6r98qxgi0iw8di3z8y65ljaic313xix74i328iv4z2001 client_pushes_test.go:112: Retrieved narinfo from S3:2002 StorePath: /build/TestClientFallsBackToClosures332778980/001/store/2xk45nqcw8yidljdg6kjc4y0fvscpzmz-b2003 URL: nar/0acqklaaswcz2hbhs7ll9yqf97dllkz5wyj9qxsmj3al0f2ypyil.nar.zst2004 Compression: zstd2005 NarHash: sha256:0acqklaaswcz2hbhs7ll9yqf97dllkz5wyj9qxsmj3al0f2ypyil2006 NarSize: 2162007 References: /build/TestClientFallsBackToClosures332778980/001/store/px0dy2zajx9d2q2dwimn1fkli1gd4c4w-shared-dep2008 CA: text:sha256:04qab7kgc9c6r98qxgi0iw8di3z8y65ljaic313xix74i328iv4z20092026/10/08 12:58:12 INFO Aborted multipart uploads count=0 kept=02010--- PASS: TestClientFallsBackToClosures (0.73s)20112026/10/08 12:58:12 WARN Force mode enabled - objects will be deleted immediately without grace period20122026/10/08 12:58:12 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=02013=== NAME TestOrphanedObjectsGCStressTest2014 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion20152026/10/08 12:58:12 INFO Vacuumed table table=pending_closures20162026/10/08 12:58:12 INFO Vacuumed table table=pending_objects20172026/10/08 12:58:12 INFO Vacuumed table table=multipart_uploads20182026/10/08 12:58:12 INFO Vacuumed table table=closures20192026/10/08 12:58:12 INFO Vacuumed table table=objects2020--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.74s)2021--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2022 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.49s)2023 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.49s)20242026/10/08 12:58:12 WARN Request failed, retrying attempt=3 backoff=411.286381ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20252026/10/08 12:58:12 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20262026/10/08 12:58:12 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2027--- PASS: TestUploadHandlersRejectOversizedBody (0.30s)2028 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)2029 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2030 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.80s)2031=== NAME TestOrphanedObjectsGCStressTest2032 orphaned_objects_gc_test.go:503: Stress test completed successfully:2033 orphaned_objects_gc_test.go:504: - Active objects preserved: 202034 orphaned_objects_gc_test.go:505: - Objects deleted: 2102035 orphaned_objects_gc_test.go:506: - Total GC'd: 2102036--- PASS: TestOrphanedObjectsGCStressTest (3.54s)2037--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2038 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.91s)2039 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.91s)20402026/10/08 12:58:12 WARN Request failed, retrying attempt=4 backoff=862.338045ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20412026/10/08 12:58:12 INFO lead: released remote=192.0.2.1:12342042--- PASS: TestLeadEndsOnShutdown (1.83s)2043--- PASS: TestDeleteClosuresRacingPins (1.33s)2044--- PASS: TestPendingClosureWriteTimeout (0.00s)2045 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2046 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2047 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2048 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.33s)20492026/10/08 12:58:12 WARN Rate limiter enabled after throttle name=s3-test rate=520502026/10/08 12:58:12 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2051=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2052 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102053 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002054--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.82s)20552026/10/08 12:58:12 INFO lead: released remote=192.0.2.1:123420562026/10/08 12:58:12 INFO lead: acquired remote=192.0.2.1:123420572026/10/08 12:58:13 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020582026/10/08 12:58:13 INFO Received create pin request method=POST path=/api/pins/myapp20592026/10/08 12:58:13 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3883093520/001/store/h1ipxwwg4jzljjqr8wdd78x3rrr33y0m-pinned-file.txt narinfo_key=h1ipxwwg4jzljjqr8wdd78x3rrr33y0m.narinfo20602026/10/08 12:58:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures20612026/10/08 12:58:13 INFO Garbage collection started20622026/10/08 12:58:13 INFO Aborted multipart uploads count=0 kept=020632026/10/08 12:58:13 WARN Force mode enabled - objects will be deleted immediately without grace period20642026/10/08 12:58:13 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020652026/10/08 12:58:13 INFO Vacuumed table table=pending_closures20662026/10/08 12:58:13 INFO Vacuumed table table=pending_objects20672026/10/08 12:58:13 INFO Vacuumed table table=multipart_uploads20682026/10/08 12:58:13 WARN Request failed, retrying attempt=5 backoff=1.586268846s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20692026/10/08 12:58:13 INFO Vacuumed table table=closures20702026/10/08 12:58:13 INFO Vacuumed table table=objects2071--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.01s)20722026/10/08 12:58:13 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02073=== NAME TestClientIntegration2074 client_integration_test.go:323: Objects in database after GC:2075 client_integration_test.go:323: Successfully deleted all objects with GC --force2076--- PASS: TestClientIntegration (2.94s)20772026/10/08 12:58:14 INFO lead: released remote=192.0.2.1:12342078--- PASS: TestLeadElectsOneAndHandsOver (3.02s)20792026/10/08 12:58:15 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/08 12:58:15 WARN Request failed, retrying attempt=2 backoff=212.47444ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20812026/10/08 12:58:15 WARN Request failed, retrying attempt=3 backoff=405.195125ms 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 collection2084--- PASS: TestPinProtectsFromGC (5.34s)20852026/10/08 12:58:15 WARN Request failed, retrying attempt=4 backoff=847.973369ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20862026/10/08 12:58:15 INFO Aborted multipart uploads count=1 kept=020872026/10/08 12:58:15 INFO Received cleanup request method=DELETE path=/api/pending_closures20882026/10/08 12:58:15 INFO Aborted multipart uploads count=1 kept=02089--- PASS: TestPendingCleanupUsesOneCutoff (6.80s)2090--- PASS: TestConnectWaitsForAPeerMigration (5.20s)20912026/10/08 12:58:16 WARN Request failed, retrying attempt=5 backoff=1.701936427s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20922026/10/08 12:58:18 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/08 12:58:18 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/08 12:58:18 WARN Request failed, retrying attempt=2 backoff=197.311484ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20952026/10/08 12:58:18 WARN Request failed, retrying attempt=3 backoff=394.047697ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20962026/10/08 12:58:19 WARN Request failed, retrying attempt=4 backoff=829.532606ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20972026/10/08 12:58:19 WARN Request failed, retrying attempt=5 backoff=1.718887514s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20982026/10/08 12:58:21 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/08 12:58:21 WARN Request failed, retrying attempt=2 backoff=188.758547ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21002026/10/08 12:58:21 WARN Request failed, retrying attempt=3 backoff=372.905613ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21012026/10/08 12:58:22 WARN Request failed, retrying attempt=4 backoff=852.705608ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21022026/10/08 12:58:23 WARN Request failed, retrying attempt=5 backoff=1.748169406s 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.48s)2105 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.34s)2106 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.18s)2107PASS21082026-10-08 12:58:25.253 UTC [128] LOG: received smart shutdown request21092026-10-08 12:58:25.257 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 121102026-10-08 12:58:25.269 UTC [133] LOG: shutting down21112026-10-08 12:58:25.272 UTC [133] LOG: checkpoint starting: shutdown immediate21122026-10-08 12:58:27.355 UTC [133] LOG: checkpoint complete: wrote 10789 buffers (65.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.288 s, sync=1.718 s, total=2.086 s; sync files=34045, longest=0.023 s, average=0.001 s; distance=531523 kB, estimate=531523 kB; lsn=0/21E76B38, redo lsn=0/21E76B3821132026-10-08 12:58:27.442 UTC [128] 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 TestValidateToken_KubernetesServiceAccount2153=== CONT TestValidateToken_MultipleProviders2154=== CONT TestValidateToken_BoundClaimsMismatch2155--- PASS: TestAudienceForIssuer (0.00s)2156=== CONT TestValidateToken_Expired2157=== CONT TestValidateToken_WrongAudience2158=== CONT TestValidateToken_ValidToken2159=== CONT TestValidateToken_BoundSubjectMismatch2160=== CONT TestGlobMatch2161=== RUN TestGlobMatch/foo_foo2162=== CONT TestPins_ConfigValidation2163=== CONT TestScopes_ConfigValidation2164=== CONT TestValidateToken_NoMatchingProvider2165=== CONT TestScopes_Rules2166=== CONT TestPins_ReservedForMatchingRule2167=== CONT TestScopes_LegacyProviderDefaultsToWrite2168=== CONT TestPins_TopLevelShorthand2169=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2170--- PASS: TestPins_ConfigValidation (0.00s)2171--- PASS: TestScopes_ConfigValidation (0.00s)2172=== CONT TestNewValidator_KubernetesRequiresCA2173=== PAUSE TestGlobMatch/foo_foo2174=== RUN TestGlobMatch/foo_bar2175=== PAUSE TestGlobMatch/foo_bar2176=== RUN TestGlobMatch/*_2177=== PAUSE TestGlobMatch/*_2178=== RUN TestGlobMatch/*_anything2179=== PAUSE TestGlobMatch/*_anything2180=== RUN TestGlobMatch/foo*_foo2181=== PAUSE TestGlobMatch/foo*_foo2182=== RUN TestGlobMatch/foo*_foobar2183=== PAUSE TestGlobMatch/foo*_foobar2184=== RUN TestGlobMatch/foo*_bar2185=== PAUSE TestGlobMatch/foo*_bar2186=== RUN TestGlobMatch/*bar_bar2187=== PAUSE TestGlobMatch/*bar_bar2188=== RUN TestGlobMatch/*bar_foobar2189=== PAUSE TestGlobMatch/*bar_foobar2190=== RUN TestGlobMatch/*bar_foo2191=== PAUSE TestGlobMatch/*bar_foo2192=== RUN TestGlobMatch/foo*bar_foobar2193=== PAUSE TestGlobMatch/foo*bar_foobar2194=== RUN TestGlobMatch/foo*bar_foo123bar2195=== PAUSE TestGlobMatch/foo*bar_foo123bar2196=== RUN TestGlobMatch/foo*bar_foobarbaz2197=== PAUSE TestGlobMatch/foo*bar_foobarbaz2198=== RUN TestGlobMatch/*/*_foo/bar2199=== PAUSE TestGlobMatch/*/*_foo/bar2200=== RUN TestGlobMatch/*/*_foo2201=== PAUSE TestGlobMatch/*/*_foo2202=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2203=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2204=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02205=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02206=== RUN TestGlobMatch/refs/*/main_refs/heads/main2207=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2208=== RUN TestGlobMatch/fo?_foo2209=== PAUSE TestGlobMatch/fo?_foo2210=== RUN TestGlobMatch/fo?_fo2211=== PAUSE TestGlobMatch/fo?_fo2212=== RUN TestGlobMatch/fo?_fooo2213=== PAUSE TestGlobMatch/fo?_fooo2214=== RUN TestGlobMatch/?oo_foo2215=== PAUSE TestGlobMatch/?oo_foo2216=== RUN TestGlobMatch/?oo_boo2217=== PAUSE TestGlobMatch/?oo_boo2218=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2219=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2220=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2221=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2222=== CONT TestGlobMatch/foo_foo2223=== CONT TestGlobMatch/*/*_foo/bar2224=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02225=== CONT TestGlobMatch/*bar_bar2226=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2227=== CONT TestGlobMatch/foo*bar_foo123bar2228=== CONT TestGlobMatch/foo*bar_foobar2229=== CONT TestGlobMatch/*bar_foo2230=== CONT TestGlobMatch/*bar_foobar2231=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2232=== CONT TestGlobMatch/foo*_foo2233=== CONT TestGlobMatch/foo*_bar2234=== CONT TestGlobMatch/foo*_foobar2235=== CONT TestGlobMatch/*_2236=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2237=== CONT TestGlobMatch/*_anything2238=== CONT TestGlobMatch/?oo_boo2239=== CONT TestGlobMatch/?oo_foo2240=== CONT TestGlobMatch/fo?_fooo2241=== CONT TestGlobMatch/fo?_fo2242=== CONT TestGlobMatch/fo?_foo2243=== CONT TestGlobMatch/refs/*/main_refs/heads/main2244=== CONT TestGlobMatch/*/*_foo2245=== CONT TestGlobMatch/foo*bar_foobarbaz2246=== CONT TestGlobMatch/foo_bar2247--- PASS: TestGlobMatch (0.01s)2248 --- PASS: TestGlobMatch/foo_foo (0.00s)2249 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2250 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2251 --- PASS: TestGlobMatch/*bar_bar (0.00s)2252 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2253 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2254 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2255 --- PASS: TestGlobMatch/*bar_foo (0.00s)2256 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2257 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2258 --- PASS: TestGlobMatch/foo*_foo (0.00s)2259 --- PASS: TestGlobMatch/foo*_bar (0.00s)2260 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2261 --- PASS: TestGlobMatch/*_ (0.00s)2262 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2263 --- PASS: TestGlobMatch/*_anything (0.00s)2264 --- PASS: TestGlobMatch/?oo_boo (0.00s)2265 --- PASS: TestGlobMatch/?oo_foo (0.00s)2266 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2267 --- PASS: TestGlobMatch/fo?_fo (0.00s)2268 --- PASS: TestGlobMatch/fo?_foo (0.00s)2269 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2270 --- PASS: TestGlobMatch/*/*_foo (0.00s)2271 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2272 --- PASS: TestGlobMatch/foo_bar (0.00s)22732026/10/08 12:58:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38197/oidc22742026/10/08 12:58:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46563/oidc2275--- PASS: TestValidateToken_BoundSubjectMismatch (0.03s)2276--- PASS: TestValidateToken_ValidToken (0.03s)22772026/10/08 12:58:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36615/oidc22782026/10/08 12:58:30 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:382132279--- PASS: TestPins_ReservedForMatchingRule (0.04s)2280--- PASS: TestValidateToken_KubernetesServiceAccount (0.05s)22812026/10/08 12:58:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36683/oidc2282--- PASS: TestValidateToken_WrongAudience (0.05s)22832026/10/08 12:58:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37195/oidc2284--- PASS: TestPins_TopLevelShorthand (0.05s)22852026/10/08 12:58:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41753/oidc2286--- PASS: TestValidateToken_Expired (0.06s)22872026/10/08 12:58:30 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33623/oidc22882026/10/08 12:58:30 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:46115/oidc2289--- PASS: TestValidateToken_MultipleProviders (0.08s)22902026/10/08 12:58:30 http: TLS handshake error from 127.0.0.1:52242: remote error: tls: bad certificate2291--- PASS: TestNewValidator_KubernetesRequiresCA (0.07s)22922026/10/08 12:58:30 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232293--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.08s)22942026/10/08 12:58:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46665/oidc2295--- PASS: TestScopes_Rules (0.12s)22962026/10/08 12:58:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43549/oidc2297--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.14s)22982026/10/08 12:58:30 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40419/oidc2299--- PASS: TestValidateToken_NoMatchingProvider (0.15s)23002026/10/08 12:58:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33413/oidc2301--- PASS: TestValidateToken_BoundClaimsMismatch (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/08 12:58:30 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 TestQueueFetchBatchLimit2351=== CONT TestQueueRetryMovesToBack2352=== CONT TestDrainTimeout2353=== CONT TestWorkerPrunesClosureDeps2354=== CONT TestWorkerSkipsGCdPaths2355=== CONT TestWorkerUploadsAndRemoves2356=== CONT TestFailedPathPrunedByLaterClosure2357=== CONT TestDrainGivesUpWhenServerDown2358=== CONT TestRunNotBlockedByPoisonHead2359=== CONT TestQueueRemove2360--- PASS: TestSendPathsEmpty (0.00s)2361=== CONT TestDrainIsolatesPoisonPath2362=== CONT TestQueueRemoveLargeClosure2363=== CONT TestQueueDeduplication2364=== CONT TestQueueConcurrentWriters2365=== CONT TestQueueFetchRemoveLifecycle2366=== CONT TestQueueEnqueueAndFetch23672026/10/08 12:58:30 INFO Uploading batch count=423682026/10/08 12:58:30 ERROR Upload failed error="upload failed" count=423692026/10/08 12:58:30 INFO Uploading batch count=223702026/10/08 12:58:30 INFO Uploading batch count=223712026/10/08 12:58:30 ERROR Upload failed error="upload failed" count=223722026/10/08 12:58:30 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2271340133/002/a23732026/10/08 12:58:30 INFO Uploading batch count=123742026/10/08 12:58:30 ERROR Upload failed error="upload failed" count=123752026/10/08 12:58:30 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath4086615839/002/bbb2376--- PASS: TestQueueEnqueueAndFetch (0.02s)23772026/10/08 12:58:30 INFO Upload queue status pending=223782026/10/08 12:58:30 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2271340133/002/b23792026/10/08 12:58:30 INFO Upload queue status pending=223802026/10/08 12:58:30 INFO Upload queue status pending=323812026/10/08 12:58:30 INFO Uploading batch count=123822026/10/08 12:58:30 ERROR Upload failed error="upload failed" count=12383--- PASS: TestQueueFetchBatchLimit (0.02s)23842026/10/08 12:58:30 INFO Upload queue status pending=223852026/10/08 12:58:30 INFO Uploading batch count=223862026/10/08 12:58:30 INFO Uploading batch count=123872026/10/08 12:58:30 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths521656716/002/nonexistent23882026/10/08 12:58:30 INFO Uploading batch count=12389--- PASS: TestQueueDeduplication (0.02s)23902026/10/08 12:58:30 INFO Uploading batch count=223912026/10/08 12:58:30 ERROR Upload failed error="upload failed" count=22392--- PASS: TestQueueRetryMovesToBack (0.02s)23932026/10/08 12:58:30 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2271340133/002/c2394--- PASS: TestQueueRemove (0.02s)2395--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23962026/10/08 12:58:30 INFO Uploading batch count=123972026/10/08 12:58:30 INFO Uploading batch count=123982026/10/08 12:58:30 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2271340133/002/d23992026/10/08 12:58:30 INFO Uploading batch count=124002026/10/08 12:58:30 ERROR Upload failed error="upload failed" count=124012026/10/08 12:58:30 INFO Uploading batch count=224022026/10/08 12:58:30 ERROR Upload failed error="upload failed" count=224032026/10/08 12:58:30 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2271340133/002/e24042026/10/08 12:58:30 INFO Uploading batch count=124052026/10/08 12:58:30 ERROR Upload failed error="upload failed" count=124062026/10/08 12:58:30 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2271340133/002/f24072026/10/08 12:58:30 INFO Uploading batch count=124082026/10/08 12:58:30 ERROR Upload failed error="upload failed" count=124092026/10/08 12:58:30 ERROR Drain finished with paths left in queue remaining=1024102026/10/08 12:58:30 ERROR Drain finished with paths left in queue remaining=12411--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2412--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2413--- PASS: TestDrainIsolatesPoisonPath (0.03s)2414--- PASS: TestWorkerSkipsGCdPaths (0.04s)2415--- PASS: TestWorkerUploadsAndRemoves (0.04s)2416--- PASS: TestWorkerPrunesClosureDeps (0.04s)2417--- PASS: TestQueueRemoveLargeClosure (0.05s)24182026/10/08 12:58:30 ERROR Upload failed error="context deadline exceeded" count=224192026/10/08 12:58:30 ERROR Drain finished with paths left in queue remaining=42420--- PASS: TestDrainTimeout (0.22s)2421--- PASS: TestQueueConcurrentWriters (0.38s)24222026/10/08 12:58:31 INFO Uploading batch count=124232026/10/08 12:58:31 INFO Uploading batch count=124242026/10/08 12:58:31 INFO Uploading batch count=124252026/10/08 12:58:31 ERROR Upload failed error="upload failed" count=124262026/10/08 12:58:31 INFO Uploading batch count=124272026/10/08 12:58:31 ERROR Upload failed error="upload failed" count=124282026/10/08 12:58:31 INFO Uploading batch count=124292026/10/08 12:58:31 ERROR Upload failed error="upload failed" count=124302026/10/08 12:58:31 INFO Uploading batch count=124312026/10/08 12:58:31 ERROR Upload failed error="upload failed" count=124322026/10/08 12:58:31 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 TestNilKeyPublicKey2466=== CONT TestSignBatch2467--- PASS: TestNilKeyPublicKey (0.00s)2468=== CONT TestSign2469=== CONT TestParseSigningKey2470=== CONT TestGenerateFingerprint2471=== CONT TestSignErrors2472=== CONT TestExternalSignerRejectsInvalidPublicKey2473=== RUN TestExternalSignerRejectsInvalidPublicKey/#002474=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002475=== CONT TestExternalSignerCancellation2476=== CONT TestExternalSignerErrors2477=== CONT TestExternalSignerRestartsAfterCrash2478=== CONT TestExternalSignerWrongPublicKey2479=== CONT TestExternalSignerClose2480=== CONT TestExternalSignerProgramErrorKeepsProcess2481=== RUN TestParseSigningKey/valid_32-byte_key2482=== PAUSE TestParseSigningKey/valid_32-byte_key2483=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2484=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2485=== RUN TestParseSigningKey/no_colon2486=== PAUSE TestParseSigningKey/no_colon2487=== RUN TestParseSigningKey/empty_name2488=== PAUSE TestParseSigningKey/empty_name2489=== RUN TestParseSigningKey/invalid_base642490=== PAUSE TestParseSigningKey/invalid_base642491=== RUN TestParseSigningKey/wrong_length2492=== PAUSE TestParseSigningKey/wrong_length2493=== CONT TestParseSigningKey/valid_32-byte_key2494=== RUN TestGenerateFingerprint/basic_with_references2495=== PAUSE TestGenerateFingerprint/basic_with_references2496=== RUN TestGenerateFingerprint/no_references2497=== PAUSE TestGenerateFingerprint/no_references2498=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2499=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2500=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2501=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2502=== RUN TestGenerateFingerprint/invalid_nar_hash_length2503=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2504=== RUN TestGenerateFingerprint/invalid_store_path_prefix2505=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2506=== RUN TestGenerateFingerprint/invalid_reference_prefix2507=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2508=== CONT TestGenerateFingerprint/basic_with_references2509=== CONT TestParseSigningKey/wrong_length2510=== CONT TestParseSigningKey/invalid_base642511=== CONT TestGenerateFingerprint/invalid_store_path_prefix2512=== CONT TestGenerateFingerprint/invalid_nar_hash_length2513=== CONT TestParseSigningKey/empty_name2514--- PASS: TestSignBatch (0.00s)2515=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2516=== RUN TestExternalSignerErrors/null_signatures2517=== PAUSE TestExternalSignerErrors/null_signatures2518=== RUN TestExternalSignerErrors/wrong_signatures_shape2519=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2520=== RUN TestExternalSignerErrors/too_few_signatures2521=== PAUSE TestExternalSignerErrors/too_few_signatures2522=== RUN TestExternalSignerErrors/wrong_signature_length2523=== PAUSE TestExternalSignerErrors/wrong_signature_length2524=== RUN TestExternalSignerErrors/exit_on_request2525=== CONT TestGenerateFingerprint/invalid_reference_prefix2526=== RUN TestSignErrors/nil_key2527=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2528=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2529=== CONT TestParseSigningKey/no_colon2530=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2531=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2532=== CONT TestGenerateFingerprint/no_references2533--- PASS: TestSign (0.00s)2534=== PAUSE TestExternalSignerErrors/exit_on_request2535=== PAUSE TestSignErrors/nil_key2536=== RUN TestSignErrors/nil_narinfo2537=== PAUSE TestSignErrors/nil_narinfo2538=== RUN TestSignErrors/invalid_narinfo2539=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2540=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2541=== RUN TestExternalSignerErrors/wrong_shape2542=== PAUSE TestExternalSignerErrors/wrong_shape2543=== PAUSE TestSignErrors/invalid_narinfo2544=== RUN TestSignErrors/canceled2545=== PAUSE TestSignErrors/canceled2546--- PASS: TestGenerateFingerprint (0.00s)2547 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2548 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2549 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2550 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2551 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2552 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2553 --- PASS: TestGenerateFingerprint/no_references (0.00s)2554=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2555=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2556=== RUN TestExternalSignerErrors/invalid_JSON2557=== PAUSE TestExternalSignerErrors/invalid_JSON2558=== RUN TestExternalSignerErrors/wrong_id2559=== PAUSE TestExternalSignerErrors/wrong_id2560=== RUN TestExternalSignerErrors/unrequested_key2561=== PAUSE TestExternalSignerErrors/unrequested_key2562=== RUN TestExternalSignerErrors/program_error2563=== PAUSE TestExternalSignerErrors/program_error2564=== RUN TestExternalSignerErrors/null2565=== PAUSE TestExternalSignerErrors/null2566=== RUN TestExternalSignerErrors/missing_signature_name2567=== PAUSE TestExternalSignerErrors/missing_signature_name2568=== RUN TestExternalSignerErrors/wrong_signature_name2569=== PAUSE TestExternalSignerErrors/wrong_signature_name2570=== RUN TestExternalSignerErrors/invalid_signature_base642571=== PAUSE TestExternalSignerErrors/invalid_signature_base642572=== RUN TestExternalSignerErrors/exit_at_startup2573=== CONT TestSignErrors/nil_key2574=== CONT TestSignErrors/canceled2575=== CONT TestSignErrors/invalid_narinfo2576=== CONT TestSignErrors/nil_narinfo2577--- PASS: TestParseSigningKey (0.00s)2578 --- PASS: TestParseSigningKey/wrong_length (0.00s)2579 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2580 --- PASS: TestParseSigningKey/empty_name (0.00s)2581 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2582 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2583 --- PASS: TestParseSigningKey/no_colon (0.00s)2584=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2585=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2586=== CONT TestExternalSignerRejectsInvalidPublicKey/#002587=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2588=== PAUSE TestExternalSignerErrors/exit_at_startup2589=== RUN TestExternalSignerErrors/missing_signatures2590=== PAUSE TestExternalSignerErrors/missing_signatures2591=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2592--- PASS: TestExternalSignerClose (0.00s)2593--- PASS: TestSignErrors (0.00s)2594 --- PASS: TestSignErrors/nil_key (0.00s)2595 --- PASS: TestSignErrors/canceled (0.00s)2596 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2597 --- PASS: TestSignErrors/nil_narinfo (0.00s)2598--- PASS: TestExternalSignerWrongPublicKey (0.00s)2599=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2600=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2601=== CONT TestExternalSignerErrors/null_signatures2602=== CONT TestExternalSignerErrors/exit_at_startup2603=== CONT TestExternalSignerErrors/invalid_signature_base642604=== CONT TestExternalSignerErrors/wrong_signature_name2605=== CONT TestExternalSignerErrors/missing_signatures2606=== CONT TestExternalSignerErrors/missing_signature_name2607=== CONT TestExternalSignerErrors/null2608=== CONT TestExternalSignerErrors/wrong_shape2609=== CONT TestExternalSignerErrors/too_few_signatures2610=== CONT TestExternalSignerErrors/wrong_signature_length2611=== CONT TestExternalSignerErrors/program_error2612=== CONT TestExternalSignerErrors/unrequested_key2613=== CONT TestExternalSignerErrors/wrong_signatures_shape2614=== CONT TestExternalSignerErrors/wrong_id2615=== CONT TestExternalSignerErrors/exit_on_request2616=== CONT TestExternalSignerErrors/invalid_JSON2617--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2618--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2619 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2620 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2621 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2622 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2623 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2624--- PASS: TestExternalSigner (0.01s)2625--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2626--- PASS: TestExternalSignerErrors (0.00s)2627 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2628 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2629 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2630 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2631 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2632 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2633 --- PASS: TestExternalSignerErrors/program_error (0.01s)2634 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2635 --- PASS: TestExternalSignerErrors/null (0.01s)2636 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2637 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2638 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2639 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2640 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2641 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2642 --- PASS: TestExternalSignerErrors/too_few_signatures (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--- PASS: TestServeRejectsGarbage (0.00s)2659=== RUN TestSignErrors/invalid_json2660=== PAUSE TestSignErrors/invalid_json2661=== RUN TestSignErrors/no_prefix2662=== PAUSE TestSignErrors/no_prefix2663=== RUN TestSignErrors/invalid_base642664=== PAUSE TestSignErrors/invalid_base642665=== RUN TestSignErrors/http_error2666=== PAUSE TestSignErrors/http_error2667=== CONT TestSignErrors/invalid_json2668=== CONT TestSignErrors/invalid_base642669=== CONT TestSignErrors/no_prefix2670=== CONT TestSignErrors/http_error2671--- PASS: TestServe (0.00s)2672--- PASS: TestSign (0.00s)2673--- PASS: TestSignErrors (0.00s)2674 --- PASS: TestSignErrors/no_prefix (0.00s)2675 --- PASS: TestSignErrors/invalid_json (0.00s)2676 --- PASS: TestSignErrors/http_error (0.00s)2677 --- PASS: TestSignErrors/invalid_base64 (0.00s)2678PASS