niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #400
· 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.05s)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 TestShellSplitErrors110--- PASS: TestShellSplitErrors (0.00s)111=== CONT TestPartSizeForNAR112=== RUN TestPartSizeForNAR/zero_stays_at_minimum113=== CONT TestScriptTokenEmptyCommand114--- PASS: TestScriptTokenEmptyCommand (0.00s)115=== CONT TestScriptTokenScriptFails116=== CONT TestScriptTokenBadJSON117=== CONT TestScriptTokenEmptyToken118=== CONT TestScriptTokenCachesUntilRefresh119=== CONT TestScriptTokenNoExpiryRerunsEveryCall120=== CONT TestFileTokenEmpty121=== CONT TestFileTokenMissing122=== CONT TestFileTokenReadsAndCaches123=== CONT TestStaticToken124=== CONT TestStreamPushRequestLine125=== CONT TestSetClientTLS126=== CONT TestSetClientTLSErrors127=== CONT TestStreamPushStopsWhenCanceled128=== CONT TestClientSignaturesByStorePath129=== CONT TestStreamPushBatchesUnderLoad130=== CONT TestStreamPushReportsSkippedPaths131=== CONT TestStreamPushGivesUpOnDeadServer132=== CONT TestStreamPushReportsSignatures133=== CONT TestStreamPushIsolatesFailures134=== CONT TestStreamPushReportsEveryPath135=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum136=== CONT TestEncodeNixBase32WithRealHash137--- PASS: TestScriptTokenScriptFails (0.00s)138=== CONT TestEncodeNixBase32139=== RUN TestEncodeNixBase32/test_string_hash140=== PAUSE TestEncodeNixBase32/test_string_hash141=== RUN TestEncodeNixBase32/empty_input142=== PAUSE TestEncodeNixBase32/empty_input143=== CONT TestDumpPathWriterError144--- PASS: TestScriptTokenBadJSON (0.00s)145=== CONT TestRetryTimeoutOutlastsMaxRetries146--- PASS: TestFileTokenEmpty (0.00s)147=== CONT TestDumpPathSingleFile148--- PASS: TestStaticToken (0.00s)149=== CONT TestDoWithRetry_BodyReplayedViaGetBody150--- PASS: TestClientSignaturesByStorePath (0.00s)151=== CONT TestDumpPathMatchesNix152--- PASS: TestStreamPushStopsWhenCanceled (0.00s)153--- PASS: TestFileTokenMissing (0.00s)154=== CONT TestUploadMultipart_SupersededByPeer155=== RUN TestUploadMultipart_SupersededByPeer/exists156=== PAUSE TestUploadMultipart_SupersededByPeer/exists157--- PASS: TestFileTokenReadsAndCaches (0.00s)158=== RUN TestUploadMultipart_SupersededByPeer/missing159=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1602026/10/08 17:08:07 ERROR Upload failed error=boom count=1161--- PASS: TestScriptTokenEmptyToken (0.01s)1622026/10/08 17:08:07 ERROR Upload failed error="connection refused" count=201632026/10/08 17:08:07 ERROR Server seems unavailable, giving up on batch untried=17164=== PAUSE TestUploadMultipart_SupersededByPeer/missing165=== CONT TestCaseHackSuffix1662026/10/08 17:08:07 WARN Rate limiter enabled after throttle name=server-test rate=5167=== RUN TestPartSizeForNAR/small_stays_at_minimum168--- PASS: TestEncodeNixBase32WithRealHash (0.00s)169--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)170=== CONT TestRateLimiterFeedback171=== RUN TestRateLimiterFeedback/429_enables_limiter172=== RUN TestSetClientTLSErrors/missing_cert_file173=== PAUSE TestSetClientTLSErrors/missing_cert_file1742026/10/08 17:08:07 ERROR Upload failed error=boom count=11752026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:383211762026/10/08 17:08:07 WARN Rate limiter enabled after throttle name=server-test rate=51772026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:35429178=== CONT TestResolveStorePath179=== CONT TestParsePathInfoJSON180=== RUN TestParsePathInfoJSON/Nix_format181=== PAUSE TestParsePathInfoJSON/Nix_format182=== RUN TestParsePathInfoJSON/Lix_format183=== PAUSE TestParsePathInfoJSON/Lix_format184=== PAUSE TestPartSizeForNAR/small_stays_at_minimum185=== CONT TestPathInfoCACompatibility186=== PAUSE TestRateLimiterFeedback/429_enables_limiter187=== RUN TestSetClientTLSErrors/missing_key_file188=== CONT TestUploadMultipart_PartsInParallel189--- PASS: TestStreamPushReportsSignatures (0.00s)190=== CONT TestFilterOversizedClosures191=== CONT TestParsePathInfoJSONMultiplePaths192=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica193--- PASS: TestStreamPushReportsSkippedPaths (0.00s)194=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1952026/10/08 17:08:07 ERROR Upload failed error="bad path" count=2196=== RUN TestFilterOversizedClosures/no_limit_keeps_everything197=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths198=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum199=== RUN TestRateLimiterFeedback/503_enables_limiter200=== RUN TestPathInfoCACompatibility/null_ca_field2012026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:38321202=== PAUSE TestPathInfoCACompatibility/null_ca_field2032026/10/08 17:08:07 WARN Rate limiter backed off name=server-test rate=5204=== PAUSE TestSetClientTLSErrors/missing_key_file2052026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:35429206--- PASS: TestStreamPushReportsEveryPath (0.00s)207=== RUN TestParsePathInfoJSON/empty_input208=== CONT TestPathInfoHashCompatibility209=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything210=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun211=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped212=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum213=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped214=== RUN TestFilterOversizedClosures/all_closures_skipped215=== PAUSE TestFilterOversizedClosures/all_closures_skipped216=== CONT TestGetStorePathHash217=== CONT TestRegisterUploadedObjectReusesConnections2182026/10/08 17:08:07 INFO Garbage collection started2192026/10/08 17:08:07 INFO Garbage collection started220=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths221=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths222=== PAUSE TestRateLimiterFeedback/503_enables_limiter223=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter224=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter225=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter226=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter227=== CONT TestUploadMultipart_SupersededByPeer/exists228=== CONT TestUploadMultipart_SupersededByPeer/missing229=== RUN TestSetClientTLS/rejects_connection_without_client_cert230--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)231=== RUN TestPathInfoCACompatibility/old_string_format_-_text232=== PAUSE TestParsePathInfoJSON/empty_input233=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)234=== RUN TestSetClientTLSErrors/missing_ca_file235=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts236=== RUN TestGetStorePathHash/valid_store_path237=== CONT TestEncodeNixBase32/test_string_hash238=== CONT TestConvertHashToNix32239=== CONT TestEncodeNixBase32/empty_input240=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text241=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive2422026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:38321243=== PAUSE TestSetClientTLSErrors/missing_ca_file244=== RUN TestSetClientTLSErrors/invalid_ca_file245=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2462026/10/08 17:08:07 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=2000247=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths248=== CONT TestRateLimiterFeedback/429_enables_limiter249=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths250=== RUN TestParsePathInfoJSON/whitespace_only251=== PAUSE TestParsePathInfoJSON/whitespace_only252=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter253=== CONT TestRateLimiterFeedback/503_enables_limiter254=== PAUSE TestSetClientTLSErrors/invalid_ca_file255=== CONT TestSetClientTLSErrors/missing_cert_file256=== RUN TestParsePathInfoJSON/invalid_JSON257=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive2582026/10/08 17:08:07 WARN Rate limiter enabled after throttle name=server-test rate=5259--- PASS: TestDoServerRequestAttachesToken (0.01s)2602026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:40673261=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts262=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)2632026/10/08 17:08:07 WARN Rate limiter enabled after throttle name=server-test rate=5264=== PAUSE TestGetStorePathHash/valid_store_path2652026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:36117266=== CONT TestFilterOversizedClosures/no_limit_keeps_everything2672026/10/08 17:08:07 WARN Rate limiter backed off name=server-test rate=5268=== RUN TestConvertHashToNix32/SRI_format_to_Nix32269=== CONT TestSetClientTLSErrors/missing_key_file2702026/10/08 17:08:07 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=0271=== CONT TestFilterOversizedClosures/all_closures_skipped2722026/10/08 17:08:07 WARN Rate limiter backed off name=server-test rate=52732026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:38321274=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert2752026/10/08 17:08:07 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=50276=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter277=== PAUSE TestParsePathInfoJSON/invalid_JSON278=== CONT TestSetClientTLSErrors/invalid_ca_file279=== RUN TestPathInfoCACompatibility/new_structured_format_-_text280=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text281=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method282--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)283--- PASS: TestStreamPushIsolatesFailures (0.01s)284--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)285=== RUN TestPartSizeForNAR/1_TiB286=== CONT TestSetClientTLSErrors/missing_ca_file287=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon288=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon289=== RUN TestGetStorePathHash/basename_without_hyphen_should_error290=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32291=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA292=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA293=== CONT TestParsePathInfoJSON/Nix_format294=== RUN TestSetClientTLS/preserves_debug_logging_transport295=== CONT TestParsePathInfoJSON/invalid_JSON296=== CONT TestParsePathInfoJSON/whitespace_only297=== CONT TestParsePathInfoJSON/empty_input298=== CONT TestParsePathInfoJSON/Lix_format299=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method300--- PASS: TestResolveStorePath (0.00s)301=== PAUSE TestPartSizeForNAR/1_TiB302=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error303=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error304=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error305=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI306=== RUN TestConvertHashToNix32/already_Nix32_format307=== PAUSE TestSetClientTLS/preserves_debug_logging_transport3082026/10/08 17:08:07 WARN Garbage collection finished on another replica. Its statistics are not available here309=== CONT TestSetClientTLS/rejects_connection_without_client_cert3102026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:38321311=== CONT TestSetClientTLS/preserves_debug_logging_transport312=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method313=== CONT TestPathInfoCACompatibility/new_structured_format_-_text314=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive315=== CONT TestPathInfoCACompatibility/old_string_format_-_text316--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)317=== RUN TestPartSizeForNAR/5_TiB_S3_max_object318=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object319=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error320=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI3212026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:38321322=== PAUSE TestConvertHashToNix32/already_Nix32_format323=== CONT TestPathInfoCACompatibility/null_ca_field324=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA325--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)326=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error327=== CONT TestGetStorePathHash/valid_store_path328=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error329=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error330=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512331=== RUN TestConvertHashToNix32/invalid_format332=== PAUSE TestConvertHashToNix32/invalid_format333--- PASS: TestDumpPathSingleFile (0.04s)334--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)335 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)336 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)3372026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:38321338=== RUN TestPartSizeForNAR/capped_at_5_GiB339=== CONT TestGetStorePathHash/basename_without_hyphen_should_error340=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512341=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)342=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512343=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI344=== CONT TestConvertHashToNix32/invalid_format345=== CONT TestConvertHashToNix32/already_Nix32_format346--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)347--- PASS: TestEncodeNixBase32 (0.00s)348 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)349 --- PASS: TestEncodeNixBase32/empty_input (0.00s)350--- PASS: TestCaseHackSuffix (0.04s)351=== PAUSE TestPartSizeForNAR/capped_at_5_GiB352=== CONT TestPartSizeForNAR/zero_stays_at_minimum3532026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:38321354=== CONT TestConvertHashToNix32/SRI_format_to_Nix32355=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon356--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)357 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)358 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)359=== CONT TestPartSizeForNAR/1_TiB360=== CONT TestPartSizeForNAR/capped_at_5_GiB361=== CONT TestPartSizeForNAR/5_TiB_S3_max_object362=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum363=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts364=== CONT TestPartSizeForNAR/small_stays_at_minimum365--- PASS: TestFilterOversizedClosures (0.00s)366 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)367 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)368 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)369--- PASS: TestRateLimiterFeedback (0.04s)370 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)371 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)372 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)373 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)374--- PASS: TestParsePathInfoJSON (0.03s)375 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)376 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)377 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)378 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)379 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)3802026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:38321381--- PASS: TestGetStorePathHash (0.03s)382 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)383 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)384 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)385 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)386--- PASS: TestSetClientTLSErrors (0.04s)387 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)388 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)389 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)391--- PASS: TestPathInfoCACompatibility (0.03s)392 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)393 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)394 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)395 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)396 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)397--- PASS: TestConvertHashToNix32 (0.00s)398 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)399 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)400 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)401--- PASS: TestPathInfoHashCompatibility (0.04s)402 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)403 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)404 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)405 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)406--- PASS: TestPartSizeForNAR (0.05s)407 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)408 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)409 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)410 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)411 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)412 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)413 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)4142026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:383214152026/10/08 17:08:07 http: TLS handshake error from 127.0.0.1:46060: remote error: tls: bad certificate416--- PASS: TestSetClientTLS (0.04s)417 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)418 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)419 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)420--- PASS: TestStreamPushRequestLine (0.05s)4212026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:383214222026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:383214232026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:383214242026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:383214252026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:383214262026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:383214272026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:38321428--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)4292026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:383214302026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:38321431--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.07s)432--- PASS: TestDumpPathWriterError (0.08s)433--- PASS: TestStreamPushBatchesUnderLoad (0.10s)434--- PASS: TestDumpPathMatchesNix (0.11s)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/postgres743898089/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/postgres743898089/data -l logfile start465466/build/postgres743898089:5432 - no response4672026-10-08 17:08:09.401 UTC [128] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4682026-10-08 17:08:09.401 UTC [128] LOG: listening on Unix socket "/build/postgres743898089/.s.PGSQL.5432"4692026-10-08 17:08:09.405 UTC [135] LOG: database system was shut down at 2026-10-08 17:08:09 UTC4702026-10-08 17:08:09.409 UTC [128] LOG: database system is ready to accept connections471/build/postgres743898089: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 17:08:09 INFO lead: acquired remote=192.0.2.1:12345202026/10/08 17:08:10 INFO lead: released remote=192.0.2.1:12345212026/10/08 17:08:10 INFO lead: acquired remote=192.0.2.1:12345222026/10/08 17:08:11 INFO lead: released remote=192.0.2.1:1234523--- PASS: TestLeadIncumbentWinsAfterRestart (1.90s)524=== RUN TestLeadIncumbentAnnouncesAtOnce525=== PAUSE TestLeadIncumbentAnnouncesAtOnce526=== RUN TestLeadEndsOnShutdown527=== PAUSE TestLeadEndsOnShutdown528=== RUN TestLeadEndsWhenItsConnectionHangs5292026/10/08 17:08:11 INFO lead: acquired remote=192.0.2.1:12345302026-10-08 17:08:13.225 UTC [575] FATAL: terminating connection due to administrator command5312026/10/08 17:08:13 INFO lead: acquired remote=192.0.2.1:12345322026/10/08 17:08:14 WARN lead: lock connection lost error="timeout: context deadline exceeded"5332026/10/08 17:08:14 INFO lead: released remote=192.0.2.1:12345342026/10/08 17:08:14 INFO lead: released remote=192.0.2.1:1234535--- PASS: TestLeadEndsWhenItsConnectionHangs (2.91s)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 17:08:14 INFO Starting HTTP server address=127.0.0.1:397716362026/10/08 17:08:14 INFO Starting HTTP server address=proxy.sock6372026/10/08 17:08:14 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6382026/10/08 17:08:14 INFO Shutdown signal received, draining in-flight requests timeout=10s639--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.11s)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 17:08:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7082026/10/08 17:08:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7092026/10/08 17:08:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7102026/10/08 17:08:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7112026/10/08 17:08:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7122026/10/08 17:08:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7132026/10/08 17:08:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7142026/10/08 17:08:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7152026/10/08 17:08:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7162026/10/08 17:08:14 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 TestService_AuthMiddleware741=== CONT TestReadProxyDisabled742=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded743=== CONT TestReadProxyRangeRequest744=== CONT TestCompleteMultipartUnregistered745=== CONT TestService_verifyS3Integrity746=== CONT TestService_createPendingClosureHandler747=== CONT TestReadRedirectKeepsNarinfoProxied748=== CONT TestReadRedirectNar749=== CONT TestService_cleanupPendingClosuresHandler750=== CONT TestUploadHandlersRejectOversizedBody751=== CONT TestUploadHandlersRejectInvalidKeys752=== CONT TestIsValidUploadKey753=== RUN TestIsValidUploadKey/narinfo754=== CONT TestPendingClosureWriteTimeout755=== CONT TestProxyWriteTimeout756=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle757=== CONT TestSkippedUploadsHandler758=== CONT TestParseSize759=== CONT TestService_Rustfstest760=== CONT TestPresignedUploadRegisteredBeforeCommit761=== CONT TestCompletedNarNotReofferedAcrossClosures762=== CONT TestCompleteMultipartUpload_ErrorButObjectExists763=== CONT TestRedundantMultipartUpload764=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT765=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info766=== PAUSE TestIsValidUploadKey/narinfo767=== RUN TestPendingClosureWriteTimeout/empty768=== RUN TestProxyWriteTimeout/narinfo769--- PASS: TestParseSize (0.00s)7702026/10/08 17:08:14 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000771=== CONT TestPush_SignsNarinfosOfItsPendingObjects772=== RUN TestIsValidUploadKey/nar_zst773=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info774=== PAUSE TestPendingClosureWriteTimeout/empty775=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal776=== RUN TestPendingClosureWriteTimeout/400_objects777=== PAUSE TestProxyWriteTimeout/narinfo778=== RUN TestProxyWriteTimeout/1_GiB_nar779=== PAUSE TestProxyWriteTimeout/1_GiB_nar780=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal781=== PAUSE TestPendingClosureWriteTimeout/400_objects782=== PAUSE TestIsValidUploadKey/nar_zst783=== RUN TestProxyWriteTimeout/10_GiB_nar784=== PAUSE TestProxyWriteTimeout/10_GiB_nar785=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key786=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key787=== RUN TestPendingClosureWriteTimeout/670k_objects788=== RUN TestIsValidUploadKey/nar_xz789=== PAUSE TestIsValidUploadKey/nar_xz790--- PASS: TestSkippedUploadsHandler (0.13s)791=== CONT TestPush_RejectsBadRequests792=== RUN TestProxyWriteTimeout/unknown_size793=== PAUSE TestProxyWriteTimeout/unknown_size794=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key795=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key796=== PAUSE TestPendingClosureWriteTimeout/670k_objects797=== RUN TestIsValidUploadKey/nar_plain798=== PAUSE TestIsValidUploadKey/nar_plain799=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit800=== CONT TestPush_RootsAreLockedInByteOrder801=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline802=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline803=== RUN TestIsValidUploadKey/listing804=== PAUSE TestIsValidUploadKey/listing805=== CONT TestPush_CompleteWaitsForCleanupOfThePush806=== RUN TestIsValidUploadKey/build_log807=== PAUSE TestIsValidUploadKey/build_log808=== RUN TestIsValidUploadKey/build_log_home-manager_file809=== PAUSE TestIsValidUploadKey/build_log_home-manager_file810=== RUN TestIsValidUploadKey/build_log_plus_in_name811=== PAUSE TestIsValidUploadKey/build_log_plus_in_name812=== RUN TestIsValidUploadKey/build_log_question_mark813=== PAUSE TestIsValidUploadKey/build_log_question_mark814=== RUN TestIsValidUploadKey/build_log_equals815=== PAUSE TestIsValidUploadKey/build_log_equals816=== RUN TestIsValidUploadKey/realisation817=== PAUSE TestIsValidUploadKey/realisation818=== RUN TestIsValidUploadKey/realisation_plus_in_output819=== PAUSE TestIsValidUploadKey/realisation_plus_in_output820=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts821=== RUN TestIsValidUploadKey/nix-cache-info822=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts823=== PAUSE TestIsValidUploadKey/nix-cache-info824=== RUN TestIsValidUploadKey/index.html825=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure826=== PAUSE TestIsValidUploadKey/index.html827=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure828=== RUN TestIsValidUploadKey/narinfo_key,_nar_type829=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type830=== RUN TestIsValidUploadKey/nar_key,_narinfo_type831=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type832=== RUN TestIsValidUploadKey/listing_key,_narinfo_type833=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type834=== RUN TestIsValidUploadKey/traversal835=== PAUSE TestIsValidUploadKey/traversal836=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart837=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart838=== RUN TestIsValidUploadKey/traversal_nar839=== PAUSE TestIsValidUploadKey/traversal_nar840=== CONT TestPush_RepeatedRootCommitsOnce841=== RUN TestIsValidUploadKey/absolute842=== PAUSE TestIsValidUploadKey/absolute843=== RUN TestIsValidUploadKey/empty_key844=== PAUSE TestIsValidUploadKey/empty_key845=== RUN TestIsValidUploadKey/unknown_type846=== PAUSE TestIsValidUploadKey/unknown_type847=== CONT TestPush_CompleteCommitsEveryRoot8482026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures849--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.56s)850=== CONT TestPush_OverlappingRootsStoreOneRowPerKey8512026/10/08 17:08:15 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"852--- PASS: TestService_AuthMiddleware (0.56s)853=== CONT TestReadRedirectUsesPublicS3URL854--- PASS: TestService_Rustfstest (0.56s)855=== CONT TestIsValidCachePath856=== RUN TestIsValidCachePath/narinfo857=== PAUSE TestIsValidCachePath/narinfo858=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars859=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars860=== RUN TestIsValidCachePath/nar_zst861=== PAUSE TestIsValidCachePath/nar_zst862=== RUN TestIsValidCachePath/nar_xz863=== PAUSE TestIsValidCachePath/nar_xz864=== RUN TestIsValidCachePath/nar_bz2865=== PAUSE TestIsValidCachePath/nar_bz2866=== RUN TestIsValidCachePath/nar_uncompressed867=== PAUSE TestIsValidCachePath/nar_uncompressed868=== RUN TestIsValidCachePath/ls869=== PAUSE TestIsValidCachePath/ls870=== RUN TestIsValidCachePath/log871=== PAUSE TestIsValidCachePath/log872=== RUN TestIsValidCachePath/realisation873=== PAUSE TestIsValidCachePath/realisation874=== RUN TestIsValidCachePath/nix-cache-info875=== PAUSE TestIsValidCachePath/nix-cache-info876=== RUN TestIsValidCachePath/index.html877=== PAUSE TestIsValidCachePath/index.html878=== RUN TestIsValidCachePath/traversal_parent879=== PAUSE TestIsValidCachePath/traversal_parent880=== RUN TestIsValidCachePath/traversal_in_middle881=== PAUSE TestIsValidCachePath/traversal_in_middle882=== RUN TestIsValidCachePath/invalid_char_e883=== PAUSE TestIsValidCachePath/invalid_char_e884=== RUN TestIsValidCachePath/invalid_char_u885=== PAUSE TestIsValidCachePath/invalid_char_u886=== RUN TestIsValidCachePath/random_path887=== PAUSE TestIsValidCachePath/random_path888=== RUN TestIsValidCachePath/empty889=== PAUSE TestIsValidCachePath/empty890=== RUN TestIsValidCachePath/leading_slash891=== PAUSE TestIsValidCachePath/leading_slash892=== RUN TestIsValidCachePath/wrong_extension893=== PAUSE TestIsValidCachePath/wrong_extension894=== RUN TestIsValidCachePath/short_hash895=== PAUSE TestIsValidCachePath/short_hash896=== CONT TestReadProxyRootRedirectsToIndexHTML897--- PASS: TestReadProxyDisabled (0.60s)898=== CONT TestReadProxyConditionalGet899--- PASS: TestReadProxyRangeRequest (0.64s)900=== CONT TestReadProxyOutlastsServerWriteTimeout9012026/10/08 17:08:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9022026/10/08 17:08:15 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst903--- PASS: TestCompleteMultipartUnregistered (0.65s)904=== CONT TestReadProxyHead9052026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures906--- PASS: TestReadRedirectNar (0.70s)907=== CONT TestReadProxyInvalidPath908--- PASS: TestReadRedirectKeepsNarinfoProxied (0.74s)909=== CONT TestReadProxy4049102026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9112026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9122026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9132026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9142026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9152026/10/08 17:08:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete916--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.81s)917=== CONT TestReadProxyNarStreaming9182026/10/08 17:08:15 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTE0NmQ5ZGMtZGE1ZS00MWE2LThlOTQtMmJlYjFiOGNkMWU1LjZiMzhmNjkwLTIzZmEtNDExYy05OGRlLTcyMGQ2YzEyNzk4ZXgxNzkxNDc5Mjk1NzcxNjIzMzQz9192026/10/08 17:08:15 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTE0NmQ5ZGMtZGE1ZS00MWE2LThlOTQtMmJlYjFiOGNkMWU1LjZiMzhmNjkwLTIzZmEtNDExYy05OGRlLTcyMGQ2YzEyNzk4ZXgxNzkxNDc5Mjk1NzcxNjIzMzQz parts=19202026/10/08 17:08:15 INFO Received push request method=POST path=/api/pushes921--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.83s)922=== CONT TestReadProxyContentNegotiation9232026/10/08 17:08:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9242026/10/08 17:08:15 INFO Signed narinfos id=1 count=19252026/10/08 17:08:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9262026/10/08 17:08:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9272026/10/08 17:08:15 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9282026/10/08 17:08:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9292026/10/08 17:08:15 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9302026/10/08 17:08:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9312026/10/08 17:08:15 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19322026/10/08 17:08:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9332026/10/08 17:08:15 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo934--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.84s)935=== CONT TestReadProxyNarinfoAlreadyDecompressed9362026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9372026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9382026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9392026/10/08 17:08:15 INFO Received cleanup request method=DELETE path=/api/pending_closures9402026/10/08 17:08:15 INFO Aborted multipart uploads count=0 kept=09412026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9422026/10/08 17:08:15 INFO Received cleanup request method=DELETE path=/api/pending_closures9432026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9442026/10/08 17:08:15 INFO Aborted multipart uploads count=1 kept=09452026/10/08 17:08:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9462026-10-08 17:08:15.932 UTC [663] ERROR: Closure does not exist: id=19472026-10-08 17:08:15.932 UTC [663] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9482026-10-08 17:08:15.932 UTC [663] STATEMENT: -- name: CommitPendingClosure :one949 SELECT commit_pending_closure($1::bigint)::bigint950 951--- PASS: TestService_cleanupPendingClosuresHandler (0.95s)952=== CONT TestReadProxyNarinfo9532026/10/08 17:08:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9542026/10/08 17:08:15 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9552026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9562026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures957--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.97s)958=== CONT TestCreatePin_ReservedPins959=== RUN TestPush_RejectsBadRequests/bad_root960=== PAUSE TestPush_RejectsBadRequests/bad_root961=== RUN TestPush_RejectsBadRequests/root_not_in_objects962=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects963=== RUN TestPush_RejectsBadRequests/no_roots964=== PAUSE TestPush_RejectsBadRequests/no_roots965=== RUN TestPush_RejectsBadRequests/no_objects966=== PAUSE TestPush_RejectsBadRequests/no_objects967=== CONT TestParseSingleRange968=== RUN TestParseSingleRange/none969=== PAUSE TestParseSingleRange/none970=== RUN TestParseSingleRange/unknown_unit971=== PAUSE TestParseSingleRange/unknown_unit972=== RUN TestParseSingleRange/multi-range_ignored973=== PAUSE TestParseSingleRange/multi-range_ignored974=== RUN TestParseSingleRange/malformed_no_dash975=== PAUSE TestParseSingleRange/malformed_no_dash976=== RUN TestParseSingleRange/malformed_both_empty977=== PAUSE TestParseSingleRange/malformed_both_empty978=== RUN TestParseSingleRange/malformed_end_before_start979=== PAUSE TestParseSingleRange/malformed_end_before_start980=== RUN TestParseSingleRange/closed981=== PAUSE TestParseSingleRange/closed982=== RUN TestParseSingleRange/open-ended983=== PAUSE TestParseSingleRange/open-ended984=== RUN TestParseSingleRange/end_clamped_to_size985=== PAUSE TestParseSingleRange/end_clamped_to_size986=== RUN TestParseSingleRange/suffix987=== PAUSE TestParseSingleRange/suffix988=== RUN TestParseSingleRange/suffix_exceeds_size989=== PAUSE TestParseSingleRange/suffix_exceeds_size990=== RUN TestParseSingleRange/single_byte991=== PAUSE TestParseSingleRange/single_byte992=== RUN TestParseSingleRange/start_past_EOF993=== PAUSE TestParseSingleRange/start_past_EOF994=== RUN TestParseSingleRange/start_far_past_EOF995=== PAUSE TestParseSingleRange/start_far_past_EOF996=== CONT TestPresentNotReportedWhileGCDeletesClosure997=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale998=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale999=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1000=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1001=== CONT TestPresentRefreshesOnlyStaleClosures10022026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes10032026/10/08 17:08:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44385/oidc10042026/10/08 17:08:16 INFO Received complete push request method=POST path=/api/pushes/1/complete10052026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes10062026/10/08 17:08:16 INFO Completed push id=1 objects=4 duration=9.240627ms10072026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes10082026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes10092026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes10102026/10/08 17:08:16 INFO Aborted multipart uploads count=0 kept=010112026-10-08 17:08:16.120 UTC [720] ERROR: could not obtain lock on row in relation "closures"10122026-10-08 17:08:16.120 UTC [720] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10132026-10-08 17:08:16.120 UTC [720] ERROR: could not obtain lock on row in relation "closures"10142026-10-08 17:08:16.120 UTC [720] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10152026-10-08 17:08:16.121 UTC [720] ERROR: could not obtain lock on row in relation "closures"10162026-10-08 17:08:16.121 UTC [720] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10172026-10-08 17:08:16.121 UTC [720] ERROR: could not obtain lock on row in relation "closures"10182026-10-08 17:08:16.121 UTC [720] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10192026-10-08 17:08:16.121 UTC [720] ERROR: could not obtain lock on row in relation "closures"10202026-10-08 17:08:16.121 UTC [720] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10212026/10/08 17:08:16 WARN Force mode enabled - objects will be deleted immediately without grace period1022--- PASS: TestPush_RootsAreLockedInByteOrder (1.01s)1023=== CONT TestPresentReportsOnlyClosureRoots10242026/10/08 17:08:16 INFO Received complete push request method=POST path=/api/pushes/1/complete10252026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes10262026/10/08 17:08:16 INFO Completed push id=1 objects=6 duration=8.776468ms1027--- PASS: TestPush_CompleteCommitsEveryRoot (0.83s)1028=== CONT TestObjectStatsLargeCommit10292026/10/08 17:08:16 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=010302026/10/08 17:08:16 INFO Vacuumed table table=pending_closures10312026/10/08 17:08:16 INFO Vacuumed table table=pending_objects10322026/10/08 17:08:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10332026/10/08 17:08:16 INFO Vacuumed table table=multipart_uploads10342026/10/08 17:08:16 INFO Vacuumed table table=closures10352026/10/08 17:08:16 INFO Received complete push request method=POST path=/api/pushes/1/complete10362026/10/08 17:08:16 INFO Vacuumed table table=objects10372026/10/08 17:08:16 INFO Received complete push request method=POST path=/api/pushes/2/complete10382026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes10392026/10/08 17:08:16 INFO Completed push id=2 objects=4 duration=9.981747ms10402026/10/08 17:08:16 INFO Completed push id=1 objects=4 duration=14.4746ms1041--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.05s)1042=== CONT TestOrphanedObjectsGCStressTest1043--- PASS: TestPush_RepeatedRootCommitsOnce (0.87s)1044=== CONT TestOrphanedObjectsGC10452026/10/08 17:08:16 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZTE0NmQ5ZGMtZGE1ZS00MWE2LThlOTQtMmJlYjFiOGNkMWU1LjJiZjkwOGQ0LWQ0OWQtNDljNi05OTk0LTQxMmYwN2NmMTA3MHgxNzkxNDc5Mjk1NjY1MjIxNzU3 parts=1010462026/10/08 17:08:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10472026/10/08 17:08:16 INFO Completed upload id=1 objects=2 duration=10.219266ms10482026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures10492026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures1050--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.68s)1051=== CONT TestGCSweepDeliversEachKeyOnce10522026/10/08 17:08:16 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10532026/10/08 17:08:16 WARN Found objects in DB but missing from S3, will re-upload count=11054--- PASS: TestService_verifyS3Integrity (1.23s)1055=== CONT TestMultipartCleanup1056--- PASS: TestReadRedirectUsesPublicS3URL (0.69s)1057=== CONT TestServerTLSConfig1058=== RUN TestServerTLSConfig/no_client_CA1059=== PAUSE TestServerTLSConfig/no_client_CA1060=== RUN TestServerTLSConfig/missing_CA_file1061=== PAUSE TestServerTLSConfig/missing_CA_file1062=== RUN TestServerTLSConfig/not_a_PEM_file1063=== PAUSE TestServerTLSConfig/not_a_PEM_file1064=== CONT TestService_NativeMTLS10652026/10/08 17:08:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1066--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.68s)1067=== CONT TestMetricsCommit10682026/10/08 17:08:16 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZTE0NmQ5ZGMtZGE1ZS00MWE2LThlOTQtMmJlYjFiOGNkMWU1LmE3NTA0MzVlLTZkNTQtNDA3NS1hMmExLTc5YTcyZjQ4NzFmM3gxNzkxNDc5Mjk1NzQyMDkyNTkz parts=1010692026/10/08 17:08:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1070--- PASS: TestReadProxyConditionalGet (0.70s)1071=== CONT TestMetricsInventory10722026/10/08 17:08:16 INFO Completed upload id=1 objects=2 duration=7.732499ms10732026/10/08 17:08:16 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010742026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures10752026/10/08 17:08:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures10762026/10/08 17:08:16 INFO Aborted multipart uploads count=0 kept=010772026/10/08 17:08:16 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=010782026/10/08 17:08:16 INFO Vacuumed table table=pending_closures10792026/10/08 17:08:16 INFO Vacuumed table table=pending_objects1080--- PASS: TestReadProxyHead (0.71s)1081=== CONT TestNARDeduplicationMetadataUploadBug10822026/10/08 17:08:16 INFO Vacuumed table table=multipart_uploads10832026/10/08 17:08:16 INFO Vacuumed table table=closures10842026/10/08 17:08:16 INFO Vacuumed table table=objects1085--- PASS: TestReadProxyInvalidPath (0.68s)1086=== CONT TestCreatePendingClosureRejectsOversizedNAR10872026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures1088--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1089=== CONT TestCacheConfigHandlerMaxNarSize1090--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1091=== CONT TestGenerateLandingPage1092--- PASS: TestGenerateLandingPage (0.00s)1093=== CONT TestService_readinessHandler10942026-10-08 17:08:16.368 UTC [715] ERROR: Push does not exist: id=110952026-10-08 17:08:16.368 UTC [715] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10962026-10-08 17:08:16.368 UTC [715] STATEMENT: SELECT commit_push($1)1097--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.25s)1098=== CONT TestService_healthCheckHandler10992026/10/08 17:08:16 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001100--- PASS: TestService_createPendingClosureHandler (1.41s)1101=== CONT TestGracefulShutdownDrainsInflight11022026/10/08 17:08:16 INFO Starting HTTP server address=127.0.0.1:4329111032026/10/08 17:08:16 INFO Shutdown signal received, draining in-flight requests timeout=10s1104--- PASS: TestReadProxy404 (0.70s)1105=== CONT TestGCTaskStore_Fail1106--- PASS: TestGCTaskStore_Fail (0.00s)1107=== CONT TestGCTaskStore_PhaseUpdates1108--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1109=== CONT TestGCTaskStore_CompletedAllowsNewTask1110--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1111=== CONT TestGCTaskStore_GetReturnsLatest1112--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1113=== CONT TestGCTaskStore_GetEmpty1114--- PASS: TestGCTaskStore_GetEmpty (0.00s)1115=== CONT TestGCTaskStore_ConflictDifferentParams1116--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1117=== CONT TestGCTaskStore_DeduplicateSameParams1118--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1119=== CONT TestGCTaskStore_StartNew1120--- PASS: TestGCTaskStore_StartNew (0.00s)1121=== CONT TestGCEndsOnShutdown1122=== RUN TestGCEndsOnShutdown/before_the_run1123=== PAUSE TestGCEndsOnShutdown/before_the_run1124=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1125=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1126=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1127=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1128=== CONT TestCommitRacingPendingCleanupKeepsObjects1129--- PASS: TestReadProxyNarStreaming (0.62s)1130=== CONT TestPushWaitsForSweepHoldingRow1131--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.62s)1132=== CONT TestSweepRechecksPendingAfterLocking1133--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1134=== CONT TestGetExistingObjectsLocksRows11352026/10/08 17:08:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11362026/10/08 17:08:16 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZTE0NmQ5ZGMtZGE1ZS00MWE2LThlOTQtMmJlYjFiOGNkMWU1LjcyZjU1YjlhLWI0ZjctNGIxYi1hM2YxLTNkNDJiYjMwZGRlMXgxNzkxNDc5Mjk1ODg1MDExMzk5 parts=1211372026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures11382026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures11392026/10/08 17:08:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1140--- PASS: TestReadProxyContentNegotiation (0.72s)1141=== CONT TestRegisterCompletedObjectNeedsPendingRow1142--- PASS: TestPresentRefreshesOnlyStaleClosures (0.57s)1143=== CONT TestSweepSkipsRowsLockedByPush11442026/10/08 17:08:16 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZTE0NmQ5ZGMtZGE1ZS00MWE2LThlOTQtMmJlYjFiOGNkMWU1LjQ4YTgzM2Q0LWJhNDQtNDNmZC1hMTIwLThjY2YxN2E2YzdkYngxNzkxNDc5Mjk1OTY4MTEwODk2 parts=1211452026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures1146--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.58s)1147=== CONT TestFailedS3DeleteKeepsTombstone11482026/10/08 17:08:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11492026/10/08 17:08:16 WARN Refused reserved pin name=worker-x86_64-linux11502026/10/08 17:08:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11512026/10/08 17:08:16 INFO Received create pin request method=POST path=/api/pins/my-app11522026/10/08 17:08:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1153--- PASS: TestCreatePin_ReservedPins (0.62s)1154=== CONT TestForceGCDuringPushOffersSweptObject1155=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1156=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1157=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1158=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1159=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection11602026/10/08 17:08:16 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1161--- PASS: TestReadProxyNarinfo (0.68s)1162=== CONT TestPendingCleanupUsesOneCutoff1163--- PASS: TestPresentReportsOnlyClosureRoots (0.50s)1164=== CONT TestClientPushesUseOnePush11652026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures11662026/10/08 17:08:16 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11672026/10/08 17:08:16 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1168--- PASS: TestService_NativeMTLS (0.60s)1169=== CONT TestTombstonedObjectOfferedWithoutWaiting11702026/10/08 17:08:16 INFO Aborted multipart uploads count=0 kept=011712026/10/08 17:08:16 WARN Force mode enabled - objects will be deleted immediately without grace period11722026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes11732026/10/08 17:08:16 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=011742026/10/08 17:08:16 INFO Vacuumed table table=pending_closures11752026/10/08 17:08:16 INFO Vacuumed table table=pending_objects11762026/10/08 17:08:16 INFO Vacuumed table table=multipart_uploads11772026/10/08 17:08:16 INFO Vacuumed table table=closures11782026/10/08 17:08:16 INFO Vacuumed table table=objects1179--- PASS: TestGCSweepDeliversEachKeyOnce (0.66s)1180=== CONT TestGCSweepSkipsPendingObjects11812026/10/08 17:08:16 INFO Received cleanup request method=DELETE path=/api/pending_closures11822026/10/08 17:08:16 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket46/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11832026/10/08 17:08:16 INFO Aborted multipart uploads count=0 kept=111842026/10/08 17:08:16 INFO Received complete push request method=POST path=/api/pushes/1/complete11852026/10/08 17:08:16 INFO Received cleanup request method=DELETE path=/api/pending_closures11862026/10/08 17:08:16 INFO Aborted multipart uploads count=1 kept=011872026/10/08 17:08:17 INFO Completed push id=1 objects=4 duration=198.76143ms1188--- PASS: TestMultipartCleanup (0.89s)1189=== CONT TestDeduplicatedObjectsRecordedAsPending11902026/10/08 17:08:17 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11912026/10/08 17:08:17 INFO Completed upload id=2 objects=2 duration=3.092286ms1192--- PASS: TestMetricsInventory (0.85s)1193=== CONT TestPushDedupSurvivesConcurrentGC1194--- PASS: TestMetricsCommit (0.89s)1195=== CONT TestGCMetrics11962026/10/08 17:08:17 WARN readiness check failed error="closed pool"1197--- PASS: TestService_readinessHandler (0.80s)1198=== CONT TestGCBugBareHashReferences1199=== NAME TestNARDeduplicationMetadataUploadBug1200 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1979260354/001/store/9pnik44rw32xk7f3mwxdsf4gq0k3cpar-file1.txt1201--- PASS: TestService_healthCheckHandler (0.82s)1202=== CONT TestGCAdvisoryLockBlocksConcurrentRun1203=== NAME TestOrphanedObjectsGC1204 orphaned_objects_gc_test.go:287: GC Test Summary:1205 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1206 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1207 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1208 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1209 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1210--- PASS: TestOrphanedObjectsGC (1.06s)1211=== CONT TestLeadEndsOnShutdown12122026/10/08 17:08:17 INFO Received uploads request method=POST path=/api/pending_closures12132026/10/08 17:08:17 INFO Aborted multipart uploads count=0 kept=012142026/10/08 17:08:17 INFO Received push request method=POST path=/api/pushes12152026/10/08 17:08:17 WARN Force mode enabled - objects will be deleted immediately without grace period12162026/10/08 17:08:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12172026/10/08 17:08:17 INFO Uploading 9pnik44rw32xk7f3mwxdsf4gq0k3cpar-file1.txt (160B)12182026/10/08 17:08:17 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=012192026/10/08 17:08:17 INFO Vacuumed table table=pending_closures12202026/10/08 17:08:17 INFO Vacuumed table table=pending_objects12212026/10/08 17:08:17 INFO Vacuumed table table=multipart_uploads12222026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12232026/10/08 17:08:17 INFO Vacuumed table table=closures12242026/10/08 17:08:17 WARN Failed to register uploaded object key=9pnik44rw32xk7f3mwxdsf4gq0k3cpar.ls error="server returned 404: 404 page not found\n"12252026/10/08 17:08:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12262026/10/08 17:08:17 INFO Vacuumed table table=objects12272026/10/08 17:08:17 INFO Signed narinfos id=1 count=112282026/10/08 17:08:17 INFO Uploading 1 narinfos12292026/10/08 17:08:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12302026/10/08 17:08:17 INFO Received complete push request method=POST path=/api/pushes/1/complete12312026/10/08 17:08:17 WARN Failed to register uploaded object key=9pnik44rw32xk7f3mwxdsf4gq0k3cpar.narinfo error="server returned 404: 404 page not found\n"1232--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.89s)1233=== CONT TestObjectStatsTrigger12342026/10/08 17:08:17 INFO Completed push id=1 objects=3 duration=9.445198ms12352026/10/08 17:08:17 INFO Upload complete. (82ms)1236=== NAME TestNARDeduplicationMetadataUploadBug1237 metadata_upload_test.go:54: Retrieved narinfo from S3:1238 StorePath: /build/TestNARDeduplicationMetadataUploadBug1979260354/001/store/9pnik44rw32xk7f3mwxdsf4gq0k3cpar-file1.txt1239 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1240 Compression: zstd1241 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1242 NarSize: 1601243 References: 1244 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1245--- PASS: TestGetExistingObjectsLocksRows (0.85s)1246=== CONT TestLeadIncumbentAnnouncesAtOnce12472026/10/08 17:08:17 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZTE0NmQ5ZGMtZGE1ZS00MWE2LThlOTQtMmJlYjFiOGNkMWU1LjM4ODE0MGZmLWQ5ZmMtNDIwNS1iNmVhLTZjY2Q2YjdmZTVhM3gxNzkxNDc5Mjk2NTEzMTYyMjc1 error="Get \"http://127.0.0.1:1/bucket18/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12482026/10/08 17:08:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZTE0NmQ5ZGMtZGE1ZS00MWE2LThlOTQtMmJlYjFiOGNkMWU1LmRlMDc1NDM1LTViM2MtNDAwNS1hMTdiLWMzMGZhYWE0ODMwMHgxNzkxNDc5Mjk2NTA1MTI5MDA2 parts=121249=== NAME TestNARDeduplicationMetadataUploadBug1250 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1251 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1252 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12532026/10/08 17:08:17 INFO Received cleanup request method=DELETE path=/api/pending_closures12542026/10/08 17:08:17 INFO Aborted multipart uploads count=1 kept=01255--- PASS: TestRedundantMultipartUpload (2.33s)1256=== CONT TestLeadElectsOneAndHandsOver12572026/10/08 17:08:17 INFO Aborted multipart uploads count=0 kept=01258=== NAME TestNARDeduplicationMetadataUploadBug1259 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1979260354/001/store/mqpy9yrkga6mxcncd6s0mi22kzc9c122-file2.txt12602026/10/08 17:08:17 WARN Force mode enabled - objects will be deleted immediately without grace period1261--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.83s)1262=== CONT TestConnectWaitsForAPeerMigration12632026/10/08 17:08:17 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=012642026/10/08 17:08:17 INFO Vacuumed table table=pending_closures12652026/10/08 17:08:17 INFO Vacuumed table table=pending_objects12662026/10/08 17:08:17 INFO Vacuumed table table=multipart_uploads12672026/10/08 17:08:17 INFO Vacuumed table table=closures12682026/10/08 17:08:17 INFO Vacuumed table table=objects1269--- PASS: TestSweepRechecksPendingAfterLocking (0.93s)1270=== CONT TestResolveDBConnectionString1271=== RUN TestResolveDBConnectionString/flag_wins1272=== PAUSE TestResolveDBConnectionString/flag_wins1273=== RUN TestResolveDBConnectionString/file_when_flag_empty1274=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1275=== RUN TestResolveDBConnectionString/missing_file_is_an_error1276=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1277=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1278=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1279=== RUN TestResolveDBConnectionString/nothing_configured1280=== PAUSE TestResolveDBConnectionString/nothing_configured1281=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12822026/10/08 17:08:17 INFO Aborted multipart uploads count=0 kept=012832026/10/08 17:08:17 WARN Force mode enabled - objects will be deleted immediately without grace period12842026/10/08 17:08:17 INFO Received uploads request method=POST path=/api/pending_closures12852026/10/08 17:08:17 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=012862026/10/08 17:08:17 INFO Vacuumed table table=pending_closures12872026/10/08 17:08:17 INFO Vacuumed table table=pending_objects12882026/10/08 17:08:17 INFO Vacuumed table table=multipart_uploads12892026/10/08 17:08:17 INFO Vacuumed table table=closures12902026/10/08 17:08:17 INFO Received push request method=POST path=/api/pushes12912026/10/08 17:08:17 INFO Vacuumed table table=objects12922026/10/08 17:08:17 INFO Aborted multipart uploads count=0 kept=012932026/10/08 17:08:17 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12942026/10/08 17:08:17 WARN Force mode enabled - objects will be deleted immediately without grace period12952026/10/08 17:08:17 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12962026/10/08 17:08:17 WARN Failed to register uploaded object key=mqpy9yrkga6mxcncd6s0mi22kzc9c122.ls error="server returned 404: 404 page not found\n"12972026/10/08 17:08:17 INFO Signed narinfos id=2 count=112982026/10/08 17:08:17 INFO Uploading 1 narinfos12992026/10/08 17:08:17 INFO Received complete push request method=POST path=/api/pushes/2/complete13002026/10/08 17:08:17 WARN Failed to register uploaded object key=mqpy9yrkga6mxcncd6s0mi22kzc9c122.narinfo error="server returned 404: 404 page not found\n"13012026/10/08 17:08:17 INFO Received uploads request method=POST path=/api/pending_closures13022026/10/08 17:08:17 INFO Completed push id=2 objects=3 duration=19.705423ms13032026/10/08 17:08:17 INFO Upload complete. (89ms)13042026/10/08 17:08:17 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=01305=== NAME TestNARDeduplicationMetadataUploadBug1306 metadata_upload_test.go:76: Retrieved narinfo from S3:1307 StorePath: /build/TestNARDeduplicationMetadataUploadBug1979260354/001/store/mqpy9yrkga6mxcncd6s0mi22kzc9c122-file2.txt1308 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1309 Compression: zstd13102026/10/08 17:08:17 INFO Vacuumed table table=pending_closures1311 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1312 NarSize: 1601313 References: 1314 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13152026/10/08 17:08:17 INFO Vacuumed table table=pending_objects13162026/10/08 17:08:17 INFO Vacuumed table table=multipart_uploads13172026/10/08 17:08:17 INFO Vacuumed table table=closures1318 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1319 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1320 {"version":1,"root":{"type":"regular","size":44}}13212026/10/08 17:08:17 INFO Vacuumed table table=objects1322--- PASS: TestSweepSkipsRowsLockedByPush (0.93s)1323=== CONT TestCacheStatsHandler1324--- PASS: TestNARDeduplicationMetadataUploadBug (1.15s)1325=== CONT TestDeleteClosuresRacingPins13262026/10/08 17:08:17 INFO Received uploads request method=POST path=/api/pending_closures13272026/10/08 17:08:17 INFO Received uploads request method=POST path=/api/pending_closures13282026/10/08 17:08:17 INFO Received cleanup request method=DELETE path=/api/pending_closures13292026/10/08 17:08:17 INFO Aborted multipart uploads count=0 kept=013302026/10/08 17:08:17 INFO Received uploads request method=POST path=/api/pending_closures13312026/10/08 17:08:17 WARN Force mode enabled - objects will be deleted immediately without grace period1332--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.76s)1333=== CONT TestClientFallsBackToClosures13342026/10/08 17:08:17 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13352026/10/08 17:08:17 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1336--- PASS: TestFailedS3DeleteKeepsTombstone (1.02s)1337=== CONT TestPinProtectsFromGC13382026/10/08 17:08:17 INFO Received uploads request method=POST path=/api/pending_closures13392026/10/08 17:08:17 INFO Aborted multipart uploads count=0 kept=013402026/10/08 17:08:17 WARN Force mode enabled - objects will be deleted immediately without grace period13412026/10/08 17:08:17 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=013422026/10/08 17:08:17 INFO Received uploads request method=POST path=/api/pending_closures13432026/10/08 17:08:17 INFO Vacuumed table table=pending_closures13442026/10/08 17:08:17 INFO Vacuumed table table=pending_objects13452026/10/08 17:08:17 INFO Vacuumed table table=multipart_uploads13462026/10/08 17:08:17 INFO Vacuumed table table=closures1347--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.54s)1348=== CONT TestClientMultipleUploads13492026/10/08 17:08:17 INFO Vacuumed table table=objects1350--- PASS: TestGCSweepSkipsPendingObjects (0.78s)1351=== CONT TestClientIntegration1352--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.06s)1353=== CONT TestClientSharedPathCommittedMidPush13542026/10/08 17:08:17 INFO Received uploads request method=POST path=/api/pending_closures13552026/10/08 17:08:17 INFO Aborted multipart uploads count=0 kept=01356--- PASS: TestObjectStatsLargeCommit (1.56s)1357=== CONT TestClientErrorHandling13582026/10/08 17:08:17 WARN Force mode enabled - objects will be deleted immediately without grace period1359=== RUN TestClientErrorHandling/InvalidStorePath1360=== PAUSE TestClientErrorHandling/InvalidStorePath1361=== RUN TestClientErrorHandling/InvalidAuthToken1362=== PAUSE TestClientErrorHandling/InvalidAuthToken1363=== RUN TestClientErrorHandling/ServerNotAvailable1364=== PAUSE TestClientErrorHandling/ServerNotAvailable1365=== CONT TestClientWithDependencies13662026/10/08 17:08:17 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=013672026/10/08 17:08:17 INFO Vacuumed table table=pending_closures13682026/10/08 17:08:17 INFO Vacuumed table table=pending_objects13692026/10/08 17:08:17 INFO Vacuumed table table=multipart_uploads13702026/10/08 17:08:17 INFO Vacuumed table table=closures13712026/10/08 17:08:17 INFO Vacuumed table table=objects1372--- PASS: TestGCMetrics (0.59s)1373=== CONT TestClientCADerivations13742026/10/08 17:08:17 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"1375--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.55s)1376=== CONT TestService_AuthMiddleware_OIDC13772026/10/08 17:08:17 INFO Received push request method=POST path=/api/pushes13782026/10/08 17:08:17 INFO lead: acquired remote=192.0.2.1:123413792026/10/08 17:08:17 INFO Aborted multipart uploads count=0 kept=013802026/10/08 17:08:17 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13812026/10/08 17:08:17 INFO Uploading dr0gl566si2x5dq60kps395rjxdvgybn-a (216B)13822026/10/08 17:08:17 INFO Uploading zsp6rkd3rlq6rr0xmc9kv0szfszpx58x-shared-dep (136B)13832026/10/08 17:08:17 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=013842026/10/08 17:08:17 WARN Failed to register uploaded object key=8wbpynli43vccv7fn2n62cfsc35x31ic.ls error="server returned 404: 404 page not found\n"13852026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13862026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/19wv2vpvibc8wsvw4py5vsbd9z7p83zg8sp8k67b7r9rzsd84fsh.nar.zst error="server returned 404: 404 page not found\n"13872026/10/08 17:08:17 WARN Failed to register uploaded object key=dr0gl566si2x5dq60kps395rjxdvgybn.ls error="server returned 404: 404 page not found\n"13882026/10/08 17:08:17 INFO Vacuumed table table=pending_closures13892026/10/08 17:08:17 WARN Failed to register uploaded object key=zsp6rkd3rlq6rr0xmc9kv0szfszpx58x.ls error="server returned 404: 404 page not found\n"13902026/10/08 17:08:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13912026/10/08 17:08:17 INFO Signed narinfos id=1 count=313922026/10/08 17:08:17 INFO Uploading 3 narinfos1393--- PASS: TestPushWaitsForSweepHoldingRow (1.35s)1394=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13952026/10/08 17:08:17 INFO Vacuumed table table=pending_objects13962026/10/08 17:08:17 INFO Vacuumed table table=multipart_uploads13972026/10/08 17:08:17 INFO Vacuumed table table=closures13982026/10/08 17:08:17 WARN Failed to register uploaded object key=8wbpynli43vccv7fn2n62cfsc35x31ic.narinfo error="server returned 404: 404 page not found\n"13992026/10/08 17:08:17 INFO Received complete push request method=POST path=/api/pushes/1/complete14002026/10/08 17:08:17 WARN Failed to register uploaded object key=dr0gl566si2x5dq60kps395rjxdvgybn.narinfo error="server returned 404: 404 page not found\n"14012026/10/08 17:08:17 WARN Failed to register uploaded object key=zsp6rkd3rlq6rr0xmc9kv0szfszpx58x.narinfo error="server returned 404: 404 page not found\n"14022026/10/08 17:08:17 INFO Vacuumed table table=objects14032026/10/08 17:08:17 INFO Aborted multipart uploads count=0 kept=014042026/10/08 17:08:17 WARN Force mode enabled - objects will be deleted immediately without grace period14052026/10/08 17:08:17 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=014062026/10/08 17:08:17 INFO Completed push id=1 objects=8 duration=9.168717ms14072026/10/08 17:08:17 INFO Upload complete. (88ms)1408=== NAME TestClientPushesUseOnePush1409 client_pushes_test.go:97: Retrieved narinfo from S3:14102026/10/08 17:08:17 INFO Vacuumed table table=pending_closures1411 StorePath: /build/TestClientPushesUseOnePush4032618568/001/store/zsp6rkd3rlq6rr0xmc9kv0szfszpx58x-shared-dep1412 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1413 Compression: zstd1414 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821415 NarSize: 1361416 References: 1417 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14182026/10/08 17:08:17 INFO Vacuumed table table=pending_objects14192026/10/08 17:08:17 INFO Vacuumed table table=multipart_uploads1420 client_pushes_test.go:97: Retrieved narinfo from S3:1421 StorePath: /build/TestClientPushesUseOnePush4032618568/001/store/dr0gl566si2x5dq60kps395rjxdvgybn-a14222026/10/08 17:08:17 INFO Vacuumed table table=closures1423 URL: nar/19wv2vpvibc8wsvw4py5vsbd9z7p83zg8sp8k67b7r9rzsd84fsh.nar.zst1424 Compression: zstd1425 NarHash: sha256:19wv2vpvibc8wsvw4py5vsbd9z7p83zg8sp8k67b7r9rzsd84fsh1426 NarSize: 2161427 References: /build/TestClientPushesUseOnePush4032618568/001/store/zsp6rkd3rlq6rr0xmc9kv0szfszpx58x-shared-dep1428 CA: text:sha256:0qi27zhc6nngahar4kvgd3spi9m07712c1f7wv7km2xjisbrmlz514292026/10/08 17:08:17 INFO Vacuumed table table=objects1430 client_pushes_test.go:97: Retrieved narinfo from S3:1431 StorePath: /build/TestClientPushesUseOnePush4032618568/001/store/8wbpynli43vccv7fn2n62cfsc35x31ic-b1432 URL: nar/19wv2vpvibc8wsvw4py5vsbd9z7p83zg8sp8k67b7r9rzsd84fsh.nar.zst1433 Compression: zstd1434 NarHash: sha256:19wv2vpvibc8wsvw4py5vsbd9z7p83zg8sp8k67b7r9rzsd84fsh1435 NarSize: 2161436 References: /build/TestClientPushesUseOnePush4032618568/001/store/zsp6rkd3rlq6rr0xmc9kv0szfszpx58x-shared-dep1437 CA: text:sha256:0qi27zhc6nngahar4kvgd3spi9m07712c1f7wv7km2xjisbrmlz51438--- PASS: TestPushDedupSurvivesConcurrentGC (0.68s)1439=== CONT TestCacheConfigHandler1440=== RUN TestCacheConfigHandler/full_config,_no_issuer1441=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1442=== RUN TestCacheConfigHandler/no_cache_url_configured1443=== PAUSE TestCacheConfigHandler/no_cache_url_configured1444=== RUN TestCacheConfigHandler/no_signing_keys1445=== PAUSE TestCacheConfigHandler/no_signing_keys1446=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1447=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1448=== CONT TestService_ReadAuthMiddleware1449--- PASS: TestObjectStatsTrigger (0.50s)1450=== CONT TestService_ReadScope_PublicByDefault1451--- PASS: TestClientPushesUseOnePush (1.19s)1452=== CONT TestService_RequireScope_OIDC14532026/10/08 17:08:17 INFO lead: acquired remote=192.0.2.1:123414542026/10/08 17:08:17 INFO lead: acquired remote=192.0.2.1:123414552026/10/08 17:08:17 INFO lead: released remote=192.0.2.1:12341456--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.54s)1457=== CONT TestService_AuthMiddleware_MTLSProxyHeader14582026/10/08 17:08:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35007/oidc14592026/10/08 17:08:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46089/oidc1460--- PASS: TestGCBugBareHashReferences (0.78s)1461=== CONT TestProxyWriteTimeout/narinfo1462=== CONT TestProxyWriteTimeout/unknown_size1463=== CONT TestProxyWriteTimeout/10_GiB_nar1464=== CONT TestProxyWriteTimeout/1_GiB_nar1465=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14662026/10/08 17:08:17 INFO Received uploads request method=POST path=/1467--- PASS: TestProxyWriteTimeout (0.13s)1468 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1469 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1470 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1471 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1472=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14732026/10/08 17:08:17 INFO Received complete multipart upload request method=POST path=/1474=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14752026/10/08 17:08:17 INFO Received uploads request method=POST path=/1476=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14772026/10/08 17:08:17 INFO Received request for more parts method=POST path=/1478--- PASS: TestUploadHandlersRejectInvalidKeys (0.13s)1479 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1480 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1481 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1482 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1483=== CONT TestPendingClosureWriteTimeout/empty1484=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1485--- PASS: TestCacheStatsHandler (0.48s)1486=== CONT TestPendingClosureWriteTimeout/670k_objects1487=== CONT TestPendingClosureWriteTimeout/400_objects1488=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14892026/10/08 17:08:17 INFO Received request for more parts method=POST path=/1490=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14912026/10/08 17:08:17 INFO Received complete multipart upload request method=POST path=/1492=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14932026/10/08 17:08:18 INFO Received uploads request method=POST path=/1494=== NAME TestClientMultipleUploads1495 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3263777910/001/store/p2gqa4ljbx7p52p9xcnvkc6d47jzd8gq-test-file-0.txt1496=== NAME TestClientIntegration1497 client_integration_test.go:286: Created store path: /build/TestClientIntegration2217476297/002/store/5a1pxyw1rzc8jz6ykxbhb1b3i82rr4a5-test-file.txt1498=== NAME TestPinProtectsFromGC1499 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC236711369/001/store/5xlbs5qzssj53178k9vfrqjr795mhxx4-pinned-file.txt1500 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC236711369/001/store/i5zc486xj37z1n2vn8fj1z1n2phr3fmd-unpinned-file.txt1501=== NAME TestClientMultipleUploads1502 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3263777910/001/store/3sdkhsp0s0y0a6j4x9qfv9m9hmz4fimj-test-file-1.txt1503--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.73s)1504=== CONT TestIsValidUploadKey/narinfo1505=== CONT TestIsValidUploadKey/realisation_plus_in_output1506=== CONT TestIsValidUploadKey/realisation1507=== CONT TestIsValidUploadKey/build_log_equals1508=== CONT TestIsValidUploadKey/build_log_question_mark1509=== CONT TestIsValidUploadKey/build_log_plus_in_name1510=== CONT TestIsValidUploadKey/nix-cache-info1511=== CONT TestIsValidUploadKey/build_log_home-manager_file1512=== CONT TestIsValidUploadKey/build_log1513=== CONT TestIsValidUploadKey/listing1514=== CONT TestIsValidUploadKey/nar_plain1515=== CONT TestIsValidUploadKey/nar_xz1516=== CONT TestIsValidUploadKey/nar_zst1517=== CONT TestIsValidUploadKey/traversal1518=== CONT TestIsValidUploadKey/unknown_type1519=== CONT TestIsValidUploadKey/empty_key1520=== CONT TestIsValidUploadKey/absolute1521=== CONT TestIsValidUploadKey/traversal_nar1522=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1523=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1524=== CONT TestIsValidUploadKey/index.html1525=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1526--- PASS: TestIsValidUploadKey (0.32s)1527 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1528 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1529 --- PASS: TestIsValidUploadKey/realisation (0.00s)1530 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1531 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1532 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1533 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1534 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1535 --- PASS: TestIsValidUploadKey/build_log (0.00s)1536 --- PASS: TestIsValidUploadKey/listing (0.00s)1537 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1538 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1539 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1540 --- PASS: TestIsValidUploadKey/traversal (0.00s)1541 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1542 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1543 --- PASS: TestIsValidUploadKey/absolute (0.00s)1544 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1545 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1546 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1547 --- PASS: TestIsValidUploadKey/index.html (0.00s)1548 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1549=== CONT TestIsValidCachePath/narinfo1550=== CONT TestIsValidCachePath/index.html1551=== CONT TestIsValidCachePath/short_hash1552=== CONT TestIsValidCachePath/wrong_extension1553=== CONT TestIsValidCachePath/leading_slash1554=== CONT TestIsValidCachePath/empty1555=== CONT TestIsValidCachePath/random_path1556=== CONT TestIsValidCachePath/invalid_char_u1557=== CONT TestIsValidCachePath/invalid_char_e1558=== CONT TestIsValidCachePath/traversal_parent1559=== CONT TestIsValidCachePath/nar_uncompressed1560=== CONT TestIsValidCachePath/nix-cache-info1561=== CONT TestIsValidCachePath/realisation1562=== CONT TestIsValidCachePath/log1563=== CONT TestIsValidCachePath/traversal_in_middle1564=== CONT TestIsValidCachePath/ls1565=== CONT TestIsValidCachePath/nar_xz1566=== CONT TestIsValidCachePath/nar_bz21567=== CONT TestIsValidCachePath/nar_zst1568=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1569--- PASS: TestIsValidCachePath (0.00s)1570 --- PASS: TestIsValidCachePath/narinfo (0.00s)1571 --- PASS: TestIsValidCachePath/index.html (0.00s)1572 --- PASS: TestIsValidCachePath/short_hash (0.00s)1573 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1574 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1575 --- PASS: TestIsValidCachePath/empty (0.00s)1576 --- PASS: TestIsValidCachePath/random_path (0.00s)1577 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1578 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1579 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1580 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1581 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1582 --- PASS: TestIsValidCachePath/realisation (0.00s)1583 --- PASS: TestIsValidCachePath/log (0.00s)1584 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1585 --- PASS: TestIsValidCachePath/ls (0.00s)1586 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1587 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1588 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1589 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1590=== CONT TestPush_RejectsBadRequests/bad_root15912026/10/08 17:08:18 INFO Received push request method=POST path=/api/pushes1592=== CONT TestPush_RejectsBadRequests/no_roots15932026/10/08 17:08:18 INFO Received push request method=POST path=/api/pushes1594=== CONT TestPush_RejectsBadRequests/no_objects15952026/10/08 17:08:18 INFO Received push request method=POST path=/api/pushes1596=== CONT TestPush_RejectsBadRequests/root_not_in_objects15972026/10/08 17:08:18 INFO Received push request method=POST path=/api/pushes1598=== CONT TestParseSingleRange/none1599--- PASS: TestPush_RejectsBadRequests (0.86s)1600 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1601 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1602 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1603 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1604=== CONT TestParseSingleRange/open-ended1605=== CONT TestParseSingleRange/start_far_past_EOF1606=== CONT TestParseSingleRange/start_past_EOF1607=== CONT TestParseSingleRange/single_byte1608=== CONT TestParseSingleRange/suffix_exceeds_size1609=== CONT TestParseSingleRange/suffix1610=== CONT TestParseSingleRange/end_clamped_to_size1611=== CONT TestParseSingleRange/malformed_both_empty1612=== CONT TestParseSingleRange/closed1613=== CONT TestParseSingleRange/malformed_end_before_start1614=== CONT TestParseSingleRange/unknown_unit1615=== CONT TestParseSingleRange/malformed_no_dash1616=== CONT TestParseSingleRange/multi-range_ignored1617--- PASS: TestParseSingleRange (0.00s)1618 --- PASS: TestParseSingleRange/none (0.00s)1619 --- PASS: TestParseSingleRange/open-ended (0.00s)1620 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1621 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1622 --- PASS: TestParseSingleRange/single_byte (0.00s)1623 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1624 --- PASS: TestParseSingleRange/suffix (0.00s)1625 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1626 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1627 --- PASS: TestParseSingleRange/closed (0.00s)1628 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1629 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1630 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1631 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1632=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale16332026/10/08 17:08:18 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16342026/10/08 17:08:18 WARN mTLS auth: bound subjects configured but subject DN unavailable16352026/10/08 17:08:18 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1636--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.35s)1637=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1638--- PASS: TestService_ReadAuthMiddleware (0.35s)1639=== CONT TestServerTLSConfig/no_client_CA1640=== CONT TestServerTLSConfig/not_a_PEM_file1641=== CONT TestServerTLSConfig/missing_CA_file1642--- PASS: TestServerTLSConfig (0.00s)1643 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1644 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1645 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1646=== CONT TestGCEndsOnShutdown/before_the_run1647=== NAME TestClientMultipleUploads1648 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3263777910/001/store/9xdx2ribl2ka7ds8p8dbav3ga876rdpj-test-file-2.txt16492026/10/08 17:08:18 INFO Received push request method=POST path=/api/pushes16502026/10/08 17:08:18 INFO Received push request method=POST path=/api/pushes16512026/10/08 17:08:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16522026/10/08 17:08:18 INFO Uploading 5a1pxyw1rzc8jz6ykxbhb1b3i82rr4a5-test-file.txt (152B)16532026/10/08 17:08:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16542026/10/08 17:08:18 INFO Uploading 5xlbs5qzssj53178k9vfrqjr795mhxx4-pinned-file.txt (128B)16552026/10/08 17:08:18 WARN Failed to register uploaded object key=5a1pxyw1rzc8jz6ykxbhb1b3i82rr4a5.ls error="server returned 404: 404 page not found\n"16562026/10/08 17:08:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1657--- PASS: TestService_ReadScope_PublicByDefault (0.37s)1658=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark16592026/10/08 17:08:18 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16602026/10/08 17:08:18 INFO Signed narinfos id=1 count=116612026/10/08 17:08:18 INFO Uploading 1 narinfos1662=== NAME TestClientWithDependencies1663 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3906123451/001/store/m76gl3m6dk0864mhwss0vcwyz238ggwy-test-script16642026/10/08 17:08:18 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16652026/10/08 17:08:18 WARN Failed to register uploaded object key=5xlbs5qzssj53178k9vfrqjr795mhxx4.ls error="server returned 404: 404 page not found\n"16662026/10/08 17:08:18 INFO Received uploads request method=POST path=/api/pending_closures16672026/10/08 17:08:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16682026/10/08 17:08:18 INFO Signed narinfos id=1 count=116692026/10/08 17:08:18 INFO Uploading 1 narinfos16702026/10/08 17:08:18 INFO Received complete push request method=POST path=/api/pushes/1/complete16712026/10/08 17:08:18 WARN Failed to register uploaded object key=5a1pxyw1rzc8jz6ykxbhb1b3i82rr4a5.narinfo error="server returned 404: 404 page not found\n"16722026/10/08 17:08:18 INFO Received complete push request method=POST path=/api/pushes/1/complete16732026/10/08 17:08:18 WARN Failed to register uploaded object key=5xlbs5qzssj53178k9vfrqjr795mhxx4.narinfo error="server returned 404: 404 page not found\n"16742026/10/08 17:08:18 INFO Received uploads request method=POST path=/api/pending_closures16752026/10/08 17:08:18 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16762026/10/08 17:08:18 INFO Uploading 8yq4agjsa2bjlrpwmvhylkx165cc3wfc-b (216B)16772026/10/08 17:08:18 INFO Uploading 4d71xqfjpb3slmj2804zkn8ibvfa97y5-shared-dep (136B)16782026/10/08 17:08:18 INFO Completed push id=1 objects=3 duration=10.143586ms16792026/10/08 17:08:18 INFO Upload complete. (78ms)16802026/10/08 17:08:18 WARN Failed to register uploaded object key=7n8mjd9gc2vai248ny9w00b264p84k8p.ls error="server returned 404: 404 page not found\n"16812026/10/08 17:08:18 WARN Failed to register uploaded object key=nar/1n02p0fs4bf7hgbvcrvcgzsqpzy24nchikrg733i4l00jcikb65r.nar.zst error="server returned 404: 404 page not found\n"16822026/10/08 17:08:18 WARN Failed to register uploaded object key=4d71xqfjpb3slmj2804zkn8ibvfa97y5.ls error="server returned 404: 404 page not found\n"16832026/10/08 17:08:18 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16842026/10/08 17:08:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16852026/10/08 17:08:18 WARN Failed to register uploaded object key=8yq4agjsa2bjlrpwmvhylkx165cc3wfc.ls error="server returned 404: 404 page not found\n"16862026/10/08 17:08:18 INFO Signed narinfos id=1 count=216872026/10/08 17:08:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16882026/10/08 17:08:18 INFO Completed push id=1 objects=3 duration=11.255115ms16892026/10/08 17:08:18 INFO Signed narinfos id=2 count=216902026/10/08 17:08:18 INFO Upload complete. (76ms)16912026/10/08 17:08:18 INFO Uploading 4 narinfos16922026/10/08 17:08:18 WARN Failed to register uploaded object key=4d71xqfjpb3slmj2804zkn8ibvfa97y5.narinfo error="server returned 404: 404 page not found\n"16932026/10/08 17:08:18 WARN Failed to register uploaded object key=7n8mjd9gc2vai248ny9w00b264p84k8p.narinfo error="server returned 404: 404 page not found\n"16942026/10/08 17:08:18 WARN Failed to register uploaded object key=8yq4agjsa2bjlrpwmvhylkx165cc3wfc.narinfo error="server returned 404: 404 page not found\n"1695--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.36s)1696=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete16972026/10/08 17:08:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16982026/10/08 17:08:18 WARN Failed to register uploaded object key=4d71xqfjpb3slmj2804zkn8ibvfa97y5.narinfo error="server returned 404: 404 page not found\n"1699=== NAME TestClientCADerivations1700 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3190059748/001/store/jynwq6yl5rg8pp4xs45v2p9xvl9g3m48-ca-test1701=== NAME TestClientWithDependencies1702 client_integration_test.go:615: Found 1 dependencies (including self)1703=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1704=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1705=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1706=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1707=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1708=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1709=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1710=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1711=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows17122026/10/08 17:08:18 INFO Completed upload id=1 objects=6 duration=26.884434ms17132026/10/08 17:08:18 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17142026/10/08 17:08:18 INFO Completed upload id=2 objects=6 duration=2.741916ms17152026/10/08 17:08:18 INFO All 1 paths already cached17162026/10/08 17:08:18 INFO Upload complete. (113ms)17172026/10/08 17:08:18 INFO Received push request method=POST path=/api/pushes17182026/10/08 17:08:18 INFO Received push request method=POST path=/api/pushes1719=== NAME TestClientIntegration1720 client_integration_test.go:312: Retrieved narinfo from S3:1721 StorePath: /build/TestClientIntegration2217476297/002/store/5a1pxyw1rzc8jz6ykxbhb1b3i82rr4a5-test-file.txt1722 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1723 Compression: zstd1724 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11725 NarSize: 1521726 References: 1727 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11728=== NAME TestClientFallsBackToClosures1729 client_pushes_test.go:112: Retrieved narinfo from S3:1730 StorePath: /build/TestClientFallsBackToClosures4077627975/001/store/4d71xqfjpb3slmj2804zkn8ibvfa97y5-shared-dep1731 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1732 Compression: zstd1733 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821734 NarSize: 1361735 References: 1736 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1737=== NAME TestClientIntegration1738 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1739 client_integration_test.go:313: Decompressed .ls content (64 bytes):1740 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1741 client_integration_test.go:316: Testing garbage collection...1742=== NAME TestClientFallsBackToClosures1743 client_pushes_test.go:112: Retrieved narinfo from S3:1744 StorePath: /build/TestClientFallsBackToClosures4077627975/001/store/7n8mjd9gc2vai248ny9w00b264p84k8p-a1745 URL: nar/1n02p0fs4bf7hgbvcrvcgzsqpzy24nchikrg733i4l00jcikb65r.nar.zst1746 Compression: zstd1747 NarHash: sha256:1n02p0fs4bf7hgbvcrvcgzsqpzy24nchikrg733i4l00jcikb65r1748 NarSize: 2161749 References: /build/TestClientFallsBackToClosures4077627975/001/store/4d71xqfjpb3slmj2804zkn8ibvfa97y5-shared-dep1750 CA: text:sha256:0mgzsmr3whcfxix2syrhmfrsh3f6l3801cvwyybx4yrpg3b4ymps17512026/10/08 17:08:18 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17522026/10/08 17:08:18 INFO Uploading 15bv97qa0fi46idy8zc667m1lp4hkm27-top (224B)17532026/10/08 17:08:18 INFO Uploading 5avvzzkfw88rjgq5sb3mk89jimijjb4m-shared-dep (136B)1754 client_pushes_test.go:112: Retrieved narinfo from S3:17552026/10/08 17:08:18 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)1756 StorePath: /build/TestClientFallsBackToClosures4077627975/001/store/8yq4agjsa2bjlrpwmvhylkx165cc3wfc-b17572026/10/08 17:08:18 INFO Uploading 3sdkhsp0s0y0a6j4x9qfv9m9hmz4fimj-test-file-1.txt (160B)1758 URL: nar/1n02p0fs4bf7hgbvcrvcgzsqpzy24nchikrg733i4l00jcikb65r.nar.zst17592026/10/08 17:08:18 INFO Uploading p2gqa4ljbx7p52p9xcnvkc6d47jzd8gq-test-file-0.txt (160B)1760 Compression: zstd1761 NarHash: sha256:1n02p0fs4bf7hgbvcrvcgzsqpzy24nchikrg733i4l00jcikb65r1762 NarSize: 2161763 References: /build/TestClientFallsBackToClosures4077627975/001/store/4d71xqfjpb3slmj2804zkn8ibvfa97y5-shared-dep1764 CA: text:sha256:0mgzsmr3whcfxix2syrhmfrsh3f6l3801cvwyybx4yrpg3b4ymps17652026/10/08 17:08:18 INFO Uploading 9xdx2ribl2ka7ds8p8dbav3ga876rdpj-test-file-2.txt (160B)17662026/10/08 17:08:18 WARN Failed to register uploaded object key=15bv97qa0fi46idy8zc667m1lp4hkm27.ls error="server returned 404: 404 page not found\n"17672026/10/08 17:08:18 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17682026/10/08 17:08:18 WARN Failed to register uploaded object key=5avvzzkfw88rjgq5sb3mk89jimijjb4m.ls error="server returned 404: 404 page not found\n"17692026/10/08 17:08:18 WARN Failed to register uploaded object key=nar/1drzqzrhfsn9rmxccy62gwigh2n5gsmdgc0ccyr30pix1g8ibk35.nar.zst error="server returned 404: 404 page not found\n"17702026/10/08 17:08:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17712026/10/08 17:08:18 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17722026/10/08 17:08:18 INFO Signed narinfos id=1 count=217732026/10/08 17:08:18 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17742026/10/08 17:08:18 INFO Uploading 2 narinfos17752026/10/08 17:08:18 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17762026/10/08 17:08:18 WARN Failed to register uploaded object key=3sdkhsp0s0y0a6j4x9qfv9m9hmz4fimj.ls error="server returned 404: 404 page not found\n"17772026/10/08 17:08:18 WARN Failed to register uploaded object key=9xdx2ribl2ka7ds8p8dbav3ga876rdpj.ls error="server returned 404: 404 page not found\n"17782026/10/08 17:08:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17792026/10/08 17:08:18 WARN Failed to register uploaded object key=p2gqa4ljbx7p52p9xcnvkc6d47jzd8gq.ls error="server returned 404: 404 page not found\n"1780--- PASS: TestClientFallsBackToClosures (0.68s)1781=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1782=== NAME TestClientCADerivations1783 client_ca_test.go:139: Found 1 dependencies (including self)17842026/10/08 17:08:18 INFO Signed narinfos id=1 count=317852026/10/08 17:08:18 INFO Uploading 3 narinfos17862026/10/08 17:08:18 WARN Failed to register uploaded object key=15bv97qa0fi46idy8zc667m1lp4hkm27.narinfo error="server returned 404: 404 page not found\n"17872026/10/08 17:08:18 INFO Received complete push request method=POST path=/api/pushes/1/complete17882026/10/08 17:08:18 INFO Received uploads request method=POST path=/api/pending_closures17892026/10/08 17:08:18 WARN Failed to register uploaded object key=5avvzzkfw88rjgq5sb3mk89jimijjb4m.narinfo error="server returned 404: 404 page not found\n"17902026/10/08 17:08:18 WARN Failed to register uploaded object key=p2gqa4ljbx7p52p9xcnvkc6d47jzd8gq.narinfo error="server returned 404: 404 page not found\n"17912026/10/08 17:08:18 WARN Failed to register uploaded object key=3sdkhsp0s0y0a6j4x9qfv9m9hmz4fimj.narinfo error="server returned 404: 404 page not found\n"17922026/10/08 17:08:18 INFO Received complete push request method=POST path=/api/pushes/1/complete17932026/10/08 17:08:18 WARN Failed to register uploaded object key=9xdx2ribl2ka7ds8p8dbav3ga876rdpj.narinfo error="server returned 404: 404 page not found\n"17942026/10/08 17:08:18 INFO Completed push id=1 objects=6 duration=10.963835ms17952026/10/08 17:08:18 INFO Upload complete. (81ms)1796=== NAME TestClientSharedPathCommittedMidPush1797 client_integration_test.go:680: Retrieved narinfo from S3:1798 StorePath: /build/TestClientSharedPathCommittedMidPush2800293972/001/store/5avvzzkfw88rjgq5sb3mk89jimijjb4m-shared-dep1799 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1800 Compression: zstd1801 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821802 NarSize: 1361803 References: 1804 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1805 client_integration_test.go:680: Retrieved narinfo from S3:1806 StorePath: /build/TestClientSharedPathCommittedMidPush2800293972/001/store/15bv97qa0fi46idy8zc667m1lp4hkm27-top1807 URL: nar/1drzqzrhfsn9rmxccy62gwigh2n5gsmdgc0ccyr30pix1g8ibk35.nar.zst1808 Compression: zstd1809 NarHash: sha256:1drzqzrhfsn9rmxccy62gwigh2n5gsmdgc0ccyr30pix1g8ibk3518102026/10/08 17:08:18 INFO Completed push id=1 objects=9 duration=10.967505ms1811 NarSize: 2241812 References: /build/TestClientSharedPathCommittedMidPush2800293972/001/store/5avvzzkfw88rjgq5sb3mk89jimijjb4m-shared-dep1813 CA: text:sha256:1byc5dck7dk5qmbbhv9iwxll6wq1s7s0c2dv66azgjcicd5mbqd418142026/10/08 17:08:18 INFO Upload complete. (88ms)1815=== NAME TestClientMultipleUploads1816 client_integration_test.go:369: Uploaded 3 paths in 121.743384ms18172026/10/08 17:08:18 INFO Received push request method=POST path=/api/pushes1818--- PASS: TestClientSharedPathCommittedMidPush (0.64s)1819=== CONT TestResolveDBConnectionString/flag_wins1820=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1821=== CONT TestResolveDBConnectionString/nothing_configured1822=== CONT TestResolveDBConnectionString/missing_file_is_an_error1823=== CONT TestResolveDBConnectionString/file_when_flag_empty1824=== CONT TestClientErrorHandling/InvalidStorePath1825--- PASS: TestResolveDBConnectionString (0.00s)1826 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1827 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1828 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1829 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1830 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)18312026/10/08 17:08:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18322026/10/08 17:08:18 INFO Uploading i5zc486xj37z1n2vn8fj1z1n2phr3fmd-unpinned-file.txt (128B)18332026/10/08 17:08:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures18342026/10/08 17:08:18 INFO Garbage collection started1835--- PASS: TestClientMultipleUploads (0.66s)1836=== CONT TestClientErrorHandling/ServerNotAvailable18372026/10/08 17:08:18 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18382026/10/08 17:08:18 WARN Failed to register uploaded object key=i5zc486xj37z1n2vn8fj1z1n2phr3fmd.ls error="server returned 404: 404 page not found\n"18392026/10/08 17:08:18 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18402026/10/08 17:08:18 INFO Signed narinfos id=2 count=118412026/10/08 17:08:18 INFO Uploading 1 narinfos18422026/10/08 17:08:18 INFO Received push request method=POST path=/api/pushes18432026/10/08 17:08:18 INFO Aborted multipart uploads count=0 kept=018442026/10/08 17:08:18 INFO Received complete push request method=POST path=/api/pushes/2/complete18452026/10/08 17:08:18 WARN Failed to register uploaded object key=i5zc486xj37z1n2vn8fj1z1n2phr3fmd.narinfo error="server returned 404: 404 page not found\n"1846=== RUN TestService_RequireScope_OIDC/builder_may_write1847=== PAUSE TestService_RequireScope_OIDC/builder_may_write1848=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1849=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1850=== RUN TestService_RequireScope_OIDC/ops_may_admin1851=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1852=== RUN TestService_RequireScope_OIDC/ops_may_not_write1853=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1854=== RUN TestService_RequireScope_OIDC/reader_may_not_write1855=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1856=== RUN TestService_RequireScope_OIDC/static_token_may_admin1857=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1858=== RUN TestService_RequireScope_OIDC/static_token_may_write1859=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1860=== RUN TestService_RequireScope_OIDC/reader_may_read1861=== PAUSE TestService_RequireScope_OIDC/reader_may_read1862=== RUN TestService_RequireScope_OIDC/writer_implies_read1863=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1864=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1865=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1866=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1867=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1868=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1869=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1870=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1871=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1872=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1873=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1874=== CONT TestClientErrorHandling/InvalidAuthToken18752026/10/08 17:08:18 WARN Force mode enabled - objects will be deleted immediately without grace period18762026/10/08 17:08:18 INFO Completed push id=2 objects=3 duration=18.857864ms18772026/10/08 17:08:18 INFO Upload complete. (75ms)18782026/10/08 17:08:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18792026/10/08 17:08:18 INFO Uploading m76gl3m6dk0864mhwss0vcwyz238ggwy-test-script (136B)18802026/10/08 17:08:18 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18812026/10/08 17:08:18 WARN Failed to register uploaded object key=m76gl3m6dk0864mhwss0vcwyz238ggwy.ls error="server returned 404: 404 page not found\n"18822026/10/08 17:08:18 WARN Failed to register uploaded object key=log/glz03h6jrra2qkny2zk6r6bhrypm4wrr-test-script.drv error="server returned 404: 404 page not found\n"18832026/10/08 17:08:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18842026/10/08 17:08:18 INFO Signed narinfos id=1 count=118852026/10/08 17:08:18 INFO Uploading 1 narinfos18862026/10/08 17:08:18 INFO Received complete push request method=POST path=/api/pushes/1/complete18872026/10/08 17:08:18 WARN Failed to register uploaded object key=m76gl3m6dk0864mhwss0vcwyz238ggwy.narinfo error="server returned 404: 404 page not found\n"18882026/10/08 17:08:18 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=018892026/10/08 17:08:18 INFO Vacuumed table table=pending_closures18902026/10/08 17:08:18 INFO Completed push id=1 objects=4 duration=8.11215ms18912026/10/08 17:08:18 INFO Upload complete. (88ms)18922026/10/08 17:08:18 INFO Vacuumed table table=pending_objects1893=== NAME TestClientWithDependencies1894 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3906123451/001/store) requires matching store prefix18952026/10/08 17:08:18 INFO Vacuumed table table=multipart_uploads18962026/10/08 17:08:18 INFO Vacuumed table table=closures1897--- PASS: TestClientWithDependencies (0.65s)1898=== CONT TestCacheConfigHandler/full_config,_no_issuer18992026/10/08 17:08:18 INFO Vacuumed table table=objects1900=== CONT TestCacheConfigHandler/no_signing_keys1901=== CONT TestCacheConfigHandler/no_cache_url_configured1902=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1903--- PASS: TestCacheConfigHandler (0.00s)1904 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1905 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1906 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1907 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1908=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1909=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19102026/10/08 17:08:18 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]1911=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1912=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19132026/10/08 17:08:18 WARN Authentication failed token_preview=eyJhbGciOi...hz9H5zNe-A token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1914=== CONT TestService_RequireScope_OIDC/builder_may_write1915=== CONT TestService_RequireScope_OIDC/reader_may_read1916--- PASS: TestService_AuthMiddleware_OIDC (0.49s)1917 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1918 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1919 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1920 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1921=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1922=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19232026/10/08 17:08:18 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]1924=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1925=== CONT TestService_RequireScope_OIDC/writer_implies_read1926=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1927=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1928=== CONT TestService_RequireScope_OIDC/reader_may_not_write1929=== CONT TestService_RequireScope_OIDC/static_token_may_write1930=== CONT TestService_RequireScope_OIDC/static_token_may_admin1931=== CONT TestService_RequireScope_OIDC/builder_may_not_admin19322026/10/08 17:08:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures1933=== CONT TestService_RequireScope_OIDC/ops_may_not_write19342026/10/08 17:08:18 INFO Garbage collection started1935=== CONT TestService_RequireScope_OIDC/ops_may_admin1936--- PASS: TestService_RequireScope_OIDC (0.49s)1937 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1938 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1939 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1940 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1941 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1942 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1943 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1944 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1945 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1946 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1947 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1948 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1949 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1950 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)19512026/10/08 17:08:18 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/present19522026/10/08 17:08:18 INFO Received push request method=POST path=/api/pushes19532026/10/08 17:08:18 INFO Aborted multipart uploads count=0 kept=019542026/10/08 17:08:18 WARN Force mode enabled - objects will be deleted immediately without grace period19552026/10/08 17:08:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19562026/10/08 17:08:18 INFO Uploading jynwq6yl5rg8pp4xs45v2p9xvl9g3m48-ca-test (144B)19572026/10/08 17:08:18 WARN Failed to register uploaded object key=jynwq6yl5rg8pp4xs45v2p9xvl9g3m48.ls error="server returned 404: 404 page not found\n"19582026/10/08 17:08:18 WARN Failed to register uploaded object key=log/z1k1p0h9laawg9wy10kljjnphi0kw3vj-ca-test.drv error="server returned 404: 404 page not found\n"19592026/10/08 17:08:18 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19602026/10/08 17:08:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19612026/10/08 17:08:18 INFO Signed narinfos id=1 count=119622026/10/08 17:08:18 INFO Uploading 1 narinfos19632026/10/08 17:08:18 INFO Received complete push request method=POST path=/api/pushes/1/complete19642026/10/08 17:08:18 WARN Failed to register uploaded object key=jynwq6yl5rg8pp4xs45v2p9xvl9g3m48.narinfo error="server returned 404: 404 page not found\n"19652026/10/08 17:08:18 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=019662026/10/08 17:08:18 INFO Completed push id=1 objects=4 duration=9.399297ms19672026/10/08 17:08:18 INFO Upload complete. (112ms)19682026/10/08 17:08:18 INFO Vacuumed table table=pending_closures1969=== NAME TestClientCADerivations1970 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3190059748/001/store/jynwq6yl5rg8pp4xs45v2p9xvl9g3m48-ca-test19712026/10/08 17:08:18 INFO Vacuumed table table=pending_objects1972 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1973 Compression: zstd1974 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1975 NarSize: 1441976 References: 1977 Deriver: /build/TestClientCADerivations3190059748/001/store/z1k1p0h9laawg9wy10kljjnphi0kw3vj-ca-test.drv1978 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1979 client_ca_test.go:185: Checking for realisation files in S3...19802026/10/08 17:08:18 INFO Vacuumed table table=multipart_uploads1981 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1982 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache19832026/10/08 17:08:18 INFO Vacuumed table table=closures19842026/10/08 17:08:18 INFO Vacuumed table table=objects19852026/10/08 17:08:18 INFO Aborted multipart uploads count=0 kept=019862026/10/08 17:08:18 WARN Force mode enabled - objects will be deleted immediately without grace period19872026/10/08 17:08:18 INFO Aborted multipart uploads count=0 kept=019882026/10/08 17:08:18 WARN Force mode enabled - objects will be deleted immediately without grace period19892026/10/08 17:08:18 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:34773/bucket96/?delete=\": context canceled"1990--- PASS: TestGCEndsOnShutdown (0.00s)1991 --- PASS: TestGCEndsOnShutdown/before_the_run (0.25s)1992 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.27s)1993 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.26s)19942026/10/08 17:08:18 INFO Received uploads request method=POST path=/api/pending_closures19952026/10/08 17:08:18 WARN Request failed, retrying attempt=2 backoff=209.568883ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19962026/10/08 17:08:18 INFO Aborted multipart uploads count=0 kept=019972026/10/08 17:08:18 WARN Force mode enabled - objects will be deleted immediately without grace period19982026/10/08 17:08:18 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=019992026/10/08 17:08:18 INFO Received uploads request method=POST path=/api/pending_closures20002026/10/08 17:08:18 INFO Vacuumed table table=pending_closures20012026/10/08 17:08:18 INFO Vacuumed table table=pending_objects20022026/10/08 17:08:18 INFO Vacuumed table table=multipart_uploads20032026/10/08 17:08:18 INFO Vacuumed table table=closures20042026/10/08 17:08:18 INFO Vacuumed table table=objects20052026/10/08 17:08:18 INFO Aborted multipart uploads count=0 kept=020062026/10/08 17:08:18 WARN Force mode enabled - objects will be deleted immediately without grace period20072026/10/08 17:08:18 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=020082026/10/08 17:08:18 INFO Vacuumed table table=pending_closures20092026/10/08 17:08:18 INFO Vacuumed table table=pending_objects20102026/10/08 17:08:18 INFO Vacuumed table table=multipart_uploads20112026/10/08 17:08:18 INFO Vacuumed table table=closures20122026/10/08 17:08:18 INFO Vacuumed table table=objects2013--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2014 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.29s)2015 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.27s)2016=== NAME TestClientCADerivations2017 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2018 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2019 error: binary cache 's3://bucket84?endpoint=http://localhost:34773®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3190059748/001/store'2020 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12021--- PASS: TestClientCADerivations (0.85s)2022=== NAME TestOrphanedObjectsGCStressTest2023 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2024 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion20252026/10/08 17:08:18 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20262026/10/08 17:08:18 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20272026/10/08 17:08:18 WARN Request failed, retrying attempt=3 backoff=388.458417ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2028--- PASS: TestUploadHandlersRejectOversizedBody (0.32s)2029 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2030 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)2031 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.70s)20322026/10/08 17:08:18 INFO lead: released remote=192.0.2.1:12342033--- PASS: TestLeadEndsOnShutdown (1.58s)2034--- PASS: TestDeleteClosuresRacingPins (1.35s)2035--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2036 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.72s)2037 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.76s)2038=== NAME TestOrphanedObjectsGCStressTest2039 orphaned_objects_gc_test.go:503: Stress test completed successfully:2040 orphaned_objects_gc_test.go:504: - Active objects preserved: 202041 orphaned_objects_gc_test.go:505: - Objects deleted: 2102042 orphaned_objects_gc_test.go:506: - Total GC'd: 2102043--- PASS: TestOrphanedObjectsGCStressTest (2.79s)20442026/10/08 17:08:19 INFO lead: released remote=192.0.2.1:12342045--- PASS: TestPendingClosureWriteTimeout (0.13s)2046 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2047 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2048 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2049 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.12s)20502026/10/08 17:08:19 INFO lead: acquired remote=192.0.2.1:123420512026/10/08 17:08:19 WARN Request failed, retrying attempt=4 backoff=771.727878ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20522026/10/08 17:08:19 WARN Request failed, retrying attempt=5 backoff=1.526833098s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20532026/10/08 17:08:20 INFO lead: released remote=192.0.2.1:12342054--- PASS: TestLeadElectsOneAndHandsOver (2.80s)20552026/10/08 17:08:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02056=== NAME TestClientIntegration2057 client_integration_test.go:323: Objects in database after GC:2058 client_integration_test.go:323: Successfully deleted all objects with GC --force2059--- PASS: TestClientIntegration (2.66s)20602026/10/08 17:08:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020612026/10/08 17:08:20 INFO Received create pin request method=POST path=/api/pins/myapp20622026/10/08 17:08:20 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC236711369/001/store/5xlbs5qzssj53178k9vfrqjr795mhxx4-pinned-file.txt narinfo_key=5xlbs5qzssj53178k9vfrqjr795mhxx4.narinfo20632026/10/08 17:08:20 INFO Starting cleanup of old closures method=DELETE path=/api/closures20642026/10/08 17:08:20 INFO Garbage collection started20652026/10/08 17:08:20 INFO Aborted multipart uploads count=0 kept=020662026/10/08 17:08:20 WARN Force mode enabled - objects will be deleted immediately without grace period20672026/10/08 17:08:20 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=020682026/10/08 17:08:20 INFO Vacuumed table table=pending_closures20692026/10/08 17:08:20 INFO Vacuumed table table=pending_objects20702026/10/08 17:08:20 INFO Vacuumed table table=multipart_uploads20712026/10/08 17:08:20 INFO Vacuumed table table=closures20722026/10/08 17:08:20 INFO Vacuumed table table=objects2073--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.90s)20742026/10/08 17:08:21 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-config20752026/10/08 17:08:21 WARN Request failed, retrying attempt=2 backoff=213.405732ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20762026/10/08 17:08:21 WARN Rate limiter enabled after throttle name=s3-test rate=520772026/10/08 17:08:21 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2078=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2079 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102080 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002081--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.69s)20822026/10/08 17:08:21 WARN Request failed, retrying attempt=3 backoff=423.37626ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20832026/10/08 17:08:22 WARN Request failed, retrying attempt=4 backoff=878.529827ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2084=== NAME TestPinProtectsFromGC2085 client_integration_test.go:840: Pin successfully protected closure from garbage collection2086--- PASS: TestPinProtectsFromGC (4.80s)2087--- PASS: TestConnectWaitsForAPeerMigration (5.19s)20882026/10/08 17:08:23 WARN Request failed, retrying attempt=5 backoff=1.492283697s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20892026/10/08 17:08:23 INFO Aborted multipart uploads count=1 kept=020902026/10/08 17:08:23 INFO Received cleanup request method=DELETE path=/api/pending_closures20912026/10/08 17:08:23 INFO Aborted multipart uploads count=1 kept=02092--- PASS: TestPendingCleanupUsesOneCutoff (6.93s)20932026/10/08 17:08:24 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"20942026/10/08 17:08:24 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-config20952026/10/08 17:08:24 WARN Request failed, retrying attempt=2 backoff=216.816648ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20962026/10/08 17:08:24 WARN Request failed, retrying attempt=3 backoff=432.752181ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20972026/10/08 17:08:25 WARN Request failed, retrying attempt=4 backoff=879.408049ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20982026/10/08 17:08:26 WARN Request failed, retrying attempt=5 backoff=1.566900563s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20992026/10/08 17:08:27 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_closures21002026/10/08 17:08:27 WARN Request failed, retrying attempt=2 backoff=201.747551ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21012026/10/08 17:08:28 WARN Request failed, retrying attempt=3 backoff=364.125842ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21022026/10/08 17:08:28 WARN Request failed, retrying attempt=4 backoff=750.65589ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21032026/10/08 17:08:29 WARN Request failed, retrying attempt=5 backoff=1.475335585s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2104--- PASS: TestClientErrorHandling (0.00s)2105 --- PASS: TestClientErrorHandling/InvalidStorePath (0.27s)2106 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.36s)2107 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.35s)2108PASS21092026-10-08 17:08:30.993 UTC [128] LOG: received smart shutdown request21102026-10-08 17:08:31.001 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 121112026-10-08 17:08:31.012 UTC [133] LOG: shutting down21122026-10-08 17:08:31.013 UTC [133] LOG: checkpoint starting: shutdown immediate21132026-10-08 17:08:32.809 UTC [133] LOG: checkpoint complete: wrote 10742 buffers (65.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.253 s, sync=1.475 s, total=1.797 s; sync files=34045, longest=0.003 s, average=0.001 s; distance=531510 kB, estimate=531510 kB; lsn=0/21E73718, redo lsn=0/21E7371821142026-10-08 17:08:32.896 UTC [128] LOG: database system is shut down2115Running OIDC tests...2116=== RUN TestAudienceForIssuer2117=== PAUSE TestAudienceForIssuer2118=== RUN TestGlobMatch2119=== PAUSE TestGlobMatch2120=== RUN TestValidateToken_ValidToken2121=== PAUSE TestValidateToken_ValidToken2122=== RUN TestValidateToken_WrongAudience2123=== PAUSE TestValidateToken_WrongAudience2124=== RUN TestValidateToken_Expired2125=== PAUSE TestValidateToken_Expired2126=== RUN TestValidateToken_BoundClaimsMismatch2127=== PAUSE TestValidateToken_BoundClaimsMismatch2128=== RUN TestValidateToken_BoundSubjectMismatch2129=== PAUSE TestValidateToken_BoundSubjectMismatch2130=== RUN TestValidateToken_MultipleProviders2131=== PAUSE TestValidateToken_MultipleProviders2132=== RUN TestValidateToken_NoMatchingProvider2133=== PAUSE TestValidateToken_NoMatchingProvider2134=== RUN TestValidateToken_KubernetesServiceAccount2135=== PAUSE TestValidateToken_KubernetesServiceAccount2136=== RUN TestNewValidator_KubernetesRequiresCA2137=== PAUSE TestNewValidator_KubernetesRequiresCA2138=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2139=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2140=== RUN TestPins_ReservedForMatchingRule2141=== PAUSE TestPins_ReservedForMatchingRule2142=== RUN TestPins_TopLevelShorthand2143=== PAUSE TestPins_TopLevelShorthand2144=== RUN TestPins_ConfigValidation2145=== PAUSE TestPins_ConfigValidation2146=== RUN TestScopes_LegacyProviderDefaultsToWrite2147=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2148=== RUN TestScopes_Rules2149=== PAUSE TestScopes_Rules2150=== RUN TestScopes_ConfigValidation2151=== PAUSE TestScopes_ConfigValidation2152=== CONT TestAudienceForIssuer2153=== CONT TestValidateToken_KubernetesServiceAccount2154--- PASS: TestAudienceForIssuer (0.00s)2155=== CONT TestValidateToken_Expired2156=== CONT TestValidateToken_WrongAudience2157=== CONT TestValidateToken_ValidToken2158=== CONT TestPins_ConfigValidation2159=== CONT TestGlobMatch2160=== RUN TestGlobMatch/foo_foo2161=== PAUSE TestGlobMatch/foo_foo2162=== RUN TestGlobMatch/foo_bar2163=== PAUSE TestGlobMatch/foo_bar2164=== RUN TestGlobMatch/*_2165=== PAUSE TestGlobMatch/*_2166=== RUN TestGlobMatch/*_anything2167=== PAUSE TestGlobMatch/*_anything2168=== RUN TestGlobMatch/foo*_foo2169=== CONT TestScopes_ConfigValidation2170=== CONT TestScopes_LegacyProviderDefaultsToWrite2171=== CONT TestScopes_Rules2172=== CONT TestValidateToken_MultipleProviders2173=== CONT TestPins_ReservedForMatchingRule2174=== CONT TestValidateToken_NoMatchingProvider2175=== CONT TestPins_TopLevelShorthand2176=== CONT TestValidateToken_BoundSubjectMismatch2177=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2178=== CONT TestNewValidator_KubernetesRequiresCA2179=== CONT TestValidateToken_BoundClaimsMismatch2180--- PASS: TestPins_ConfigValidation (0.00s)2181=== 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*bar_foobarbaz2224=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2225=== CONT TestGlobMatch/foo*_foo2226=== CONT TestGlobMatch/*/*_foo/bar2227=== CONT TestGlobMatch/*_2228=== CONT TestGlobMatch/foo_bar2229=== CONT TestGlobMatch/fo?_fo2230=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2231=== CONT TestGlobMatch/foo*bar_foo123bar2232=== CONT TestGlobMatch/?oo_foo2233=== CONT TestGlobMatch/fo?_fooo2234=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02235=== CONT TestGlobMatch/fo?_foo2236=== CONT TestGlobMatch/refs/*/main_refs/heads/main2237=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2238=== CONT TestGlobMatch/*/*_foo2239=== CONT TestGlobMatch/foo*bar_foobar2240=== CONT TestGlobMatch/*bar_foo2241=== CONT TestGlobMatch/*bar_foobar2242=== CONT TestGlobMatch/*bar_bar2243=== CONT TestGlobMatch/foo*_bar2244=== CONT TestGlobMatch/foo*_foobar2245=== CONT TestGlobMatch/*_anything2246=== CONT TestGlobMatch/?oo_boo2247--- PASS: TestGlobMatch (0.00s)2248 --- PASS: TestGlobMatch/foo_foo (0.00s)2249 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2250 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2251 --- PASS: TestGlobMatch/foo*_foo (0.00s)2252 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2253 --- PASS: TestGlobMatch/*_ (0.00s)2254 --- PASS: TestGlobMatch/foo_bar (0.00s)2255 --- PASS: TestGlobMatch/fo?_fo (0.00s)2256 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2257 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2258 --- PASS: TestGlobMatch/?oo_foo (0.00s)2259 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2260 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2261 --- PASS: TestGlobMatch/fo?_foo (0.00s)2262 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2263 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2264 --- PASS: TestGlobMatch/*/*_foo (0.00s)2265 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2266 --- PASS: TestGlobMatch/*bar_foo (0.00s)2267 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2268 --- PASS: TestGlobMatch/*bar_bar (0.00s)2269 --- PASS: TestGlobMatch/foo*_bar (0.00s)2270 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2271 --- PASS: TestGlobMatch/*_anything (0.00s)2272 --- PASS: TestGlobMatch/?oo_boo (0.00s)2273--- PASS: TestScopes_ConfigValidation (0.00s)22742026/10/08 17:08:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37711/oidc2275--- PASS: TestValidateToken_WrongAudience (0.04s)22762026/10/08 17:08:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40827/oidc22772026/10/08 17:08:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46501/oidc2278--- PASS: TestValidateToken_ValidToken (0.06s)2279--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)22802026/10/08 17:08:35 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232281--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.07s)22822026/10/08 17:08:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43529/oidc2283--- PASS: TestValidateToken_Expired (0.08s)22842026/10/08 17:08:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44639/oidc22852026/10/08 17:08:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37041/oidc2286--- PASS: TestValidateToken_BoundSubjectMismatch (0.08s)2287--- PASS: TestScopes_Rules (0.09s)22882026/10/08 17:08:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36645/oidc22892026/10/08 17:08:35 http: TLS handshake error from 127.0.0.1:52594: remote error: tls: bad certificate2290--- PASS: TestNewValidator_KubernetesRequiresCA (0.11s)2291--- PASS: TestPins_TopLevelShorthand (0.11s)22922026/10/08 17:08:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33733/oidc2293--- PASS: TestPins_ReservedForMatchingRule (0.12s)22942026/10/08 17:08:35 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:351272295--- PASS: TestValidateToken_KubernetesServiceAccount (0.13s)22962026/10/08 17:08:35 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:44057/oidc22972026/10/08 17:08:35 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33117/oidc2298--- PASS: TestValidateToken_MultipleProviders (0.13s)22992026/10/08 17:08:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46621/oidc2300--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.14s)23012026/10/08 17:08:35 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39989/oidc2302--- PASS: TestValidateToken_NoMatchingProvider (0.23s)2303PASS2304Running hook tests...2305=== RUN TestSendPathsEmpty2306=== PAUSE TestSendPathsEmpty2307=== RUN TestQueueEnqueueAndFetch2308=== PAUSE TestQueueEnqueueAndFetch2309=== RUN TestQueueDeduplication2310=== PAUSE TestQueueDeduplication2311=== RUN TestQueueRemove2312=== PAUSE TestQueueRemove2313=== RUN TestQueueFetchBatchLimit2314=== PAUSE TestQueueFetchBatchLimit2315=== RUN TestQueueRetryMovesToBack2316=== PAUSE TestQueueRetryMovesToBack2317=== RUN TestQueueFetchRemoveLifecycle2318=== PAUSE TestQueueFetchRemoveLifecycle2319=== RUN TestQueueConcurrentWriters2320=== PAUSE TestQueueConcurrentWriters2321=== RUN TestQueueRemoveLargeClosure2322=== PAUSE TestQueueRemoveLargeClosure2323=== RUN TestServerClientIntegration2324--- PASS: TestServerClientIntegration (0.00s)2325=== RUN TestServerQueueError23262026/10/08 17:08:35 ERROR Failed to queue paths error="permission denied" count=12327--- PASS: TestServerQueueError (0.00s)2328=== RUN TestGetListenerSocketActivation2329 server_test.go:219: === RUN TestGetListenerSocketActivation2330 --- PASS: TestGetListenerSocketActivation (0.00s)2331 PASS2332 2333--- PASS: TestGetListenerSocketActivation (0.01s)2334=== RUN TestDrainIsolatesPoisonPath2335=== PAUSE TestDrainIsolatesPoisonPath2336=== RUN TestRunNotBlockedByPoisonHead2337=== PAUSE TestRunNotBlockedByPoisonHead2338=== RUN TestDrainGivesUpWhenServerDown2339=== PAUSE TestDrainGivesUpWhenServerDown2340=== RUN TestFailedPathPrunedByLaterClosure2341=== PAUSE TestFailedPathPrunedByLaterClosure2342=== RUN TestWorkerUploadsAndRemoves2343=== PAUSE TestWorkerUploadsAndRemoves2344=== RUN TestWorkerSkipsGCdPaths2345=== PAUSE TestWorkerSkipsGCdPaths2346=== RUN TestWorkerPrunesClosureDeps2347=== PAUSE TestWorkerPrunesClosureDeps2348=== RUN TestDrainTimeout2349=== PAUSE TestDrainTimeout2350=== CONT TestSendPathsEmpty2351=== CONT TestWorkerUploadsAndRemoves2352--- PASS: TestSendPathsEmpty (0.00s)2353=== CONT TestDrainTimeout2354=== CONT TestWorkerPrunesClosureDeps2355=== CONT TestWorkerSkipsGCdPaths2356=== CONT TestDrainIsolatesPoisonPath2357=== CONT TestQueueRemoveLargeClosure2358=== CONT TestQueueConcurrentWriters2359=== CONT TestDrainGivesUpWhenServerDown2360=== CONT TestQueueFetchRemoveLifecycle2361=== CONT TestQueueRetryMovesToBack2362=== CONT TestQueueFetchBatchLimit2363=== CONT TestQueueRemove2364=== CONT TestFailedPathPrunedByLaterClosure2365=== CONT TestQueueDeduplication2366=== CONT TestRunNotBlockedByPoisonHead2367=== CONT TestQueueEnqueueAndFetch23682026/10/08 17:08:35 INFO Uploading batch count=123692026/10/08 17:08:35 ERROR Upload failed error="upload failed" count=123702026/10/08 17:08:35 INFO Upload queue status pending=223712026/10/08 17:08:35 INFO Uploading batch count=123722026/10/08 17:08:35 INFO Upload queue status pending=22373--- PASS: TestQueueEnqueueAndFetch (0.01s)23742026/10/08 17:08:35 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1868718015/002/nonexistent23752026/10/08 17:08:35 INFO Uploading batch count=223762026/10/08 17:08:35 INFO Uploading batch count=123772026/10/08 17:08:35 INFO Uploading batch count=22378--- PASS: TestQueueFetchBatchLimit (0.02s)23792026/10/08 17:08:35 ERROR Upload failed error="upload failed" count=223802026/10/08 17:08:35 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3998453537/002/a23812026/10/08 17:08:35 INFO Uploading batch count=123822026/10/08 17:08:35 INFO Uploading batch count=423832026/10/08 17:08:35 ERROR Upload failed error="upload failed" count=42384--- PASS: TestQueueRemove (0.02s)23852026/10/08 17:08:35 INFO Upload queue status pending=22386--- PASS: TestQueueRetryMovesToBack (0.02s)23872026/10/08 17:08:35 INFO Upload queue status pending=32388--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23892026/10/08 17:08:35 INFO Uploading batch count=123902026/10/08 17:08:35 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3998453537/002/b23912026/10/08 17:08:35 INFO Uploading batch count=223922026/10/08 17:08:35 INFO Uploading batch count=123932026/10/08 17:08:35 ERROR Upload failed error="upload failed" count=123942026/10/08 17:08:35 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2008128583/002/bbb23952026/10/08 17:08:35 INFO Uploading batch count=223962026/10/08 17:08:35 ERROR Upload failed error="upload failed" count=223972026/10/08 17:08:35 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3998453537/002/c2398--- PASS: TestQueueDeduplication (0.02s)23992026/10/08 17:08:35 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3998453537/002/d24002026/10/08 17:08:35 INFO Uploading batch count=124012026/10/08 17:08:35 ERROR Upload failed error="upload failed" count=12402--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)24032026/10/08 17:08:35 INFO Uploading batch count=124042026/10/08 17:08:35 ERROR Upload failed error="upload failed" count=124052026/10/08 17:08:35 INFO Uploading batch count=224062026/10/08 17:08:35 ERROR Upload failed error="upload failed" count=224072026/10/08 17:08:35 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3998453537/002/e24082026/10/08 17:08:35 INFO Uploading batch count=124092026/10/08 17:08:35 ERROR Upload failed error="upload failed" count=124102026/10/08 17:08:35 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3998453537/002/f24112026/10/08 17:08:35 ERROR Drain finished with paths left in queue remaining=124122026/10/08 17:08:35 ERROR Drain finished with paths left in queue remaining=102413--- PASS: TestDrainIsolatesPoisonPath (0.02s)2414--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2415--- PASS: TestWorkerPrunesClosureDeps (0.03s)2416--- PASS: TestWorkerSkipsGCdPaths (0.04s)2417--- PASS: TestWorkerUploadsAndRemoves (0.04s)2418--- PASS: TestQueueRemoveLargeClosure (0.05s)24192026/10/08 17:08:35 ERROR Upload failed error="context deadline exceeded" count=224202026/10/08 17:08:35 ERROR Drain finished with paths left in queue remaining=42421--- PASS: TestDrainTimeout (0.22s)2422--- PASS: TestQueueConcurrentWriters (0.42s)24232026/10/08 17:08:36 INFO Uploading batch count=124242026/10/08 17:08:36 INFO Uploading batch count=124252026/10/08 17:08:36 INFO Uploading batch count=124262026/10/08 17:08:36 ERROR Upload failed error="upload failed" count=124272026/10/08 17:08:36 INFO Uploading batch count=124282026/10/08 17:08:36 ERROR Upload failed error="upload failed" count=124292026/10/08 17:08:36 INFO Uploading batch count=124302026/10/08 17:08:36 ERROR Upload failed error="upload failed" count=124312026/10/08 17:08:36 INFO Uploading batch count=124322026/10/08 17:08:36 ERROR Upload failed error="upload failed" count=124332026/10/08 17:08:36 ERROR Drain finished with paths left in queue remaining=12434--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2435PASS2436Running signing tests...2437=== RUN TestExternalSigner2438=== PAUSE TestExternalSigner2439=== RUN TestExternalSignerWrongPublicKey2440=== PAUSE TestExternalSignerWrongPublicKey2441=== RUN TestExternalSignerErrors2442=== PAUSE TestExternalSignerErrors2443=== RUN TestExternalSignerRestartsAfterCrash2444=== PAUSE TestExternalSignerRestartsAfterCrash2445=== RUN TestExternalSignerProgramErrorKeepsProcess2446=== PAUSE TestExternalSignerProgramErrorKeepsProcess2447=== RUN TestExternalSignerClose2448=== PAUSE TestExternalSignerClose2449=== RUN TestExternalSignerRejectsInvalidPublicKey2450=== PAUSE TestExternalSignerRejectsInvalidPublicKey2451=== RUN TestExternalSignerCancellation2452=== PAUSE TestExternalSignerCancellation2453=== RUN TestGenerateFingerprint2454=== PAUSE TestGenerateFingerprint2455=== RUN TestParseSigningKey2456=== PAUSE TestParseSigningKey2457=== RUN TestSign2458=== PAUSE TestSign2459=== RUN TestSignBatch2460=== PAUSE TestSignBatch2461=== RUN TestNilKeyPublicKey2462=== PAUSE TestNilKeyPublicKey2463=== RUN TestSignErrors2464=== PAUSE TestSignErrors2465=== CONT TestExternalSigner2466=== CONT TestExternalSignerProgramErrorKeepsProcess2467=== CONT TestExternalSignerCancellation2468=== CONT TestSignErrors2469=== CONT TestNilKeyPublicKey2470=== CONT TestSignBatch2471=== CONT TestSign2472=== CONT TestParseSigningKey2473--- PASS: TestNilKeyPublicKey (0.00s)2474=== RUN TestParseSigningKey/valid_32-byte_key2475=== PAUSE TestParseSigningKey/valid_32-byte_key2476=== CONT TestExternalSignerWrongPublicKey2477=== CONT TestExternalSignerRestartsAfterCrash2478=== CONT TestExternalSignerRejectsInvalidPublicKey2479=== CONT TestExternalSignerClose2480=== CONT TestExternalSignerErrors2481=== CONT TestGenerateFingerprint2482=== RUN TestGenerateFingerprint/basic_with_references2483=== RUN TestExternalSignerRejectsInvalidPublicKey/#002484=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002485=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2486=== PAUSE TestGenerateFingerprint/basic_with_references2487=== RUN TestGenerateFingerprint/no_references2488=== PAUSE TestGenerateFingerprint/no_references2489=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2490=== RUN TestExternalSignerErrors/wrong_signature_length2491=== PAUSE TestExternalSignerErrors/wrong_signature_length2492=== RUN TestExternalSignerErrors/program_error2493=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2494=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2495=== RUN TestParseSigningKey/no_colon2496=== PAUSE TestParseSigningKey/no_colon2497=== PAUSE TestExternalSignerErrors/program_error2498=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2499=== RUN TestExternalSignerErrors/exit_at_startup2500=== PAUSE TestExternalSignerErrors/exit_at_startup2501=== RUN TestSignErrors/nil_key2502--- PASS: TestSign (0.00s)2503=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2504=== RUN TestParseSigningKey/empty_name2505=== PAUSE TestParseSigningKey/empty_name2506=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2507=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2508=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2509=== RUN TestExternalSignerErrors/invalid_JSON2510=== PAUSE TestExternalSignerErrors/invalid_JSON2511=== PAUSE TestSignErrors/nil_key2512--- PASS: TestSignBatch (0.00s)2513=== RUN TestParseSigningKey/invalid_base642514=== PAUSE TestParseSigningKey/invalid_base642515=== RUN TestParseSigningKey/wrong_length2516=== PAUSE TestParseSigningKey/wrong_length2517=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2518=== RUN TestGenerateFingerprint/invalid_nar_hash_length2519=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2520--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2521=== RUN TestExternalSignerErrors/null2522=== PAUSE TestExternalSignerErrors/null2523=== RUN TestSignErrors/nil_narinfo2524=== PAUSE TestSignErrors/nil_narinfo2525=== RUN TestSignErrors/invalid_narinfo2526=== PAUSE TestSignErrors/invalid_narinfo2527=== RUN TestSignErrors/canceled2528=== PAUSE TestSignErrors/canceled2529=== CONT TestParseSigningKey/valid_32-byte_key2530=== CONT TestParseSigningKey/no_colon2531=== CONT TestParseSigningKey/empty_name2532=== CONT TestParseSigningKey/wrong_length2533=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2534=== CONT TestParseSigningKey/invalid_base642535--- PASS: TestParseSigningKey (0.00s)2536 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2537 --- PASS: TestParseSigningKey/no_colon (0.00s)2538 --- PASS: TestParseSigningKey/empty_name (0.00s)2539 --- PASS: TestParseSigningKey/wrong_length (0.00s)2540 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2541 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2542=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2543=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2544=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2545=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2546=== RUN TestGenerateFingerprint/invalid_store_path_prefix2547=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2548=== RUN TestExternalSignerErrors/null_signatures2549--- PASS: TestExternalSignerClose (0.00s)2550--- PASS: TestExternalSignerWrongPublicKey (0.00s)2551=== CONT TestSignErrors/nil_key2552=== CONT TestSignErrors/nil_narinfo2553=== CONT TestSignErrors/invalid_narinfo2554=== CONT TestSignErrors/canceled2555--- PASS: TestSignErrors (0.00s)2556 --- PASS: TestSignErrors/nil_key (0.00s)2557 --- PASS: TestSignErrors/nil_narinfo (0.00s)2558 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2559 --- PASS: TestSignErrors/canceled (0.00s)2560=== CONT TestExternalSignerRejectsInvalidPublicKey/#002561=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2562=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2563=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2564=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2565--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2566 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2567 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2568 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2569 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2570 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2571=== RUN TestGenerateFingerprint/invalid_reference_prefix2572=== PAUSE TestExternalSignerErrors/null_signatures2573=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2574=== RUN TestExternalSignerErrors/wrong_signature_name2575=== CONT TestGenerateFingerprint/basic_with_references2576=== CONT TestGenerateFingerprint/invalid_reference_prefix2577=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2578=== CONT TestGenerateFingerprint/no_references2579=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2580=== CONT TestGenerateFingerprint/invalid_store_path_prefix2581=== CONT TestGenerateFingerprint/invalid_nar_hash_length2582--- PASS: TestGenerateFingerprint (0.00s)2583 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2584 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2585 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2586 --- PASS: TestGenerateFingerprint/no_references (0.00s)2587 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2588 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2589 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2590=== PAUSE TestExternalSignerErrors/wrong_signature_name2591=== RUN TestExternalSignerErrors/wrong_shape2592=== PAUSE TestExternalSignerErrors/wrong_shape2593=== RUN TestExternalSignerErrors/unrequested_key2594=== PAUSE TestExternalSignerErrors/unrequested_key2595=== RUN TestExternalSignerErrors/wrong_id2596=== PAUSE TestExternalSignerErrors/wrong_id2597=== RUN TestExternalSignerErrors/too_few_signatures2598=== PAUSE TestExternalSignerErrors/too_few_signatures2599=== RUN TestExternalSignerErrors/missing_signature_name2600=== PAUSE TestExternalSignerErrors/missing_signature_name2601=== RUN TestExternalSignerErrors/invalid_signature_base642602=== PAUSE TestExternalSignerErrors/invalid_signature_base642603=== RUN TestExternalSignerErrors/exit_on_request2604=== PAUSE TestExternalSignerErrors/exit_on_request2605=== RUN TestExternalSignerErrors/missing_signatures2606=== PAUSE TestExternalSignerErrors/missing_signatures2607=== RUN TestExternalSignerErrors/wrong_signatures_shape2608=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2609=== CONT TestExternalSignerErrors/wrong_signature_length2610=== CONT TestExternalSignerErrors/wrong_id2611=== CONT TestExternalSignerErrors/exit_at_startup2612=== CONT TestExternalSignerErrors/wrong_signature_name2613=== CONT TestExternalSignerErrors/wrong_signatures_shape2614=== CONT TestExternalSignerErrors/missing_signatures2615=== CONT TestExternalSignerErrors/exit_on_request2616=== CONT TestExternalSignerErrors/invalid_signature_base642617=== CONT TestExternalSignerErrors/unrequested_key2618=== CONT TestExternalSignerErrors/wrong_shape2619=== CONT TestExternalSignerErrors/invalid_JSON2620=== CONT TestExternalSignerErrors/too_few_signatures2621=== CONT TestExternalSignerErrors/null_signatures2622=== CONT TestExternalSignerErrors/null2623=== CONT TestExternalSignerErrors/missing_signature_name2624=== CONT TestExternalSignerErrors/program_error2625--- PASS: TestExternalSigner (0.01s)2626--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2627--- PASS: TestExternalSignerErrors (0.01s)2628 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2629 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2630 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2631 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2632 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2633 --- PASS: TestExternalSignerErrors/program_error (0.00s)2634 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2635 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2636 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2637 --- PASS: TestExternalSignerErrors/null (0.01s)2638 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2639 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2640 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2641 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2642 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2643 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2644--- PASS: TestExternalSignerCancellation (0.02s)2645PASS2646Running OpenBao signer tests...2647=== RUN TestSign2648=== PAUSE TestSign2649=== RUN TestSignErrors2650=== PAUSE TestSignErrors2651=== RUN TestServe2652=== PAUSE TestServe2653=== RUN TestServeRejectsGarbage2654=== PAUSE TestServeRejectsGarbage2655=== CONT TestSign2656=== CONT TestServeRejectsGarbage2657=== CONT TestSignErrors2658=== CONT TestServe2659=== RUN TestSignErrors/no_prefix2660--- PASS: TestServeRejectsGarbage (0.00s)2661=== PAUSE TestSignErrors/no_prefix2662=== RUN TestSignErrors/invalid_base642663=== PAUSE TestSignErrors/invalid_base642664=== RUN TestSignErrors/http_error2665=== PAUSE TestSignErrors/http_error2666=== RUN TestSignErrors/invalid_json2667=== PAUSE TestSignErrors/invalid_json2668=== CONT TestSignErrors/no_prefix2669--- PASS: TestServe (0.00s)2670=== CONT TestSignErrors/http_error2671=== CONT TestSignErrors/invalid_json2672=== CONT TestSignErrors/invalid_base642673--- PASS: TestSign (0.00s)2674--- PASS: TestSignErrors (0.00s)2675 --- PASS: TestSignErrors/http_error (0.00s)2676 --- PASS: TestSignErrors/no_prefix (0.00s)2677 --- PASS: TestSignErrors/invalid_base64 (0.00s)2678 --- PASS: TestSignErrors/invalid_json (0.00s)2679PASS