niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #392
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestSetClientTLSErrors102=== CONT TestScriptTokenCachesUntilRefresh103=== CONT TestFileTokenReadsAndCaches104=== CONT TestScriptTokenEmptyCommand105--- PASS: TestScriptTokenEmptyCommand (0.00s)106=== CONT TestDumpPathSingleFile107=== CONT TestScriptTokenScriptFails108--- PASS: TestFileTokenReadsAndCaches (0.00s)109=== CONT TestDumpPathMatchesNix110=== CONT TestScriptTokenBadJSON111=== CONT TestStaticToken112--- PASS: TestStaticToken (0.00s)113=== CONT TestUploadMultipart_SupersededByPeer114=== RUN TestUploadMultipart_SupersededByPeer/exists115=== PAUSE TestUploadMultipart_SupersededByPeer/exists116=== CONT TestScriptTokenEmptyToken117=== CONT TestEncodeNixBase32118--- PASS: TestScriptTokenScriptFails (0.00s)119=== RUN TestEncodeNixBase32/test_string_hash120=== CONT TestPartSizeForNAR121=== CONT TestParsePathInfoJSON122=== CONT TestResolveStorePath123=== CONT TestPathInfoHashCompatibility124=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess125=== CONT TestGetStorePathHash126=== CONT TestRateLimiterFeedback127=== CONT TestConvertHashToNix32128=== CONT TestPathInfoCACompatibility129=== CONT TestEncodeNixBase32WithRealHash130=== CONT TestUploadMultipart_PartsInParallel131=== CONT TestDumpPathWriterError132=== CONT TestScriptTokenNoExpiryRerunsEveryCall133=== RUN TestUploadMultipart_SupersededByPeer/missing134=== CONT TestParsePathInfoJSONMultiplePaths135=== PAUSE TestEncodeNixBase32/test_string_hash136=== RUN TestRateLimiterFeedback/429_enables_limiter137=== RUN TestParsePathInfoJSON/Nix_format138--- PASS: TestEncodeNixBase32WithRealHash (0.00s)139=== PAUSE TestUploadMultipart_SupersededByPeer/missing140=== RUN TestPartSizeForNAR/zero_stays_at_minimum141=== PAUSE TestParsePathInfoJSON/Nix_format142=== RUN TestParsePathInfoJSON/Lix_format143=== PAUSE TestParsePathInfoJSON/Lix_format144=== RUN TestParsePathInfoJSON/empty_input145=== PAUSE TestParsePathInfoJSON/empty_input146=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths147=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths148=== RUN TestParsePathInfoJSON/whitespace_only1492026/10/07 06:17:54 WARN Rate limiter enabled after throttle name=server-test rate=51502026/10/07 06:17:54 WARN Rate limiter enabled after throttle name=server-test rate=51512026/10/07 06:17:54 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:44831152=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum153=== RUN TestGetStorePathHash/valid_store_path154=== CONT TestSetClientTLSDoesNotMutateDefaultTransport155=== CONT TestSetClientTLS156=== CONT TestClientSignaturesByStorePath157=== PAUSE TestGetStorePathHash/valid_store_path1582026/10/07 06:17:54 WARN Rate limiter backed off name=server-test rate=5159=== RUN TestGetStorePathHash/basename_without_hyphen_should_error1602026/10/07 06:17:54 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:44831161=== PAUSE TestRateLimiterFeedback/429_enables_limiter162=== RUN TestRateLimiterFeedback/503_enables_limiter163=== RUN TestPathInfoCACompatibility/null_ca_field164=== PAUSE TestPathInfoCACompatibility/null_ca_field165=== RUN TestEncodeNixBase32/empty_input166=== PAUSE TestEncodeNixBase32/empty_input167=== CONT TestStreamPushGivesUpOnDeadServer168--- PASS: TestScriptTokenBadJSON (0.01s)169=== RUN TestSetClientTLSErrors/missing_cert_file170--- PASS: TestScriptTokenEmptyToken (0.00s)171=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1722026/10/07 06:17:54 ERROR Upload failed error="connection refused" count=201732026/10/07 06:17:54 ERROR Server seems unavailable, giving up on batch untried=17174=== RUN TestConvertHashToNix32/SRI_format_to_Nix32175=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32176=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths177=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths178=== RUN TestConvertHashToNix32/already_Nix32_format179=== PAUSE TestConvertHashToNix32/already_Nix32_format180=== RUN TestPartSizeForNAR/small_stays_at_minimum181=== PAUSE TestPartSizeForNAR/small_stays_at_minimum182=== CONT TestFileTokenEmpty183=== CONT TestFilterOversizedClosures184=== RUN TestFilterOversizedClosures/no_limit_keeps_everything185=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything186=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped187=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped188=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun189=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error190=== PAUSE TestRateLimiterFeedback/503_enables_limiter191=== RUN TestPathInfoCACompatibility/old_string_format_-_text192=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text193=== CONT TestStreamPushReportsSignatures194=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter195=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter196=== PAUSE TestSetClientTLSErrors/missing_cert_file197=== RUN TestSetClientTLSErrors/missing_key_file198=== PAUSE TestSetClientTLSErrors/missing_key_file199=== CONT TestCaseHackSuffix200--- PASS: TestResolveStorePath (0.00s)201--- PASS: TestDoServerRequestAttachesToken (0.04s)202=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)203--- PASS: TestClientSignaturesByStorePath (0.00s)204--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)2052026/10/07 06:17:54 ERROR Upload failed error=boom count=1206--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)207=== CONT TestStreamPushBatchesUnderLoad208=== CONT TestStreamPushRequestLine209=== RUN TestSetClientTLS/rejects_connection_without_client_cert210=== CONT TestStreamPushReportsEveryPath211=== PAUSE TestParsePathInfoJSON/whitespace_only212=== CONT TestStreamPushIsolatesFailures213=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2142026/10/07 06:17:54 ERROR Upload failed error=boom count=1215=== CONT TestShellSplitErrors216=== CONT TestRegisterUploadedObjectReusesConnections217=== CONT TestShellSplit218=== RUN TestConvertHashToNix32/invalid_format219=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum2202026/10/07 06:17:54 ERROR Upload failed error="bad path" count=3221=== CONT TestFileTokenMissing222=== CONT TestUploadMultipart_SupersededByPeer/exists2232026/10/07 06:17:54 INFO Garbage collection started224=== CONT TestUploadMultipart_SupersededByPeer/missing2252026/10/07 06:17:54 INFO Garbage collection started226=== CONT TestEncodeNixBase32/test_string_hash227=== CONT TestEncodeNixBase32/empty_input228=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths229=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths230=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum231=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts232=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts233=== RUN TestPartSizeForNAR/1_TiB234=== PAUSE TestPartSizeForNAR/1_TiB235=== RUN TestPartSizeForNAR/5_TiB_S3_max_object236=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object237=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error238=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive239=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter240=== RUN TestSetClientTLSErrors/missing_ca_file241=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon242--- PASS: TestDumpPathSingleFile (0.04s)243=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert244=== RUN TestParsePathInfoJSON/invalid_JSON245=== PAUSE TestConvertHashToNix32/invalid_format246=== RUN TestFilterOversizedClosures/all_closures_skipped247=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error248=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter249=== PAUSE TestFilterOversizedClosures/all_closures_skipped250=== CONT TestRateLimiterFeedback/429_enables_limiter251=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error252=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error253=== RUN TestPartSizeForNAR/capped_at_5_GiB254=== PAUSE TestPartSizeForNAR/capped_at_5_GiB255=== CONT TestConvertHashToNix32/already_Nix32_format256=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2572026/10/07 06:17:54 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=2000258=== CONT TestRateLimiterFeedback/503_enables_limiter2592026/10/07 06:17:54 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=02602026/10/07 06:17:54 WARN Rate limiter enabled after throttle name=server-test rate=52612026/10/07 06:17:54 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:40853262=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter263=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2642026/10/07 06:17:54 WARN Rate limiter backed off name=server-test rate=5265=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon2662026/10/07 06:17:54 WARN Rate limiter enabled after throttle name=server-test rate=5267=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2682026/10/07 06:17:54 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:44771269=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI270=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512271=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512272--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)273--- PASS: TestStreamPushReportsSignatures (0.00s)274--- PASS: TestStreamPushReportsEveryPath (0.00s)275--- PASS: TestShellSplitErrors (0.00s)276--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)277--- PASS: TestShellSplit (0.00s)278--- PASS: TestStreamPushIsolatesFailures (0.00s)279--- PASS: TestFileTokenEmpty (0.00s)280--- PASS: TestFileTokenMissing (0.00s)281=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA282--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)283=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error284=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error285=== CONT TestGetStorePathHash/basename_without_hyphen_should_error286=== CONT TestPartSizeForNAR/capped_at_5_GiB2872026/10/07 06:17:54 WARN Rate limiter backed off name=server-test rate=5288=== CONT TestPartSizeForNAR/5_TiB_S3_max_object289=== CONT TestPartSizeForNAR/1_TiB290=== CONT TestPartSizeForNAR/small_stays_at_minimum291=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum292=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts293=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI294--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)295=== CONT TestPartSizeForNAR/zero_stays_at_minimum296--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)297 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)298 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)299--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)300 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)301 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)302--- PASS: TestPartSizeForNAR (0.04s)303 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)304 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)305 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)306 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)307 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)308 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)309 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)310=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon311=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512312=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA3132026/10/07 06:17:54 WARN Garbage collection finished on another replica. Its statistics are not available here314=== RUN TestSetClientTLS/preserves_debug_logging_transport315=== PAUSE TestSetClientTLS/preserves_debug_logging_transport316=== CONT TestSetClientTLS/rejects_connection_without_client_cert317=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA318=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)319=== CONT TestSetClientTLS/preserves_debug_logging_transport320--- PASS: TestRateLimiterFeedback (0.03s)321 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)322 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)323 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)324 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)325--- PASS: TestEncodeNixBase32 (0.03s)326 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)327 --- PASS: TestEncodeNixBase32/empty_input (0.00s)328=== CONT TestConvertHashToNix32/SRI_format_to_Nix32329=== CONT TestFilterOversizedClosures/no_limit_keeps_everything330=== PAUSE TestSetClientTLSErrors/missing_ca_file331=== CONT TestConvertHashToNix32/invalid_format332=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive333=== CONT TestFilterOversizedClosures/all_closures_skipped334=== CONT TestGetStorePathHash/valid_store_path335=== PAUSE TestParsePathInfoJSON/invalid_JSON3362026/10/07 06:17:54 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50337--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)338=== RUN TestSetClientTLSErrors/invalid_ca_file339=== PAUSE TestSetClientTLSErrors/invalid_ca_file340=== CONT TestSetClientTLSErrors/missing_cert_file341=== CONT TestSetClientTLSErrors/missing_ca_file342=== CONT TestSetClientTLSErrors/missing_key_file343=== RUN TestPathInfoCACompatibility/new_structured_format_-_text344=== CONT TestParsePathInfoJSON/Nix_format345=== CONT TestParsePathInfoJSON/invalid_JSON346=== CONT TestParsePathInfoJSON/whitespace_only347=== CONT TestParsePathInfoJSON/empty_input348=== CONT TestParsePathInfoJSON/Lix_format349--- PASS: TestPathInfoHashCompatibility (0.01s)350 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)351 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)352 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)353 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)354=== CONT TestSetClientTLSErrors/invalid_ca_file355--- PASS: TestConvertHashToNix32 (0.03s)356 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)357 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)358 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)359=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text360--- PASS: TestFilterOversizedClosures (0.00s)361 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)362 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)363 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)364--- PASS: TestGetStorePathHash (0.04s)365 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)366 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)367 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)368 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)369--- PASS: TestParsePathInfoJSON (0.04s)370 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)371 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)372 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)373 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)374 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)375=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method376=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method377=== CONT TestPathInfoCACompatibility/null_ca_field378--- PASS: TestSetClientTLSErrors (0.05s)379 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)380 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)381 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)382 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)383=== CONT TestPathInfoCACompatibility/new_structured_format_-_text384=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method385=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive386=== CONT TestPathInfoCACompatibility/old_string_format_-_text387--- PASS: TestPathInfoCACompatibility (0.05s)388 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)389 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)390 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)391 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)392 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)3932026/10/07 06:17:54 http: TLS handshake error from 127.0.0.1:45868: remote error: tls: bad certificate394--- PASS: TestSetClientTLS (0.01s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)397 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)398--- PASS: TestStreamPushRequestLine (0.02s)399--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)400--- PASS: TestCaseHackSuffix (0.03s)401--- PASS: TestDumpPathWriterError (0.07s)402--- PASS: TestDumpPathMatchesNix (0.13s)403--- PASS: TestStreamPushBatchesUnderLoad (0.10s)404--- PASS: TestUploadMultipart_PartsInParallel (0.65s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres445151688/data ... ok418creating subdirectories ... ok419selecting dynamic shared memory implementation ... posix420selecting default "max_connections" ... 100421selecting default "shared_buffers" ... 128MB422selecting default time zone ... UTC423creating configuration files ... ok424running bootstrap script ... ok425performing post-bootstrap initialization ... ok426syncing data to disk ... ok427428initdb: warning: enabling "trust" authentication for local connections429initdb: 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.430431Success. You can now start the database server using:432433 pg_ctl -D /build/postgres445151688/data -l logfile start434435/build/postgres445151688:5432 - no response4362026-10-07 06:17:56.314 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-07 06:17:56.314 UTC [129] LOG: listening on Unix socket "/build/postgres445151688/.s.PGSQL.5432"4382026-10-07 06:17:56.320 UTC [136] LOG: database system was shut down at 2026-10-07 06:17:56 UTC4392026-10-07 06:17:56.325 UTC [129] LOG: database system is ready to accept connections440/build/postgres445151688:5432 - accepting connections441{"timestamp":"2026-10-07T06:17:56.621164709Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"f7f99306-3c3e-4d75-80f8-5ec550a9af1b","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(397)"}442=== RUN TestService_AuthMiddleware443=== PAUSE TestService_AuthMiddleware444=== RUN TestService_AuthMiddleware_MTLSProxyHeader445=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader446=== RUN TestService_AuthMiddleware_MTLSBoundSubjects447=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects448=== RUN TestService_ReadAuthMiddleware449=== PAUSE TestService_ReadAuthMiddleware450=== RUN TestService_AuthMiddleware_OIDC451=== PAUSE TestService_AuthMiddleware_OIDC452=== RUN TestService_RequireScope_OIDC453=== PAUSE TestService_RequireScope_OIDC454=== RUN TestService_ReadScope_PublicByDefault455=== PAUSE TestService_ReadScope_PublicByDefault456=== RUN TestCacheConfigHandler457=== PAUSE TestCacheConfigHandler458=== RUN TestCacheStatsHandler459=== PAUSE TestCacheStatsHandler460=== RUN TestClientCADerivations461=== PAUSE TestClientCADerivations462=== RUN TestClientErrorHandling463=== PAUSE TestClientErrorHandling464=== RUN TestClientIntegration465=== PAUSE TestClientIntegration466=== RUN TestClientMultipleUploads467=== PAUSE TestClientMultipleUploads468=== RUN TestClientWithDependencies469=== PAUSE TestClientWithDependencies470=== RUN TestClientSharedPathCommittedMidPush471=== PAUSE TestClientSharedPathCommittedMidPush472=== RUN TestPinProtectsFromGC473=== PAUSE TestPinProtectsFromGC474=== RUN TestClientPushesUseOnePush475=== PAUSE TestClientPushesUseOnePush476=== RUN TestClientFallsBackToClosures477=== PAUSE TestClientFallsBackToClosures478=== RUN TestDeleteClosuresRacingPins479=== PAUSE TestDeleteClosuresRacingPins480=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock482=== RUN TestResolveDBConnectionString483=== PAUSE TestResolveDBConnectionString484=== RUN TestConnectWaitsForAPeerMigration485=== PAUSE TestConnectWaitsForAPeerMigration486=== RUN TestLeadElectsOneAndHandsOver487=== PAUSE TestLeadElectsOneAndHandsOver488=== RUN TestLeadIncumbentWinsAfterRestart4892026/10/07 06:17:56 INFO lead: acquired remote=192.0.2.1:12344902026/10/07 06:17:57 INFO lead: released remote=192.0.2.1:12344912026/10/07 06:17:57 INFO lead: acquired remote=192.0.2.1:12344922026/10/07 06:17:58 INFO lead: released remote=192.0.2.1:1234493--- PASS: TestLeadIncumbentWinsAfterRestart (1.90s)494=== RUN TestLeadIncumbentAnnouncesAtOnce495=== PAUSE TestLeadIncumbentAnnouncesAtOnce496=== RUN TestLeadEndsOnShutdown497=== PAUSE TestLeadEndsOnShutdown498=== RUN TestLeadEndsWhenItsConnectionHangs4992026/10/07 06:17:58 INFO lead: acquired remote=192.0.2.1:12345002026-10-07 06:18:00.138 UTC [576] FATAL: terminating connection due to administrator command5012026/10/07 06:18:00 INFO lead: acquired remote=192.0.2.1:12345022026/10/07 06:18:01 WARN lead: lock connection lost error="timeout: context deadline exceeded"5032026/10/07 06:18:01 INFO lead: released remote=192.0.2.1:12345042026/10/07 06:18:01 INFO lead: released remote=192.0.2.1:1234505--- PASS: TestLeadEndsWhenItsConnectionHangs (2.91s)506=== RUN TestGCAdvisoryLockBlocksConcurrentRun507=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestSweepRechecksPendingAfterLocking535=== PAUSE TestSweepRechecksPendingAfterLocking536=== RUN TestPushWaitsForSweepHoldingRow537=== PAUSE TestPushWaitsForSweepHoldingRow538=== RUN TestCommitRacingPendingCleanupKeepsObjects539=== PAUSE TestCommitRacingPendingCleanupKeepsObjects540=== RUN TestGCEndsOnShutdown541=== PAUSE TestGCEndsOnShutdown542=== RUN TestGCTaskStore_StartNew543=== PAUSE TestGCTaskStore_StartNew544=== RUN TestGCTaskStore_DeduplicateSameParams545=== PAUSE TestGCTaskStore_DeduplicateSameParams546=== RUN TestGCTaskStore_ConflictDifferentParams547=== PAUSE TestGCTaskStore_ConflictDifferentParams548=== RUN TestGCTaskStore_GetEmpty549=== PAUSE TestGCTaskStore_GetEmpty550=== RUN TestGCTaskStore_GetReturnsLatest551=== PAUSE TestGCTaskStore_GetReturnsLatest552=== RUN TestGCTaskStore_CompletedAllowsNewTask553=== PAUSE TestGCTaskStore_CompletedAllowsNewTask554=== RUN TestGCTaskStore_PhaseUpdates555=== PAUSE TestGCTaskStore_PhaseUpdates556=== RUN TestGCTaskStore_Fail557=== PAUSE TestGCTaskStore_Fail558=== RUN TestGracefulShutdownDrainsInflight559=== PAUSE TestGracefulShutdownDrainsInflight560=== RUN TestService_healthCheckHandler561=== PAUSE TestService_healthCheckHandler562=== RUN TestService_readinessHandler563=== PAUSE TestService_readinessHandler564=== RUN TestGenerateLandingPage565=== PAUSE TestGenerateLandingPage566=== RUN TestCacheConfigHandlerMaxNarSize567=== PAUSE TestCacheConfigHandlerMaxNarSize568=== RUN TestCreatePendingClosureRejectsOversizedNAR569=== PAUSE TestCreatePendingClosureRejectsOversizedNAR570=== RUN TestNARDeduplicationMetadataUploadBug571=== PAUSE TestNARDeduplicationMetadataUploadBug572=== RUN TestMetricsInventory573=== PAUSE TestMetricsInventory574=== RUN TestMetricsCommit575=== PAUSE TestMetricsCommit576=== RUN TestService_NativeMTLS577=== PAUSE TestService_NativeMTLS578=== RUN TestServerTLSConfig579=== PAUSE TestServerTLSConfig580=== RUN TestMultipartCleanup581=== PAUSE TestMultipartCleanup582=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded584=== RUN TestPendingCleanupUsesOneCutoff585=== PAUSE TestPendingCleanupUsesOneCutoff586=== RUN TestObjectStatsTrigger587=== PAUSE TestObjectStatsTrigger588=== RUN TestObjectStatsLargeCommit589=== PAUSE TestObjectStatsLargeCommit590=== RUN TestOrphanedObjectsGC591=== PAUSE TestOrphanedObjectsGC592=== RUN TestOrphanedObjectsGCStressTest593=== PAUSE TestOrphanedObjectsGCStressTest594=== RUN TestCreatePin_ReservedPins595=== PAUSE TestCreatePin_ReservedPins596=== RUN TestPresentReportsOnlyClosureRoots597=== PAUSE TestPresentReportsOnlyClosureRoots598=== RUN TestPresentRefreshesOnlyStaleClosures599=== PAUSE TestPresentRefreshesOnlyStaleClosures600=== RUN TestPresentNotReportedWhileGCDeletesClosure601=== PAUSE TestPresentNotReportedWhileGCDeletesClosure602=== RUN TestParseSingleRange603=== PAUSE TestParseSingleRange604=== RUN TestProxyHeadersOnlyTrustedOnSocket6052026/10/07 06:18:01 INFO Starting HTTP server address=127.0.0.1:445456062026/10/07 06:18:01 INFO Starting HTTP server address=proxy.sock6072026/10/07 06:18:01 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6082026/10/07 06:18:01 INFO Shutdown signal received, draining in-flight requests timeout=10s609--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.11s)610=== RUN TestIsValidCachePath611=== PAUSE TestIsValidCachePath612=== RUN TestReadProxyNarinfo613=== PAUSE TestReadProxyNarinfo614=== RUN TestReadProxyNarinfoAlreadyDecompressed615=== PAUSE TestReadProxyNarinfoAlreadyDecompressed616=== RUN TestReadProxyContentNegotiation617=== PAUSE TestReadProxyContentNegotiation618=== RUN TestReadProxyNarStreaming619=== PAUSE TestReadProxyNarStreaming620=== RUN TestReadProxy404621=== PAUSE TestReadProxy404622=== RUN TestReadProxyInvalidPath623=== PAUSE TestReadProxyInvalidPath624=== RUN TestReadProxyHead625=== PAUSE TestReadProxyHead626=== RUN TestReadProxyOutlastsServerWriteTimeout627=== PAUSE TestReadProxyOutlastsServerWriteTimeout628=== RUN TestReadProxyConditionalGet629=== PAUSE TestReadProxyConditionalGet630=== RUN TestReadProxyRootRedirectsToIndexHTML631=== PAUSE TestReadProxyRootRedirectsToIndexHTML632=== RUN TestReadProxyDisabled633=== PAUSE TestReadProxyDisabled634=== RUN TestReadRedirectNar635=== PAUSE TestReadRedirectNar636=== RUN TestReadRedirectKeepsNarinfoProxied637=== PAUSE TestReadRedirectKeepsNarinfoProxied638=== RUN TestReadProxyRangeRequest639=== PAUSE TestReadProxyRangeRequest640=== RUN TestReadRedirectUsesPublicS3URL641=== PAUSE TestReadRedirectUsesPublicS3URL642=== RUN TestPush_OverlappingRootsStoreOneRowPerKey643=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey644=== RUN TestPush_CompleteCommitsEveryRoot645=== PAUSE TestPush_CompleteCommitsEveryRoot646=== RUN TestPush_RepeatedRootCommitsOnce647=== PAUSE TestPush_RepeatedRootCommitsOnce648=== RUN TestPush_CompleteWaitsForCleanupOfThePush649=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush650=== RUN TestPush_RootsAreLockedInByteOrder651=== PAUSE TestPush_RootsAreLockedInByteOrder652=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit653=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit654=== RUN TestPush_RejectsBadRequests655=== PAUSE TestPush_RejectsBadRequests656=== RUN TestPush_SignsNarinfosOfItsPendingObjects657=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects658=== RUN TestRedundantMultipartUpload659=== PAUSE TestRedundantMultipartUpload660=== RUN TestCompleteMultipartUpload_ErrorButObjectExists661=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists662=== RUN TestCompletedNarNotReofferedAcrossClosures663=== PAUSE TestCompletedNarNotReofferedAcrossClosures664=== RUN TestPresignedUploadRegisteredBeforeCommit665=== PAUSE TestPresignedUploadRegisteredBeforeCommit666=== RUN TestService_Rustfstest667=== PAUSE TestService_Rustfstest668=== RUN TestParseSize669=== PAUSE TestParseSize670=== RUN TestSkippedUploadsHandler671=== PAUSE TestSkippedUploadsHandler672=== RUN TestSystemdListenerNotActivated673--- PASS: TestSystemdListenerNotActivated (0.00s)674=== RUN TestWatchdogBeatsWhenHealthy675--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)676=== RUN TestWatchdogSkipsWhenUnhealthy6772026/10/07 06:18:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6782026/10/07 06:18:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6792026/10/07 06:18:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6802026/10/07 06:18:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6812026/10/07 06:18:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6822026/10/07 06:18:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6832026/10/07 06:18:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6842026/10/07 06:18:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6852026/10/07 06:18:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6862026/10/07 06:18:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"687--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)688=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle689=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle690=== RUN TestProxyWriteTimeout691=== PAUSE TestProxyWriteTimeout692=== RUN TestPendingClosureWriteTimeout693=== PAUSE TestPendingClosureWriteTimeout694=== RUN TestIsValidUploadKey695=== PAUSE TestIsValidUploadKey696=== RUN TestUploadHandlersRejectInvalidKeys697=== PAUSE TestUploadHandlersRejectInvalidKeys698=== RUN TestUploadHandlersRejectOversizedBody699=== PAUSE TestUploadHandlersRejectOversizedBody700=== RUN TestService_cleanupPendingClosuresHandler701=== PAUSE TestService_cleanupPendingClosuresHandler702=== RUN TestService_createPendingClosureHandler703=== PAUSE TestService_createPendingClosureHandler704=== RUN TestService_verifyS3Integrity705=== PAUSE TestService_verifyS3Integrity706=== RUN TestCompleteMultipartUnregistered707=== PAUSE TestCompleteMultipartUnregistered708=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT709=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT710=== CONT TestService_AuthMiddleware711=== CONT TestReadProxyInvalidPath712=== CONT TestOrphanedObjectsGCStressTest713=== CONT TestProxyWriteTimeout714=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT715=== RUN TestProxyWriteTimeout/narinfo716=== CONT TestCompleteMultipartUnregistered717=== CONT TestService_verifyS3Integrity718=== CONT TestService_createPendingClosureHandler719=== CONT TestService_cleanupPendingClosuresHandler720=== CONT TestUploadHandlersRejectOversizedBody721=== CONT TestReadProxyRangeRequest722=== CONT TestReadRedirectKeepsNarinfoProxied723=== CONT TestReadRedirectNar724=== CONT TestReadProxyDisabled725=== CONT TestReadProxyRootRedirectsToIndexHTML726=== CONT TestReadRedirectUsesPublicS3URL727=== CONT TestReadProxyConditionalGet728=== CONT TestUploadHandlersRejectInvalidKeys729=== CONT TestReadProxyOutlastsServerWriteTimeout730=== CONT TestIsValidUploadKey731=== CONT TestReadProxyHead732=== CONT TestPendingClosureWriteTimeout733=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle734=== CONT TestSkippedUploadsHandler735=== PAUSE TestProxyWriteTimeout/narinfo736=== RUN TestProxyWriteTimeout/1_GiB_nar737=== PAUSE TestProxyWriteTimeout/1_GiB_nar738=== RUN TestProxyWriteTimeout/10_GiB_nar739=== PAUSE TestProxyWriteTimeout/10_GiB_nar740=== RUN TestProxyWriteTimeout/unknown_size741=== PAUSE TestProxyWriteTimeout/unknown_size742=== RUN TestIsValidUploadKey/narinfo743=== PAUSE TestIsValidUploadKey/narinfo744=== RUN TestIsValidUploadKey/nar_zst745=== PAUSE TestIsValidUploadKey/nar_zst746=== RUN TestIsValidUploadKey/nar_xz747=== PAUSE TestIsValidUploadKey/nar_xz748=== RUN TestIsValidUploadKey/nar_plain749=== PAUSE TestIsValidUploadKey/nar_plain750=== RUN TestIsValidUploadKey/listing751=== PAUSE TestIsValidUploadKey/listing752=== RUN TestIsValidUploadKey/build_log753=== PAUSE TestIsValidUploadKey/build_log754=== CONT TestParseSize755=== RUN TestPendingClosureWriteTimeout/empty756=== PAUSE TestPendingClosureWriteTimeout/empty757--- PASS: TestParseSize (0.00s)7582026/10/07 06:18:01 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000759=== CONT TestService_Rustfstest760=== RUN TestIsValidUploadKey/build_log_home-manager_file761=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info762=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info763=== RUN TestPendingClosureWriteTimeout/400_objects764=== PAUSE TestIsValidUploadKey/build_log_home-manager_file765=== PAUSE TestPendingClosureWriteTimeout/400_objects766=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal767=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal768=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key769=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key770=== RUN TestIsValidUploadKey/build_log_plus_in_name771=== RUN TestPendingClosureWriteTimeout/670k_objects772=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key773=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key774=== PAUSE TestIsValidUploadKey/build_log_plus_in_name775=== PAUSE TestPendingClosureWriteTimeout/670k_objects776=== CONT TestPresignedUploadRegisteredBeforeCommit777=== RUN TestIsValidUploadKey/build_log_question_mark778=== PAUSE TestIsValidUploadKey/build_log_question_mark779=== RUN TestIsValidUploadKey/build_log_equals780=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline781=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline782=== PAUSE TestIsValidUploadKey/build_log_equals783=== CONT TestCompletedNarNotReofferedAcrossClosures784=== RUN TestIsValidUploadKey/realisation785=== PAUSE TestIsValidUploadKey/realisation786=== RUN TestIsValidUploadKey/realisation_plus_in_output787=== PAUSE TestIsValidUploadKey/realisation_plus_in_output788=== RUN TestIsValidUploadKey/nix-cache-info789=== PAUSE TestIsValidUploadKey/nix-cache-info790=== RUN TestIsValidUploadKey/index.html791=== PAUSE TestIsValidUploadKey/index.html792=== RUN TestIsValidUploadKey/narinfo_key,_nar_type793=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type794=== RUN TestIsValidUploadKey/nar_key,_narinfo_type795--- PASS: TestSkippedUploadsHandler (0.02s)796=== CONT TestCompleteMultipartUpload_ErrorButObjectExists797=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type798=== RUN TestIsValidUploadKey/listing_key,_narinfo_type799=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type800=== RUN TestIsValidUploadKey/traversal801=== PAUSE TestIsValidUploadKey/traversal802=== RUN TestIsValidUploadKey/traversal_nar803=== PAUSE TestIsValidUploadKey/traversal_nar804=== RUN TestIsValidUploadKey/absolute805=== PAUSE TestIsValidUploadKey/absolute806=== RUN TestIsValidUploadKey/empty_key807=== PAUSE TestIsValidUploadKey/empty_key808=== RUN TestIsValidUploadKey/unknown_type809=== PAUSE TestIsValidUploadKey/unknown_type810=== CONT TestRedundantMultipartUpload811=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure812=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure813=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart814=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart815=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts816=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts817=== CONT TestPush_SignsNarinfosOfItsPendingObjects8182026/10/07 06:18:02 INFO Received uploads request method=POST path=/api/pending_closures819--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.53s)820=== CONT TestPush_RejectsBadRequests8212026/10/07 06:18:02 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"822--- PASS: TestService_AuthMiddleware (0.54s)823=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit8242026/10/07 06:18:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8252026/10/07 06:18:02 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst826--- PASS: TestCompleteMultipartUnregistered (0.57s)827=== CONT TestPush_RootsAreLockedInByteOrder8282026/10/07 06:18:02 INFO Received uploads request method=POST path=/api/pending_closures8292026/10/07 06:18:02 INFO Received uploads request method=POST path=/api/pending_closures8302026/10/07 06:18:02 INFO Received uploads request method=POST path=/api/pending_closures831--- PASS: TestReadProxyInvalidPath (0.61s)832=== CONT TestPush_CompleteWaitsForCleanupOfThePush833--- PASS: TestReadProxyHead (0.67s)834=== CONT TestPush_RepeatedRootCommitsOnce8352026/10/07 06:18:02 INFO Received uploads request method=POST path=/api/pending_closures8362026/10/07 06:18:02 INFO Received cleanup request method=DELETE path=/api/pending_closures8372026/10/07 06:18:02 INFO Aborted multipart uploads count=0 kept=08382026/10/07 06:18:02 INFO Received uploads request method=POST path=/api/pending_closures8392026/10/07 06:18:02 INFO Received cleanup request method=DELETE path=/api/pending_closures8402026/10/07 06:18:02 INFO Aborted multipart uploads count=1 kept=08412026/10/07 06:18:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8422026-10-07 06:18:02.625 UTC [662] ERROR: Closure does not exist: id=18432026-10-07 06:18:02.625 UTC [662] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE8442026-10-07 06:18:02.625 UTC [662] STATEMENT: -- name: CommitPendingClosure :one845 SELECT commit_pending_closure($1::bigint)::bigint846 847--- PASS: TestService_cleanupPendingClosuresHandler (0.75s)848=== CONT TestPush_CompleteCommitsEveryRoot849--- PASS: TestReadProxyRangeRequest (0.76s)850=== CONT TestPush_OverlappingRootsStoreOneRowPerKey8512026/10/07 06:18:02 INFO Received uploads request method=POST path=/api/pending_closures8522026/10/07 06:18:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete853--- PASS: TestReadRedirectNar (0.81s)854=== CONT TestClientFallsBackToClosures8552026/10/07 06:18:02 INFO Received uploads request method=POST path=/api/pending_closures856--- PASS: TestReadRedirectKeepsNarinfoProxied (0.87s)857=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection858--- PASS: TestService_Rustfstest (0.89s)859=== CONT TestForceGCDuringPushOffersSweptObject860=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows861=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows862=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check863=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check864=== CONT TestGCSweepDeliversEachKeyOnce865--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.92s)866=== CONT TestOrphanedObjectsGC867--- PASS: TestReadProxyConditionalGet (0.95s)868=== CONT TestTombstonedObjectOfferedWithoutWaiting8692026/10/07 06:18:02 INFO Received uploads request method=POST path=/api/pending_closures8702026/10/07 06:18:02 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8712026/10/07 06:18:02 INFO Received uploads request method=POST path=/api/pending_closures872--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.99s)873=== CONT TestObjectStatsLargeCommit874--- PASS: TestReadRedirectUsesPublicS3URL (1.02s)875=== CONT TestGCSweepSkipsPendingObjects876--- PASS: TestReadProxyDisabled (1.03s)877=== CONT TestObjectStatsTrigger8782026/10/07 06:18:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8792026/10/07 06:18:02 INFO Received uploads request method=POST path=/api/pending_closures8802026/10/07 06:18:02 INFO Received uploads request method=POST path=/api/pending_closures8812026/10/07 06:18:02 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ODBkZWQ1NGYtOTNhYy00MDk1LTkzMjEtNTllOGM3N2FiZmY0LjViMzgyMzg0LWM1MWQtNDVmNC04MmVlLWI3OTNlZGE3N2JjNHgxNzkxMzUzODgyNDY4ODM2MDI0 parts=108822026/10/07 06:18:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8832026/10/07 06:18:02 INFO Completed upload id=1 objects=2 duration=2.683559ms8842026/10/07 06:18:02 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008852026/10/07 06:18:02 INFO Received uploads request method=POST path=/api/pending_closures8862026/10/07 06:18:02 INFO Received uploads request method=POST path=/api/pending_closures8872026/10/07 06:18:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures8882026/10/07 06:18:03 INFO Aborted multipart uploads count=0 kept=08892026/10/07 06:18:03 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=08902026/10/07 06:18:03 INFO Vacuumed table table=pending_closures8912026/10/07 06:18:03 INFO Received push request method=POST path=/api/pushes8922026/10/07 06:18:03 INFO Vacuumed table table=pending_objects8932026/10/07 06:18:03 INFO Vacuumed table table=multipart_uploads8942026/10/07 06:18:03 INFO Vacuumed table table=closures8952026/10/07 06:18:03 INFO Vacuumed table table=objects8962026/10/07 06:18:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8972026/10/07 06:18:03 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODBkZWQ1NGYtOTNhYy00MDk1LTkzMjEtNTllOGM3N2FiZmY0LmQ3NWU0ZmU4LTUyMzctNDEyNi04MjcxLTIxNjFlYzRlY2I4MXgxNzkxMzUzODgzMDA1MjExMjIz8982026/10/07 06:18:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8992026/10/07 06:18:03 INFO Signed narinfos id=1 count=19002026/10/07 06:18:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9012026/10/07 06:18:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9022026/10/07 06:18:03 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9032026/10/07 06:18:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9042026/10/07 06:18:03 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9052026/10/07 06:18:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9062026/10/07 06:18:03 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19072026/10/07 06:18:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9082026/10/07 06:18:03 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo909--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.85s)910=== CONT TestDeduplicatedObjectsRecordedAsPending9112026/10/07 06:18:03 INFO Received push request method=POST path=/api/pushes9122026/10/07 06:18:03 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODBkZWQ1NGYtOTNhYy00MDk1LTkzMjEtNTllOGM3N2FiZmY0LmQ3NWU0ZmU4LTUyMzctNDEyNi04MjcxLTIxNjFlYzRlY2I4MXgxNzkxMzUzODgzMDA1MjExMjIz parts=1913--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.04s)914=== CONT TestPendingCleanupUsesOneCutoff9152026/10/07 06:18:03 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000916--- PASS: TestService_createPendingClosureHandler (1.18s)917=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded9182026/10/07 06:18:03 INFO Received complete push request method=POST path=/api/pushes/1/complete919=== RUN TestPush_RejectsBadRequests/no_roots920=== PAUSE TestPush_RejectsBadRequests/no_roots921=== RUN TestPush_RejectsBadRequests/no_objects922=== PAUSE TestPush_RejectsBadRequests/no_objects923=== RUN TestPush_RejectsBadRequests/bad_root924=== PAUSE TestPush_RejectsBadRequests/bad_root925=== RUN TestPush_RejectsBadRequests/root_not_in_objects926=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects927=== CONT TestPushDedupSurvivesConcurrentGC9282026/10/07 06:18:03 INFO Completed push id=1 objects=4 duration=9.467497ms9292026/10/07 06:18:03 INFO Received push request method=POST path=/api/pushes9302026/10/07 06:18:03 INFO Received push request method=POST path=/api/pushes9312026/10/07 06:18:03 INFO Received push request method=POST path=/api/pushes9322026/10/07 06:18:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9332026/10/07 06:18:03 INFO Aborted multipart uploads count=0 kept=09342026/10/07 06:18:03 WARN Force mode enabled - objects will be deleted immediately without grace period9352026/10/07 06:18:03 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ODBkZWQ1NGYtOTNhYy00MDk1LTkzMjEtNTllOGM3N2FiZmY0LmYyZTM3Yjk5LWFhNTYtNDRkNy05NDhjLTcwOTQ5MWUwZDkwMngxNzkxMzUzODgyNjYzNDk3NTg4 parts=109362026/10/07 06:18:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9372026/10/07 06:18:03 INFO Received push request method=POST path=/api/pushes9382026-10-07 06:18:03.155 UTC [756] ERROR: could not obtain lock on row in relation "closures"9392026-10-07 06:18:03.155 UTC [756] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9402026/10/07 06:18:03 INFO Completed upload id=1 objects=2 duration=5.505468ms9412026-10-07 06:18:03.156 UTC [756] ERROR: could not obtain lock on row in relation "closures"9422026-10-07 06:18:03.156 UTC [756] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9432026-10-07 06:18:03.157 UTC [756] ERROR: could not obtain lock on row in relation "closures"9442026-10-07 06:18:03.157 UTC [756] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9452026-10-07 06:18:03.157 UTC [756] ERROR: could not obtain lock on row in relation "closures"9462026-10-07 06:18:03.157 UTC [756] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9472026-10-07 06:18:03.157 UTC [756] ERROR: could not obtain lock on row in relation "closures"9482026-10-07 06:18:03.157 UTC [756] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9492026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures9502026/10/07 06:18:03 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=09512026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures952--- PASS: TestPush_RootsAreLockedInByteOrder (0.72s)953=== CONT TestMultipartCleanup9542026/10/07 06:18:03 INFO Vacuumed table table=pending_closures9552026/10/07 06:18:03 INFO Vacuumed table table=pending_objects9562026/10/07 06:18:03 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9572026/10/07 06:18:03 WARN Found objects in DB but missing from S3, will re-upload count=1958--- PASS: TestService_verifyS3Integrity (1.29s)959=== CONT TestServerTLSConfig960=== RUN TestServerTLSConfig/no_client_CA961=== PAUSE TestServerTLSConfig/no_client_CA962=== RUN TestServerTLSConfig/missing_CA_file963=== PAUSE TestServerTLSConfig/missing_CA_file964=== RUN TestServerTLSConfig/not_a_PEM_file965=== PAUSE TestServerTLSConfig/not_a_PEM_file966=== CONT TestGCMetrics9672026/10/07 06:18:03 INFO Vacuumed table table=multipart_uploads9682026/10/07 06:18:03 INFO Vacuumed table table=closures9692026/10/07 06:18:03 INFO Received complete push request method=POST path=/api/pushes/1/complete9702026/10/07 06:18:03 INFO Vacuumed table table=objects9712026/10/07 06:18:03 INFO Received complete push request method=POST path=/api/pushes/2/complete9722026/10/07 06:18:03 INFO Completed push id=2 objects=4 duration=6.247848ms973--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.77s)974=== CONT TestService_NativeMTLS9752026/10/07 06:18:03 INFO Completed push id=1 objects=4 duration=9.533697ms976--- PASS: TestPush_RepeatedRootCommitsOnce (0.64s)977=== CONT TestGCBugBareHashReferences9782026/10/07 06:18:03 INFO Received push request method=POST path=/api/pushes9792026/10/07 06:18:03 INFO Received complete push request method=POST path=/api/pushes/1/complete9802026/10/07 06:18:03 INFO Received push request method=POST path=/api/pushes9812026/10/07 06:18:03 INFO Completed push id=1 objects=6 duration=10.819646ms982--- PASS: TestPush_CompleteCommitsEveryRoot (0.60s)983=== CONT TestMetricsCommit984--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.62s)985=== CONT TestGCAdvisoryLockBlocksConcurrentRun9862026/10/07 06:18:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9872026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures9882026/10/07 06:18:03 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ODBkZWQ1NGYtOTNhYy00MDk1LTkzMjEtNTllOGM3N2FiZmY0LmMzMTAyN2ZlLTYzZjUtNDVmYS05ZWQzLTBiN2Q0NDc2NzY1OHgxNzkxMzUzODgyNzE5OTY1Mjc5 parts=129892026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures990--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.43s)991=== CONT TestMetricsInventory9922026/10/07 06:18:03 INFO Aborted multipart uploads count=0 kept=09932026/10/07 06:18:03 WARN Force mode enabled - objects will be deleted immediately without grace period9942026/10/07 06:18:03 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=09952026/10/07 06:18:03 INFO Vacuumed table table=pending_closures9962026/10/07 06:18:03 INFO Vacuumed table table=pending_objects9972026/10/07 06:18:03 INFO Vacuumed table table=multipart_uploads9982026/10/07 06:18:03 INFO Vacuumed table table=closures9992026/10/07 06:18:03 INFO Vacuumed table table=objects1000--- PASS: TestGCSweepDeliversEachKeyOnce (0.61s)1001=== CONT TestLeadEndsOnShutdown10022026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures1003--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.56s)1004=== CONT TestNARDeduplicationMetadataUploadBug10052026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures10062026-10-07 06:18:03.449 UTC [761] ERROR: Push does not exist: id=110072026-10-07 06:18:03.449 UTC [761] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10082026-10-07 06:18:03.449 UTC [761] STATEMENT: SELECT commit_push($1)1009--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.96s)1010=== CONT TestLeadIncumbentAnnouncesAtOnce10112026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures10122026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures10132026/10/07 06:18:03 INFO Aborted multipart uploads count=0 kept=010142026/10/07 06:18:03 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10152026/10/07 06:18:03 INFO Uploading nzd1k0nm38rvm8s9r2saf21105xpxzkf-shared-dep (136B)10162026/10/07 06:18:03 INFO Uploading ylaw8hkmkdmp0x3mggylwlw12n9nbi03-a (216B)10172026/10/07 06:18:03 WARN Force mode enabled - objects will be deleted immediately without grace period10182026/10/07 06:18:03 WARN Failed to register uploaded object key=3rqp1hsck3qx95r58fsch5f0iz295iy2.ls error="server returned 404: 404 page not found\n"10192026/10/07 06:18:03 WARN Failed to register uploaded object key=ylaw8hkmkdmp0x3mggylwlw12n9nbi03.ls error="server returned 404: 404 page not found\n"10202026/10/07 06:18:03 WARN Failed to register uploaded object key=nzd1k0nm38rvm8s9r2saf21105xpxzkf.ls error="server returned 404: 404 page not found\n"10212026/10/07 06:18:03 WARN Failed to register uploaded object key=nar/0nb27hl8lzm7gkqs15cx1rpninpr3s1aq9bb40y96l112f3s5197.nar.zst error="server returned 404: 404 page not found\n"10222026/10/07 06:18:03 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=010232026/10/07 06:18:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10242026/10/07 06:18:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10252026/10/07 06:18:03 INFO Signed narinfos id=1 count=210262026/10/07 06:18:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10272026/10/07 06:18:03 INFO Vacuumed table table=pending_closures10282026/10/07 06:18:03 INFO Signed narinfos id=2 count=210292026/10/07 06:18:03 INFO Uploading 4 narinfos10302026/10/07 06:18:03 WARN Failed to register uploaded object key=nzd1k0nm38rvm8s9r2saf21105xpxzkf.narinfo error="server returned 404: 404 page not found\n"10312026/10/07 06:18:03 WARN Failed to register uploaded object key=3rqp1hsck3qx95r58fsch5f0iz295iy2.narinfo error="server returned 404: 404 page not found\n"10322026/10/07 06:18:03 WARN Failed to register uploaded object key=ylaw8hkmkdmp0x3mggylwlw12n9nbi03.narinfo error="server returned 404: 404 page not found\n"10332026/10/07 06:18:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10342026/10/07 06:18:03 WARN Failed to register uploaded object key=nzd1k0nm38rvm8s9r2saf21105xpxzkf.narinfo error="server returned 404: 404 page not found\n"10352026/10/07 06:18:03 INFO Vacuumed table table=pending_objects10362026/10/07 06:18:03 INFO Vacuumed table table=multipart_uploads10372026/10/07 06:18:03 INFO Vacuumed table table=closures10382026/10/07 06:18:03 INFO Completed upload id=1 objects=6 duration=6.100918ms10392026/10/07 06:18:03 INFO Vacuumed table table=objects10402026/10/07 06:18:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10412026/10/07 06:18:03 INFO Completed upload id=2 objects=6 duration=2.329819ms10422026/10/07 06:18:03 INFO Upload complete. (79ms)1043=== NAME TestClientFallsBackToClosures1044 client_pushes_test.go:112: Retrieved narinfo from S3:1045 StorePath: /build/TestClientFallsBackToClosures114714191/001/store/nzd1k0nm38rvm8s9r2saf21105xpxzkf-shared-dep1046 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1047 Compression: zstd1048 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821049 NarSize: 1361050 References: 1051 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1052--- PASS: TestObjectStatsTrigger (0.59s)1053=== CONT TestCreatePendingClosureRejectsOversizedNAR10542026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures1055--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1056=== CONT TestCacheConfigHandlerMaxNarSize1057--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1058=== CONT TestLeadElectsOneAndHandsOver1059=== NAME TestClientFallsBackToClosures1060 client_pushes_test.go:112: Retrieved narinfo from S3:1061 StorePath: /build/TestClientFallsBackToClosures114714191/001/store/ylaw8hkmkdmp0x3mggylwlw12n9nbi03-a1062 URL: nar/0nb27hl8lzm7gkqs15cx1rpninpr3s1aq9bb40y96l112f3s5197.nar.zst1063 Compression: zstd1064 NarHash: sha256:0nb27hl8lzm7gkqs15cx1rpninpr3s1aq9bb40y96l112f3s51971065 NarSize: 2161066 References: /build/TestClientFallsBackToClosures114714191/001/store/nzd1k0nm38rvm8s9r2saf21105xpxzkf-shared-dep1067 CA: text:sha256:1354ij9kbnhf1w3ihq699p4na8qw0j6w2chn3c3hmil4pkdnmkxp1068--- PASS: TestGCSweepSkipsPendingObjects (0.61s)1069=== CONT TestGenerateLandingPage10702026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures1071=== NAME TestClientFallsBackToClosures1072 client_pushes_test.go:112: Retrieved narinfo from S3:1073 StorePath: /build/TestClientFallsBackToClosures114714191/001/store/3rqp1hsck3qx95r58fsch5f0iz295iy2-b1074 URL: nar/0nb27hl8lzm7gkqs15cx1rpninpr3s1aq9bb40y96l112f3s5197.nar.zst1075 Compression: zstd1076 NarHash: sha256:0nb27hl8lzm7gkqs15cx1rpninpr3s1aq9bb40y96l112f3s51971077 NarSize: 2161078 References: /build/TestClientFallsBackToClosures114714191/001/store/nzd1k0nm38rvm8s9r2saf21105xpxzkf-shared-dep1079 CA: text:sha256:1354ij9kbnhf1w3ihq699p4na8qw0j6w2chn3c3hmil4pkdnmkxp1080--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.76s)1081--- PASS: TestGenerateLandingPage (0.00s)1082=== CONT TestConnectWaitsForAPeerMigration1083=== CONT TestService_readinessHandler1084--- PASS: TestClientFallsBackToClosures (0.83s)1085=== CONT TestResolveDBConnectionString1086--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.48s)1087=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1088=== RUN TestResolveDBConnectionString/flag_wins1089=== PAUSE TestResolveDBConnectionString/flag_wins1090=== RUN TestResolveDBConnectionString/file_when_flag_empty1091=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1092=== RUN TestResolveDBConnectionString/missing_file_is_an_error1093=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1094=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1095=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1096=== RUN TestResolveDBConnectionString/nothing_configured1097=== PAUSE TestResolveDBConnectionString/nothing_configured1098=== CONT TestService_healthCheckHandler10992026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures11002026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures11012026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures11022026/10/07 06:18:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11032026/10/07 06:18:03 INFO Received cleanup request method=DELETE path=/api/pending_closures1104--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.54s)1105=== CONT TestDeleteClosuresRacingPins11062026/10/07 06:18:03 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ODBkZWQ1NGYtOTNhYy00MDk1LTkzMjEtNTllOGM3N2FiZmY0LjM1ZTNkMGI4LTE1M2ItNDk3Ni05MDk4LWVhZjk3MGQwY2U4MngxNzkxMzUzODgyOTgxMzU5NTcx parts=1211072026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures11082026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures11092026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures11102026/10/07 06:18:03 INFO Received uploads request method=POST path=/api/pending_closures11112026/10/07 06:18:03 INFO Aborted multipart uploads count=0 kept=011122026/10/07 06:18:03 WARN Force mode enabled - objects will be deleted immediately without grace period11132026/10/07 06:18:03 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=011142026/10/07 06:18:03 INFO Vacuumed table table=pending_closures11152026/10/07 06:18:03 INFO Vacuumed table table=pending_objects11162026/10/07 06:18:03 INFO Vacuumed table table=multipart_uploads11172026/10/07 06:18:03 INFO Vacuumed table table=closures11182026/10/07 06:18:03 INFO Vacuumed table table=objects1119--- PASS: TestGCMetrics (0.51s)1120=== CONT TestGracefulShutdownDrainsInflight11212026/10/07 06:18:03 INFO Starting HTTP server address=127.0.0.1:4440111222026/10/07 06:18:03 INFO Shutdown signal received, draining in-flight requests timeout=10s11232026/10/07 06:18:03 INFO Aborted multipart uploads count=0 kept=01124=== NAME TestOrphanedObjectsGC1125 orphaned_objects_gc_test.go:287: GC Test Summary:1126 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1127 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1128 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1129 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1130 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1131--- PASS: TestOrphanedObjectsGC (0.91s)1132=== CONT TestGCTaskStore_Fail1133--- PASS: TestGCTaskStore_Fail (0.00s)1134=== CONT TestGCTaskStore_PhaseUpdates1135--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1136=== CONT TestClientCADerivations11372026/10/07 06:18:03 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=011382026/10/07 06:18:03 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11392026/10/07 06:18:03 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1140--- PASS: TestService_NativeMTLS (0.52s)1141=== CONT TestGCTaskStore_CompletedAllowsNewTask1142--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1143=== CONT TestClientPushesUseOnePush11442026/10/07 06:18:03 INFO Vacuumed table table=pending_closures11452026/10/07 06:18:03 INFO Vacuumed table table=pending_objects11462026/10/07 06:18:03 INFO Vacuumed table table=multipart_uploads11472026/10/07 06:18:03 INFO Vacuumed table table=closures11482026/10/07 06:18:03 INFO Vacuumed table table=objects11492026/10/07 06:18:03 INFO Aborted multipart uploads count=0 kept=011502026/10/07 06:18:03 WARN Force mode enabled - objects will be deleted immediately without grace period11512026/10/07 06:18:03 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=011522026/10/07 06:18:03 INFO Vacuumed table table=pending_closures11532026/10/07 06:18:03 INFO Vacuumed table table=pending_objects11542026/10/07 06:18:03 INFO Vacuumed table table=multipart_uploads11552026/10/07 06:18:03 INFO Received push request method=POST path=/api/pushes11562026/10/07 06:18:03 INFO Received cleanup request method=DELETE path=/api/pending_closures11572026/10/07 06:18:03 INFO Vacuumed table table=closures11582026/10/07 06:18:03 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket47/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11592026/10/07 06:18:03 INFO Aborted multipart uploads count=0 kept=111602026/10/07 06:18:03 INFO Vacuumed table table=objects1161--- PASS: TestPushDedupSurvivesConcurrentGC (0.67s)1162=== CONT TestGCTaskStore_GetReturnsLatest1163--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1164=== CONT TestGCTaskStore_GetEmpty1165--- PASS: TestGCTaskStore_GetEmpty (0.00s)1166=== CONT TestPinProtectsFromGC11672026/10/07 06:18:03 INFO Received cleanup request method=DELETE path=/api/pending_closures1168--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1169=== CONT TestClientSharedPathCommittedMidPush11702026/10/07 06:18:03 INFO Aborted multipart uploads count=1 kept=01171--- PASS: TestMultipartCleanup (0.59s)1172=== CONT TestClientWithDependencies11732026/10/07 06:18:03 INFO Received complete push request method=POST path=/api/pushes/1/complete11742026/10/07 06:18:03 INFO Completed push id=1 objects=4 duration=8.298467ms11752026/10/07 06:18:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11762026/10/07 06:18:03 INFO Completed upload id=2 objects=2 duration=1.366379ms11772026/10/07 06:18:03 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"1178--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.52s)1179=== CONT TestGCTaskStore_ConflictDifferentParams1180--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1181=== CONT TestClientMultipleUploads1182--- PASS: TestMetricsCommit (0.55s)1183=== CONT TestClientIntegration11842026/10/07 06:18:03 INFO lead: acquired remote=192.0.2.1:12341185--- PASS: TestMetricsInventory (0.52s)1186=== CONT TestGCTaskStore_DeduplicateSameParams1187--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1188=== CONT TestClientErrorHandling1189=== RUN TestClientErrorHandling/InvalidStorePath1190=== PAUSE TestClientErrorHandling/InvalidStorePath1191=== RUN TestClientErrorHandling/InvalidAuthToken1192=== PAUSE TestClientErrorHandling/InvalidAuthToken1193=== RUN TestClientErrorHandling/ServerNotAvailable1194=== PAUSE TestClientErrorHandling/ServerNotAvailable1195=== CONT TestGCTaskStore_StartNew1196--- PASS: TestGCTaskStore_StartNew (0.00s)1197=== CONT TestIsValidCachePath1198=== RUN TestIsValidCachePath/narinfo1199=== PAUSE TestIsValidCachePath/narinfo1200=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1201=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1202=== RUN TestIsValidCachePath/nar_zst1203=== PAUSE TestIsValidCachePath/nar_zst1204=== RUN TestIsValidCachePath/nar_xz1205=== PAUSE TestIsValidCachePath/nar_xz1206=== RUN TestIsValidCachePath/nar_bz21207=== PAUSE TestIsValidCachePath/nar_bz21208=== RUN TestIsValidCachePath/nar_uncompressed1209=== PAUSE TestIsValidCachePath/nar_uncompressed1210=== RUN TestIsValidCachePath/ls1211=== PAUSE TestIsValidCachePath/ls1212=== RUN TestIsValidCachePath/log1213=== PAUSE TestIsValidCachePath/log1214=== RUN TestIsValidCachePath/realisation1215=== PAUSE TestIsValidCachePath/realisation1216=== RUN TestIsValidCachePath/nix-cache-info1217=== PAUSE TestIsValidCachePath/nix-cache-info1218=== RUN TestIsValidCachePath/index.html1219=== PAUSE TestIsValidCachePath/index.html1220=== RUN TestIsValidCachePath/traversal_parent1221=== PAUSE TestIsValidCachePath/traversal_parent1222=== RUN TestIsValidCachePath/traversal_in_middle1223=== PAUSE TestIsValidCachePath/traversal_in_middle1224=== RUN TestIsValidCachePath/invalid_char_e1225=== PAUSE TestIsValidCachePath/invalid_char_e1226=== RUN TestIsValidCachePath/invalid_char_u1227=== PAUSE TestIsValidCachePath/invalid_char_u1228=== RUN TestIsValidCachePath/random_path1229=== PAUSE TestIsValidCachePath/random_path1230=== RUN TestIsValidCachePath/empty1231=== PAUSE TestIsValidCachePath/empty1232=== RUN TestIsValidCachePath/leading_slash1233=== PAUSE TestIsValidCachePath/leading_slash1234=== RUN TestIsValidCachePath/wrong_extension1235=== PAUSE TestIsValidCachePath/wrong_extension1236=== RUN TestIsValidCachePath/short_hash1237=== PAUSE TestIsValidCachePath/short_hash1238=== CONT TestGCEndsOnShutdown1239=== RUN TestGCEndsOnShutdown/before_the_run1240=== PAUSE TestGCEndsOnShutdown/before_the_run1241=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1242=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1243=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1244=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1245=== CONT TestCommitRacingPendingCleanupKeepsObjects12462026/10/07 06:18:03 INFO lead: acquired remote=192.0.2.1:123412472026/10/07 06:18:03 INFO lead: released remote=192.0.2.1:12341248--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.43s)1249=== CONT TestReadProxy4041250=== NAME TestNARDeduplicationMetadataUploadBug1251 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2971504011/001/store/wzw4fpf7vqf1imjx34rby2aika7j4qw4-file1.txt12522026/10/07 06:18:03 INFO lead: acquired remote=192.0.2.1:123412532026/10/07 06:18:03 WARN readiness check failed error="closed pool"1254--- PASS: TestService_readinessHandler (0.42s)1255=== CONT TestPushWaitsForSweepHoldingRow1256--- PASS: TestGCBugBareHashReferences (0.74s)1257=== CONT TestReadProxyNarStreaming12582026/10/07 06:18:03 INFO Received push request method=POST path=/api/pushes12592026/10/07 06:18:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12602026/10/07 06:18:03 INFO Uploading wzw4fpf7vqf1imjx34rby2aika7j4qw4-file1.txt (160B)12612026/10/07 06:18:03 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12622026/10/07 06:18:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12632026/10/07 06:18:03 WARN Failed to register uploaded object key=wzw4fpf7vqf1imjx34rby2aika7j4qw4.ls error="server returned 404: 404 page not found\n"12642026/10/07 06:18:03 INFO Signed narinfos id=1 count=112652026/10/07 06:18:03 INFO Uploading 1 narinfos1266--- PASS: TestService_healthCheckHandler (0.46s)1267=== CONT TestSweepRechecksPendingAfterLocking12682026/10/07 06:18:03 INFO Received complete push request method=POST path=/api/pushes/1/complete12692026/10/07 06:18:03 WARN Failed to register uploaded object key=wzw4fpf7vqf1imjx34rby2aika7j4qw4.narinfo error="server returned 404: 404 page not found\n"12702026/10/07 06:18:04 INFO Completed push id=1 objects=3 duration=22.025373ms12712026/10/07 06:18:04 INFO Upload complete. (74ms)1272=== NAME TestNARDeduplicationMetadataUploadBug1273 metadata_upload_test.go:54: Retrieved narinfo from S3:1274 StorePath: /build/TestNARDeduplicationMetadataUploadBug2971504011/001/store/wzw4fpf7vqf1imjx34rby2aika7j4qw4-file1.txt1275 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1276 Compression: zstd1277 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1278 NarSize: 1601279 References: 1280 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1281 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1282 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1283 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1284 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2971504011/001/store/aisvnx2cy69xwip767la3bjp4rdfw0wl-file2.txt12852026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes12862026/10/07 06:18:04 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12872026/10/07 06:18:04 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12882026/10/07 06:18:04 WARN Failed to register uploaded object key=aisvnx2cy69xwip767la3bjp4rdfw0wl.ls error="server returned 404: 404 page not found\n"12892026/10/07 06:18:04 INFO Signed narinfos id=2 count=112902026/10/07 06:18:04 INFO Uploading 1 narinfos12912026/10/07 06:18:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12922026/10/07 06:18:04 INFO Received complete push request method=POST path=/api/pushes/2/complete12932026/10/07 06:18:04 WARN Failed to register uploaded object key=aisvnx2cy69xwip767la3bjp4rdfw0wl.narinfo error="server returned 404: 404 page not found\n"12942026/10/07 06:18:04 INFO Completed push id=2 objects=3 duration=3.343769ms12952026/10/07 06:18:04 INFO Upload complete. (53ms)1296 metadata_upload_test.go:76: Retrieved narinfo from S3:1297 StorePath: /build/TestNARDeduplicationMetadataUploadBug2971504011/001/store/aisvnx2cy69xwip767la3bjp4rdfw0wl-file2.txt1298 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1299 Compression: zstd1300 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1301 NarSize: 1601302 References: 1303 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1304 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1305 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1306 {"version":1,"root":{"type":"regular","size":44}}13072026/10/07 06:18:04 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ODBkZWQ1NGYtOTNhYy00MDk1LTkzMjEtNTllOGM3N2FiZmY0LjY1YTU1NWIwLTFhMGUtNDllYS04ODNkLWMzNDQ1MGFiNDAwN3gxNzkxMzUzODgzNjI5OTIxNDAz error="Get \"http://127.0.0.1:1/bucket25/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13082026/10/07 06:18:04 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ODBkZWQ1NGYtOTNhYy00MDk1LTkzMjEtNTllOGM3N2FiZmY0LjJlZGEyMTBlLTI2OWQtNDBkNy1hODAwLWY5NDcxNmUyNTYxMHgxNzkxMzUzODgzNjExNzU4NzA5 parts=1213092026/10/07 06:18:04 INFO Received cleanup request method=DELETE path=/api/pending_closures1310--- PASS: TestNARDeduplicationMetadataUploadBug (0.76s)1311=== CONT TestReadProxyContentNegotiation13122026/10/07 06:18:04 INFO Aborted multipart uploads count=1 kept=01313=== NAME TestClientCADerivations1314 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations686108702/001/store/rd05ljwk1dwz1gmfv71x47ipwqm49qnk-ca-test1315=== NAME TestPinProtectsFromGC1316 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC4129405337/001/store/5wlqxavfljn2y134wzhmnmh1w1qmn9w5-pinned-file.txt1317 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC4129405337/001/store/17z8mwp4r7xi4g3szx2mixvvx7kzvhy2-unpinned-file.txt1318--- PASS: TestRedundantMultipartUpload (2.16s)1319=== CONT TestGetExistingObjectsLocksRows1320--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.67s)1321=== CONT TestReadProxyNarinfoAlreadyDecompressed1322=== NAME TestClientCADerivations1323 client_ca_test.go:139: Found 1 dependencies (including self)1324=== NAME TestClientMultipleUploads1325 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3311388521/001/store/4fkibgd1ijs2amkffifvbs69rdcw93xi-test-file-0.txt13262026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes13272026/10/07 06:18:04 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13282026/10/07 06:18:04 INFO Uploading wn8qm4652lzf8n733ncda5jxrccbikkn-b (216B)13292026/10/07 06:18:04 INFO Uploading rca9zxnfn9k5wd7sc631yv9dxjws3ykk-shared-dep (136B)13302026/10/07 06:18:04 WARN Failed to register uploaded object key=nar/1kv5dvnpgcayjrihv646gzk8l0qd8qs53i4f0wnz5y3xjxfxglp5.nar.zst error="server returned 404: 404 page not found\n"13312026/10/07 06:18:04 WARN Failed to register uploaded object key=wn8qm4652lzf8n733ncda5jxrccbikkn.ls error="server returned 404: 404 page not found\n"13322026/10/07 06:18:04 WARN Failed to register uploaded object key=qw9gshj3vxcjyl3k9mpk08sfnhfzcshn.ls error="server returned 404: 404 page not found\n"13332026/10/07 06:18:04 WARN Failed to register uploaded object key=rca9zxnfn9k5wd7sc631yv9dxjws3ykk.ls error="server returned 404: 404 page not found\n"13342026/10/07 06:18:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13352026/10/07 06:18:04 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13362026/10/07 06:18:04 INFO Signed narinfos id=1 count=313372026/10/07 06:18:04 INFO Uploading 3 narinfos1338=== NAME TestClientIntegration1339 client_integration_test.go:286: Created store path: /build/TestClientIntegration3847027360/002/store/pjfb8zi0nbzcg78r2nds8h065vw6kpv1-test-file.txt1340=== NAME TestClientWithDependencies1341 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies984719065/001/store/cg9360dgdk7mbkffhm64v2ci98zp06vx-test-script13422026/10/07 06:18:04 WARN Failed to register uploaded object key=rca9zxnfn9k5wd7sc631yv9dxjws3ykk.narinfo error="server returned 404: 404 page not found\n"13432026/10/07 06:18:04 WARN Failed to register uploaded object key=qw9gshj3vxcjyl3k9mpk08sfnhfzcshn.narinfo error="server returned 404: 404 page not found\n"13442026/10/07 06:18:04 INFO Received complete push request method=POST path=/api/pushes/1/complete13452026/10/07 06:18:04 WARN Failed to register uploaded object key=wn8qm4652lzf8n733ncda5jxrccbikkn.narinfo error="server returned 404: 404 page not found\n"1346=== NAME TestClientMultipleUploads1347 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3311388521/001/store/wgxl8z88s17cf5rfm5mng11gns99ifkb-test-file-1.txt13482026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes13492026/10/07 06:18:04 INFO Completed push id=1 objects=8 duration=11.105177ms13502026/10/07 06:18:04 INFO Upload complete. (77ms)1351=== NAME TestClientPushesUseOnePush1352 client_pushes_test.go:97: Retrieved narinfo from S3:1353 StorePath: /build/TestClientPushesUseOnePush2325525288/001/store/rca9zxnfn9k5wd7sc631yv9dxjws3ykk-shared-dep1354 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1355 Compression: zstd1356 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821357 NarSize: 1361358 References: 1359 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1360 client_pushes_test.go:97: Retrieved narinfo from S3:1361 StorePath: /build/TestClientPushesUseOnePush2325525288/001/store/qw9gshj3vxcjyl3k9mpk08sfnhfzcshn-a1362 URL: nar/1kv5dvnpgcayjrihv646gzk8l0qd8qs53i4f0wnz5y3xjxfxglp5.nar.zst1363 Compression: zstd1364 NarHash: sha256:1kv5dvnpgcayjrihv646gzk8l0qd8qs53i4f0wnz5y3xjxfxglp51365 NarSize: 2161366 References: /build/TestClientPushesUseOnePush2325525288/001/store/rca9zxnfn9k5wd7sc631yv9dxjws3ykk-shared-dep1367 CA: text:sha256:0ljdsz1is8nvh5yrn43pdkh2k3cp42ip864k0acsi39k4q82cf7n13682026/10/07 06:18:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13692026/10/07 06:18:04 INFO Uploading 5wlqxavfljn2y134wzhmnmh1w1qmn9w5-pinned-file.txt (128B)1370 client_pushes_test.go:97: Retrieved narinfo from S3:1371 StorePath: /build/TestClientPushesUseOnePush2325525288/001/store/wn8qm4652lzf8n733ncda5jxrccbikkn-b1372 URL: nar/1kv5dvnpgcayjrihv646gzk8l0qd8qs53i4f0wnz5y3xjxfxglp5.nar.zst1373 Compression: zstd1374 NarHash: sha256:1kv5dvnpgcayjrihv646gzk8l0qd8qs53i4f0wnz5y3xjxfxglp51375 NarSize: 2161376 References: /build/TestClientPushesUseOnePush2325525288/001/store/rca9zxnfn9k5wd7sc631yv9dxjws3ykk-shared-dep1377 CA: text:sha256:0ljdsz1is8nvh5yrn43pdkh2k3cp42ip864k0acsi39k4q82cf7n13782026/10/07 06:18:04 WARN Failed to register uploaded object key=5wlqxavfljn2y134wzhmnmh1w1qmn9w5.ls error="server returned 404: 404 page not found\n"13792026/10/07 06:18:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13802026/10/07 06:18:04 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13812026/10/07 06:18:04 INFO Signed narinfos id=1 count=113822026/10/07 06:18:04 INFO Uploading 1 narinfos13832026/10/07 06:18:04 INFO Received complete push request method=POST path=/api/pushes/1/complete13842026/10/07 06:18:04 WARN Failed to register uploaded object key=5wlqxavfljn2y134wzhmnmh1w1qmn9w5.narinfo error="server returned 404: 404 page not found\n"13852026/10/07 06:18:04 INFO Aborted multipart uploads count=0 kept=01386--- PASS: TestClientPushesUseOnePush (0.56s)1387=== CONT TestRegisterCompletedObjectNeedsPendingRow13882026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures13892026/10/07 06:18:04 WARN Force mode enabled - objects will be deleted immediately without grace period1390=== NAME TestClientWithDependencies1391 client_integration_test.go:615: Found 1 dependencies (including self)13922026/10/07 06:18:04 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=013932026/10/07 06:18:04 INFO Completed push id=1 objects=3 duration=10.176636ms13942026/10/07 06:18:04 INFO Upload complete. (73ms)13952026/10/07 06:18:04 INFO Vacuumed table table=pending_closures13962026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes13972026/10/07 06:18:04 INFO Vacuumed table table=pending_objects13982026/10/07 06:18:04 INFO Vacuumed table table=multipart_uploads1399=== NAME TestClientMultipleUploads1400 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3311388521/001/store/4a5shw1s73hc59jdyi99qy0rjxgwg0v4-test-file-2.txt14012026/10/07 06:18:04 INFO Vacuumed table table=closures14022026/10/07 06:18:04 INFO Vacuumed table table=objects14032026/10/07 06:18:04 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14042026/10/07 06:18:04 INFO Uploading gdp85kxcvw9hfpgy20r398pya3zbcza8-top (224B)14052026/10/07 06:18:04 INFO Uploading j8ii6g7i85jnp461gq95mcgg0dssdsgv-shared-dep (136B)1406--- PASS: TestReadProxy404 (0.40s)1407=== CONT TestReadProxyNarinfo14082026/10/07 06:18:04 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14092026/10/07 06:18:04 WARN Failed to register uploaded object key=gdp85kxcvw9hfpgy20r398pya3zbcza8.ls error="server returned 404: 404 page not found\n"14102026/10/07 06:18:04 WARN Failed to register uploaded object key=j8ii6g7i85jnp461gq95mcgg0dssdsgv.ls error="server returned 404: 404 page not found\n"14112026/10/07 06:18:04 WARN Failed to register uploaded object key=nar/0cjs9zavp17vansmw51gkzl3cajnm9kmc8a9k8m5f47k5yy7ri7f.nar.zst error="server returned 404: 404 page not found\n"1412--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.45s)14132026/10/07 06:18:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1414=== CONT TestSweepSkipsRowsLockedByPush14152026/10/07 06:18:04 INFO Signed narinfos id=1 count=214162026/10/07 06:18:04 INFO Uploading 2 narinfos14172026/10/07 06:18:04 WARN Failed to register uploaded object key=j8ii6g7i85jnp461gq95mcgg0dssdsgv.narinfo error="server returned 404: 404 page not found\n"14182026/10/07 06:18:04 INFO Received complete push request method=POST path=/api/pushes/1/complete14192026/10/07 06:18:04 WARN Failed to register uploaded object key=gdp85kxcvw9hfpgy20r398pya3zbcza8.narinfo error="server returned 404: 404 page not found\n"1420--- PASS: TestReadProxyNarStreaming (0.37s)1421=== CONT TestFailedS3DeleteKeepsTombstone14222026/10/07 06:18:04 INFO Completed push id=1 objects=6 duration=11.366856ms14232026/10/07 06:18:04 INFO Upload complete. (75ms)1424=== NAME TestClientSharedPathCommittedMidPush1425 client_integration_test.go:680: Retrieved narinfo from S3:1426 StorePath: /build/TestClientSharedPathCommittedMidPush2216921254/001/store/j8ii6g7i85jnp461gq95mcgg0dssdsgv-shared-dep1427 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1428 Compression: zstd1429 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821430 NarSize: 1361431 References: 1432 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14332026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes1434=== NAME TestOrphanedObjectsGCStressTest1435 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1436=== NAME TestClientSharedPathCommittedMidPush1437 client_integration_test.go:680: Retrieved narinfo from S3:1438 StorePath: /build/TestClientSharedPathCommittedMidPush2216921254/001/store/gdp85kxcvw9hfpgy20r398pya3zbcza8-top1439 URL: nar/0cjs9zavp17vansmw51gkzl3cajnm9kmc8a9k8m5f47k5yy7ri7f.nar.zst1440 Compression: zstd1441 NarHash: sha256:0cjs9zavp17vansmw51gkzl3cajnm9kmc8a9k8m5f47k5yy7ri7f1442 NarSize: 2241443 References: /build/TestClientSharedPathCommittedMidPush2216921254/001/store/j8ii6g7i85jnp461gq95mcgg0dssdsgv-shared-dep1444 CA: text:sha256:1s6q35n2zq16i6831ms3a33k4civ45yfi0abkibc128xhfr29kya14452026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes14462026/10/07 06:18:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14472026/10/07 06:18:04 INFO Uploading rd05ljwk1dwz1gmfv71x47ipwqm49qnk-ca-test (144B)1448--- PASS: TestClientSharedPathCommittedMidPush (0.57s)1449=== CONT TestPresentRefreshesOnlyStaleClosures14502026/10/07 06:18:04 WARN Failed to register uploaded object key=log/0k3ydzyjxr2cmf7jm3fkbl1skr7p93wi-ca-test.drv error="server returned 404: 404 page not found\n"14512026/10/07 06:18:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14522026/10/07 06:18:04 WARN Failed to register uploaded object key=rd05ljwk1dwz1gmfv71x47ipwqm49qnk.ls error="server returned 404: 404 page not found\n"14532026/10/07 06:18:04 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14542026/10/07 06:18:04 INFO Signed narinfos id=1 count=114552026/10/07 06:18:04 INFO Uploading 1 narinfos14562026/10/07 06:18:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14572026/10/07 06:18:04 INFO Uploading pjfb8zi0nbzcg78r2nds8h065vw6kpv1-test-file.txt (152B)1458--- PASS: TestObjectStatsLargeCommit (1.45s)1459=== CONT TestService_RequireScope_OIDC14602026/10/07 06:18:04 INFO Aborted multipart uploads count=0 kept=014612026/10/07 06:18:04 INFO Received complete push request method=POST path=/api/pushes/1/complete14622026/10/07 06:18:04 WARN Failed to register uploaded object key=rd05ljwk1dwz1gmfv71x47ipwqm49qnk.narinfo error="server returned 404: 404 page not found\n"14632026/10/07 06:18:04 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14642026/10/07 06:18:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14652026/10/07 06:18:04 WARN Failed to register uploaded object key=pjfb8zi0nbzcg78r2nds8h065vw6kpv1.ls error="server returned 404: 404 page not found\n"14662026/10/07 06:18:04 INFO Signed narinfos id=1 count=114672026/10/07 06:18:04 INFO Uploading 1 narinfos14682026/10/07 06:18:04 WARN Force mode enabled - objects will be deleted immediately without grace period14692026/10/07 06:18:04 INFO Received complete push request method=POST path=/api/pushes/1/complete14702026/10/07 06:18:04 WARN Failed to register uploaded object key=pjfb8zi0nbzcg78r2nds8h065vw6kpv1.narinfo error="server returned 404: 404 page not found\n"14712026/10/07 06:18:04 INFO Completed push id=1 objects=4 duration=6.927538ms14722026/10/07 06:18:04 INFO Upload complete. (101ms)1473=== NAME TestClientCADerivations1474 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations686108702/001/store/rd05ljwk1dwz1gmfv71x47ipwqm49qnk-ca-test1475 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1476 Compression: zstd1477 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1478 NarSize: 1441479 References: 1480 Deriver: /build/TestClientCADerivations686108702/001/store/0k3ydzyjxr2cmf7jm3fkbl1skr7p93wi-ca-test.drv1481 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1482 client_ca_test.go:185: Checking for realisation files in S3...1483 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1484 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14852026/10/07 06:18:04 INFO Completed push id=1 objects=3 duration=11.696686ms14862026/10/07 06:18:04 INFO Upload complete. (72ms)14872026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes14882026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes1489=== NAME TestOrphanedObjectsGCStressTest1490 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion14912026/10/07 06:18:04 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=014922026/10/07 06:18:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14932026/10/07 06:18:04 INFO Uploading 17z8mwp4r7xi4g3szx2mixvvx7kzvhy2-unpinned-file.txt (128B)14942026/10/07 06:18:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14952026/10/07 06:18:04 INFO Uploading cg9360dgdk7mbkffhm64v2ci98zp06vx-test-script (136B)14962026/10/07 06:18:04 INFO Vacuumed table table=pending_closures14972026/10/07 06:18:04 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14982026/10/07 06:18:04 WARN Failed to register uploaded object key=17z8mwp4r7xi4g3szx2mixvvx7kzvhy2.ls error="server returned 404: 404 page not found\n"14992026/10/07 06:18:04 INFO Signed narinfos id=2 count=115002026/10/07 06:18:04 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15012026/10/07 06:18:04 INFO Uploading 1 narinfos15022026/10/07 06:18:04 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15032026/10/07 06:18:04 WARN Failed to register uploaded object key=log/n5iall5ga3l5qmvmjg4v7axfrggagj4r-test-script.drv error="server returned 404: 404 page not found\n"15042026/10/07 06:18:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15052026/10/07 06:18:04 WARN Failed to register uploaded object key=cg9360dgdk7mbkffhm64v2ci98zp06vx.ls error="server returned 404: 404 page not found\n"15062026/10/07 06:18:04 INFO Signed narinfos id=1 count=115072026/10/07 06:18:04 INFO Vacuumed table table=pending_objects15082026/10/07 06:18:04 INFO Uploading 1 narinfos15092026/10/07 06:18:04 INFO Vacuumed table table=multipart_uploads15102026/10/07 06:18:04 INFO Vacuumed table table=closures15112026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes15122026/10/07 06:18:04 INFO Received complete push request method=POST path=/api/pushes/2/complete15132026/10/07 06:18:04 WARN Failed to register uploaded object key=17z8mwp4r7xi4g3szx2mixvvx7kzvhy2.narinfo error="server returned 404: 404 page not found\n"15142026/10/07 06:18:04 INFO Received complete push request method=POST path=/api/pushes/1/complete15152026/10/07 06:18:04 WARN Failed to register uploaded object key=cg9360dgdk7mbkffhm64v2ci98zp06vx.narinfo error="server returned 404: 404 page not found\n"15162026/10/07 06:18:04 INFO Vacuumed table table=objects1517--- PASS: TestSweepRechecksPendingAfterLocking (0.38s)1518=== CONT TestParseSingleRange1519=== RUN TestParseSingleRange/none1520=== PAUSE TestParseSingleRange/none1521=== RUN TestParseSingleRange/unknown_unit1522=== PAUSE TestParseSingleRange/unknown_unit1523=== RUN TestParseSingleRange/multi-range_ignored1524=== PAUSE TestParseSingleRange/multi-range_ignored1525=== RUN TestParseSingleRange/malformed_no_dash1526=== PAUSE TestParseSingleRange/malformed_no_dash1527=== RUN TestParseSingleRange/malformed_both_empty1528=== PAUSE TestParseSingleRange/malformed_both_empty1529=== RUN TestParseSingleRange/malformed_end_before_start1530=== PAUSE TestParseSingleRange/malformed_end_before_start1531=== RUN TestParseSingleRange/closed1532=== PAUSE TestParseSingleRange/closed1533=== RUN TestParseSingleRange/open-ended15342026/10/07 06:18:04 INFO Completed push id=2 objects=3 duration=3.387129ms1535=== PAUSE TestParseSingleRange/open-ended15362026/10/07 06:18:04 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)1537=== RUN TestParseSingleRange/end_clamped_to_size15382026/10/07 06:18:04 INFO Uploading 4a5shw1s73hc59jdyi99qy0rjxgwg0v4-test-file-2.txt (160B)1539=== PAUSE TestParseSingleRange/end_clamped_to_size15402026/10/07 06:18:04 INFO Upload complete. (51ms)1541=== RUN TestParseSingleRange/suffix15422026/10/07 06:18:04 INFO Uploading 4fkibgd1ijs2amkffifvbs69rdcw93xi-test-file-0.txt (160B)1543=== PAUSE TestParseSingleRange/suffix15442026/10/07 06:18:04 INFO Uploading wgxl8z88s17cf5rfm5mng11gns99ifkb-test-file-1.txt (160B)1545=== RUN TestParseSingleRange/suffix_exceeds_size1546=== PAUSE TestParseSingleRange/suffix_exceeds_size1547=== RUN TestParseSingleRange/single_byte1548=== PAUSE TestParseSingleRange/single_byte1549=== RUN TestParseSingleRange/start_past_EOF1550=== PAUSE TestParseSingleRange/start_past_EOF1551=== RUN TestParseSingleRange/start_far_past_EOF1552=== PAUSE TestParseSingleRange/start_far_past_EOF1553=== CONT TestCacheStatsHandler15542026/10/07 06:18:04 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15552026/10/07 06:18:04 WARN Failed to register uploaded object key=4a5shw1s73hc59jdyi99qy0rjxgwg0v4.ls error="server returned 404: 404 page not found\n"15562026/10/07 06:18:04 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15572026/10/07 06:18:04 WARN Failed to register uploaded object key=4fkibgd1ijs2amkffifvbs69rdcw93xi.ls error="server returned 404: 404 page not found\n"15582026/10/07 06:18:04 WARN Failed to register uploaded object key=wgxl8z88s17cf5rfm5mng11gns99ifkb.ls error="server returned 404: 404 page not found\n"15592026/10/07 06:18:04 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15602026/10/07 06:18:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15612026/10/07 06:18:04 INFO Signed narinfos id=1 count=315622026/10/07 06:18:04 INFO Uploading 3 narinfos15632026/10/07 06:18:04 WARN Failed to register uploaded object key=4fkibgd1ijs2amkffifvbs69rdcw93xi.narinfo error="server returned 404: 404 page not found\n"15642026/10/07 06:18:04 WARN Failed to register uploaded object key=wgxl8z88s17cf5rfm5mng11gns99ifkb.narinfo error="server returned 404: 404 page not found\n"15652026/10/07 06:18:04 INFO Completed push id=1 objects=4 duration=16.931344ms15662026/10/07 06:18:04 INFO Upload complete. (72ms)15672026/10/07 06:18:04 INFO Received complete push request method=POST path=/api/pushes/1/complete15682026/10/07 06:18:04 WARN Failed to register uploaded object key=4a5shw1s73hc59jdyi99qy0rjxgwg0v4.narinfo error="server returned 404: 404 page not found\n"1569=== NAME TestClientWithDependencies1570 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies984719065/001/store) requires matching store prefix15712026/10/07 06:18:04 INFO All 1 paths already cached15722026/10/07 06:18:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44613/oidc1573=== NAME TestClientIntegration1574 client_integration_test.go:312: Retrieved narinfo from S3:1575 StorePath: /build/TestClientIntegration3847027360/002/store/pjfb8zi0nbzcg78r2nds8h065vw6kpv1-test-file.txt1576 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1577 Compression: zstd1578 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11579 NarSize: 1521580 References: 1581 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11582--- PASS: TestClientWithDependencies (0.63s)1583=== CONT TestPresentNotReportedWhileGCDeletesClosure1584=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1585=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1586=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1587=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1588=== CONT TestCacheConfigHandler1589=== RUN TestCacheConfigHandler/full_config,_no_issuer1590=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1591=== RUN TestCacheConfigHandler/no_cache_url_configured1592=== PAUSE TestCacheConfigHandler/no_cache_url_configured1593=== RUN TestCacheConfigHandler/no_signing_keys1594=== PAUSE TestCacheConfigHandler/no_signing_keys1595=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1596=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1597=== CONT TestService_ReadScope_PublicByDefault1598=== NAME TestClientIntegration1599 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1600 client_integration_test.go:313: Decompressed .ls content (64 bytes):1601 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1602 client_integration_test.go:316: Testing garbage collection...1603--- PASS: TestGetExistingObjectsLocksRows (0.22s)1604=== CONT TestPresentReportsOnlyClosureRoots16052026/10/07 06:18:04 INFO Completed push id=1 objects=9 duration=10.846456ms16062026/10/07 06:18:04 INFO Upload complete. (76ms)1607=== NAME TestClientMultipleUploads1608 client_integration_test.go:369: Uploaded 3 paths in 107.924484ms1609--- PASS: TestReadProxyContentNegotiation (0.24s)1610=== CONT TestService_ReadAuthMiddleware16112026/10/07 06:18:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures1612--- PASS: TestClientMultipleUploads (0.62s)16132026/10/07 06:18:04 INFO Garbage collection started1614=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1615--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.23s)1616=== CONT TestService_AuthMiddleware_OIDC16172026/10/07 06:18:04 INFO Aborted multipart uploads count=0 kept=016182026/10/07 06:18:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures16192026/10/07 06:18:04 INFO Garbage collection started16202026/10/07 06:18:04 INFO Aborted multipart uploads count=0 kept=016212026/10/07 06:18:04 WARN Force mode enabled - objects will be deleted immediately without grace period16222026/10/07 06:18:04 WARN Force mode enabled - objects will be deleted immediately without grace period16232026/10/07 06:18:04 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=016242026/10/07 06:18:04 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=016252026/10/07 06:18:04 INFO Vacuumed table table=pending_closures16262026/10/07 06:18:04 INFO Vacuumed table table=pending_objects16272026/10/07 06:18:04 INFO Vacuumed table table=multipart_uploads16282026/10/07 06:18:04 INFO Vacuumed table table=pending_closures1629=== NAME TestClientCADerivations1630 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1631 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1632 error: binary cache 's3://bucket63?endpoint=http://localhost:41473®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations686108702/001/store'1633 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 116342026/10/07 06:18:04 INFO Vacuumed table table=closures16352026/10/07 06:18:04 INFO Vacuumed table table=pending_objects16362026/10/07 06:18:04 INFO Vacuumed table table=multipart_uploads1637--- PASS: TestClientCADerivations (0.77s)1638=== CONT TestCreatePin_ReservedPins16392026/10/07 06:18:04 INFO Vacuumed table table=objects16402026/10/07 06:18:04 INFO Vacuumed table table=closures16412026/10/07 06:18:04 INFO Vacuumed table table=objects1642--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.23s)1643=== CONT TestService_AuthMiddleware_MTLSProxyHeader16442026/10/07 06:18:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46845/oidc16452026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures16462026/10/07 06:18:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38719/oidc16472026/10/07 06:18:04 INFO Aborted multipart uploads count=0 kept=016482026/10/07 06:18:04 WARN Force mode enabled - objects will be deleted immediately without grace period16492026/10/07 06:18:04 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=016502026/10/07 06:18:04 INFO Vacuumed table table=pending_closures16512026/10/07 06:18:04 INFO Vacuumed table table=pending_objects16522026/10/07 06:18:04 INFO Vacuumed table table=multipart_uploads16532026/10/07 06:18:04 INFO Vacuumed table table=closures1654--- PASS: TestPresentRefreshesOnlyStaleClosures (0.31s)1655=== CONT TestProxyWriteTimeout/narinfo1656=== CONT TestProxyWriteTimeout/10_GiB_nar1657=== CONT TestProxyWriteTimeout/unknown_size1658=== CONT TestProxyWriteTimeout/1_GiB_nar1659--- PASS: TestProxyWriteTimeout (0.00s)1660 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1661 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1662 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1663 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1664=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16652026/10/07 06:18:04 INFO Received uploads request method=POST path=/1666=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16672026/10/07 06:18:04 INFO Received request for more parts method=POST path=/1668=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16692026/10/07 06:18:04 INFO Received complete multipart upload request method=POST path=/1670=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16712026/10/07 06:18:04 INFO Received uploads request method=POST path=/1672=== CONT TestPendingClosureWriteTimeout/empty1673--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1674 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1675 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1676 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1677 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1678=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline16792026/10/07 06:18:04 INFO Vacuumed table table=objects16802026/10/07 06:18:04 INFO Aborted multipart uploads count=0 kept=016812026/10/07 06:18:04 WARN Force mode enabled - objects will be deleted immediately without grace period16822026/10/07 06:18:04 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1683--- PASS: TestReadProxyNarinfo (0.36s)1684=== CONT TestPendingClosureWriteTimeout/670k_objects1685=== CONT TestPendingClosureWriteTimeout/400_objects1686=== CONT TestIsValidUploadKey/narinfo1687=== CONT TestIsValidUploadKey/realisation_plus_in_output1688=== CONT TestIsValidUploadKey/unknown_type1689=== CONT TestIsValidUploadKey/empty_key1690=== CONT TestIsValidUploadKey/absolute1691=== CONT TestIsValidUploadKey/nix-cache-info1692=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1693=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1694=== CONT TestIsValidUploadKey/index.html1695=== CONT TestIsValidUploadKey/build_log_home-manager_file1696=== CONT TestIsValidUploadKey/traversal_nar1697=== CONT TestIsValidUploadKey/realisation1698=== CONT TestIsValidUploadKey/traversal1699=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1700=== CONT TestIsValidUploadKey/build_log_equals1701=== CONT TestIsValidUploadKey/nar_plain1702=== CONT TestIsValidUploadKey/nar_xz1703=== CONT TestIsValidUploadKey/build_log1704=== CONT TestIsValidUploadKey/build_log_plus_in_name1705=== CONT TestIsValidUploadKey/listing1706=== CONT TestIsValidUploadKey/nar_zst1707=== CONT TestIsValidUploadKey/build_log_question_mark1708=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17092026/10/07 06:18:04 INFO Received uploads request method=POST path=/1710--- PASS: TestIsValidUploadKey (0.13s)1711 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1712 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1713 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1714 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1715 --- PASS: TestIsValidUploadKey/absolute (0.00s)1716 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1717 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1718 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1719 --- PASS: TestIsValidUploadKey/index.html (0.00s)1720 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1721 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1722 --- PASS: TestIsValidUploadKey/realisation (0.00s)1723 --- PASS: TestIsValidUploadKey/traversal (0.00s)1724 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1725 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1726 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1727 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1728 --- PASS: TestIsValidUploadKey/build_log (0.00s)1729 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1730 --- PASS: TestIsValidUploadKey/listing (0.00s)1731 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1732 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1733--- PASS: TestCacheStatsHandler (0.28s)1734=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17352026/10/07 06:18:04 INFO Received complete multipart upload request method=POST path=/17362026/10/07 06:18:04 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=017372026/10/07 06:18:04 INFO Vacuumed table table=pending_closures17382026/10/07 06:18:04 INFO Vacuumed table table=pending_objects17392026/10/07 06:18:04 INFO Vacuumed table table=multipart_uploads17402026/10/07 06:18:04 INFO Vacuumed table table=closures17412026/10/07 06:18:04 INFO Aborted multipart uploads count=0 kept=017422026/10/07 06:18:04 INFO Vacuumed table table=objects1743--- PASS: TestSweepSkipsRowsLockedByPush (0.37s)1744=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17452026/10/07 06:18:04 INFO Received request for more parts method=POST path=/17462026/10/07 06:18:04 WARN Force mode enabled - objects will be deleted immediately without grace period17472026/10/07 06:18:04 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."17482026/10/07 06:18:04 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1749--- PASS: TestFailedS3DeleteKeepsTombstone (0.38s)1750=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1751=== RUN TestService_RequireScope_OIDC/builder_may_write1752=== PAUSE TestService_RequireScope_OIDC/builder_may_write1753=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1754=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1755=== RUN TestService_RequireScope_OIDC/ops_may_admin1756=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1757=== RUN TestService_RequireScope_OIDC/ops_may_not_write1758=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1759=== RUN TestService_RequireScope_OIDC/reader_may_not_write1760=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1761=== RUN TestService_RequireScope_OIDC/static_token_may_admin1762=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1763=== RUN TestService_RequireScope_OIDC/static_token_may_write1764=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1765=== RUN TestService_RequireScope_OIDC/reader_may_read1766=== PAUSE TestService_RequireScope_OIDC/reader_may_read1767=== RUN TestService_RequireScope_OIDC/writer_implies_read1768=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1769=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1770=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1771=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1772=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1773=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1774=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1775=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1776=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1777=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1778=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1779=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1780--- PASS: TestService_ReadScope_PublicByDefault (0.31s)1781=== CONT TestPush_RejectsBadRequests/no_roots17822026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes1783=== CONT TestPush_RejectsBadRequests/bad_root17842026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes1785=== CONT TestPush_RejectsBadRequests/root_not_in_objects17862026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes1787=== CONT TestPush_RejectsBadRequests/no_objects17882026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes1789=== CONT TestServerTLSConfig/no_client_CA1790--- PASS: TestPush_RejectsBadRequests (0.66s)1791 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1792 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1793 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1794 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1795=== CONT TestServerTLSConfig/not_a_PEM_file1796=== CONT TestServerTLSConfig/missing_CA_file1797--- PASS: TestServerTLSConfig (0.00s)1798 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1799 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1800 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1801=== CONT TestResolveDBConnectionString/flag_wins1802=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1803=== CONT TestResolveDBConnectionString/nothing_configured1804=== CONT TestResolveDBConnectionString/missing_file_is_an_error1805=== CONT TestResolveDBConnectionString/file_when_flag_empty1806=== CONT TestClientErrorHandling/InvalidStorePath1807--- PASS: TestResolveDBConnectionString (0.00s)1808 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1809 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1810 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1811 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1812 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1813=== CONT TestClientErrorHandling/ServerNotAvailable1814=== CONT TestClientErrorHandling/InvalidAuthToken1815=== NAME TestOrphanedObjectsGCStressTest1816 orphaned_objects_gc_test.go:503: Stress test completed successfully:1817 orphaned_objects_gc_test.go:504: - Active objects preserved: 201818 orphaned_objects_gc_test.go:505: - Objects deleted: 2101819 orphaned_objects_gc_test.go:506: - Total GC'd: 2101820--- PASS: TestOrphanedObjectsGCStressTest (2.86s)1821=== CONT TestIsValidCachePath/narinfo1822=== CONT TestIsValidCachePath/index.html1823=== CONT TestIsValidCachePath/short_hash1824=== CONT TestIsValidCachePath/wrong_extension1825=== CONT TestIsValidCachePath/invalid_char_e1826=== CONT TestIsValidCachePath/traversal_in_middle1827=== CONT TestIsValidCachePath/traversal_parent1828=== CONT TestIsValidCachePath/empty1829=== CONT TestIsValidCachePath/invalid_char_u1830=== CONT TestIsValidCachePath/leading_slash1831=== CONT TestIsValidCachePath/random_path1832=== CONT TestIsValidCachePath/nar_uncompressed1833=== CONT TestIsValidCachePath/ls1834=== CONT TestIsValidCachePath/realisation1835=== CONT TestIsValidCachePath/nix-cache-info1836=== CONT TestIsValidCachePath/nar_xz1837=== CONT TestIsValidCachePath/nar_bz21838=== CONT TestIsValidCachePath/log1839=== CONT TestIsValidCachePath/nar_zst1840=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1841--- PASS: TestIsValidCachePath (0.00s)1842 --- PASS: TestIsValidCachePath/narinfo (0.00s)1843 --- PASS: TestIsValidCachePath/index.html (0.00s)1844 --- PASS: TestIsValidCachePath/short_hash (0.00s)1845 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1846 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1847 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1848 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1849 --- PASS: TestIsValidCachePath/empty (0.00s)1850 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1851 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1852 --- PASS: TestIsValidCachePath/random_path (0.00s)1853 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1854 --- PASS: TestIsValidCachePath/ls (0.00s)1855 --- PASS: TestIsValidCachePath/realisation (0.00s)1856 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1857 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1858 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1859 --- PASS: TestIsValidCachePath/log (0.00s)1860 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1861 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1862=== CONT TestGCEndsOnShutdown/before_the_run1863--- PASS: TestPresentReportsOnlyClosureRoots (0.35s)1864=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark18652026/10/07 06:18:04 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18662026/10/07 06:18:04 WARN mTLS auth: bound subjects configured but subject DN unavailable18672026/10/07 06:18:04 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1868--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.34s)1869=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1870--- PASS: TestService_ReadAuthMiddleware (0.38s)1871=== CONT TestParseSingleRange/none1872=== CONT TestParseSingleRange/malformed_end_before_start1873=== CONT TestParseSingleRange/malformed_both_empty1874=== CONT TestParseSingleRange/malformed_no_dash1875=== CONT TestParseSingleRange/multi-range_ignored1876=== CONT TestParseSingleRange/closed1877=== CONT TestParseSingleRange/unknown_unit1878=== CONT TestParseSingleRange/start_past_EOF1879=== CONT TestParseSingleRange/single_byte1880=== CONT TestParseSingleRange/suffix_exceeds_size1881=== CONT TestParseSingleRange/start_far_past_EOF1882=== CONT TestParseSingleRange/suffix1883=== CONT TestParseSingleRange/end_clamped_to_size1884=== CONT TestParseSingleRange/open-ended1885--- PASS: TestParseSingleRange (0.00s)1886 --- PASS: TestParseSingleRange/none (0.00s)1887 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1888 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1889 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1890 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1891 --- PASS: TestParseSingleRange/closed (0.00s)1892 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1893 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1894 --- PASS: TestParseSingleRange/single_byte (0.00s)1895 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1896 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1897 --- PASS: TestParseSingleRange/suffix (0.00s)1898 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1899 --- PASS: TestParseSingleRange/open-ended (0.00s)1900=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1901--- PASS: TestPushWaitsForSweepHoldingRow (0.86s)1902=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh19032026/10/07 06:18:04 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1904--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.31s)1905=== CONT TestCacheConfigHandler/full_config,_no_issuer1906=== CONT TestCacheConfigHandler/no_signing_keys1907=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1908=== CONT TestCacheConfigHandler/no_cache_url_configured1909--- PASS: TestCacheConfigHandler (0.00s)1910 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1911 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1912 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1913 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1914=== CONT TestService_RequireScope_OIDC/builder_may_write1915=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1916=== CONT TestService_RequireScope_OIDC/writer_implies_read1917=== CONT TestService_RequireScope_OIDC/reader_may_read1918=== CONT TestService_RequireScope_OIDC/static_token_may_write1919=== CONT TestService_RequireScope_OIDC/static_token_may_admin1920=== CONT TestService_RequireScope_OIDC/reader_may_not_write1921=== CONT TestService_RequireScope_OIDC/ops_may_not_write1922=== CONT TestService_RequireScope_OIDC/ops_may_admin1923=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1924=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1925=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19262026/10/07 06:18:04 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]1927=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1928=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1929--- PASS: TestService_RequireScope_OIDC (0.36s)1930 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1931 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1932 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1933 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1934 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1935 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1936 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1937 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1938 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1939 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1940 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1941 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1942 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1943 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)19442026/10/07 06:18:04 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux19452026/10/07 06:18:04 WARN Refused reserved pin name=worker-x86_64-linux19462026/10/07 06:18:04 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux19472026/10/07 06:18:04 INFO Received create pin request method=POST path=/api/pins/my-app19482026/10/07 06:18:04 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1949--- PASS: TestCreatePin_ReservedPins (0.37s)1950=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1951=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1952=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1953=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1954=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1955=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1956=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1957=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1958=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1959=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19602026/10/07 06:18:04 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]1961=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1962=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19632026/10/07 06:18:04 WARN Authentication failed token_preview=eyJhbGciOi...VEln-vyPAA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1964--- PASS: TestService_AuthMiddleware_OIDC (0.46s)1965 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1966 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1967 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1968 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19692026/10/07 06:18:04 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.17498ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19702026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures19712026/10/07 06:18:04 INFO lead: released remote=192.0.2.1:12341972--- PASS: TestLeadEndsOnShutdown (1.55s)19732026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures19742026/10/07 06:18:04 INFO Aborted multipart uploads count=0 kept=019752026/10/07 06:18:04 WARN Force mode enabled - objects will be deleted immediately without grace period19762026/10/07 06:18:04 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=019772026/10/07 06:18:04 INFO Vacuumed table table=pending_closures19782026/10/07 06:18:04 INFO Vacuumed table table=pending_objects19792026/10/07 06:18:04 INFO Vacuumed table table=multipart_uploads19802026/10/07 06:18:04 INFO Vacuumed table table=closures19812026/10/07 06:18:04 INFO Vacuumed table table=objects19822026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures19832026/10/07 06:18:05 INFO Aborted multipart uploads count=0 kept=019842026/10/07 06:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period19852026/10/07 06:18:05 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=019862026/10/07 06:18:05 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=407.963894ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19872026/10/07 06:18:05 INFO Vacuumed table table=pending_closures19882026/10/07 06:18:05 INFO Vacuumed table table=pending_objects19892026/10/07 06:18:05 INFO Vacuumed table table=multipart_uploads19902026/10/07 06:18:05 INFO Vacuumed table table=closures19912026/10/07 06:18:05 INFO Vacuumed table table=objects1992--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1993 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.40s)1994 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.42s)1995--- PASS: TestDeleteClosuresRacingPins (1.54s)19962026/10/07 06:18:05 INFO Aborted multipart uploads count=0 kept=019972026/10/07 06:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period19982026/10/07 06:18:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19992026/10/07 06:18:05 INFO Aborted multipart uploads count=0 kept=020002026/10/07 06:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period20012026/10/07 06:18:05 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:41473/bucket98/?delete=\": context canceled"2002--- PASS: TestGCEndsOnShutdown (0.00s)2003 --- PASS: TestGCEndsOnShutdown/before_the_run (0.40s)2004 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.45s)2005 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.45s)20062026/10/07 06:18:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20072026/10/07 06:18:05 INFO lead: released remote=192.0.2.1:123420082026/10/07 06:18:05 INFO lead: acquired remote=192.0.2.1:12342009--- PASS: TestUploadHandlersRejectOversizedBody (0.31s)2010 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2011 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2012 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.73s)20132026/10/07 06:18:05 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=764.036984ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2014--- PASS: TestPendingClosureWriteTimeout (0.01s)2015 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2016 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2017 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2018 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.07s)2019--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2020 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.93s)2021 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.94s)20222026/10/07 06:18:06 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.685688916s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20232026/10/07 06:18:06 INFO lead: released remote=192.0.2.1:12342024--- PASS: TestLeadElectsOneAndHandsOver (2.87s)20252026/10/07 06:18:06 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020262026/10/07 06:18:06 INFO Received create pin request method=POST path=/api/pins/myapp20272026/10/07 06:18:06 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4129405337/001/store/5wlqxavfljn2y134wzhmnmh1w1qmn9w5-pinned-file.txt narinfo_key=5wlqxavfljn2y134wzhmnmh1w1qmn9w5.narinfo20282026/10/07 06:18:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures20292026/10/07 06:18:06 INFO Garbage collection started20302026/10/07 06:18:06 INFO Aborted multipart uploads count=0 kept=020312026/10/07 06:18:06 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02032=== NAME TestClientIntegration2033 client_integration_test.go:323: Objects in database after GC:2034 client_integration_test.go:323: Successfully deleted all objects with GC --force20352026/10/07 06:18:06 WARN Force mode enabled - objects will be deleted immediately without grace period2036--- PASS: TestClientIntegration (2.65s)20372026/10/07 06:18:06 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020382026/10/07 06:18:06 INFO Vacuumed table table=pending_closures20392026/10/07 06:18:06 INFO Vacuumed table table=pending_objects20402026/10/07 06:18:06 INFO Vacuumed table table=multipart_uploads20412026/10/07 06:18:06 INFO Vacuumed table table=closures20422026/10/07 06:18:06 INFO Vacuumed table table=objects20432026/10/07 06:18:06 WARN Rate limiter enabled after throttle name=s3-test rate=520442026/10/07 06:18:06 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2045=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2046 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102047 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002048--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.08s)2049--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.27s)20502026/10/07 06:18:07 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20512026/10/07 06:18:08 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.479882ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20522026/10/07 06:18:08 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=397.276464ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2053=== NAME TestPinProtectsFromGC2054 client_integration_test.go:840: Pin successfully protected closure from garbage collection2055--- PASS: TestPinProtectsFromGC (4.68s)20562026/10/07 06:18:08 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=748.916309ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2057--- PASS: TestConnectWaitsForAPeerMigration (5.18s)20582026/10/07 06:18:09 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.596709285s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20592026/10/07 06:18:09 INFO Aborted multipart uploads count=1 kept=020602026/10/07 06:18:09 INFO Received cleanup request method=DELETE path=/api/pending_closures20612026/10/07 06:18:09 INFO Aborted multipart uploads count=1 kept=02062--- PASS: TestPendingCleanupUsesOneCutoff (6.55s)20632026/10/07 06:18:11 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"20642026/10/07 06:18:11 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20652026/10/07 06:18:11 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.506011ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20662026/10/07 06:18:11 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=380.35988ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20672026/10/07 06:18:11 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=862.431819ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20682026/10/07 06:18:12 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.455985095s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20692026/10/07 06:18:14 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20702026/10/07 06:18:14 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.844525ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20712026/10/07 06:18:14 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=387.150059ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20722026/10/07 06:18:14 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=855.759305ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20732026/10/07 06:18:15 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.565481387s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2074--- PASS: TestClientErrorHandling (0.00s)2075 --- PASS: TestClientErrorHandling/InvalidStorePath (0.41s)2076 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.49s)2077 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.46s)2078PASS20792026-10-07 06:18:17.566 UTC [129] LOG: received smart shutdown request20802026-10-07 06:18:17.571 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120812026-10-07 06:18:17.584 UTC [134] LOG: shutting down20822026-10-07 06:18:17.586 UTC [134] LOG: checkpoint starting: shutdown immediate20832026-10-07 06:18:19.074 UTC [134] LOG: checkpoint complete: wrote 11017 buffers (67.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.269 s, sync=1.166 s, total=1.489 s; sync files=34045, longest=0.002 s, average=0.001 s; distance=531573 kB, estimate=531573 kB; lsn=0/21E834A0, redo lsn=0/21E834A020842026-10-07 06:18:19.157 UTC [129] LOG: database system is shut down2085Running OIDC tests...2086=== RUN TestAudienceForIssuer2087=== PAUSE TestAudienceForIssuer2088=== RUN TestGlobMatch2089=== PAUSE TestGlobMatch2090=== RUN TestValidateToken_ValidToken2091=== PAUSE TestValidateToken_ValidToken2092=== RUN TestValidateToken_WrongAudience2093=== PAUSE TestValidateToken_WrongAudience2094=== RUN TestValidateToken_Expired2095=== PAUSE TestValidateToken_Expired2096=== RUN TestValidateToken_BoundClaimsMismatch2097=== PAUSE TestValidateToken_BoundClaimsMismatch2098=== RUN TestValidateToken_BoundSubjectMismatch2099=== PAUSE TestValidateToken_BoundSubjectMismatch2100=== RUN TestValidateToken_MultipleProviders2101=== PAUSE TestValidateToken_MultipleProviders2102=== RUN TestValidateToken_NoMatchingProvider2103=== PAUSE TestValidateToken_NoMatchingProvider2104=== RUN TestValidateToken_KubernetesServiceAccount2105=== PAUSE TestValidateToken_KubernetesServiceAccount2106=== RUN TestNewValidator_KubernetesRequiresCA2107=== PAUSE TestNewValidator_KubernetesRequiresCA2108=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2109=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2110=== RUN TestPins_ReservedForMatchingRule2111=== PAUSE TestPins_ReservedForMatchingRule2112=== RUN TestPins_TopLevelShorthand2113=== PAUSE TestPins_TopLevelShorthand2114=== RUN TestPins_ConfigValidation2115=== PAUSE TestPins_ConfigValidation2116=== RUN TestScopes_LegacyProviderDefaultsToWrite2117=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2118=== RUN TestScopes_Rules2119=== PAUSE TestScopes_Rules2120=== RUN TestScopes_ConfigValidation2121=== PAUSE TestScopes_ConfigValidation2122=== CONT TestAudienceForIssuer2123=== CONT TestPins_ConfigValidation2124=== CONT TestValidateToken_KubernetesServiceAccount2125--- PASS: TestAudienceForIssuer (0.00s)2126=== CONT TestValidateToken_Expired2127=== CONT TestValidateToken_WrongAudience2128=== CONT TestValidateToken_ValidToken2129=== CONT TestGlobMatch2130=== RUN TestGlobMatch/foo_foo2131=== PAUSE TestGlobMatch/foo_foo2132=== RUN TestGlobMatch/foo_bar2133=== PAUSE TestGlobMatch/foo_bar2134=== RUN TestGlobMatch/*_2135=== PAUSE TestGlobMatch/*_2136=== RUN TestGlobMatch/*_anything2137=== PAUSE TestGlobMatch/*_anything2138=== RUN TestGlobMatch/foo*_foo2139=== PAUSE TestGlobMatch/foo*_foo2140=== RUN TestGlobMatch/foo*_foobar2141=== PAUSE TestGlobMatch/foo*_foobar2142=== RUN TestGlobMatch/foo*_bar2143=== PAUSE TestGlobMatch/foo*_bar2144=== RUN TestGlobMatch/*bar_bar2145=== PAUSE TestGlobMatch/*bar_bar2146=== RUN TestGlobMatch/*bar_foobar2147=== PAUSE TestGlobMatch/*bar_foobar2148=== RUN TestGlobMatch/*bar_foo2149=== PAUSE TestGlobMatch/*bar_foo2150=== RUN TestGlobMatch/foo*bar_foobar2151=== PAUSE TestGlobMatch/foo*bar_foobar2152=== RUN TestGlobMatch/foo*bar_foo123bar2153=== PAUSE TestGlobMatch/foo*bar_foo123bar2154=== RUN TestGlobMatch/foo*bar_foobarbaz2155=== PAUSE TestGlobMatch/foo*bar_foobarbaz2156=== RUN TestGlobMatch/*/*_foo/bar2157=== PAUSE TestGlobMatch/*/*_foo/bar2158=== RUN TestGlobMatch/*/*_foo2159=== CONT TestScopes_Rules2160--- PASS: TestPins_ConfigValidation (0.00s)2161=== CONT TestScopes_ConfigValidation2162=== CONT TestScopes_LegacyProviderDefaultsToWrite2163=== CONT TestValidateToken_MultipleProviders2164=== CONT TestValidateToken_NoMatchingProvider2165=== CONT TestPins_ReservedForMatchingRule2166=== CONT TestPins_TopLevelShorthand2167=== CONT TestValidateToken_BoundSubjectMismatch2168=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2169=== CONT TestNewValidator_KubernetesRequiresCA2170=== CONT TestValidateToken_BoundClaimsMismatch2171=== PAUSE TestGlobMatch/*/*_foo2172--- PASS: TestScopes_ConfigValidation (0.00s)2173=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2174=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2175=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02176=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02177=== RUN TestGlobMatch/refs/*/main_refs/heads/main2178=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2179=== RUN TestGlobMatch/fo?_foo2180=== PAUSE TestGlobMatch/fo?_foo2181=== RUN TestGlobMatch/fo?_fo2182=== PAUSE TestGlobMatch/fo?_fo2183=== RUN TestGlobMatch/fo?_fooo2184=== PAUSE TestGlobMatch/fo?_fooo2185=== RUN TestGlobMatch/?oo_foo2186=== PAUSE TestGlobMatch/?oo_foo2187=== RUN TestGlobMatch/?oo_boo2188=== PAUSE TestGlobMatch/?oo_boo2189=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2190=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2191=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2192=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2193=== CONT TestGlobMatch/foo_foo2194=== CONT TestGlobMatch/*bar_foo2195=== CONT TestGlobMatch/*bar_foobar2196=== CONT TestGlobMatch/*bar_bar2197=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2198=== CONT TestGlobMatch/fo?_fo2199=== CONT TestGlobMatch/fo?_fooo2200=== CONT TestGlobMatch/foo*_bar2201=== CONT TestGlobMatch/fo?_foo2202=== CONT TestGlobMatch/foo*_foobar2203=== CONT TestGlobMatch/foo*_foo2204=== CONT TestGlobMatch/*_anything2205=== CONT TestGlobMatch/*_2206=== CONT TestGlobMatch/foo_bar2207=== CONT TestGlobMatch/?oo_boo2208=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2209=== CONT TestGlobMatch/?oo_foo2210=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2211=== CONT TestGlobMatch/*/*_foo2212=== CONT TestGlobMatch/*/*_foo/bar2213=== CONT TestGlobMatch/foo*bar_foobar2214=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02215=== CONT TestGlobMatch/refs/*/main_refs/heads/main2216=== CONT TestGlobMatch/foo*bar_foo123bar2217=== CONT TestGlobMatch/foo*bar_foobarbaz2218--- PASS: TestGlobMatch (0.01s)2219 --- PASS: TestGlobMatch/foo_foo (0.00s)2220 --- PASS: TestGlobMatch/*bar_foo (0.00s)2221 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2222 --- PASS: TestGlobMatch/*bar_bar (0.00s)2223 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2224 --- PASS: TestGlobMatch/fo?_fo (0.00s)2225 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2226 --- PASS: TestGlobMatch/foo*_bar (0.00s)2227 --- PASS: TestGlobMatch/foo_bar (0.00s)2228 --- PASS: TestGlobMatch/?oo_foo (0.00s)2229 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2230 --- PASS: TestGlobMatch/*_ (0.00s)2231 --- PASS: TestGlobMatch/*/*_foo (0.00s)2232 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2233 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2234 --- PASS: TestGlobMatch/fo?_foo (0.00s)2235 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2236 --- PASS: TestGlobMatch/*_anything (0.00s)2237 --- PASS: TestGlobMatch/foo*_foo (0.00s)2238 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2239 --- PASS: TestGlobMatch/?oo_boo (0.00s)2240 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2241 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2242 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2243 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)22442026/10/07 06:18:21 http: TLS handshake error from 127.0.0.1:55524: remote error: tls: bad certificate2245--- PASS: TestNewValidator_KubernetesRequiresCA (0.03s)22462026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44835/oidc22472026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45689/oidc2248--- PASS: TestPins_ReservedForMatchingRule (0.04s)2249--- PASS: TestValidateToken_ValidToken (0.04s)22502026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41009/oidc2251--- PASS: TestScopes_Rules (0.05s)22522026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42481/oidc2253--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.06s)22542026/10/07 06:18:21 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:427092255--- PASS: TestValidateToken_KubernetesServiceAccount (0.07s)22562026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42401/oidc2257--- PASS: TestValidateToken_BoundSubjectMismatch (0.08s)22582026/10/07 06:18:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46523/oidc22592026/10/07 06:18:21 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34959/oidc2260--- PASS: TestValidateToken_MultipleProviders (0.09s)22612026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34757/oidc2262--- PASS: TestPins_TopLevelShorthand (0.09s)22632026/10/07 06:18:21 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232264--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.11s)22652026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43595/oidc2266--- PASS: TestValidateToken_BoundClaimsMismatch (0.12s)22672026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33739/oidc2268--- PASS: TestValidateToken_Expired (0.13s)22692026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39723/oidc2270--- PASS: TestValidateToken_WrongAudience (0.19s)22712026/10/07 06:18:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36109/oidc2272--- PASS: TestValidateToken_NoMatchingProvider (0.22s)2273PASS2274Running hook tests...2275=== RUN TestSendPathsEmpty2276=== PAUSE TestSendPathsEmpty2277=== RUN TestQueueEnqueueAndFetch2278=== PAUSE TestQueueEnqueueAndFetch2279=== RUN TestQueueDeduplication2280=== PAUSE TestQueueDeduplication2281=== RUN TestQueueRemove2282=== PAUSE TestQueueRemove2283=== RUN TestQueueFetchBatchLimit2284=== PAUSE TestQueueFetchBatchLimit2285=== RUN TestQueueRetryMovesToBack2286=== PAUSE TestQueueRetryMovesToBack2287=== RUN TestQueueFetchRemoveLifecycle2288=== PAUSE TestQueueFetchRemoveLifecycle2289=== RUN TestQueueConcurrentWriters2290=== PAUSE TestQueueConcurrentWriters2291=== RUN TestQueueRemoveLargeClosure2292=== PAUSE TestQueueRemoveLargeClosure2293=== RUN TestServerClientIntegration2294=== PAUSE TestServerClientIntegration2295=== RUN TestServerQueueError2296=== PAUSE TestServerQueueError2297=== RUN TestGetListenerSocketActivation2298 server_test.go:210: === RUN TestGetListenerSocketActivation2299 --- PASS: TestGetListenerSocketActivation (0.00s)2300 PASS2301 2302--- PASS: TestGetListenerSocketActivation (0.01s)2303=== RUN TestDrainIsolatesPoisonPath2304=== PAUSE TestDrainIsolatesPoisonPath2305=== RUN TestRunNotBlockedByPoisonHead2306=== PAUSE TestRunNotBlockedByPoisonHead2307=== RUN TestDrainGivesUpWhenServerDown2308=== PAUSE TestDrainGivesUpWhenServerDown2309=== RUN TestFailedPathPrunedByLaterClosure2310=== PAUSE TestFailedPathPrunedByLaterClosure2311=== RUN TestWorkerUploadsAndRemoves2312=== PAUSE TestWorkerUploadsAndRemoves2313=== RUN TestWorkerSkipsGCdPaths2314=== PAUSE TestWorkerSkipsGCdPaths2315=== RUN TestWorkerPrunesClosureDeps2316=== PAUSE TestWorkerPrunesClosureDeps2317=== RUN TestDrainTimeout2318=== PAUSE TestDrainTimeout2319=== CONT TestSendPathsEmpty2320=== CONT TestServerQueueError2321--- PASS: TestSendPathsEmpty (0.00s)2322=== CONT TestServerClientIntegration2323=== CONT TestQueueRemoveLargeClosure2324=== CONT TestQueueConcurrentWriters2325=== CONT TestQueueFetchRemoveLifecycle23262026/10/07 06:18:21 ERROR Failed to queue paths error="permission denied" count=12327--- PASS: TestServerClientIntegration (0.00s)2328=== CONT TestQueueRetryMovesToBack2329=== CONT TestQueueFetchBatchLimit2330--- PASS: TestServerQueueError (0.00s)2331=== CONT TestQueueRemove2332=== CONT TestQueueDeduplication2333=== CONT TestQueueEnqueueAndFetch2334=== CONT TestDrainTimeout2335=== CONT TestWorkerSkipsGCdPaths2336=== CONT TestDrainGivesUpWhenServerDown2337=== CONT TestFailedPathPrunedByLaterClosure2338=== CONT TestRunNotBlockedByPoisonHead2339=== CONT TestDrainIsolatesPoisonPath2340=== CONT TestWorkerUploadsAndRemoves2341=== CONT TestWorkerPrunesClosureDeps23422026/10/07 06:18:22 INFO Uploading batch count=223432026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=223442026/10/07 06:18:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1890880558/002/a23452026/10/07 06:18:22 INFO Upload queue status pending=223462026/10/07 06:18:22 INFO Upload queue status pending=223472026/10/07 06:18:22 INFO Uploading batch count=123482026/10/07 06:18:22 INFO Uploading batch count=123492026/10/07 06:18:22 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1223056862/002/nonexistent23502026/10/07 06:18:22 INFO Uploading batch count=223512026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=123522026/10/07 06:18:22 INFO Uploading batch count=423532026/10/07 06:18:22 INFO Upload queue status pending=323542026/10/07 06:18:22 INFO Upload queue status pending=22355--- PASS: TestQueueFetchBatchLimit (0.02s)23562026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=423572026/10/07 06:18:22 INFO Uploading batch count=123582026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=123592026/10/07 06:18:22 INFO Uploading batch count=123602026/10/07 06:18:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1890880558/002/b23612026/10/07 06:18:22 INFO Uploading batch count=223622026/10/07 06:18:22 INFO Uploading batch count=12363--- PASS: TestQueueRetryMovesToBack (0.02s)23642026/10/07 06:18:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2118602950/002/bbb2365--- PASS: TestQueueEnqueueAndFetch (0.02s)23662026/10/07 06:18:22 INFO Uploading batch count=223672026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=22368--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23692026/10/07 06:18:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1890880558/002/c2370--- PASS: TestQueueRemove (0.02s)2371--- PASS: TestQueueDeduplication (0.02s)23722026/10/07 06:18:22 INFO Uploading batch count=123732026/10/07 06:18:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1890880558/002/d23742026/10/07 06:18:22 INFO Uploading batch count=123752026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=123762026/10/07 06:18:22 INFO Uploading batch count=223772026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=223782026/10/07 06:18:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1890880558/002/e23792026/10/07 06:18:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1890880558/002/f23802026/10/07 06:18:22 INFO Uploading batch count=123812026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=12382--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)23832026/10/07 06:18:22 ERROR Drain finished with paths left in queue remaining=1023842026/10/07 06:18:22 INFO Uploading batch count=123852026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=123862026/10/07 06:18:22 ERROR Drain finished with paths left in queue remaining=12387--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2388--- PASS: TestDrainIsolatesPoisonPath (0.03s)2389--- PASS: TestWorkerPrunesClosureDeps (0.04s)2390--- PASS: TestWorkerSkipsGCdPaths (0.04s)2391--- PASS: TestWorkerUploadsAndRemoves (0.04s)2392--- PASS: TestQueueRemoveLargeClosure (0.07s)23932026/10/07 06:18:22 ERROR Upload failed error="context deadline exceeded" count=223942026/10/07 06:18:22 ERROR Drain finished with paths left in queue remaining=42395--- PASS: TestDrainTimeout (0.22s)2396--- PASS: TestQueueConcurrentWriters (0.38s)23972026/10/07 06:18:23 INFO Uploading batch count=123982026/10/07 06:18:23 INFO Uploading batch count=123992026/10/07 06:18:23 INFO Uploading batch count=124002026/10/07 06:18:23 ERROR Upload failed error="upload failed" count=124012026/10/07 06:18:23 INFO Uploading batch count=124022026/10/07 06:18:23 ERROR Upload failed error="upload failed" count=124032026/10/07 06:18:23 INFO Uploading batch count=124042026/10/07 06:18:23 ERROR Upload failed error="upload failed" count=124052026/10/07 06:18:23 INFO Uploading batch count=124062026/10/07 06:18:23 ERROR Upload failed error="upload failed" count=124072026/10/07 06:18:23 ERROR Drain finished with paths left in queue remaining=12408--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2409PASS2410Running signing tests...2411=== RUN TestExternalSigner2412=== PAUSE TestExternalSigner2413=== RUN TestExternalSignerWrongPublicKey2414=== PAUSE TestExternalSignerWrongPublicKey2415=== RUN TestExternalSignerErrors2416=== PAUSE TestExternalSignerErrors2417=== RUN TestExternalSignerRestartsAfterCrash2418=== PAUSE TestExternalSignerRestartsAfterCrash2419=== RUN TestExternalSignerProgramErrorKeepsProcess2420=== PAUSE TestExternalSignerProgramErrorKeepsProcess2421=== RUN TestExternalSignerClose2422=== PAUSE TestExternalSignerClose2423=== RUN TestExternalSignerRejectsInvalidPublicKey2424=== PAUSE TestExternalSignerRejectsInvalidPublicKey2425=== RUN TestExternalSignerCancellation2426=== PAUSE TestExternalSignerCancellation2427=== RUN TestGenerateFingerprint2428=== PAUSE TestGenerateFingerprint2429=== RUN TestParseSigningKey2430=== PAUSE TestParseSigningKey2431=== RUN TestSign2432=== PAUSE TestSign2433=== RUN TestSignBatch2434=== PAUSE TestSignBatch2435=== RUN TestNilKeyPublicKey2436=== PAUSE TestNilKeyPublicKey2437=== RUN TestSignErrors2438=== PAUSE TestSignErrors2439=== CONT TestExternalSigner2440=== CONT TestExternalSignerCancellation2441=== CONT TestExternalSignerProgramErrorKeepsProcess2442=== CONT TestExternalSignerRejectsInvalidPublicKey2443=== CONT TestExternalSignerClose2444=== CONT TestSign2445=== CONT TestNilKeyPublicKey2446--- PASS: TestNilKeyPublicKey (0.00s)2447=== CONT TestSignErrors2448=== CONT TestSignBatch2449=== CONT TestParseSigningKey2450=== CONT TestExternalSignerWrongPublicKey2451=== CONT TestGenerateFingerprint2452=== CONT TestExternalSignerErrors2453=== CONT TestExternalSignerRestartsAfterCrash2454=== RUN TestExternalSignerRejectsInvalidPublicKey/#002455=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002456=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2457=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2458=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2459=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2460=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2461=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2462=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2463=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2464=== RUN TestParseSigningKey/valid_32-byte_key2465=== RUN TestGenerateFingerprint/basic_with_references2466=== PAUSE TestParseSigningKey/valid_32-byte_key2467=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2468=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2469=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2470=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2471=== RUN TestParseSigningKey/no_colon2472=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2473=== RUN TestExternalSignerErrors/invalid_JSON2474=== PAUSE TestExternalSignerErrors/invalid_JSON2475=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2476=== CONT TestExternalSignerRejectsInvalidPublicKey/#002477=== PAUSE TestParseSigningKey/no_colon2478=== PAUSE TestGenerateFingerprint/basic_with_references2479--- PASS: TestSign (0.00s)2480--- PASS: TestSignBatch (0.00s)2481=== RUN TestSignErrors/nil_key2482=== PAUSE TestSignErrors/nil_key2483=== RUN TestSignErrors/nil_narinfo2484=== PAUSE TestSignErrors/nil_narinfo2485=== RUN TestExternalSignerErrors/wrong_id2486=== PAUSE TestExternalSignerErrors/wrong_id2487=== RUN TestExternalSignerErrors/null_signatures2488=== PAUSE TestExternalSignerErrors/null_signatures2489=== RUN TestExternalSignerErrors/unrequested_key2490=== PAUSE TestExternalSignerErrors/unrequested_key2491=== RUN TestParseSigningKey/empty_name2492=== RUN TestGenerateFingerprint/no_references2493=== PAUSE TestGenerateFingerprint/no_references2494=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2495=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2496--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2497 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2498 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2499 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2500 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2501 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2502=== RUN TestSignErrors/invalid_narinfo2503=== RUN TestExternalSignerErrors/missing_signature_name2504=== PAUSE TestExternalSignerErrors/missing_signature_name2505=== RUN TestExternalSignerErrors/wrong_signatures_shape2506=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2507=== RUN TestExternalSignerErrors/too_few_signatures2508=== PAUSE TestExternalSignerErrors/too_few_signatures2509=== RUN TestExternalSignerErrors/wrong_signature_length2510=== PAUSE TestExternalSignerErrors/wrong_signature_length2511=== RUN TestExternalSignerErrors/exit_at_startup2512=== PAUSE TestExternalSignerErrors/exit_at_startup2513=== RUN TestExternalSignerErrors/wrong_shape2514=== PAUSE TestParseSigningKey/empty_name2515=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2516=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2517=== PAUSE TestSignErrors/invalid_narinfo2518=== PAUSE TestExternalSignerErrors/wrong_shape2519=== RUN TestExternalSignerErrors/missing_signatures2520=== PAUSE TestExternalSignerErrors/missing_signatures2521=== RUN TestExternalSignerErrors/wrong_signature_name2522=== PAUSE TestExternalSignerErrors/wrong_signature_name2523=== RUN TestExternalSignerErrors/invalid_signature_base642524--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2525=== RUN TestParseSigningKey/invalid_base642526=== PAUSE TestParseSigningKey/invalid_base642527=== RUN TestParseSigningKey/wrong_length2528=== PAUSE TestParseSigningKey/wrong_length2529=== CONT TestParseSigningKey/valid_32-byte_key2530=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2531=== RUN TestGenerateFingerprint/invalid_nar_hash_length2532=== CONT TestParseSigningKey/no_colon2533=== CONT TestParseSigningKey/invalid_base642534=== RUN TestSignErrors/canceled2535=== PAUSE TestSignErrors/canceled2536=== PAUSE TestExternalSignerErrors/invalid_signature_base642537=== RUN TestExternalSignerErrors/exit_on_request2538=== PAUSE TestExternalSignerErrors/exit_on_request2539=== RUN TestExternalSignerErrors/null2540=== PAUSE TestExternalSignerErrors/null2541=== RUN TestExternalSignerErrors/program_error2542=== PAUSE TestExternalSignerErrors/program_error2543=== CONT TestExternalSignerErrors/invalid_JSON2544=== CONT TestExternalSignerErrors/wrong_shape2545=== CONT TestParseSigningKey/wrong_length2546=== CONT TestExternalSignerErrors/null_signatures2547=== CONT TestExternalSignerErrors/wrong_signatures_shape2548=== CONT TestParseSigningKey/empty_name2549--- PASS: TestExternalSignerClose (0.00s)2550=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2551=== CONT TestSignErrors/nil_key2552=== CONT TestSignErrors/canceled2553=== CONT TestSignErrors/invalid_narinfo2554=== CONT TestSignErrors/nil_narinfo2555=== CONT TestExternalSignerErrors/exit_at_startup2556=== CONT TestExternalSignerErrors/wrong_signature_length2557=== CONT TestExternalSignerErrors/too_few_signatures2558=== CONT TestExternalSignerErrors/exit_on_request2559=== CONT TestExternalSignerErrors/wrong_signature_name2560=== CONT TestExternalSignerErrors/invalid_signature_base642561=== CONT TestExternalSignerErrors/missing_signatures2562=== CONT TestExternalSignerErrors/program_error2563=== CONT TestExternalSignerErrors/null2564=== CONT TestExternalSignerErrors/unrequested_key2565=== CONT TestExternalSignerErrors/missing_signature_name2566=== CONT TestExternalSignerErrors/wrong_id2567--- PASS: TestExternalSignerWrongPublicKey (0.00s)2568=== RUN TestGenerateFingerprint/invalid_store_path_prefix2569=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2570--- PASS: TestParseSigningKey (0.00s)2571 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2572 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2573 --- PASS: TestParseSigningKey/no_colon (0.00s)2574 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2575 --- PASS: TestParseSigningKey/wrong_length (0.00s)2576 --- PASS: TestParseSigningKey/empty_name (0.00s)2577--- PASS: TestExternalSigner (0.01s)2578=== RUN TestGenerateFingerprint/invalid_reference_prefix2579=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2580--- PASS: TestSignErrors (0.00s)2581 --- PASS: TestSignErrors/nil_key (0.00s)2582 --- PASS: TestSignErrors/canceled (0.00s)2583 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2584 --- PASS: TestSignErrors/nil_narinfo (0.00s)2585=== CONT TestGenerateFingerprint/basic_with_references2586=== CONT TestGenerateFingerprint/invalid_reference_prefix2587=== CONT TestGenerateFingerprint/invalid_store_path_prefix2588=== CONT TestGenerateFingerprint/invalid_nar_hash_length2589=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2590=== CONT TestGenerateFingerprint/no_references2591=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2592--- PASS: TestGenerateFingerprint (0.01s)2593 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2594 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2595 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2596 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2597 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2598 --- PASS: TestGenerateFingerprint/no_references (0.00s)2599 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2600--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2601--- PASS: TestExternalSignerErrors (0.00s)2602 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)2603 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2604 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2605 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2606 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2607 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2608 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2609 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2610 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2611 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2612 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2613 --- PASS: TestExternalSignerErrors/null (0.01s)2614 --- PASS: TestExternalSignerErrors/program_error (0.01s)2615 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2616 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2617 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2618--- PASS: TestExternalSignerCancellation (0.02s)2619PASS2620Running OpenBao signer tests...2621=== RUN TestSign2622=== PAUSE TestSign2623=== RUN TestSignErrors2624=== PAUSE TestSignErrors2625=== RUN TestServe2626=== PAUSE TestServe2627=== RUN TestServeRejectsGarbage2628=== PAUSE TestServeRejectsGarbage2629=== CONT TestSign2630=== CONT TestServe2631=== CONT TestSignErrors2632=== CONT TestServeRejectsGarbage2633--- PASS: TestServeRejectsGarbage (0.00s)2634=== RUN TestSignErrors/no_prefix2635=== PAUSE TestSignErrors/no_prefix2636=== RUN TestSignErrors/invalid_base642637=== PAUSE TestSignErrors/invalid_base642638=== RUN TestSignErrors/http_error2639=== PAUSE TestSignErrors/http_error2640--- PASS: TestServe (0.00s)2641=== RUN TestSignErrors/invalid_json2642=== PAUSE TestSignErrors/invalid_json2643=== CONT TestSignErrors/no_prefix2644=== CONT TestSignErrors/http_error2645=== CONT TestSignErrors/invalid_json2646=== CONT TestSignErrors/invalid_base642647--- PASS: TestSign (0.00s)2648--- PASS: TestSignErrors (0.00s)2649 --- PASS: TestSignErrors/no_prefix (0.00s)2650 --- PASS: TestSignErrors/http_error (0.00s)2651 --- PASS: TestSignErrors/invalid_json (0.00s)2652 --- PASS: TestSignErrors/invalid_base64 (0.00s)2653PASS