nixbot

builds

succeeded niks3-go-unit-tests checks.aarch64-linux.go-unit-tests · build #369 · raw

1tribuchet: building on eliza2Running 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 TestScriptTokenScriptFails101=== CONT TestResolveStorePath102=== CONT TestClientSignaturesByStorePath103--- PASS: TestClientSignaturesByStorePath (0.00s)104=== CONT TestRateLimiterFeedback105=== CONT TestStreamPushReportsSignatures106=== CONT TestSetClientTLS107=== CONT TestStreamPushRequestLine108=== CONT TestStreamPushGivesUpOnDeadServer109=== CONT TestFileTokenMissing110--- PASS: TestResolveStorePath (0.00s)111=== CONT TestPathInfoCACompatibility112=== RUN TestPathInfoCACompatibility/null_ca_field113=== PAUSE TestPathInfoCACompatibility/null_ca_field114=== RUN TestPathInfoCACompatibility/old_string_format_-_text115=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text116=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive117=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive118=== RUN TestPathInfoCACompatibility/new_structured_format_-_text119--- PASS: TestFileTokenMissing (0.00s)120=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text121=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method1222026/10/06 10:44:46 ERROR Upload failed error=boom count=11232026/10/06 10:44:46 ERROR Upload failed error="connection refused" count=201242026/10/06 10:44:46 ERROR Server seems unavailable, giving up on batch untried=171252026/10/06 10:44:46 ERROR Upload failed error=boom count=1126=== CONT TestParsePathInfoJSONMultiplePaths127=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths128=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method129=== CONT TestStreamPushBatchesUnderLoad130=== CONT TestStaticToken131=== CONT TestStreamPushReportsEveryPath132=== CONT TestSetClientTLSErrors133=== CONT TestShellSplitErrors134=== CONT TestSetClientTLSDoesNotMutateDefaultTransport135=== CONT TestShellSplit136=== CONT TestDoWithRetry_BodyReplayedViaGetBody137=== CONT TestScriptTokenEmptyCommand138=== CONT TestDumpPathWriterError139=== CONT TestScriptTokenEmptyToken140=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess141=== CONT TestScriptTokenBadJSON142=== RUN TestRateLimiterFeedback/429_enables_limiter143=== CONT TestStreamPushIsolatesFailures144=== CONT TestFileTokenReadsAndCaches145=== CONT TestDumpPathSingleFile146=== CONT TestDumpPathMatchesNix147=== CONT TestParsePathInfoJSON148=== RUN TestParsePathInfoJSON/Nix_format149=== CONT TestGetStorePathHash150=== RUN TestGetStorePathHash/valid_store_path151=== CONT TestConvertHashToNix32152=== PAUSE TestGetStorePathHash/valid_store_path153=== RUN TestConvertHashToNix32/SRI_format_to_Nix32154=== CONT TestPathInfoHashCompatibility155=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32156=== RUN TestConvertHashToNix32/already_Nix32_format157=== PAUSE TestConvertHashToNix32/already_Nix32_format158=== RUN TestConvertHashToNix32/invalid_format159=== PAUSE TestConvertHashToNix32/invalid_format160=== CONT TestUploadMultipart_SupersededByPeer161=== RUN TestUploadMultipart_SupersededByPeer/exists162=== PAUSE TestUploadMultipart_SupersededByPeer/exists163=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)164=== PAUSE TestParsePathInfoJSON/Nix_format165=== RUN TestUploadMultipart_SupersededByPeer/missing166=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)167=== RUN TestGetStorePathHash/basename_without_hyphen_should_error168=== PAUSE TestUploadMultipart_SupersededByPeer/missing1692026/10/06 10:44:46 WARN Rate limiter enabled after throttle name=server-test rate=5170--- PASS: TestStreamPushReportsSignatures (0.00s)1712026/10/06 10:44:46 ERROR Upload failed error="bad path" count=3172=== CONT TestUploadMultipart_PartsInParallel173=== CONT TestPartSizeForNAR174=== CONT TestEncodeNixBase32WithRealHash175=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon176=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths177=== RUN TestParsePathInfoJSON/Lix_format178=== PAUSE TestRateLimiterFeedback/429_enables_limiter179=== RUN TestSetClientTLSErrors/missing_cert_file180=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths181=== CONT TestScriptTokenCachesUntilRefresh182--- PASS: TestScriptTokenScriptFails (0.00s)183--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)184=== RUN TestPartSizeForNAR/zero_stays_at_minimum185=== CONT TestEncodeNixBase32186=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon187=== PAUSE TestParsePathInfoJSON/Lix_format188=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error189=== RUN TestEncodeNixBase32/test_string_hash190=== RUN TestParsePathInfoJSON/empty_input191=== CONT TestScriptTokenNoExpiryRerunsEveryCall192--- PASS: TestDoServerRequestAttachesToken (0.01s)193--- PASS: TestStaticToken (0.00s)194--- PASS: TestShellSplitErrors (0.00s)195--- PASS: TestStreamPushReportsEveryPath (0.00s)196--- PASS: TestShellSplit (0.00s)197--- PASS: TestScriptTokenEmptyCommand (0.00s)198--- PASS: TestEncodeNixBase32WithRealHash (0.00s)199--- PASS: TestStreamPushIsolatesFailures (0.00s)200=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun201--- PASS: TestFileTokenReadsAndCaches (0.00s)202=== CONT TestFilterOversizedClosures203=== PAUSE TestSetClientTLSErrors/missing_cert_file204=== RUN TestSetClientTLSErrors/missing_key_file205=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI206=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths207=== RUN TestRateLimiterFeedback/503_enables_limiter208=== PAUSE TestEncodeNixBase32/test_string_hash209=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error210=== RUN TestEncodeNixBase32/empty_input211=== RUN TestFilterOversizedClosures/no_limit_keeps_everything212=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI213=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything214=== PAUSE TestRateLimiterFeedback/503_enables_limiter215=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped216=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512217=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter218=== CONT TestCaseHackSuffix219=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped220=== RUN TestFilterOversizedClosures/all_closures_skipped221=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum222=== RUN TestPartSizeForNAR/small_stays_at_minimum223=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512224=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica225=== PAUSE TestEncodeNixBase32/empty_input226=== CONT TestRegisterUploadedObjectReusesConnections227--- PASS: TestDumpPathSingleFile (0.03s)228=== CONT TestFileTokenEmpty229--- PASS: TestFileTokenEmpty (0.00s)230=== CONT TestPathInfoCACompatibility/null_ca_field231=== CONT TestPathInfoCACompatibility/new_structured_format_-_text232=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method233=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive234=== CONT TestPathInfoCACompatibility/old_string_format_-_text235--- PASS: TestPathInfoCACompatibility (0.00s)236 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)237 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)238 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)239 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)240 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)241=== CONT TestConvertHashToNix32/SRI_format_to_Nix32242=== CONT TestConvertHashToNix32/invalid_format2432026/10/06 10:44:46 INFO Garbage collection started244=== CONT TestConvertHashToNix32/already_Nix32_format245--- PASS: TestConvertHashToNix32 (0.00s)246 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)247 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)248 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)249=== CONT TestUploadMultipart_SupersededByPeer/exists250--- PASS: TestScriptTokenEmptyToken (0.04s)251=== CONT TestUploadMultipart_SupersededByPeer/missing2522026/10/06 10:44:46 WARN Rate limiter enabled after throttle name=server-test rate=52532026/10/06 10:44:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35705254=== PAUSE TestParsePathInfoJSON/empty_input255=== RUN TestParsePathInfoJSON/whitespace_only256=== PAUSE TestParsePathInfoJSON/whitespace_only257=== RUN TestParsePathInfoJSON/invalid_JSON258=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths259=== PAUSE TestParsePathInfoJSON/invalid_JSON2602026/10/06 10:44:46 WARN Rate limiter backed off name=server-test rate=5261=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error2622026/10/06 10:44:46 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35705263=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error264=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error265=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)266=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512267=== CONT TestEncodeNixBase32/test_string_hash268=== CONT TestEncodeNixBase32/empty_input269=== CONT TestParsePathInfoJSON/Nix_format270=== CONT TestParsePathInfoJSON/whitespace_only271=== CONT TestParsePathInfoJSON/invalid_JSON272=== CONT TestParsePathInfoJSON/empty_input273=== CONT TestGetStorePathHash/valid_store_path274--- PASS: TestScriptTokenBadJSON (0.04s)275=== PAUSE TestFilterOversizedClosures/all_closures_skipped276=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2772026/10/06 10:44:46 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=0278=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error279=== CONT TestGetStorePathHash/basename_without_hyphen_should_error280=== CONT TestFilterOversizedClosures/no_limit_keeps_everything281=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped282=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2832026/10/06 10:44:46 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=2000284=== CONT TestFilterOversizedClosures/all_closures_skipped2852026/10/06 10:44:46 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50286=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon287=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error288--- PASS: TestEncodeNixBase32 (0.03s)289 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)290 --- PASS: TestEncodeNixBase32/empty_input (0.00s)291=== CONT TestParsePathInfoJSON/Lix_format292--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)293--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.04s)294--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)295 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)296 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)297--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)298 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)299 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)300=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter301--- PASS: TestPathInfoHashCompatibility (0.03s)302 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)303 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)304 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)305 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)306--- PASS: TestGetStorePathHash (0.04s)307 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)308 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)309 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)310 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)311--- PASS: TestParsePathInfoJSON (0.04s)312 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)313 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)314 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)315 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)316 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)317=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter318=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter319=== CONT TestRateLimiterFeedback/429_enables_limiter320=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter321=== CONT TestRateLimiterFeedback/503_enables_limiter322--- PASS: TestFilterOversizedClosures (0.03s)323 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)324 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)325 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)326=== PAUSE TestSetClientTLSErrors/missing_key_file327=== PAUSE TestPartSizeForNAR/small_stays_at_minimum328=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum329=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum330=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts331=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts332=== RUN TestPartSizeForNAR/1_TiB333=== PAUSE TestPartSizeForNAR/1_TiB334=== RUN TestPartSizeForNAR/5_TiB_S3_max_object335=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object3362026/10/06 10:44:46 WARN Rate limiter enabled after throttle name=server-test rate=5337=== RUN TestPartSizeForNAR/capped_at_5_GiB3382026/10/06 10:44:46 WARN Rate limiter enabled after throttle name=server-test rate=5339=== PAUSE TestPartSizeForNAR/capped_at_5_GiB3402026/10/06 10:44:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:38171341=== CONT TestPartSizeForNAR/zero_stays_at_minimum342=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3432026/10/06 10:44:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:36917344=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum3452026/10/06 10:44:46 WARN Rate limiter backed off name=server-test rate=5346=== CONT TestPartSizeForNAR/small_stays_at_minimum3472026/10/06 10:44:46 WARN Rate limiter backed off name=server-test rate=5348=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts349=== CONT TestPartSizeForNAR/1_TiB3502026/10/06 10:44:46 WARN Garbage collection finished on another replica. Its statistics are not available here351=== RUN TestSetClientTLSErrors/missing_ca_file352=== PAUSE TestSetClientTLSErrors/missing_ca_file353=== RUN TestSetClientTLSErrors/invalid_ca_file354=== PAUSE TestSetClientTLSErrors/invalid_ca_file355=== CONT TestSetClientTLSErrors/missing_cert_file356=== CONT TestSetClientTLSErrors/invalid_ca_file357--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)358=== CONT TestPartSizeForNAR/5_TiB_S3_max_object359=== CONT TestPartSizeForNAR/capped_at_5_GiB360=== CONT TestSetClientTLSErrors/missing_key_file361=== RUN TestSetClientTLS/rejects_connection_without_client_cert362=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert363=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA364=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA365--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)366=== CONT TestSetClientTLSErrors/missing_ca_file367--- PASS: TestPartSizeForNAR (0.04s)368 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)369 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)370 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)371 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)372 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)373 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)374 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)375--- PASS: TestRateLimiterFeedback (0.04s)376 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)377 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)378 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)379 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)380=== RUN TestSetClientTLS/preserves_debug_logging_transport381=== PAUSE TestSetClientTLS/preserves_debug_logging_transport382=== CONT TestSetClientTLS/rejects_connection_without_client_cert383=== CONT TestSetClientTLS/preserves_debug_logging_transport384--- PASS: TestSetClientTLSErrors (0.04s)385 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)386 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)387 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)388 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)389=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3902026/10/06 10:44:46 INFO Garbage collection started391--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)392--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.04s)3932026/10/06 10:44:46 http: TLS handshake error from 127.0.0.1:47136: remote error: tls: bad certificate394--- PASS: TestSetClientTLS (0.04s)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: TestRegisterUploadedObjectReusesConnections (0.02s)399--- PASS: TestStreamPushRequestLine (0.06s)400--- PASS: TestCaseHackSuffix (0.03s)401--- PASS: TestDumpPathWriterError (0.07s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (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/postgres3710921869/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/postgres3710921869/data -l logfile start434435/build/postgres3710921869:5432 - no response4362026-10-06 10:44:48.119 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 10:44:48.119 UTC [128] LOG: listening on Unix socket "/build/postgres3710921869/.s.PGSQL.5432"4382026-10-06 10:44:48.123 UTC [135] LOG: database system was shut down at 2026-10-06 10:44:47 UTC4392026-10-06 10:44:48.126 UTC [128] LOG: database system is ready to accept connections440/build/postgres3710921869:5432 - accepting connections441{"timestamp":"2026-10-06T10:44:48.316819379Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"1fd1e524-d948-4084-9904-101549a63012","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(196)"}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 TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== RUN TestResolveDBConnectionString481=== PAUSE TestResolveDBConnectionString482=== RUN TestConnectWaitsForAPeerMigration483=== PAUSE TestConnectWaitsForAPeerMigration484=== RUN TestLeadElectsOneAndHandsOver485=== PAUSE TestLeadElectsOneAndHandsOver486=== RUN TestLeadIncumbentWinsAfterRestart4872026/10/06 10:44:48 INFO lead: acquired remote=192.0.2.1:12344882026/10/06 10:44:49 INFO lead: released remote=192.0.2.1:12344892026/10/06 10:44:49 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 10:44:50 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (1.82s)492=== RUN TestLeadIncumbentAnnouncesAtOnce493=== PAUSE TestLeadIncumbentAnnouncesAtOnce494=== RUN TestLeadEndsOnShutdown495=== PAUSE TestLeadEndsOnShutdown496=== RUN TestLeadEndsWhenItsConnectionHangs4972026/10/06 10:44:50 INFO lead: acquired remote=192.0.2.1:12344982026-10-06 10:44:51.747 UTC [380] FATAL: terminating connection due to administrator command4992026/10/06 10:44:51 INFO lead: acquired remote=192.0.2.1:12345002026/10/06 10:44:52 WARN lead: lock connection lost error="timeout: context deadline exceeded"5012026/10/06 10:44:52 INFO lead: released remote=192.0.2.1:12345022026/10/06 10:44:53 INFO lead: released remote=192.0.2.1:1234503--- PASS: TestLeadEndsWhenItsConnectionHangs (3.10s)504=== RUN TestGCAdvisoryLockBlocksConcurrentRun505=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun506=== RUN TestGCBugBareHashReferences507=== PAUSE TestGCBugBareHashReferences508=== RUN TestGCMetrics509=== PAUSE TestGCMetrics510=== RUN TestPushDedupSurvivesConcurrentGC511=== PAUSE TestPushDedupSurvivesConcurrentGC512=== RUN TestDeduplicatedObjectsRecordedAsPending513=== PAUSE TestDeduplicatedObjectsRecordedAsPending514=== RUN TestGCSweepSkipsPendingObjects515=== PAUSE TestGCSweepSkipsPendingObjects516=== RUN TestTombstonedObjectOfferedWithoutWaiting517=== PAUSE TestTombstonedObjectOfferedWithoutWaiting518=== RUN TestGCSweepDeliversEachKeyOnce519=== PAUSE TestGCSweepDeliversEachKeyOnce520=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== RUN TestForceGCDuringPushOffersSweptObject523=== PAUSE TestForceGCDuringPushOffersSweptObject524=== RUN TestFailedS3DeleteKeepsTombstone525=== PAUSE TestFailedS3DeleteKeepsTombstone526=== RUN TestSweepSkipsRowsLockedByPush527=== PAUSE TestSweepSkipsRowsLockedByPush528=== RUN TestRegisterCompletedObjectNeedsPendingRow529=== PAUSE TestRegisterCompletedObjectNeedsPendingRow530=== RUN TestGetExistingObjectsLocksRows531=== PAUSE TestGetExistingObjectsLocksRows532=== RUN TestSweepRechecksPendingAfterLocking533=== PAUSE TestSweepRechecksPendingAfterLocking534=== RUN TestPushWaitsForSweepHoldingRow535=== PAUSE TestPushWaitsForSweepHoldingRow536=== RUN TestCommitRacingPendingCleanupKeepsObjects537=== PAUSE TestCommitRacingPendingCleanupKeepsObjects538=== RUN TestGCEndsOnShutdown539=== PAUSE TestGCEndsOnShutdown540=== RUN TestGCTaskStore_StartNew541=== PAUSE TestGCTaskStore_StartNew542=== RUN TestGCTaskStore_DeduplicateSameParams543=== PAUSE TestGCTaskStore_DeduplicateSameParams544=== RUN TestGCTaskStore_ConflictDifferentParams545=== PAUSE TestGCTaskStore_ConflictDifferentParams546=== RUN TestGCTaskStore_GetEmpty547=== PAUSE TestGCTaskStore_GetEmpty548=== RUN TestGCTaskStore_GetReturnsLatest549=== PAUSE TestGCTaskStore_GetReturnsLatest550=== RUN TestGCTaskStore_CompletedAllowsNewTask551=== PAUSE TestGCTaskStore_CompletedAllowsNewTask552=== RUN TestGCTaskStore_PhaseUpdates553=== PAUSE TestGCTaskStore_PhaseUpdates554=== RUN TestGCTaskStore_Fail555=== PAUSE TestGCTaskStore_Fail556=== RUN TestGracefulShutdownDrainsInflight557=== PAUSE TestGracefulShutdownDrainsInflight558=== RUN TestService_healthCheckHandler559=== PAUSE TestService_healthCheckHandler560=== RUN TestService_readinessHandler561=== PAUSE TestService_readinessHandler562=== RUN TestGenerateLandingPage563=== PAUSE TestGenerateLandingPage564=== RUN TestCacheConfigHandlerMaxNarSize565=== PAUSE TestCacheConfigHandlerMaxNarSize566=== RUN TestCreatePendingClosureRejectsOversizedNAR567=== PAUSE TestCreatePendingClosureRejectsOversizedNAR568=== RUN TestNARDeduplicationMetadataUploadBug569=== PAUSE TestNARDeduplicationMetadataUploadBug570=== RUN TestMetricsInventory571=== PAUSE TestMetricsInventory572=== RUN TestService_NativeMTLS573=== PAUSE TestService_NativeMTLS574=== RUN TestServerTLSConfig575=== PAUSE TestServerTLSConfig576=== RUN TestMultipartCleanup577=== PAUSE TestMultipartCleanup578=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded580=== RUN TestPendingCleanupUsesOneCutoff581=== PAUSE TestPendingCleanupUsesOneCutoff582=== RUN TestObjectStatsTrigger583=== PAUSE TestObjectStatsTrigger584=== RUN TestOrphanedObjectsGC585=== PAUSE TestOrphanedObjectsGC586=== RUN TestOrphanedObjectsGCStressTest587=== PAUSE TestOrphanedObjectsGCStressTest588=== RUN TestCreatePin_ReservedPins589=== PAUSE TestCreatePin_ReservedPins590=== RUN TestPresentReportsOnlyClosureRoots591=== PAUSE TestPresentReportsOnlyClosureRoots592=== RUN TestPresentNotReportedWhileGCDeletesClosure593=== PAUSE TestPresentNotReportedWhileGCDeletesClosure594=== RUN TestParseSingleRange595=== PAUSE TestParseSingleRange596=== RUN TestProxyHeadersOnlyTrustedOnSocket597=== PAUSE TestProxyHeadersOnlyTrustedOnSocket598=== RUN TestIsValidCachePath599=== PAUSE TestIsValidCachePath600=== RUN TestReadProxyNarinfo601=== PAUSE TestReadProxyNarinfo602=== RUN TestReadProxyNarinfoAlreadyDecompressed603=== PAUSE TestReadProxyNarinfoAlreadyDecompressed604=== RUN TestReadProxyContentNegotiation605=== PAUSE TestReadProxyContentNegotiation606=== RUN TestReadProxyNarStreaming607=== PAUSE TestReadProxyNarStreaming608=== RUN TestReadProxy404609=== PAUSE TestReadProxy404610=== RUN TestReadProxyInvalidPath611=== PAUSE TestReadProxyInvalidPath612=== RUN TestReadProxyHead613=== PAUSE TestReadProxyHead614=== RUN TestReadProxyOutlastsServerWriteTimeout615=== PAUSE TestReadProxyOutlastsServerWriteTimeout616=== RUN TestReadProxyConditionalGet617=== PAUSE TestReadProxyConditionalGet618=== RUN TestReadProxyRootRedirectsToIndexHTML619=== PAUSE TestReadProxyRootRedirectsToIndexHTML620=== RUN TestReadProxyDisabled621=== PAUSE TestReadProxyDisabled622=== RUN TestReadRedirectNar623=== PAUSE TestReadRedirectNar624=== RUN TestReadRedirectKeepsNarinfoProxied625=== PAUSE TestReadRedirectKeepsNarinfoProxied626=== RUN TestReadProxyRangeRequest627=== PAUSE TestReadProxyRangeRequest628=== RUN TestReadRedirectUsesPublicS3URL629=== PAUSE TestReadRedirectUsesPublicS3URL630=== RUN TestPush_OverlappingRootsStoreOneRowPerKey631=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey632=== RUN TestPush_CompleteCommitsEveryRoot633=== PAUSE TestPush_CompleteCommitsEveryRoot634=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit635=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit636=== RUN TestPush_RejectsBadRequests637=== PAUSE TestPush_RejectsBadRequests638=== RUN TestPush_SignsNarinfosOfItsPendingObjects639=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects640=== RUN TestRedundantMultipartUpload641=== PAUSE TestRedundantMultipartUpload642=== RUN TestCompleteMultipartUpload_ErrorButObjectExists643=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists644=== RUN TestCompletedNarNotReofferedAcrossClosures645=== PAUSE TestCompletedNarNotReofferedAcrossClosures646=== RUN TestPresignedUploadRegisteredBeforeCommit647=== PAUSE TestPresignedUploadRegisteredBeforeCommit648=== RUN TestService_Rustfstest649=== PAUSE TestService_Rustfstest650=== RUN TestParseSize651=== PAUSE TestParseSize652=== RUN TestSkippedUploadsHandler653=== PAUSE TestSkippedUploadsHandler654=== RUN TestSystemdListenerNotActivated655--- PASS: TestSystemdListenerNotActivated (0.00s)656=== RUN TestWatchdogBeatsWhenHealthy657--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)658=== RUN TestWatchdogSkipsWhenUnhealthy6592026/10/06 10:44:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/06 10:44:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 10:44:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 10:44:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 10:44:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 10:44:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 10:44:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 10:44:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 10:44:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 10:44:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"669--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)670=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle672=== RUN TestProxyWriteTimeout673=== PAUSE TestProxyWriteTimeout674=== RUN TestPendingClosureWriteTimeout675=== PAUSE TestPendingClosureWriteTimeout676=== RUN TestIsValidUploadKey677=== PAUSE TestIsValidUploadKey678=== RUN TestUploadHandlersRejectInvalidKeys679=== PAUSE TestUploadHandlersRejectInvalidKeys680=== RUN TestUploadHandlersRejectOversizedBody681=== PAUSE TestUploadHandlersRejectOversizedBody682=== RUN TestService_cleanupPendingClosuresHandler683=== PAUSE TestService_cleanupPendingClosuresHandler684=== RUN TestService_createPendingClosureHandler685=== PAUSE TestService_createPendingClosureHandler686=== RUN TestService_verifyS3Integrity687=== PAUSE TestService_verifyS3Integrity688=== RUN TestCompleteMultipartUnregistered689=== PAUSE TestCompleteMultipartUnregistered690=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT691=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT692=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit693=== CONT TestReadProxyRangeRequest694=== CONT TestService_cleanupPendingClosuresHandler695=== CONT TestProxyWriteTimeout696=== CONT TestUploadHandlersRejectInvalidKeys697=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info698=== CONT TestService_AuthMiddleware699=== CONT TestPresignedUploadRegisteredBeforeCommit700=== RUN TestProxyWriteTimeout/narinfo701=== PAUSE TestProxyWriteTimeout/narinfo702=== RUN TestProxyWriteTimeout/1_GiB_nar703=== CONT TestPush_CompleteCommitsEveryRoot704=== CONT TestPush_OverlappingRootsStoreOneRowPerKey705=== CONT TestReadRedirectUsesPublicS3URL706=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle707=== CONT TestSkippedUploadsHandler708=== CONT TestParseSize709--- PASS: TestParseSize (0.00s)710=== CONT TestGCTaskStore_DeduplicateSameParams711--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)712=== CONT TestReadRedirectKeepsNarinfoProxied7132026/10/06 10:44:53 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000714=== CONT TestService_Rustfstest715=== CONT TestCompleteMultipartUnregistered716=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT717=== CONT TestService_verifyS3Integrity718=== CONT TestIsValidUploadKey719=== RUN TestIsValidUploadKey/narinfo720=== PAUSE TestIsValidUploadKey/narinfo721=== RUN TestIsValidUploadKey/nar_zst722=== PAUSE TestIsValidUploadKey/nar_zst723=== RUN TestIsValidUploadKey/nar_xz724=== PAUSE TestIsValidUploadKey/nar_xz725=== RUN TestIsValidUploadKey/nar_plain726=== PAUSE TestIsValidUploadKey/nar_plain727=== RUN TestIsValidUploadKey/listing728=== PAUSE TestIsValidUploadKey/listing729=== RUN TestIsValidUploadKey/build_log730=== PAUSE TestIsValidUploadKey/build_log731=== RUN TestIsValidUploadKey/build_log_home-manager_file732=== PAUSE TestIsValidUploadKey/build_log_home-manager_file733=== CONT TestRedundantMultipartUpload734=== CONT TestCompletedNarNotReofferedAcrossClosures735=== CONT TestCompleteMultipartUpload_ErrorButObjectExists736=== CONT TestService_createPendingClosureHandler737=== CONT TestUploadHandlersRejectOversizedBody738=== CONT TestPush_SignsNarinfosOfItsPendingObjects739=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info740=== PAUSE TestProxyWriteTimeout/1_GiB_nar741=== RUN TestProxyWriteTimeout/10_GiB_nar742=== PAUSE TestProxyWriteTimeout/10_GiB_nar743=== RUN TestProxyWriteTimeout/unknown_size744=== PAUSE TestProxyWriteTimeout/unknown_size745=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal746=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal747=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key748=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key749=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key750=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key751=== RUN TestIsValidUploadKey/build_log_plus_in_name752=== PAUSE TestIsValidUploadKey/build_log_plus_in_name753=== RUN TestIsValidUploadKey/build_log_question_mark754=== PAUSE TestIsValidUploadKey/build_log_question_mark755=== RUN TestIsValidUploadKey/build_log_equals756=== PAUSE TestIsValidUploadKey/build_log_equals757=== RUN TestIsValidUploadKey/realisation758=== PAUSE TestIsValidUploadKey/realisation759=== RUN TestIsValidUploadKey/realisation_plus_in_output760=== PAUSE TestIsValidUploadKey/realisation_plus_in_output761=== RUN TestIsValidUploadKey/nix-cache-info762=== PAUSE TestIsValidUploadKey/nix-cache-info763=== RUN TestIsValidUploadKey/index.html764=== PAUSE TestIsValidUploadKey/index.html765=== RUN TestIsValidUploadKey/narinfo_key,_nar_type766=== CONT TestReadRedirectNar767=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type768=== CONT TestReadProxyDisabled769=== RUN TestIsValidUploadKey/nar_key,_narinfo_type770=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type771=== RUN TestIsValidUploadKey/listing_key,_narinfo_type772=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type773=== RUN TestIsValidUploadKey/traversal774=== PAUSE TestIsValidUploadKey/traversal775=== RUN TestIsValidUploadKey/traversal_nar776=== PAUSE TestIsValidUploadKey/traversal_nar777=== RUN TestIsValidUploadKey/absolute778=== PAUSE TestIsValidUploadKey/absolute779=== RUN TestIsValidUploadKey/empty_key780=== PAUSE TestIsValidUploadKey/empty_key781=== RUN TestIsValidUploadKey/unknown_type782=== PAUSE TestIsValidUploadKey/unknown_type783=== CONT TestReadProxyRootRedirectsToIndexHTML784--- PASS: TestSkippedUploadsHandler (0.01s)785=== CONT TestReadProxyConditionalGet786=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure787=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure788=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart789=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart790=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts791=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts792=== CONT TestReadProxyOutlastsServerWriteTimeout7932026/10/06 10:44:53 INFO Received push request method=POST path=/api/pushes794--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.27s)795=== CONT TestReadProxyHead7962026/10/06 10:44:53 INFO Received cleanup request method=DELETE path=/api/pending_closures7972026/10/06 10:44:53 INFO Aborted multipart uploads count=0 kept=07982026/10/06 10:44:53 INFO Received uploads request method=POST path=/api/pending_closures7992026/10/06 10:44:53 INFO Received cleanup request method=DELETE path=/api/pending_closures8002026/10/06 10:44:53 INFO Aborted multipart uploads count=1 kept=08012026/10/06 10:44:53 INFO Received uploads request method=POST path=/api/pending_closures8022026/10/06 10:44:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8032026-10-06 10:44:53.861 UTC [453] ERROR: Closure does not exist: id=18042026-10-06 10:44:53.861 UTC [453] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8052026-10-06 10:44:53.861 UTC [453] STATEMENT: -- name: CommitPendingClosure :exec806 SELECT commit_pending_closure($1::bigint)807 808--- PASS: TestService_cleanupPendingClosuresHandler (0.29s)809=== CONT TestReadProxyInvalidPath8102026/10/06 10:44:53 INFO Received push request method=POST path=/api/pushes8112026/10/06 10:44:53 INFO Received complete push request method=POST path=/api/pushes/1/complete812--- PASS: TestReadRedirectKeepsNarinfoProxied (0.33s)813=== CONT TestReadProxy4048142026/10/06 10:44:53 INFO Received push request method=POST path=/api/pushes8152026/10/06 10:44:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete816--- PASS: TestReadRedirectUsesPublicS3URL (0.36s)817=== CONT TestReadProxyNarStreaming8182026/10/06 10:44:53 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"819--- PASS: TestService_AuthMiddleware (0.36s)820=== CONT TestReadProxyContentNegotiation8212026/10/06 10:44:53 INFO Received uploads request method=POST path=/api/pending_closures822--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.38s)823=== CONT TestReadProxyNarinfoAlreadyDecompressed8242026/10/06 10:44:53 INFO Aborted multipart uploads count=0 kept=0825--- PASS: TestService_Rustfstest (0.39s)826=== CONT TestReadProxyNarinfo8272026/10/06 10:44:53 WARN Force mode enabled - objects will be deleted immediately without grace period8282026/10/06 10:44:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=08292026/10/06 10:44:53 INFO Received uploads request method=POST path=/api/pending_closures8302026/10/06 10:44:53 INFO Vacuumed table table=pending_closures8312026/10/06 10:44:53 INFO Vacuumed table table=pending_objects8322026/10/06 10:44:53 INFO Vacuumed table table=multipart_uploads8332026/10/06 10:44:53 INFO Vacuumed table table=closures8342026/10/06 10:44:53 INFO Vacuumed table table=objects8352026/10/06 10:44:54 INFO Received complete push request method=POST path=/api/pushes/2/complete836--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.43s)837=== CONT TestIsValidCachePath838=== RUN TestIsValidCachePath/narinfo839=== PAUSE TestIsValidCachePath/narinfo840=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars841=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars842=== RUN TestIsValidCachePath/nar_zst843=== PAUSE TestIsValidCachePath/nar_zst844=== RUN TestIsValidCachePath/nar_xz845=== PAUSE TestIsValidCachePath/nar_xz846=== RUN TestIsValidCachePath/nar_bz2847=== PAUSE TestIsValidCachePath/nar_bz2848=== RUN TestIsValidCachePath/nar_uncompressed849=== PAUSE TestIsValidCachePath/nar_uncompressed850=== RUN TestIsValidCachePath/ls851=== PAUSE TestIsValidCachePath/ls852=== RUN TestIsValidCachePath/log853=== PAUSE TestIsValidCachePath/log854=== RUN TestIsValidCachePath/realisation855=== PAUSE TestIsValidCachePath/realisation856=== RUN TestIsValidCachePath/nix-cache-info857=== PAUSE TestIsValidCachePath/nix-cache-info858=== RUN TestIsValidCachePath/index.html859=== PAUSE TestIsValidCachePath/index.html860=== RUN TestIsValidCachePath/traversal_parent861=== PAUSE TestIsValidCachePath/traversal_parent862=== RUN TestIsValidCachePath/traversal_in_middle863=== PAUSE TestIsValidCachePath/traversal_in_middle864=== RUN TestIsValidCachePath/invalid_char_e865=== PAUSE TestIsValidCachePath/invalid_char_e866=== RUN TestIsValidCachePath/invalid_char_u867=== PAUSE TestIsValidCachePath/invalid_char_u868=== RUN TestIsValidCachePath/random_path869=== PAUSE TestIsValidCachePath/random_path870=== RUN TestIsValidCachePath/empty871=== PAUSE TestIsValidCachePath/empty872=== RUN TestIsValidCachePath/leading_slash873=== PAUSE TestIsValidCachePath/leading_slash874=== RUN TestIsValidCachePath/wrong_extension875=== PAUSE TestIsValidCachePath/wrong_extension876=== RUN TestIsValidCachePath/short_hash877=== PAUSE TestIsValidCachePath/short_hash878=== CONT TestProxyHeadersOnlyTrustedOnSocket8792026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures8802026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures8812026/10/06 10:44:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8822026/10/06 10:44:54 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTI3YzdlYjItOTViZC00NGYwLTliMDYtYTViNzgyMmIyMGFlLjdkM2VkZmRlLWQ3ZGMtNDk4YS04NWFiLTRmZjIzNTY4NTQ0ZngxNzkxMjgzNDk0MDE0MTkyNjY08832026/10/06 10:44:54 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8842026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures8852026/10/06 10:44:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTI3YzdlYjItOTViZC00NGYwLTliMDYtYTViNzgyMmIyMGFlLjdkM2VkZmRlLWQ3ZGMtNDk4YS04NWFiLTRmZjIzNTY4NTQ0ZngxNzkxMjgzNDk0MDE0MTkyNjY0 parts=1886--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.47s)887=== CONT TestParseSingleRange888=== RUN TestParseSingleRange/none889=== PAUSE TestParseSingleRange/none890=== RUN TestParseSingleRange/unknown_unit891=== PAUSE TestParseSingleRange/unknown_unit892=== RUN TestParseSingleRange/multi-range_ignored893=== PAUSE TestParseSingleRange/multi-range_ignored894=== RUN TestParseSingleRange/malformed_no_dash895=== PAUSE TestParseSingleRange/malformed_no_dash896=== RUN TestParseSingleRange/malformed_both_empty897=== PAUSE TestParseSingleRange/malformed_both_empty898=== RUN TestParseSingleRange/malformed_end_before_start899=== PAUSE TestParseSingleRange/malformed_end_before_start900--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.47s)901=== CONT TestPresentNotReportedWhileGCDeletesClosure902=== RUN TestParseSingleRange/closed903=== PAUSE TestParseSingleRange/closed904=== RUN TestParseSingleRange/open-ended905=== PAUSE TestParseSingleRange/open-ended906=== RUN TestParseSingleRange/end_clamped_to_size907=== PAUSE TestParseSingleRange/end_clamped_to_size908=== RUN TestParseSingleRange/suffix909=== PAUSE TestParseSingleRange/suffix910=== RUN TestParseSingleRange/suffix_exceeds_size911=== PAUSE TestParseSingleRange/suffix_exceeds_size912=== RUN TestParseSingleRange/single_byte913=== PAUSE TestParseSingleRange/single_byte914=== RUN TestParseSingleRange/start_past_EOF915=== PAUSE TestParseSingleRange/start_past_EOF916=== RUN TestParseSingleRange/start_far_past_EOF917=== PAUSE TestParseSingleRange/start_far_past_EOF918=== CONT TestPresentReportsOnlyClosureRoots9192026/10/06 10:44:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9202026/10/06 10:44:54 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst921--- PASS: TestCompleteMultipartUnregistered (0.47s)922=== CONT TestCreatePin_ReservedPins9232026/10/06 10:44:54 INFO Received push request method=POST path=/api/pushes9242026/10/06 10:44:54 INFO Received complete push request method=POST path=/api/pushes/1/complete925--- PASS: TestPush_CompleteCommitsEveryRoot (0.53s)926=== CONT TestOrphanedObjectsGCStressTest927--- PASS: TestReadProxyRangeRequest (0.53s)928=== CONT TestOrphanedObjectsGC929--- PASS: TestReadProxyConditionalGet (0.55s)930=== CONT TestObjectStatsTrigger931--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.56s)932=== CONT TestPendingCleanupUsesOneCutoff9332026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures9342026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures9352026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures9362026/10/06 10:44:54 INFO Received push request method=POST path=/api/pushes9372026/10/06 10:44:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9382026/10/06 10:44:54 INFO Signed narinfos id=1 count=19392026/10/06 10:44:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9402026/10/06 10:44:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9412026/10/06 10:44:54 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9422026/10/06 10:44:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9432026/10/06 10:44:54 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9442026/10/06 10:44:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9452026/10/06 10:44:54 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19462026/10/06 10:44:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9472026/10/06 10:44:54 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo948--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.62s)949=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded950--- PASS: TestReadRedirectNar (0.63s)951=== CONT TestMultipartCleanup9522026/10/06 10:44:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44203/oidc9532026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures9542026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures9552026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures956--- PASS: TestReadProxyDisabled (0.68s)957=== CONT TestServerTLSConfig958=== RUN TestServerTLSConfig/no_client_CA959=== PAUSE TestServerTLSConfig/no_client_CA960=== RUN TestServerTLSConfig/missing_CA_file961=== PAUSE TestServerTLSConfig/missing_CA_file962=== RUN TestServerTLSConfig/not_a_PEM_file963=== PAUSE TestServerTLSConfig/not_a_PEM_file964=== CONT TestService_NativeMTLS9652026/10/06 10:44:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete966--- PASS: TestReadProxyHead (0.47s)967=== CONT TestMetricsInventory9682026/10/06 10:44:54 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MTI3YzdlYjItOTViZC00NGYwLTliMDYtYTViNzgyMmIyMGFlLjVmYTE3MTdiLTQ0MzUtNDE1OS1hNjk4LTExMDg3Y2RhZTBkNXgxNzkxMjgzNDkzOTk1Mjg4MzU2 parts=109692026/10/06 10:44:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9702026/10/06 10:44:54 INFO Completed upload id=19712026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures972--- PASS: TestReadProxyInvalidPath (0.46s)973=== CONT TestNARDeduplicationMetadataUploadBug9742026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures9752026/10/06 10:44:54 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9762026/10/06 10:44:54 WARN Found objects in DB but missing from S3, will re-upload count=1977--- PASS: TestService_verifyS3Integrity (0.75s)978=== CONT TestCreatePendingClosureRejectsOversizedNAR9792026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures980--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)981=== CONT TestCacheConfigHandlerMaxNarSize982--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)983=== CONT TestGenerateLandingPage984--- PASS: TestGenerateLandingPage (0.00s)985=== CONT TestService_readinessHandler986--- PASS: TestReadProxy404 (0.46s)987=== CONT TestService_healthCheckHandler988--- PASS: TestReadProxyNarStreaming (0.46s)989=== CONT TestGracefulShutdownDrainsInflight9902026/10/06 10:44:54 INFO Starting HTTP server address=127.0.0.1:426199912026/10/06 10:44:54 INFO Shutdown signal received, draining in-flight requests timeout=10s992--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.45s)993=== CONT TestGCTaskStore_Fail994--- PASS: TestGCTaskStore_Fail (0.00s)995=== CONT TestGCTaskStore_PhaseUpdates996--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)997=== CONT TestGCTaskStore_CompletedAllowsNewTask998--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)999=== CONT TestGCTaskStore_GetReturnsLatest1000--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1001=== CONT TestGCTaskStore_GetEmpty1002--- PASS: TestGCTaskStore_GetEmpty (0.00s)1003=== CONT TestGCTaskStore_ConflictDifferentParams1004--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1005=== CONT TestPush_RejectsBadRequests1006--- PASS: TestReadProxyContentNegotiation (0.48s)1007=== CONT TestLeadIncumbentAnnouncesAtOnce10082026/10/06 10:44:54 INFO Starting HTTP server address=127.0.0.1:3936710092026/10/06 10:44:54 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3907438181/001/proxy.sock10102026/10/06 10:44:54 WARN mTLS auth: subject not in bound subjects subject="CN=someone"10112026/10/06 10:44:54 INFO Shutdown signal received, draining in-flight requests timeout=10s1012--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.44s)1013=== CONT TestGCTaskStore_StartNew1014--- PASS: TestGCTaskStore_StartNew (0.00s)1015=== CONT TestGCEndsOnShutdown1016=== RUN TestGCEndsOnShutdown/before_the_run1017=== PAUSE TestGCEndsOnShutdown/before_the_run1018=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1019=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1020=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1021=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1022=== CONT TestCommitRacingPendingCleanupKeepsObjects1023--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1024=== CONT TestPushWaitsForSweepHoldingRow10252026/10/06 10:44:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1026--- PASS: TestPresentReportsOnlyClosureRoots (0.43s)1027=== CONT TestSweepRechecksPendingAfterLocking10282026/10/06 10:44:54 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MTI3YzdlYjItOTViZC00NGYwLTliMDYtYTViNzgyMmIyMGFlLmY1NWYxNzA0LWZmZjctNGQzMy1iODAzLWY3NzIwYWFjNjMzZngxNzkxMjgzNDk0MTY5MDg2NDk4 parts=1010292026/10/06 10:44:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10302026/10/06 10:44:54 INFO Completed upload id=110312026/10/06 10:44:54 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010322026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures10332026/10/06 10:44:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures10342026/10/06 10:44:54 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1035--- PASS: TestReadProxyNarinfo (0.53s)1036=== CONT TestGetExistingObjectsLocksRows10372026/10/06 10:44:54 INFO Aborted multipart uploads count=0 kept=010382026/10/06 10:44:54 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010392026/10/06 10:44:54 INFO Vacuumed table table=pending_closures10402026/10/06 10:44:54 INFO Vacuumed table table=pending_objects10412026/10/06 10:44:54 INFO Vacuumed table table=multipart_uploads10422026/10/06 10:44:54 INFO Vacuumed table table=closures10432026/10/06 10:44:54 INFO Vacuumed table table=objects10442026/10/06 10:44:54 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001045--- PASS: TestService_createPendingClosureHandler (0.97s)1046=== CONT TestRegisterCompletedObjectNeedsPendingRow1047--- PASS: TestObjectStatsTrigger (0.45s)1048=== CONT TestSweepSkipsRowsLockedByPush10492026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures10502026/10/06 10:44:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10512026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures10522026/10/06 10:44:54 INFO Received cleanup request method=DELETE path=/api/pending_closures10532026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures10542026/10/06 10:44:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10552026/10/06 10:44:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MTI3YzdlYjItOTViZC00NGYwLTliMDYtYTViNzgyMmIyMGFlLjAwMzcwYjM5LTA4OGMtNDc2NC1iNmJiLTVlM2Y3ZjJiODg1YngxNzkxMjgzNDk0MjMwNDE5ODYy parts=1210562026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures10572026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures1058--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.42s)1059=== CONT TestFailedS3DeleteKeepsTombstone10602026/10/06 10:44:54 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MTI3YzdlYjItOTViZC00NGYwLTliMDYtYTViNzgyMmIyMGFlLjA0MDUxNDQ3LTM0MDMtNDE5Mi1iNDIzLWUyNTc2ZjMzZDk0ZngxNzkxMjgzNDk0MjU1OTU5NjY5 parts=1210612026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures10622026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures1063--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.05s)1064=== CONT TestForceGCDuringPushOffersSweptObject1065=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1066=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1067=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1068=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1069=== CONT TestPendingClosureWriteTimeout1070=== RUN TestPendingClosureWriteTimeout/empty1071=== PAUSE TestPendingClosureWriteTimeout/empty1072=== RUN TestPendingClosureWriteTimeout/400_objects1073=== PAUSE TestPendingClosureWriteTimeout/400_objects1074=== RUN TestPendingClosureWriteTimeout/670k_objects1075=== PAUSE TestPendingClosureWriteTimeout/670k_objects1076=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1077=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1078=== CONT TestClientIntegration10792026/10/06 10:44:54 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10802026/10/06 10:44:54 WARN Refused reserved pin name=worker-x86_64-linux10812026/10/06 10:44:54 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10822026/10/06 10:44:54 INFO Received create pin request method=POST path=/api/pins/my-app10832026/10/06 10:44:54 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1084--- PASS: TestCreatePin_ReservedPins (0.61s)1085=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10862026/10/06 10:44:54 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10872026/10/06 10:44:54 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1088--- PASS: TestService_NativeMTLS (0.40s)1089=== CONT TestService_ReadScope_PublicByDefault1090--- PASS: TestMetricsInventory (0.39s)1091=== CONT TestLeadElectsOneAndHandsOver10922026/10/06 10:44:54 WARN readiness check failed error="closed pool"1093--- PASS: TestService_readinessHandler (0.39s)1094=== CONT TestGCSweepDeliversEachKeyOnce10952026/10/06 10:44:54 INFO Received cleanup request method=DELETE path=/api/pending_closures10962026/10/06 10:44:54 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket42/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10972026/10/06 10:44:54 INFO Aborted multipart uploads count=0 kept=110982026/10/06 10:44:54 INFO Received cleanup request method=DELETE path=/api/pending_closures1099=== NAME TestNARDeduplicationMetadataUploadBug1100 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2944360378/001/store/phdwvizlhvm8n3ffh7pk0zqm2sky02fm-file1.txt1101--- PASS: TestService_healthCheckHandler (0.38s)1102=== CONT TestClientErrorHandling1103=== RUN TestClientErrorHandling/InvalidStorePath1104=== PAUSE TestClientErrorHandling/InvalidStorePath1105=== RUN TestClientErrorHandling/InvalidAuthToken1106=== PAUSE TestClientErrorHandling/InvalidAuthToken1107=== RUN TestClientErrorHandling/ServerNotAvailable1108=== PAUSE TestClientErrorHandling/ServerNotAvailable1109=== CONT TestConnectWaitsForAPeerMigration11102026/10/06 10:44:54 INFO Aborted multipart uploads count=1 kept=01111--- PASS: TestMultipartCleanup (0.54s)1112=== CONT TestTombstonedObjectOfferedWithoutWaiting1113=== RUN TestPush_RejectsBadRequests/no_roots1114=== PAUSE TestPush_RejectsBadRequests/no_roots1115=== RUN TestPush_RejectsBadRequests/no_objects1116=== PAUSE TestPush_RejectsBadRequests/no_objects1117=== RUN TestPush_RejectsBadRequests/bad_root1118=== PAUSE TestPush_RejectsBadRequests/bad_root1119=== RUN TestPush_RejectsBadRequests/root_not_in_objects1120=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1121=== CONT TestClientCADerivations11222026/10/06 10:44:54 INFO lead: acquired remote=192.0.2.1:123411232026/10/06 10:44:54 INFO lead: released remote=192.0.2.1:12341124--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.38s)1125=== CONT TestResolveDBConnectionString1126=== RUN TestResolveDBConnectionString/flag_wins1127=== PAUSE TestResolveDBConnectionString/flag_wins1128=== RUN TestResolveDBConnectionString/file_when_flag_empty1129=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1130=== RUN TestResolveDBConnectionString/missing_file_is_an_error1131=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1132=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1133=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1134=== RUN TestResolveDBConnectionString/nothing_configured1135=== PAUSE TestResolveDBConnectionString/nothing_configured1136=== CONT TestCacheStatsHandler11372026/10/06 10:44:54 INFO Received push request method=POST path=/api/pushes11382026/10/06 10:44:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11392026/10/06 10:44:54 INFO Uploading phdwvizlhvm8n3ffh7pk0zqm2sky02fm-file1.txt (160B)11402026/10/06 10:44:54 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11412026/10/06 10:44:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11422026/10/06 10:44:54 WARN Failed to register uploaded object key=phdwvizlhvm8n3ffh7pk0zqm2sky02fm.ls error="server returned 404: 404 page not found\n"11432026/10/06 10:44:54 INFO Signed narinfos id=1 count=111442026/10/06 10:44:54 INFO Uploading 1 narinfos11452026/10/06 10:44:54 INFO Received complete push request method=POST path=/api/pushes/1/complete11462026/10/06 10:44:54 WARN Failed to register uploaded object key=phdwvizlhvm8n3ffh7pk0zqm2sky02fm.narinfo error="server returned 404: 404 page not found\n"11472026/10/06 10:44:54 INFO Upload complete. (62ms)1148=== NAME TestNARDeduplicationMetadataUploadBug1149 metadata_upload_test.go:54: Retrieved narinfo from S3:1150 StorePath: /build/TestNARDeduplicationMetadataUploadBug2944360378/001/store/phdwvizlhvm8n3ffh7pk0zqm2sky02fm-file1.txt1151 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1152 Compression: zstd1153 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1154 NarSize: 1601155 References: 1156 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1157 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1158 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1159 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11602026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures11612026/10/06 10:44:54 INFO Aborted multipart uploads count=0 kept=011622026/10/06 10:44:54 WARN Force mode enabled - objects will be deleted immediately without grace period11632026/10/06 10:44:54 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01164=== NAME TestOrphanedObjectsGC1165 orphaned_objects_gc_test.go:290: GC Test Summary:1166 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1167 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1168 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1169 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1170 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1171--- PASS: TestOrphanedObjectsGC (0.76s)1172=== CONT TestGCSweepSkipsPendingObjects11732026/10/06 10:44:54 INFO Vacuumed table table=pending_closures11742026/10/06 10:44:54 INFO Vacuumed table table=pending_objects11752026/10/06 10:44:54 INFO Vacuumed table table=multipart_uploads11762026/10/06 10:44:54 INFO Vacuumed table table=closures11772026/10/06 10:44:54 INFO Vacuumed table table=objects1178--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.43s)1179=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1180=== NAME TestNARDeduplicationMetadataUploadBug1181 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2944360378/001/store/d4gd7763dqxn778426vrmhchpzknbwvx-file2.txt11822026/10/06 10:44:54 INFO Aborted multipart uploads count=0 kept=011832026/10/06 10:44:54 WARN Force mode enabled - objects will be deleted immediately without grace period1184--- PASS: TestGetExistingObjectsLocksRows (0.40s)1185=== CONT TestCacheConfigHandler1186=== RUN TestCacheConfigHandler/full_config,_no_issuer1187=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1188=== RUN TestCacheConfigHandler/no_cache_url_configured1189=== PAUSE TestCacheConfigHandler/no_cache_url_configured1190=== RUN TestCacheConfigHandler/no_signing_keys1191=== PAUSE TestCacheConfigHandler/no_signing_keys1192=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1193=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1194=== CONT TestDeduplicatedObjectsRecordedAsPending11952026/10/06 10:44:54 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011962026/10/06 10:44:54 INFO Vacuumed table table=pending_closures1197--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.37s)1198=== CONT TestClientFallsBackToClosures11992026/10/06 10:44:54 INFO Vacuumed table table=pending_objects12002026/10/06 10:44:54 INFO Vacuumed table table=multipart_uploads12012026/10/06 10:44:54 INFO Vacuumed table table=closures12022026/10/06 10:44:54 INFO Vacuumed table table=objects1203--- PASS: TestSweepRechecksPendingAfterLocking (0.44s)1204=== CONT TestGCAdvisoryLockBlocksConcurrentRun12052026/10/06 10:44:54 INFO Received push request method=POST path=/api/pushes12062026/10/06 10:44:54 INFO Aborted multipart uploads count=0 kept=012072026/10/06 10:44:54 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12082026/10/06 10:44:54 INFO Received uploads request method=POST path=/api/pending_closures12092026/10/06 10:44:54 WARN Force mode enabled - objects will be deleted immediately without grace period12102026/10/06 10:44:54 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12112026/10/06 10:44:54 INFO Signed narinfos id=2 count=112122026/10/06 10:44:54 WARN Failed to register uploaded object key=d4gd7763dqxn778426vrmhchpzknbwvx.ls error="server returned 404: 404 page not found\n"12132026/10/06 10:44:54 INFO Uploading 1 narinfos12142026/10/06 10:44:54 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012152026/10/06 10:44:54 INFO Vacuumed table table=pending_closures12162026/10/06 10:44:54 INFO Vacuumed table table=pending_objects12172026/10/06 10:44:54 INFO Vacuumed table table=multipart_uploads12182026/10/06 10:44:54 INFO Vacuumed table table=closures12192026/10/06 10:44:54 INFO Received complete push request method=POST path=/api/pushes/2/complete12202026/10/06 10:44:54 WARN Failed to register uploaded object key=d4gd7763dqxn778426vrmhchpzknbwvx.narinfo error="server returned 404: 404 page not found\n"12212026/10/06 10:44:54 INFO Vacuumed table table=objects12222026/10/06 10:44:54 INFO Upload complete. (58ms)1223=== NAME TestNARDeduplicationMetadataUploadBug1224 metadata_upload_test.go:76: Retrieved narinfo from S3:1225 StorePath: /build/TestNARDeduplicationMetadataUploadBug2944360378/001/store/d4gd7763dqxn778426vrmhchpzknbwvx-file2.txt1226 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1227 Compression: zstd1228 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1229 NarSize: 1601230 References: 1231 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12322026/10/06 10:44:54 INFO Aborted multipart uploads count=0 kept=01233 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1234 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1235 {"version":1,"root":{"type":"regular","size":44}}12362026/10/06 10:44:54 WARN Force mode enabled - objects will be deleted immediately without grace period12372026/10/06 10:44:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1238--- PASS: TestNARDeduplicationMetadataUploadBug (0.66s)1239=== CONT TestClientPushesUseOnePush12402026/10/06 10:44:54 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=012412026/10/06 10:44:54 INFO Vacuumed table table=pending_closures12422026/10/06 10:44:54 INFO Vacuumed table table=pending_objects12432026/10/06 10:44:54 INFO Vacuumed table table=multipart_uploads12442026/10/06 10:44:54 INFO Vacuumed table table=closures12452026/10/06 10:44:54 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MTI3YzdlYjItOTViZC00NGYwLTliMDYtYTViNzgyMmIyMGFlLjE5ZWRiNWNmLTNhZWQtNDNhNi1hMzIxLWJlMTFjMmM5NGYzYngxNzkxMjgzNDk0NjE1NjA1Mjgw error="Get \"http://127.0.0.1:1/bucket23/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12462026/10/06 10:44:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MTI3YzdlYjItOTViZC00NGYwLTliMDYtYTViNzgyMmIyMGFlLmZiY2ZiYTE4LTdmMDItNGIwMy05NDA3LTkzNGZhMjI0NWY4MXgxNzkxMjgzNDk0NjEwNDkzNTM0 parts=1212472026/10/06 10:44:54 INFO Vacuumed table table=objects12482026/10/06 10:44:54 INFO Received cleanup request method=DELETE path=/api/pending_closures1249--- PASS: TestSweepSkipsRowsLockedByPush (0.42s)1250=== CONT TestLeadEndsOnShutdown12512026/10/06 10:44:54 INFO Aborted multipart uploads count=1 kept=01252--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.95s)1253=== CONT TestGCBugBareHashReferences12542026/10/06 10:44:55 INFO Received uploads request method=POST path=/api/pending_closures1255--- PASS: TestRedundantMultipartUpload (1.42s)1256=== CONT TestClientSharedPathCommittedMidPush1257--- PASS: TestService_ReadScope_PublicByDefault (0.35s)1258=== CONT TestPushDedupSurvivesConcurrentGC1259=== NAME TestClientIntegration1260 client_integration_test.go:286: Created store path: /build/TestClientIntegration2501828098/002/store/8b2vp8kdbpnj8dv22h08q0gbdr71hjwk-test-file.txt12612026/10/06 10:44:55 INFO Aborted multipart uploads count=0 kept=012622026/10/06 10:44:55 WARN Force mode enabled - objects will be deleted immediately without grace period12632026/10/06 10:44:55 INFO lead: acquired remote=192.0.2.1:123412642026/10/06 10:44:55 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12652026/10/06 10:44:55 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1266--- PASS: TestFailedS3DeleteKeepsTombstone (0.44s)1267=== CONT TestPinProtectsFromGC12682026/10/06 10:44:55 INFO Received uploads request method=POST path=/api/pending_closures12692026/10/06 10:44:55 INFO Aborted multipart uploads count=0 kept=012702026/10/06 10:44:55 INFO Received push request method=POST path=/api/pushes12712026/10/06 10:44:55 WARN Force mode enabled - objects will be deleted immediately without grace period1272--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.34s)1273=== CONT TestClientWithDependencies12742026/10/06 10:44:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12752026/10/06 10:44:55 INFO Uploading 8b2vp8kdbpnj8dv22h08q0gbdr71hjwk-test-file.txt (152B)12762026/10/06 10:44:55 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12772026/10/06 10:44:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12782026/10/06 10:44:55 WARN Failed to register uploaded object key=8b2vp8kdbpnj8dv22h08q0gbdr71hjwk.ls error="server returned 404: 404 page not found\n"12792026/10/06 10:44:55 INFO Signed narinfos id=1 count=112802026/10/06 10:44:55 INFO Uploading 1 narinfos12812026/10/06 10:44:55 INFO Received complete push request method=POST path=/api/pushes/1/complete12822026/10/06 10:44:55 WARN Failed to register uploaded object key=8b2vp8kdbpnj8dv22h08q0gbdr71hjwk.narinfo error="server returned 404: 404 page not found\n"12832026/10/06 10:44:55 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=012842026/10/06 10:44:55 INFO Vacuumed table table=pending_closures12852026/10/06 10:44:55 INFO Vacuumed table table=pending_objects12862026/10/06 10:44:55 INFO Vacuumed table table=multipart_uploads12872026/10/06 10:44:55 INFO Vacuumed table table=closures12882026/10/06 10:44:55 INFO Upload complete. (56ms)12892026/10/06 10:44:55 INFO Vacuumed table table=objects1290--- PASS: TestGCSweepDeliversEachKeyOnce (0.39s)1291=== CONT TestClientMultipleUploads1292--- PASS: TestCacheStatsHandler (0.34s)1293=== CONT TestService_ReadAuthMiddleware12942026/10/06 10:44:55 INFO All 1 paths already cached1295=== NAME TestClientIntegration1296 client_integration_test.go:312: Retrieved narinfo from S3:1297 StorePath: /build/TestClientIntegration2501828098/002/store/8b2vp8kdbpnj8dv22h08q0gbdr71hjwk-test-file.txt1298 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1299 Compression: zstd1300 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11301 NarSize: 1521302 References: 1303 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11304 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1305 client_integration_test.go:313: Decompressed .ls content (64 bytes):1306 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1307 client_integration_test.go:316: Testing garbage collection...13082026/10/06 10:44:55 INFO Received uploads request method=POST path=/api/pending_closures13092026/10/06 10:44:55 INFO Aborted multipart uploads count=0 kept=013102026/10/06 10:44:55 WARN Force mode enabled - objects will be deleted immediately without grace period13112026/10/06 10:44:55 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=013122026/10/06 10:44:55 INFO Vacuumed table table=pending_closures13132026/10/06 10:44:55 INFO Vacuumed table table=pending_objects13142026/10/06 10:44:55 INFO Vacuumed table table=multipart_uploads13152026/10/06 10:44:55 INFO Vacuumed table table=closures13162026/10/06 10:44:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures13172026/10/06 10:44:55 INFO Garbage collection started13182026/10/06 10:44:55 INFO Vacuumed table table=objects1319--- PASS: TestGCSweepSkipsPendingObjects (0.32s)1320=== CONT TestService_RequireScope_OIDC13212026/10/06 10:44:55 INFO Aborted multipart uploads count=0 kept=013222026/10/06 10:44:55 INFO Received uploads request method=POST path=/api/pending_closures1323=== NAME TestClientCADerivations1324 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2579318598/001/store/4qwx2ahrqrzvglgvrfz8p05ygjsdywm2-ca-test13252026/10/06 10:44:55 WARN Force mode enabled - objects will be deleted immediately without grace period1326--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.29s)1327=== CONT TestService_AuthMiddleware_OIDC13282026/10/06 10:44:55 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=01329--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.55s)1330=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13312026/10/06 10:44:55 INFO Vacuumed table table=pending_closures13322026/10/06 10:44:55 INFO Vacuumed table table=pending_objects13332026/10/06 10:44:55 INFO Vacuumed table table=multipart_uploads13342026/10/06 10:44:55 INFO Vacuumed table table=closures13352026/10/06 10:44:55 INFO Vacuumed table table=objects1336=== NAME TestClientCADerivations1337 client_ca_test.go:139: Found 1 dependencies (including self)13382026/10/06 10:44:55 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"1339--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.31s)1340=== CONT TestService_AuthMiddleware_MTLSProxyHeader13412026/10/06 10:44:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39835/oidc13422026/10/06 10:44:55 INFO lead: acquired remote=192.0.2.1:123413432026/10/06 10:44:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34151/oidc13442026/10/06 10:44:55 INFO Received push request method=POST path=/api/pushes13452026/10/06 10:44:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13462026/10/06 10:44:55 INFO Uploading 4qwx2ahrqrzvglgvrfz8p05ygjsdywm2-ca-test (144B)13472026/10/06 10:44:55 WARN Failed to register uploaded object key=4qwx2ahrqrzvglgvrfz8p05ygjsdywm2.ls error="server returned 404: 404 page not found\n"13482026/10/06 10:44:55 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13492026/10/06 10:44:55 WARN Failed to register uploaded object key=log/1idib2hxd7r5nil2ryb8adxi03sc498s-ca-test.drv error="server returned 404: 404 page not found\n"13502026/10/06 10:44:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13512026/10/06 10:44:55 INFO Signed narinfos id=1 count=113522026/10/06 10:44:55 INFO Uploading 1 narinfos13532026/10/06 10:44:55 INFO Received complete push request method=POST path=/api/pushes/1/complete13542026/10/06 10:44:55 WARN Failed to register uploaded object key=4qwx2ahrqrzvglgvrfz8p05ygjsdywm2.narinfo error="server returned 404: 404 page not found\n"13552026/10/06 10:44:55 INFO Received uploads request method=POST path=/api/pending_closures13562026/10/06 10:44:55 INFO Upload complete. (88ms)1357=== NAME TestClientCADerivations1358 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2579318598/001/store/4qwx2ahrqrzvglgvrfz8p05ygjsdywm2-ca-test1359 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1360 Compression: zstd1361 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1362 NarSize: 1441363 References: 1364 Deriver: /build/TestClientCADerivations2579318598/001/store/1idib2hxd7r5nil2ryb8adxi03sc498s-ca-test.drv1365 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1366 client_ca_test.go:185: Checking for realisation files in S3...1367 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1368 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1369--- PASS: TestPushWaitsForSweepHoldingRow (0.90s)1370=== CONT TestGCMetrics13712026/10/06 10:44:55 INFO Received uploads request method=POST path=/api/pending_closures13722026/10/06 10:44:55 INFO Received uploads request method=POST path=/api/pending_closures13732026/10/06 10:44:55 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13742026/10/06 10:44:55 INFO Uploading 6mxmhr9m0vx7qpcnmv8k3krbalzcgh8v-shared-dep (136B)13752026/10/06 10:44:55 INFO Uploading 5pzvgibnnpqkbzznvw4rwc05hp5rqa9y-b (216B)13762026/10/06 10:44:55 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13772026/10/06 10:44:55 WARN Failed to register uploaded object key=nar/0wqy2bbspgrv5smsalkzpddzxggbmv04ga4ckgmrzwybbmiq520q.nar.zst error="server returned 404: 404 page not found\n"13782026/10/06 10:44:55 WARN Failed to register uploaded object key=6mxmhr9m0vx7qpcnmv8k3krbalzcgh8v.ls error="server returned 404: 404 page not found\n"13792026/10/06 10:44:55 WARN Failed to register uploaded object key=5pzvgibnnpqkbzznvw4rwc05hp5rqa9y.ls error="server returned 404: 404 page not found\n"13802026/10/06 10:44:55 WARN Failed to register uploaded object key=5pj63kxf9hlh13p5sh4fsg0gfgvw15dw.ls error="server returned 404: 404 page not found\n"13812026/10/06 10:44:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13822026/10/06 10:44:55 INFO Signed narinfos id=1 count=213832026/10/06 10:44:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13842026/10/06 10:44:55 INFO Signed narinfos id=2 count=213852026/10/06 10:44:55 INFO Uploading 4 narinfos13862026/10/06 10:44:55 WARN Failed to register uploaded object key=6mxmhr9m0vx7qpcnmv8k3krbalzcgh8v.narinfo error="server returned 404: 404 page not found\n"13872026/10/06 10:44:55 WARN Failed to register uploaded object key=5pj63kxf9hlh13p5sh4fsg0gfgvw15dw.narinfo error="server returned 404: 404 page not found\n"13882026/10/06 10:44:55 WARN Failed to register uploaded object key=5pzvgibnnpqkbzznvw4rwc05hp5rqa9y.narinfo error="server returned 404: 404 page not found\n"13892026/10/06 10:44:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13902026/10/06 10:44:55 WARN Failed to register uploaded object key=6mxmhr9m0vx7qpcnmv8k3krbalzcgh8v.narinfo error="server returned 404: 404 page not found\n"1391--- PASS: TestService_ReadAuthMiddleware (0.27s)1392=== CONT TestProxyWriteTimeout/narinfo1393=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info13942026/10/06 10:44:55 INFO Received uploads request method=POST path=/1395=== CONT TestProxyWriteTimeout/unknown_size1396=== CONT TestProxyWriteTimeout/10_GiB_nar1397=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key13982026/10/06 10:44:55 INFO Received complete multipart upload request method=POST path=/1399=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14002026/10/06 10:44:55 INFO Received request for more parts method=POST path=/1401=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14022026/10/06 10:44:55 INFO Received uploads request method=POST path=/1403--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1404 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1405 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1406 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1407 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1408=== CONT TestProxyWriteTimeout/1_GiB_nar1409--- PASS: TestProxyWriteTimeout (0.00s)1410 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1411 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1412 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1413 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1414=== CONT TestIsValidUploadKey/narinfo1415=== CONT TestIsValidUploadKey/realisation_plus_in_output1416=== CONT TestIsValidUploadKey/unknown_type1417=== CONT TestIsValidUploadKey/empty_key1418=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1419=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1420=== CONT TestIsValidUploadKey/index.html1421=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1422=== CONT TestIsValidUploadKey/nix-cache-info1423=== CONT TestIsValidUploadKey/absolute1424=== CONT TestIsValidUploadKey/traversal_nar1425=== CONT TestIsValidUploadKey/traversal1426=== CONT TestIsValidUploadKey/build_log_home-manager_file1427=== CONT TestIsValidUploadKey/nar_plain1428=== CONT TestIsValidUploadKey/build_log_question_mark1429=== CONT TestIsValidUploadKey/build_log1430=== CONT TestIsValidUploadKey/build_log_plus_in_name1431=== CONT TestIsValidUploadKey/listing1432=== CONT TestIsValidUploadKey/build_log_equals1433=== CONT TestIsValidUploadKey/realisation1434=== CONT TestIsValidUploadKey/nar_xz1435=== CONT TestIsValidUploadKey/nar_zst1436=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14372026/10/06 10:44:55 INFO Received uploads request method=POST path=/1438--- PASS: TestIsValidUploadKey (0.00s)1439 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1440 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1441 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1442 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1443 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1444 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1445 --- PASS: TestIsValidUploadKey/index.html (0.00s)1446 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1447 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1448 --- PASS: TestIsValidUploadKey/absolute (0.00s)1449 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1450 --- PASS: TestIsValidUploadKey/traversal (0.00s)1451 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1452 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1453 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1454 --- PASS: TestIsValidUploadKey/build_log (0.00s)1455 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1456 --- PASS: TestIsValidUploadKey/listing (0.00s)1457 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1458 --- PASS: TestIsValidUploadKey/realisation (0.00s)1459 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1460 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)14612026/10/06 10:44:55 INFO Completed upload id=114622026/10/06 10:44:55 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14632026/10/06 10:44:55 INFO Completed upload id=214642026/10/06 10:44:55 INFO Upload complete. (59ms)14652026/10/06 10:44:55 INFO Aborted multipart uploads count=0 kept=01466=== NAME TestClientFallsBackToClosures1467 client_pushes_test.go:112: Retrieved narinfo from S3:1468 StorePath: /build/TestClientFallsBackToClosures2271348129/001/store/6mxmhr9m0vx7qpcnmv8k3krbalzcgh8v-shared-dep1469 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1470 Compression: zstd1471 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821472 NarSize: 1361473 References: 1474 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1475 client_pushes_test.go:112: Retrieved narinfo from S3:1476 StorePath: /build/TestClientFallsBackToClosures2271348129/001/store/5pj63kxf9hlh13p5sh4fsg0gfgvw15dw-a1477 URL: nar/0wqy2bbspgrv5smsalkzpddzxggbmv04ga4ckgmrzwybbmiq520q.nar.zst1478 Compression: zstd1479 NarHash: sha256:0wqy2bbspgrv5smsalkzpddzxggbmv04ga4ckgmrzwybbmiq520q1480 NarSize: 2161481 References: /build/TestClientFallsBackToClosures2271348129/001/store/6mxmhr9m0vx7qpcnmv8k3krbalzcgh8v-shared-dep1482 CA: text:sha256:0am64lfl5pzf9fz6lmg8l85jq4ciylvmwh0winziqs5s6zgqskzm1483 client_pushes_test.go:112: Retrieved narinfo from S3:1484 StorePath: /build/TestClientFallsBackToClosures2271348129/001/store/5pzvgibnnpqkbzznvw4rwc05hp5rqa9y-b1485 URL: nar/0wqy2bbspgrv5smsalkzpddzxggbmv04ga4ckgmrzwybbmiq520q.nar.zst1486 Compression: zstd1487 NarHash: sha256:0wqy2bbspgrv5smsalkzpddzxggbmv04ga4ckgmrzwybbmiq520q1488 NarSize: 2161489 References: /build/TestClientFallsBackToClosures2271348129/001/store/6mxmhr9m0vx7qpcnmv8k3krbalzcgh8v-shared-dep1490 CA: text:sha256:0am64lfl5pzf9fz6lmg8l85jq4ciylvmwh0winziqs5s6zgqskzm14912026/10/06 10:44:55 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=014922026/10/06 10:44:55 INFO Received push request method=POST path=/api/pushes1493=== NAME TestPinProtectsFromGC1494 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1727641437/001/store/m794ym1nhf2l0qa11w9jvyl6ba53qjxl-pinned-file.txt1495 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1727641437/001/store/5w2fhz5z369vkazv6ldcr1g9wj300hva-unpinned-file.txt14962026/10/06 10:44:55 INFO Vacuumed table table=pending_closures14972026/10/06 10:44:55 INFO Vacuumed table table=pending_objects1498--- PASS: TestClientFallsBackToClosures (0.51s)1499=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15002026/10/06 10:44:55 INFO Received complete multipart upload request method=POST path=/15012026/10/06 10:44:55 INFO Vacuumed table table=multipart_uploads15022026/10/06 10:44:55 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15032026/10/06 10:44:55 INFO Uploading cyv6q289rpgg9xrk5xz4fim1ngb70bch-shared-dep (136B)15042026/10/06 10:44:55 INFO Uploading zazjy1n62gpbkj22pcjlpwvrnm2zilb4-a (216B)15052026/10/06 10:44:55 INFO Vacuumed table table=closures15062026/10/06 10:44:55 INFO Vacuumed table table=objects1507=== NAME TestClientMultipleUploads1508 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads4219107017/001/store/5yqklpr9ppmn5p79p71pzc6l8h9x0s14-test-file-0.txt15092026/10/06 10:44:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15102026/10/06 10:44:55 WARN mTLS auth: bound subjects configured but subject DN unavailable15112026/10/06 10:44:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1512--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.22s)1513=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15142026/10/06 10:44:55 INFO Received request for more parts method=POST path=/15152026/10/06 10:44:55 WARN Failed to register uploaded object key=nar/0m4bswizb6arpw5xcpdbshx61ii4jybai039wkp833gr6rwz4jpd.nar.zst error="server returned 404: 404 page not found\n"15162026/10/06 10:44:55 WARN Failed to register uploaded object key=cyv6q289rpgg9xrk5xz4fim1ngb70bch.ls error="server returned 404: 404 page not found\n"15172026/10/06 10:44:55 WARN Failed to register uploaded object key=zazjy1n62gpbkj22pcjlpwvrnm2zilb4.ls error="server returned 404: 404 page not found\n"15182026/10/06 10:44:55 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15192026/10/06 10:44:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15202026/10/06 10:44:55 WARN Failed to register uploaded object key=45q8hvmz7ix2picbv99kx0ad4x5qml4n.ls error="server returned 404: 404 page not found\n"15212026/10/06 10:44:55 INFO Signed narinfos id=1 count=315222026/10/06 10:44:55 INFO Uploading 3 narinfos15232026/10/06 10:44:55 INFO Aborted multipart uploads count=0 kept=015242026/10/06 10:44:55 WARN Force mode enabled - objects will be deleted immediately without grace period15252026/10/06 10:44:55 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=015262026/10/06 10:44:55 INFO Vacuumed table table=pending_closures15272026/10/06 10:44:55 WARN Failed to register uploaded object key=zazjy1n62gpbkj22pcjlpwvrnm2zilb4.narinfo error="server returned 404: 404 page not found\n"15282026/10/06 10:44:55 INFO Received complete push request method=POST path=/api/pushes/1/complete15292026/10/06 10:44:55 WARN Failed to register uploaded object key=45q8hvmz7ix2picbv99kx0ad4x5qml4n.narinfo error="server returned 404: 404 page not found\n"15302026/10/06 10:44:55 WARN Failed to register uploaded object key=cyv6q289rpgg9xrk5xz4fim1ngb70bch.narinfo error="server returned 404: 404 page not found\n"15312026/10/06 10:44:55 INFO Vacuumed table table=pending_objects15322026/10/06 10:44:55 INFO Vacuumed table table=multipart_uploads15332026/10/06 10:44:55 INFO Vacuumed table table=closures15342026/10/06 10:44:55 INFO Vacuumed table table=objects1535--- PASS: TestPushDedupSurvivesConcurrentGC (0.42s)1536=== CONT TestIsValidCachePath/narinfo1537=== CONT TestIsValidCachePath/wrong_extension1538=== CONT TestIsValidCachePath/leading_slash1539=== CONT TestIsValidCachePath/empty1540=== CONT TestIsValidCachePath/random_path1541=== CONT TestIsValidCachePath/invalid_char_u1542=== CONT TestIsValidCachePath/invalid_char_e1543=== CONT TestIsValidCachePath/traversal_in_middle1544=== CONT TestIsValidCachePath/traversal_parent1545=== CONT TestIsValidCachePath/index.html1546=== CONT TestIsValidCachePath/nix-cache-info1547=== CONT TestIsValidCachePath/realisation1548=== CONT TestIsValidCachePath/log1549=== CONT TestIsValidCachePath/ls1550=== CONT TestIsValidCachePath/short_hash1551=== CONT TestIsValidCachePath/nar_uncompressed1552=== CONT TestIsValidCachePath/nar_xz1553=== CONT TestIsValidCachePath/nar_zst1554=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1555=== CONT TestIsValidCachePath/nar_bz21556--- PASS: TestIsValidCachePath (0.00s)1557 --- PASS: TestIsValidCachePath/narinfo (0.00s)1558 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1559 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1560 --- PASS: TestIsValidCachePath/empty (0.00s)1561 --- PASS: TestIsValidCachePath/random_path (0.00s)1562 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1563 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1564 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1565 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1566 --- PASS: TestIsValidCachePath/index.html (0.00s)1567 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1568 --- PASS: TestIsValidCachePath/realisation (0.00s)1569 --- PASS: TestIsValidCachePath/log (0.00s)1570 --- PASS: TestIsValidCachePath/ls (0.00s)1571 --- PASS: TestIsValidCachePath/short_hash (0.00s)1572 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1573 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1574 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1575 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1576 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1577=== CONT TestParseSingleRange/none1578=== CONT TestParseSingleRange/suffix_exceeds_size1579=== CONT TestParseSingleRange/suffix1580=== CONT TestParseSingleRange/single_byte1581=== CONT TestParseSingleRange/end_clamped_to_size1582=== CONT TestParseSingleRange/open-ended1583=== CONT TestParseSingleRange/closed1584=== CONT TestParseSingleRange/malformed_end_before_start1585=== CONT TestParseSingleRange/malformed_both_empty1586=== CONT TestParseSingleRange/unknown_unit1587=== CONT TestParseSingleRange/malformed_no_dash1588=== CONT TestParseSingleRange/start_far_past_EOF1589=== CONT TestParseSingleRange/start_past_EOF1590=== CONT TestParseSingleRange/multi-range_ignored1591--- PASS: TestParseSingleRange (0.00s)1592 --- PASS: TestParseSingleRange/none (0.00s)1593 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1594 --- PASS: TestParseSingleRange/suffix (0.00s)1595 --- PASS: TestParseSingleRange/single_byte (0.00s)1596 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1597 --- PASS: TestParseSingleRange/open-ended (0.00s)1598 --- PASS: TestParseSingleRange/closed (0.00s)1599 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1600 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1601 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1602 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1603 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1604 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1605 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1606=== CONT TestServerTLSConfig/no_client_CA1607=== CONT TestServerTLSConfig/missing_CA_file1608=== CONT TestServerTLSConfig/not_a_PEM_file1609--- PASS: TestServerTLSConfig (0.00s)1610 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1611 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1612 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1613=== CONT TestGCEndsOnShutdown/before_the_run16142026/10/06 10:44:55 INFO Upload complete. (61ms)1615=== NAME TestClientPushesUseOnePush1616 client_pushes_test.go:97: Retrieved narinfo from S3:1617 StorePath: /build/TestClientPushesUseOnePush1350942725/001/store/cyv6q289rpgg9xrk5xz4fim1ngb70bch-shared-dep1618 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1619 Compression: zstd1620 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821621 NarSize: 1361622 References: 1623 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1624 client_pushes_test.go:97: Retrieved narinfo from S3:1625 StorePath: /build/TestClientPushesUseOnePush1350942725/001/store/zazjy1n62gpbkj22pcjlpwvrnm2zilb4-a1626 URL: nar/0m4bswizb6arpw5xcpdbshx61ii4jybai039wkp833gr6rwz4jpd.nar.zst1627 Compression: zstd1628 NarHash: sha256:0m4bswizb6arpw5xcpdbshx61ii4jybai039wkp833gr6rwz4jpd1629 NarSize: 2161630 References: /build/TestClientPushesUseOnePush1350942725/001/store/cyv6q289rpgg9xrk5xz4fim1ngb70bch-shared-dep1631 CA: text:sha256:06l31s7822dff1p4i5zy5l597yskwkygvrnlizsd6218r1lxp4di1632--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.21s)1633=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1634=== NAME TestClientPushesUseOnePush1635 client_pushes_test.go:97: Retrieved narinfo from S3:1636 StorePath: /build/TestClientPushesUseOnePush1350942725/001/store/45q8hvmz7ix2picbv99kx0ad4x5qml4n-b1637 URL: nar/0m4bswizb6arpw5xcpdbshx61ii4jybai039wkp833gr6rwz4jpd.nar.zst1638 Compression: zstd1639 NarHash: sha256:0m4bswizb6arpw5xcpdbshx61ii4jybai039wkp833gr6rwz4jpd1640 NarSize: 2161641 References: /build/TestClientPushesUseOnePush1350942725/001/store/cyv6q289rpgg9xrk5xz4fim1ngb70bch-shared-dep1642 CA: text:sha256:06l31s7822dff1p4i5zy5l597yskwkygvrnlizsd6218r1lxp4di1643=== NAME TestClientCADerivations1644 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1645 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1646 error: binary cache 's3://bucket64?endpoint=http://localhost:39781&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2579318598/001/store'1647 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11648=== NAME TestClientWithDependencies1649 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1990545842/001/store/lwi1wfxh53zmabsbly3sxkv0dhmfnlss-test-script1650--- PASS: TestClientPushesUseOnePush (0.47s)1651=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1652--- PASS: TestClientCADerivations (0.69s)1653=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows16542026/10/06 10:44:55 INFO Received push request method=POST path=/api/pushes1655=== NAME TestClientMultipleUploads1656 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads4219107017/001/store/xmkg9kl6r1gzqqya7i0g76gvy14a7gx0-test-file-1.txt16572026/10/06 10:44:55 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16582026/10/06 10:44:55 INFO Uploading qc1achxy975lg5pnm84y2dq1v8h3x19f-shared-dep (136B)16592026/10/06 10:44:55 INFO Uploading xbpnrcp1qyzq9m1lk9b8f107qf60rhbi-top (224B)16602026/10/06 10:44:55 WARN Failed to register uploaded object key=nar/0cwryhqsiwg6k16mzdk6apx4a7hfzhympyh0d94947vcz721fjwv.nar.zst error="server returned 404: 404 page not found\n"16612026/10/06 10:44:55 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16622026/10/06 10:44:55 WARN Failed to register uploaded object key=qc1achxy975lg5pnm84y2dq1v8h3x19f.ls error="server returned 404: 404 page not found\n"16632026/10/06 10:44:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16642026/10/06 10:44:55 WARN Failed to register uploaded object key=xbpnrcp1qyzq9m1lk9b8f107qf60rhbi.ls error="server returned 404: 404 page not found\n"16652026/10/06 10:44:55 INFO Signed narinfos id=1 count=216662026/10/06 10:44:55 INFO Uploading 2 narinfos16672026/10/06 10:44:55 INFO Received complete push request method=POST path=/api/pushes/1/complete16682026/10/06 10:44:55 WARN Failed to register uploaded object key=xbpnrcp1qyzq9m1lk9b8f107qf60rhbi.narinfo error="server returned 404: 404 page not found\n"16692026/10/06 10:44:55 WARN Failed to register uploaded object key=qc1achxy975lg5pnm84y2dq1v8h3x19f.narinfo error="server returned 404: 404 page not found\n"16702026/10/06 10:44:55 INFO Upload complete. (64ms)1671=== NAME TestClientSharedPathCommittedMidPush1672 client_integration_test.go:680: Retrieved narinfo from S3:1673 StorePath: /build/TestClientSharedPathCommittedMidPush1257232395/001/store/qc1achxy975lg5pnm84y2dq1v8h3x19f-shared-dep1674 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1675 Compression: zstd1676 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821677 NarSize: 1361678 References: 1679 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1680 client_integration_test.go:680: Retrieved narinfo from S3:1681 StorePath: /build/TestClientSharedPathCommittedMidPush1257232395/001/store/xbpnrcp1qyzq9m1lk9b8f107qf60rhbi-top1682 URL: nar/0cwryhqsiwg6k16mzdk6apx4a7hfzhympyh0d94947vcz721fjwv.nar.zst1683 Compression: zstd1684 NarHash: sha256:0cwryhqsiwg6k16mzdk6apx4a7hfzhympyh0d94947vcz721fjwv1685 NarSize: 2241686 References: /build/TestClientSharedPathCommittedMidPush1257232395/001/store/qc1achxy975lg5pnm84y2dq1v8h3x19f-shared-dep1687 CA: text:sha256:1q9jdpz8dqr2brl573cbmf7hzcy3y14jdawdc11s7skxpv50fswx1688=== RUN TestService_RequireScope_OIDC/builder_may_write1689=== PAUSE TestService_RequireScope_OIDC/builder_may_write1690=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1691=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1692=== RUN TestService_RequireScope_OIDC/ops_may_admin1693=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1694=== RUN TestService_RequireScope_OIDC/ops_may_not_write1695=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1696=== RUN TestService_RequireScope_OIDC/reader_may_not_write1697=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1698=== RUN TestService_RequireScope_OIDC/static_token_may_admin1699=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1700=== RUN TestService_RequireScope_OIDC/static_token_may_write1701=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1702=== RUN TestService_RequireScope_OIDC/reader_may_read1703=== PAUSE TestService_RequireScope_OIDC/reader_may_read1704=== RUN TestService_RequireScope_OIDC/writer_implies_read1705=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1706=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1707=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1708=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1709=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1710=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1711=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1712=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1713=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1714=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1715=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1716=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1717--- PASS: TestClientSharedPathCommittedMidPush (0.48s)1718=== CONT TestPendingClosureWriteTimeout/empty1719=== CONT TestPendingClosureWriteTimeout/670k_objects1720=== CONT TestPendingClosureWriteTimeout/400_objects1721=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1722=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1723=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1724=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1725=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1726=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1727=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1728=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1729=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1730=== CONT TestClientErrorHandling/InvalidStorePath1731--- PASS: TestGCBugBareHashReferences (0.49s)1732=== CONT TestClientErrorHandling/ServerNotAvailable1733=== NAME TestClientWithDependencies1734 client_integration_test.go:615: Found 1 dependencies (including self)1735=== CONT TestClientErrorHandling/InvalidAuthToken17362026/10/06 10:44:55 INFO Received push request method=POST path=/api/pushes1737=== NAME TestClientMultipleUploads1738 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads4219107017/001/store/ki2jz755ja0r004nnc2mi0w7hf7bgzy3-test-file-2.txt1739=== CONT TestPush_RejectsBadRequests/no_roots17402026/10/06 10:44:55 INFO Received push request method=POST path=/api/pushes1741=== CONT TestPush_RejectsBadRequests/root_not_in_objects17422026/10/06 10:44:55 INFO Received push request method=POST path=/api/pushes1743=== CONT TestPush_RejectsBadRequests/bad_root17442026/10/06 10:44:55 INFO Received push request method=POST path=/api/pushes1745=== CONT TestPush_RejectsBadRequests/no_objects17462026/10/06 10:44:55 INFO Received push request method=POST path=/api/pushes1747=== CONT TestResolveDBConnectionString/flag_wins1748=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1749=== CONT TestResolveDBConnectionString/nothing_configured1750=== CONT TestResolveDBConnectionString/file_when_flag_empty1751--- PASS: TestPush_RejectsBadRequests (0.36s)1752 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1753 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1754 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1755 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1756=== CONT TestResolveDBConnectionString/missing_file_is_an_error1757=== CONT TestCacheConfigHandler/full_config,_no_issuer1758=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1759=== CONT TestCacheConfigHandler/no_signing_keys1760=== CONT TestCacheConfigHandler/no_cache_url_configured1761--- PASS: TestCacheConfigHandler (0.00s)1762 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1763 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1764 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1765 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1766=== CONT TestService_RequireScope_OIDC/builder_may_write1767--- PASS: TestResolveDBConnectionString (0.00s)1768 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1769 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1770 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1771 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1772 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1773=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1774=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read17752026/10/06 10:44:55 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]1776=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1777=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1778=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1779=== CONT TestService_RequireScope_OIDC/writer_implies_read1780=== CONT TestService_RequireScope_OIDC/reader_may_read1781=== CONT TestService_RequireScope_OIDC/static_token_may_write1782=== CONT TestService_RequireScope_OIDC/static_token_may_admin1783=== CONT TestService_RequireScope_OIDC/reader_may_not_write1784=== CONT TestService_RequireScope_OIDC/ops_may_not_write1785=== CONT TestService_RequireScope_OIDC/ops_may_admin1786=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1787=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1788--- PASS: TestService_RequireScope_OIDC (0.29s)1789 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1790 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1791 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1792 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1793 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1794 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1795 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1796 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1797 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1798 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1799 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1800 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1801 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1802 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)18032026/10/06 10:44:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18042026/10/06 10:44:55 INFO Uploading m794ym1nhf2l0qa11w9jvyl6ba53qjxl-pinned-file.txt (128B)1805=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18062026/10/06 10:44:55 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]1807=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1808=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18092026/10/06 10:44:55 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"18102026/10/06 10:44:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18112026/10/06 10:44:55 WARN Failed to register uploaded object key=m794ym1nhf2l0qa11w9jvyl6ba53qjxl.ls error="server returned 404: 404 page not found\n"18122026/10/06 10:44:55 INFO Signed narinfos id=1 count=118132026/10/06 10:44:55 INFO Uploading 1 narinfos18142026/10/06 10:44:55 WARN Authentication failed token_preview=eyJhbGciOi...-_MrKOZRDw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1815--- PASS: TestService_AuthMiddleware_OIDC (0.29s)1816 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1817 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1818 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1819 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)18202026/10/06 10:44:55 INFO Received complete push request method=POST path=/api/pushes/1/complete18212026/10/06 10:44:55 WARN Failed to register uploaded object key=m794ym1nhf2l0qa11w9jvyl6ba53qjxl.narinfo error="server returned 404: 404 page not found\n"18222026/10/06 10:44:55 INFO Aborted multipart uploads count=0 kept=018232026/10/06 10:44:55 INFO Upload complete. (62ms)18242026/10/06 10:44:55 WARN Force mode enabled - objects will be deleted immediately without grace period18252026/10/06 10:44:55 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=018262026/10/06 10:44:55 INFO Vacuumed table table=pending_closures18272026/10/06 10:44:55 INFO Vacuumed table table=pending_objects18282026/10/06 10:44:55 INFO Vacuumed table table=multipart_uploads18292026/10/06 10:44:55 INFO Vacuumed table table=closures18302026/10/06 10:44:55 INFO Vacuumed table table=objects1831--- PASS: TestGCMetrics (0.18s)18322026/10/06 10:44:55 INFO Received push request method=POST path=/api/pushes18332026/10/06 10:44:55 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/present18342026/10/06 10:44:55 INFO Received push request method=POST path=/api/pushes18352026/10/06 10:44:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18362026/10/06 10:44:55 INFO Uploading lwi1wfxh53zmabsbly3sxkv0dhmfnlss-test-script (136B)18372026/10/06 10:44:55 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18382026/10/06 10:44:55 INFO Uploading 5yqklpr9ppmn5p79p71pzc6l8h9x0s14-test-file-0.txt (160B)18392026/10/06 10:44:55 INFO Uploading xmkg9kl6r1gzqqya7i0g76gvy14a7gx0-test-file-1.txt (160B)18402026/10/06 10:44:55 INFO Uploading ki2jz755ja0r004nnc2mi0w7hf7bgzy3-test-file-2.txt (160B)18412026/10/06 10:44:55 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18422026/10/06 10:44:55 WARN Failed to register uploaded object key=log/389j115nyvs5gqb16vx55d1s2l7cq0z3-test-script.drv error="server returned 404: 404 page not found\n"18432026/10/06 10:44:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18442026/10/06 10:44:55 WARN Failed to register uploaded object key=lwi1wfxh53zmabsbly3sxkv0dhmfnlss.ls error="server returned 404: 404 page not found\n"18452026/10/06 10:44:55 INFO Signed narinfos id=1 count=118462026/10/06 10:44:55 WARN Failed to register uploaded object key=ki2jz755ja0r004nnc2mi0w7hf7bgzy3.ls error="server returned 404: 404 page not found\n"18472026/10/06 10:44:55 INFO Uploading 1 narinfos18482026/10/06 10:44:55 WARN Failed to register uploaded object key=xmkg9kl6r1gzqqya7i0g76gvy14a7gx0.ls error="server returned 404: 404 page not found\n"18492026/10/06 10:44:55 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18502026/10/06 10:44:55 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18512026/10/06 10:44:55 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18522026/10/06 10:44:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18532026/10/06 10:44:55 WARN Failed to register uploaded object key=5yqklpr9ppmn5p79p71pzc6l8h9x0s14.ls error="server returned 404: 404 page not found\n"18542026/10/06 10:44:55 INFO Signed narinfos id=1 count=318552026/10/06 10:44:55 INFO Uploading 3 narinfos1856--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.69s)18572026/10/06 10:44:55 INFO Received complete push request method=POST path=/api/pushes/1/complete18582026/10/06 10:44:55 WARN Failed to register uploaded object key=lwi1wfxh53zmabsbly3sxkv0dhmfnlss.narinfo error="server returned 404: 404 page not found\n"18592026/10/06 10:44:55 WARN Failed to register uploaded object key=5yqklpr9ppmn5p79p71pzc6l8h9x0s14.narinfo error="server returned 404: 404 page not found\n"18602026/10/06 10:44:55 WARN Failed to register uploaded object key=ki2jz755ja0r004nnc2mi0w7hf7bgzy3.narinfo error="server returned 404: 404 page not found\n"18612026/10/06 10:44:55 INFO Received complete push request method=POST path=/api/pushes/1/complete18622026/10/06 10:44:55 WARN Failed to register uploaded object key=xmkg9kl6r1gzqqya7i0g76gvy14a7gx0.narinfo error="server returned 404: 404 page not found\n"18632026/10/06 10:44:55 INFO Upload complete. (54ms)18642026/10/06 10:44:55 INFO Upload complete. (56ms)1865=== NAME TestClientMultipleUploads1866 client_integration_test.go:369: Uploaded 3 paths in 82.460992ms1867=== NAME TestClientWithDependencies1868 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1990545842/001/store) requires matching store prefix1869--- PASS: TestClientWithDependencies (0.49s)18702026/10/06 10:44:55 INFO Received push request method=POST path=/api/pushes18712026/10/06 10:44:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18722026/10/06 10:44:55 INFO Uploading 5w2fhz5z369vkazv6ldcr1g9wj300hva-unpinned-file.txt (128B)1873--- PASS: TestClientMultipleUploads (0.47s)18742026/10/06 10:44:55 WARN Failed to register uploaded object key=5w2fhz5z369vkazv6ldcr1g9wj300hva.ls error="server returned 404: 404 page not found\n"18752026/10/06 10:44:55 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18762026/10/06 10:44:55 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18772026/10/06 10:44:55 INFO Signed narinfos id=2 count=118782026/10/06 10:44:55 INFO Uploading 1 narinfos18792026/10/06 10:44:55 INFO Received complete push request method=POST path=/api/pushes/2/complete18802026/10/06 10:44:55 WARN Failed to register uploaded object key=5w2fhz5z369vkazv6ldcr1g9wj300hva.narinfo error="server returned 404: 404 page not found\n"18812026/10/06 10:44:55 INFO Upload complete. (43ms)18822026/10/06 10:44:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures18832026/10/06 10:44:55 INFO Garbage collection started18842026/10/06 10:44:55 INFO Aborted multipart uploads count=0 kept=018852026/10/06 10:44:55 WARN Force mode enabled - objects will be deleted immediately without grace period18862026/10/06 10:44:55 INFO Received uploads request method=POST path=/api/pending_closures18872026/10/06 10:44:55 INFO Aborted multipart uploads count=0 kept=018882026-10-06 10:44:55.642 UTC [1751] ERROR: canceling statement due to user request18892026-10-06 10:44:55.642 UTC [1751] CONTEXT: PL/pgSQL expression "d_count <> 0 OR d_bytes <> 0"1890 PL/pgSQL function object_stats_apply() line 16 at IF18912026-10-06 10:44:55.642 UTC [1751] STATEMENT: -- name: MarkStaleObjects :execrows1892 WITH RECURSIVE ct AS (1893 SELECT timezone('UTC', now()) AS now1894 ),1895 closure_reach AS (1896 -- Start with all closure keys1897 SELECT o.key, o.refs1898 FROM objects o1899 INNER JOIN closures c ON o.key = c.key1900 UNION1901 -- Recursively add all referenced objects1902 SELECT o.key, o.refs1903 FROM objects o1904 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1905 ),1906 reachable_objects AS (1907 SELECT DISTINCT key FROM closure_reach1908 ),1909 stale_objects AS (1910 SELECT o.key1911 FROM objects AS o, ct1912 WHERE1913 NOT EXISTS (1914 SELECT 11915 FROM reachable_objects ro1916 WHERE ro.key = o.key1917 )1918 AND NOT EXISTS (1919 SELECT 11920 FROM pending_objects AS po1921 WHERE po.key = o.key1922 )1923 AND o.deleted_at IS NULL -- Only mark fresh objects1924 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1925 FOR UPDATE1926 )1927 UPDATE objects1928 SET1929 deleted_at = ct.now,1930 first_deleted_at = COALESCE(first_deleted_at, ct.now)1931 FROM stale_objects, ct1932 WHERE objects.key = stale_objects.key1933 19342026/10/06 10:44:55 INFO Aborted multipart uploads count=0 kept=019352026/10/06 10:44:55 WARN Force mode enabled - objects will be deleted immediately without grace period19362026/10/06 10:44:55 WARN Force mode enabled - objects will be deleted immediately without grace period19372026/10/06 10:44:55 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=019382026/10/06 10:44:55 INFO Vacuumed table table=pending_closures19392026/10/06 10:44:55 INFO Vacuumed table table=pending_objects19402026/10/06 10:44:55 INFO Vacuumed table table=multipart_uploads19412026/10/06 10:44:55 INFO Vacuumed table table=closures19422026/10/06 10:44:55 INFO Vacuumed table table=objects19432026/10/06 10:44:55 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=019442026/10/06 10:44:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=207.070507ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19452026/10/06 10:44:55 INFO Aborted multipart uploads count=0 kept=019462026/10/06 10:44:55 INFO Vacuumed table table=pending_closures19472026/10/06 10:44:55 INFO Vacuumed table table=pending_objects19482026/10/06 10:44:55 INFO Vacuumed table table=multipart_uploads19492026/10/06 10:44:55 WARN Force mode enabled - objects will be deleted immediately without grace period19502026/10/06 10:44:55 INFO Vacuumed table table=closures19512026/10/06 10:44:55 INFO Vacuumed table table=objects19522026/10/06 10:44:55 INFO Received uploads request method=POST path=/api/pending_closures19532026/10/06 10:44:55 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:39781/bucket88/?delete=\": context canceled"1954--- PASS: TestGCEndsOnShutdown (0.00s)1955 --- PASS: TestGCEndsOnShutdown/before_the_run (0.16s)1956 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.20s)1957 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.22s)19582026/10/06 10:44:55 INFO Received uploads request method=POST path=/api/pending_closures19592026/10/06 10:44:55 INFO Aborted multipart uploads count=0 kept=019602026/10/06 10:44:55 WARN Force mode enabled - objects will be deleted immediately without grace period19612026/10/06 10:44:55 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=019622026/10/06 10:44:55 INFO Vacuumed table table=pending_closures19632026/10/06 10:44:55 INFO Vacuumed table table=pending_objects19642026/10/06 10:44:55 INFO Vacuumed table table=multipart_uploads19652026/10/06 10:44:55 INFO Vacuumed table table=closures19662026/10/06 10:44:55 INFO Vacuumed table table=objects1967--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1968 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.22s)1969 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.25s)19702026/10/06 10:44:55 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19712026/10/06 10:44:55 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1972=== NAME TestOrphanedObjectsGCStressTest1973 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1974 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19752026/10/06 10:44:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=364.653429ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1976 orphaned_objects_gc_test.go:509: Stress test completed successfully:1977 orphaned_objects_gc_test.go:510: - Active objects preserved: 201978 orphaned_objects_gc_test.go:511: - Objects deleted: 2101979 orphaned_objects_gc_test.go:512: - Total GC'd: 2101980--- PASS: TestOrphanedObjectsGCStressTest (1.96s)19812026/10/06 10:44:56 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=869.430786ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19822026/10/06 10:44:56 INFO lead: released remote=192.0.2.1:123419832026/10/06 10:44:56 INFO lead: acquired remote=192.0.2.1:123419842026/10/06 10:44:56 INFO lead: released remote=192.0.2.1:12341985--- PASS: TestLeadEndsOnShutdown (1.34s)1986--- PASS: TestPendingClosureWriteTimeout (0.00s)1987 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1988 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1989 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1990 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (0.98s)1991--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)1992 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)1993 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)1994 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.09s)19952026/10/06 10:44:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.71138618s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19962026/10/06 10:44:57 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01997=== NAME TestClientIntegration1998 client_integration_test.go:323: Objects in database after GC:1999 client_integration_test.go:323: Successfully deleted all objects with GC --force2000--- PASS: TestClientIntegration (2.56s)20012026/10/06 10:44:57 INFO lead: released remote=192.0.2.1:12342002--- PASS: TestLeadElectsOneAndHandsOver (2.65s)20032026/10/06 10:44:57 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020042026/10/06 10:44:57 INFO Received create pin request method=POST path=/api/pins/myapp20052026/10/06 10:44:57 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1727641437/001/store/m794ym1nhf2l0qa11w9jvyl6ba53qjxl-pinned-file.txt narinfo_key=m794ym1nhf2l0qa11w9jvyl6ba53qjxl.narinfo20062026/10/06 10:44:57 INFO Starting cleanup of old closures method=DELETE path=/api/closures20072026/10/06 10:44:57 INFO Garbage collection started20082026/10/06 10:44:57 INFO Aborted multipart uploads count=0 kept=020092026/10/06 10:44:57 WARN Force mode enabled - objects will be deleted immediately without grace period20102026/10/06 10:44:57 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=020112026/10/06 10:44:57 INFO Vacuumed table table=pending_closures20122026/10/06 10:44:57 INFO Vacuumed table table=pending_objects20132026/10/06 10:44:57 INFO Vacuumed table table=multipart_uploads20142026/10/06 10:44:57 INFO Vacuumed table table=closures20152026/10/06 10:44:57 INFO Vacuumed table table=objects20162026/10/06 10:44:57 WARN Rate limiter enabled after throttle name=s3-test rate=520172026/10/06 10:44:57 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2018=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2019 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102020 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002021--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.31s)2022--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.76s)20232026/10/06 10:44:58 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-config20242026/10/06 10:44:58 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.394705ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20252026/10/06 10:44:59 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=412.521945ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20262026/10/06 10:44:59 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=748.759477ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2027=== NAME TestPinProtectsFromGC2028 client_integration_test.go:840: Pin successfully protected closure from garbage collection2029--- PASS: TestPinProtectsFromGC (4.59s)2030--- PASS: TestConnectWaitsForAPeerMigration (5.13s)20312026/10/06 10:45:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.690510985s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20322026/10/06 10:45:00 INFO Aborted multipart uploads count=1 kept=020332026/10/06 10:45:00 INFO Received cleanup request method=DELETE path=/api/pending_closures20342026/10/06 10:45:00 INFO Aborted multipart uploads count=1 kept=02035--- PASS: TestPendingCleanupUsesOneCutoff (6.47s)20362026/10/06 10:45:02 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"20372026/10/06 10:45:02 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-config20382026/10/06 10:45:02 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.162934ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20392026/10/06 10:45:02 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=362.877939ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20402026/10/06 10:45:02 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=841.347911ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20412026/10/06 10:45:03 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.718068167s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20422026/10/06 10:45:05 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_closures20432026/10/06 10:45:05 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=216.134624ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20442026/10/06 10:45:05 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=396.573152ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20452026/10/06 10:45:05 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=733.849198ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20462026/10/06 10:45:06 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.659266757s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2047--- PASS: TestClientErrorHandling (0.00s)2048 --- PASS: TestClientErrorHandling/InvalidStorePath (0.22s)2049 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.32s)2050 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.84s)2051PASS20522026-10-06 10:45:08.575 UTC [128] LOG: received smart shutdown request20532026-10-06 10:45:08.579 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 120542026-10-06 10:45:08.593 UTC [133] LOG: shutting down20552026-10-06 10:45:08.593 UTC [133] LOG: checkpoint starting: shutdown immediate20562026-10-06 10:45:09.369 UTC [133] LOG: checkpoint complete: wrote 10825 buffers (66.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.178 s, sync=0.567 s, total=0.776 s; sync files=31336, longest=0.002 s, average=0.001 s; distance=433076 kB, estimate=433076 kB; lsn=0/1BE52DB8, redo lsn=0/1BE52DB820572026-10-06 10:45:09.446 UTC [128] LOG: database system is shut down2058Running OIDC tests...2059=== RUN TestAudienceForIssuer2060=== PAUSE TestAudienceForIssuer2061=== RUN TestGlobMatch2062=== PAUSE TestGlobMatch2063=== RUN TestValidateToken_ValidToken2064=== PAUSE TestValidateToken_ValidToken2065=== RUN TestValidateToken_WrongAudience2066=== PAUSE TestValidateToken_WrongAudience2067=== RUN TestValidateToken_Expired2068=== PAUSE TestValidateToken_Expired2069=== RUN TestValidateToken_BoundClaimsMismatch2070=== PAUSE TestValidateToken_BoundClaimsMismatch2071=== RUN TestValidateToken_BoundSubjectMismatch2072=== PAUSE TestValidateToken_BoundSubjectMismatch2073=== RUN TestValidateToken_MultipleProviders2074=== PAUSE TestValidateToken_MultipleProviders2075=== RUN TestValidateToken_NoMatchingProvider2076=== PAUSE TestValidateToken_NoMatchingProvider2077=== RUN TestValidateToken_KubernetesServiceAccount2078=== PAUSE TestValidateToken_KubernetesServiceAccount2079=== RUN TestNewValidator_KubernetesRequiresCA2080=== PAUSE TestNewValidator_KubernetesRequiresCA2081=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2082=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2083=== RUN TestPins_ReservedForMatchingRule2084=== PAUSE TestPins_ReservedForMatchingRule2085=== RUN TestPins_TopLevelShorthand2086=== PAUSE TestPins_TopLevelShorthand2087=== RUN TestPins_ConfigValidation2088=== PAUSE TestPins_ConfigValidation2089=== RUN TestScopes_LegacyProviderDefaultsToWrite2090=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2091=== RUN TestScopes_Rules2092=== PAUSE TestScopes_Rules2093=== RUN TestScopes_ConfigValidation2094=== PAUSE TestScopes_ConfigValidation2095=== CONT TestAudienceForIssuer2096=== CONT TestValidateToken_BoundClaimsMismatch2097=== CONT TestScopes_ConfigValidation2098--- PASS: TestAudienceForIssuer (0.00s)2099=== CONT TestValidateToken_WrongAudience2100=== CONT TestPins_TopLevelShorthand2101=== CONT TestGlobMatch2102=== RUN TestGlobMatch/foo_foo2103=== PAUSE TestGlobMatch/foo_foo2104=== RUN TestGlobMatch/foo_bar2105=== PAUSE TestGlobMatch/foo_bar2106=== RUN TestGlobMatch/*_2107=== PAUSE TestGlobMatch/*_2108=== RUN TestGlobMatch/*_anything2109=== PAUSE TestGlobMatch/*_anything2110=== RUN TestGlobMatch/foo*_foo2111=== PAUSE TestGlobMatch/foo*_foo2112=== RUN TestGlobMatch/foo*_foobar2113=== PAUSE TestGlobMatch/foo*_foobar2114=== RUN TestGlobMatch/foo*_bar2115=== PAUSE TestGlobMatch/foo*_bar2116=== RUN TestGlobMatch/*bar_bar2117=== PAUSE TestGlobMatch/*bar_bar2118=== RUN TestGlobMatch/*bar_foobar2119=== CONT TestValidateToken_KubernetesServiceAccount2120=== CONT TestValidateToken_ValidToken2121=== CONT TestValidateToken_Expired2122--- PASS: TestScopes_ConfigValidation (0.00s)2123=== CONT TestScopes_Rules2124=== CONT TestScopes_LegacyProviderDefaultsToWrite2125=== CONT TestPins_ConfigValidation2126=== CONT TestValidateToken_MultipleProviders2127=== CONT TestValidateToken_NoMatchingProvider2128=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2129--- PASS: TestPins_ConfigValidation (0.00s)2130=== CONT TestPins_ReservedForMatchingRule2131=== CONT TestNewValidator_KubernetesRequiresCA2132=== CONT TestValidateToken_BoundSubjectMismatch2133=== PAUSE TestGlobMatch/*bar_foobar2134=== RUN TestGlobMatch/*bar_foo2135=== PAUSE TestGlobMatch/*bar_foo2136=== RUN TestGlobMatch/foo*bar_foobar2137=== PAUSE TestGlobMatch/foo*bar_foobar2138=== RUN TestGlobMatch/foo*bar_foo123bar2139=== PAUSE TestGlobMatch/foo*bar_foo123bar2140=== RUN TestGlobMatch/foo*bar_foobarbaz2141=== PAUSE TestGlobMatch/foo*bar_foobarbaz2142=== RUN TestGlobMatch/*/*_foo/bar2143=== PAUSE TestGlobMatch/*/*_foo/bar2144=== RUN TestGlobMatch/*/*_foo2145=== PAUSE TestGlobMatch/*/*_foo2146=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2147=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2148=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02149=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02150=== RUN TestGlobMatch/refs/*/main_refs/heads/main2151=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2152=== RUN TestGlobMatch/fo?_foo2153=== PAUSE TestGlobMatch/fo?_foo2154=== RUN TestGlobMatch/fo?_fo2155=== PAUSE TestGlobMatch/fo?_fo2156=== RUN TestGlobMatch/fo?_fooo2157=== PAUSE TestGlobMatch/fo?_fooo2158=== RUN TestGlobMatch/?oo_foo2159=== PAUSE TestGlobMatch/?oo_foo2160=== RUN TestGlobMatch/?oo_boo2161=== PAUSE TestGlobMatch/?oo_boo2162=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2163=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2164=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2165=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2166=== CONT TestGlobMatch/foo_foo2167=== CONT TestGlobMatch/fo?_fooo2168=== CONT TestGlobMatch/fo?_fo2169=== CONT TestGlobMatch/fo?_foo2170=== CONT TestGlobMatch/refs/*/main_refs/heads/main2171=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02172=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2173=== CONT TestGlobMatch/*/*_foo2174=== CONT TestGlobMatch/*/*_foo/bar2175=== CONT TestGlobMatch/foo*bar_foobarbaz2176=== CONT TestGlobMatch/foo*bar_foo123bar2177=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2178=== CONT TestGlobMatch/*_anything2179=== CONT TestGlobMatch/*_2180=== CONT TestGlobMatch/foo_bar2181=== CONT TestGlobMatch/?oo_foo2182=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2183=== CONT TestGlobMatch/foo*bar_foobar2184=== CONT TestGlobMatch/*bar_foo2185=== CONT TestGlobMatch/*bar_foobar2186=== CONT TestGlobMatch/*bar_bar2187=== CONT TestGlobMatch/foo*_bar2188=== CONT TestGlobMatch/foo*_foobar2189=== CONT TestGlobMatch/foo*_foo2190=== CONT TestGlobMatch/?oo_boo2191--- PASS: TestGlobMatch (0.01s)2192 --- PASS: TestGlobMatch/foo_foo (0.00s)2193 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2194 --- PASS: TestGlobMatch/fo?_fo (0.00s)2195 --- PASS: TestGlobMatch/fo?_foo (0.00s)2196 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2197 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2198 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2199 --- PASS: TestGlobMatch/*/*_foo (0.00s)2200 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2201 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2202 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2203 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2204 --- PASS: TestGlobMatch/*_anything (0.00s)2205 --- PASS: TestGlobMatch/*_ (0.00s)2206 --- PASS: TestGlobMatch/foo_bar (0.00s)2207 --- PASS: TestGlobMatch/?oo_foo (0.00s)2208 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2209 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2210 --- PASS: TestGlobMatch/*bar_foo (0.00s)2211 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2212 --- PASS: TestGlobMatch/*bar_bar (0.00s)2213 --- PASS: TestGlobMatch/foo*_bar (0.00s)2214 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2215 --- PASS: TestGlobMatch/foo*_foo (0.00s)2216 --- PASS: TestGlobMatch/?oo_boo (0.00s)22172026/10/06 10:45:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37511/oidc22182026/10/06 10:45:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32905/oidc2219--- PASS: TestPins_TopLevelShorthand (0.04s)2220--- PASS: TestValidateToken_BoundSubjectMismatch (0.04s)22212026/10/06 10:45:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39791/oidc2222--- PASS: TestValidateToken_ValidToken (0.06s)22232026/10/06 10:45:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46317/oidc2224--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.08s)22252026/10/06 10:45:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42211/oidc2226--- PASS: TestValidateToken_Expired (0.09s)22272026/10/06 10:45:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36519/oidc2228--- PASS: TestScopes_Rules (0.11s)22292026/10/06 10:45:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33199/oidc2230--- PASS: TestValidateToken_WrongAudience (0.14s)22312026/10/06 10:45:11 http: TLS handshake error from 127.0.0.1:34966: remote error: tls: bad certificate2232--- PASS: TestNewValidator_KubernetesRequiresCA (0.19s)22332026/10/06 10:45:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33143/oidc22342026/10/06 10:45:11 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:42463/oidc2235--- PASS: TestValidateToken_MultipleProviders (0.25s)22362026/10/06 10:45:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35707/oidc2237--- PASS: TestValidateToken_BoundClaimsMismatch (0.28s)22382026/10/06 10:45:11 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:395392239--- PASS: TestValidateToken_KubernetesServiceAccount (0.31s)22402026/10/06 10:45:11 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232241--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.37s)22422026/10/06 10:45:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39557/oidc2243--- PASS: TestPins_ReservedForMatchingRule (0.40s)22442026/10/06 10:45:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34467/oidc2245--- PASS: TestValidateToken_NoMatchingProvider (0.59s)2246PASS2247Running hook tests...2248=== RUN TestSendPathsEmpty2249=== PAUSE TestSendPathsEmpty2250=== RUN TestQueueEnqueueAndFetch2251=== PAUSE TestQueueEnqueueAndFetch2252=== RUN TestQueueDeduplication2253=== PAUSE TestQueueDeduplication2254=== RUN TestQueueRemove2255=== PAUSE TestQueueRemove2256=== RUN TestQueueFetchBatchLimit2257=== PAUSE TestQueueFetchBatchLimit2258=== RUN TestQueueRetryMovesToBack2259=== PAUSE TestQueueRetryMovesToBack2260=== RUN TestQueueFetchRemoveLifecycle2261=== PAUSE TestQueueFetchRemoveLifecycle2262=== RUN TestQueueConcurrentWriters2263=== PAUSE TestQueueConcurrentWriters2264=== RUN TestQueueRemoveLargeClosure2265=== PAUSE TestQueueRemoveLargeClosure2266=== RUN TestServerClientIntegration2267=== PAUSE TestServerClientIntegration2268=== RUN TestServerQueueError2269=== PAUSE TestServerQueueError2270=== RUN TestGetListenerSocketActivation2271 server_test.go:210: === RUN TestGetListenerSocketActivation2272 --- PASS: TestGetListenerSocketActivation (0.00s)2273 PASS2274 2275--- PASS: TestGetListenerSocketActivation (0.01s)2276=== RUN TestDrainIsolatesPoisonPath2277=== PAUSE TestDrainIsolatesPoisonPath2278=== RUN TestRunNotBlockedByPoisonHead2279=== PAUSE TestRunNotBlockedByPoisonHead2280=== RUN TestDrainGivesUpWhenServerDown2281=== PAUSE TestDrainGivesUpWhenServerDown2282=== RUN TestFailedPathPrunedByLaterClosure2283=== PAUSE TestFailedPathPrunedByLaterClosure2284=== RUN TestWorkerUploadsAndRemoves2285=== PAUSE TestWorkerUploadsAndRemoves2286=== RUN TestWorkerSkipsGCdPaths2287=== PAUSE TestWorkerSkipsGCdPaths2288=== RUN TestWorkerPrunesClosureDeps2289=== PAUSE TestWorkerPrunesClosureDeps2290=== RUN TestDrainTimeout2291=== PAUSE TestDrainTimeout2292=== CONT TestSendPathsEmpty2293=== CONT TestRunNotBlockedByPoisonHead2294=== CONT TestQueueRetryMovesToBack2295--- PASS: TestSendPathsEmpty (0.00s)2296=== CONT TestDrainIsolatesPoisonPath2297=== CONT TestWorkerSkipsGCdPaths2298=== CONT TestServerQueueError2299=== CONT TestDrainTimeout2300=== CONT TestWorkerPrunesClosureDeps2301=== CONT TestServerClientIntegration2302=== CONT TestQueueFetchBatchLimit23032026/10/06 10:45:11 ERROR Failed to queue paths error="permission denied" count=12304=== CONT TestQueueConcurrentWriters2305--- PASS: TestServerQueueError (0.00s)2306=== CONT TestQueueRemove2307=== CONT TestQueueEnqueueAndFetch2308=== CONT TestQueueRemoveLargeClosure2309=== CONT TestQueueFetchRemoveLifecycle2310=== CONT TestQueueDeduplication2311=== CONT TestFailedPathPrunedByLaterClosure2312=== CONT TestDrainGivesUpWhenServerDown2313=== CONT TestWorkerUploadsAndRemoves2314--- PASS: TestServerClientIntegration (0.00s)23152026/10/06 10:45:11 INFO Uploading batch count=123162026/10/06 10:45:11 ERROR Upload failed error="upload failed" count=123172026/10/06 10:45:11 INFO Upload queue status pending=223182026/10/06 10:45:11 INFO Upload queue status pending=223192026/10/06 10:45:11 INFO Uploading batch count=423202026/10/06 10:45:11 ERROR Upload failed error="upload failed" count=423212026/10/06 10:45:11 INFO Uploading batch count=123222026/10/06 10:45:11 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths275087754/002/nonexistent23232026/10/06 10:45:11 INFO Uploading batch count=123242026/10/06 10:45:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2516811967/002/bbb23252026/10/06 10:45:11 INFO Uploading batch count=22326--- PASS: TestQueueFetchBatchLimit (0.01s)23272026/10/06 10:45:11 INFO Uploading batch count=123282026/10/06 10:45:11 INFO Upload queue status pending=223292026/10/06 10:45:11 INFO Uploading batch count=223302026/10/06 10:45:11 ERROR Upload failed error="upload failed" count=223312026/10/06 10:45:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown822809049/002/a23322026/10/06 10:45:11 INFO Uploading batch count=22333--- PASS: TestQueueDeduplication (0.01s)2334--- PASS: TestQueueEnqueueAndFetch (0.01s)23352026/10/06 10:45:11 INFO Uploading batch count=123362026/10/06 10:45:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown822809049/002/b2337--- PASS: TestQueueFetchRemoveLifecycle (0.01s)23382026/10/06 10:45:11 INFO Upload queue status pending=323392026/10/06 10:45:11 INFO Uploading batch count=123402026/10/06 10:45:11 ERROR Upload failed error="upload failed" count=12341--- PASS: TestQueueRetryMovesToBack (0.02s)23422026/10/06 10:45:11 INFO Uploading batch count=223432026/10/06 10:45:11 ERROR Upload failed error="upload failed" count=223442026/10/06 10:45:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown822809049/002/c2345--- PASS: TestQueueRemove (0.01s)23462026/10/06 10:45:11 INFO Uploading batch count=123472026/10/06 10:45:11 ERROR Upload failed error="upload failed" count=123482026/10/06 10:45:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown822809049/002/d23492026/10/06 10:45:11 INFO Uploading batch count=22350--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)23512026/10/06 10:45:11 ERROR Upload failed error="upload failed" count=223522026/10/06 10:45:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown822809049/002/e23532026/10/06 10:45:11 INFO Uploading batch count=123542026/10/06 10:45:11 ERROR Upload failed error="upload failed" count=123552026/10/06 10:45:11 INFO Uploading batch count=123562026/10/06 10:45:11 ERROR Upload failed error="upload failed" count=123572026/10/06 10:45:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown822809049/002/f23582026/10/06 10:45:11 ERROR Drain finished with paths left in queue remaining=123592026/10/06 10:45:11 ERROR Drain finished with paths left in queue remaining=102360--- PASS: TestDrainIsolatesPoisonPath (0.02s)2361--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2362--- PASS: TestWorkerUploadsAndRemoves (0.03s)2363--- PASS: TestWorkerSkipsGCdPaths (0.03s)2364--- PASS: TestWorkerPrunesClosureDeps (0.03s)2365--- PASS: TestQueueRemoveLargeClosure (0.10s)2366--- PASS: TestQueueConcurrentWriters (0.13s)23672026/10/06 10:45:11 ERROR Upload failed error="context deadline exceeded" count=223682026/10/06 10:45:11 ERROR Drain finished with paths left in queue remaining=42369--- PASS: TestDrainTimeout (0.21s)23702026/10/06 10:45:12 INFO Uploading batch count=123712026/10/06 10:45:12 INFO Uploading batch count=123722026/10/06 10:45:12 INFO Uploading batch count=123732026/10/06 10:45:12 ERROR Upload failed error="upload failed" count=123742026/10/06 10:45:12 INFO Uploading batch count=123752026/10/06 10:45:12 ERROR Upload failed error="upload failed" count=123762026/10/06 10:45:12 INFO Uploading batch count=123772026/10/06 10:45:12 ERROR Upload failed error="upload failed" count=123782026/10/06 10:45:12 INFO Uploading batch count=123792026/10/06 10:45:12 ERROR Upload failed error="upload failed" count=123802026/10/06 10:45:12 ERROR Drain finished with paths left in queue remaining=12381--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2382PASS2383Running signing tests...2384=== RUN TestExternalSigner2385=== PAUSE TestExternalSigner2386=== RUN TestExternalSignerWrongPublicKey2387=== PAUSE TestExternalSignerWrongPublicKey2388=== RUN TestExternalSignerErrors2389=== PAUSE TestExternalSignerErrors2390=== RUN TestExternalSignerRestartsAfterCrash2391=== PAUSE TestExternalSignerRestartsAfterCrash2392=== RUN TestExternalSignerProgramErrorKeepsProcess2393=== PAUSE TestExternalSignerProgramErrorKeepsProcess2394=== RUN TestExternalSignerClose2395=== PAUSE TestExternalSignerClose2396=== RUN TestExternalSignerRejectsInvalidPublicKey2397=== PAUSE TestExternalSignerRejectsInvalidPublicKey2398=== RUN TestExternalSignerCancellation2399=== PAUSE TestExternalSignerCancellation2400=== RUN TestGenerateFingerprint2401=== PAUSE TestGenerateFingerprint2402=== RUN TestParseSigningKey2403=== PAUSE TestParseSigningKey2404=== RUN TestSign2405=== PAUSE TestSign2406=== RUN TestSignBatch2407=== PAUSE TestSignBatch2408=== RUN TestNilKeyPublicKey2409=== PAUSE TestNilKeyPublicKey2410=== RUN TestSignErrors2411=== PAUSE TestSignErrors2412=== CONT TestExternalSigner2413=== CONT TestExternalSignerCancellation2414=== CONT TestExternalSignerProgramErrorKeepsProcess2415=== CONT TestSignBatch2416=== CONT TestSignErrors2417=== CONT TestNilKeyPublicKey2418--- PASS: TestNilKeyPublicKey (0.00s)2419=== CONT TestParseSigningKey2420=== RUN TestParseSigningKey/valid_32-byte_key2421=== PAUSE TestParseSigningKey/valid_32-byte_key2422=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2423=== CONT TestSign2424=== CONT TestExternalSignerRejectsInvalidPublicKey2425=== RUN TestExternalSignerRejectsInvalidPublicKey/#002426=== CONT TestExternalSignerErrors2427=== CONT TestExternalSignerRestartsAfterCrash2428=== CONT TestGenerateFingerprint2429=== CONT TestExternalSignerWrongPublicKey2430=== CONT TestExternalSignerClose2431=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2432=== RUN TestParseSigningKey/no_colon2433=== RUN TestExternalSignerErrors/invalid_JSON2434=== PAUSE TestExternalSignerErrors/invalid_JSON2435=== RUN TestExternalSignerErrors/null2436=== PAUSE TestExternalSignerErrors/null2437=== RUN TestExternalSignerErrors/wrong_id2438=== PAUSE TestExternalSignerErrors/wrong_id2439=== RUN TestExternalSignerErrors/wrong_signatures_shape2440=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2441=== RUN TestExternalSignerErrors/invalid_signature_base642442=== PAUSE TestExternalSignerErrors/invalid_signature_base642443=== RUN TestExternalSignerErrors/wrong_signature_name2444=== PAUSE TestExternalSignerErrors/wrong_signature_name2445=== PAUSE TestParseSigningKey/no_colon2446=== RUN TestParseSigningKey/empty_name2447=== PAUSE TestParseSigningKey/empty_name2448=== RUN TestParseSigningKey/invalid_base642449=== RUN TestGenerateFingerprint/basic_with_references2450=== PAUSE TestGenerateFingerprint/basic_with_references2451=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002452=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2453=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2454=== RUN TestExternalSignerErrors/program_error2455=== RUN TestGenerateFingerprint/no_references2456=== PAUSE TestGenerateFingerprint/no_references2457=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2458=== PAUSE TestParseSigningKey/invalid_base642459=== RUN TestParseSigningKey/wrong_length2460=== PAUSE TestParseSigningKey/wrong_length2461=== CONT TestParseSigningKey/valid_32-byte_key2462=== CONT TestParseSigningKey/invalid_base642463=== CONT TestParseSigningKey/empty_name2464=== PAUSE TestExternalSignerErrors/program_error2465=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2466=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2467=== CONT TestParseSigningKey/no_colon2468=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2469=== RUN TestGenerateFingerprint/invalid_nar_hash_length2470=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2471=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2472=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2473=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2474=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2475=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2476=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2477=== CONT TestParseSigningKey/wrong_length2478=== RUN TestExternalSignerErrors/exit_at_startup2479=== PAUSE TestExternalSignerErrors/exit_at_startup2480=== RUN TestGenerateFingerprint/invalid_store_path_prefix2481=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2482=== RUN TestExternalSignerErrors/missing_signatures2483=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2484=== CONT TestExternalSignerRejectsInvalidPublicKey/#002485=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2486=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2487=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2488=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2489--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2490 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2491 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2492 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2493 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2494 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2495=== RUN TestGenerateFingerprint/invalid_reference_prefix2496=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2497=== CONT TestGenerateFingerprint/basic_with_references2498=== CONT TestGenerateFingerprint/no_references2499=== PAUSE TestExternalSignerErrors/missing_signatures2500=== CONT TestGenerateFingerprint/invalid_nar_hash_length2501=== CONT TestGenerateFingerprint/invalid_reference_prefix2502=== CONT TestGenerateFingerprint/invalid_store_path_prefix2503=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2504=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2505--- PASS: TestGenerateFingerprint (0.00s)2506 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2507 --- PASS: TestGenerateFingerprint/no_references (0.00s)2508 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2509 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2510 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2511 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2512 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2513=== RUN TestExternalSignerErrors/null_signatures2514=== PAUSE TestExternalSignerErrors/null_signatures2515=== RUN TestExternalSignerErrors/too_few_signatures2516=== PAUSE TestExternalSignerErrors/too_few_signatures2517=== RUN TestExternalSignerErrors/unrequested_key2518=== PAUSE TestExternalSignerErrors/unrequested_key2519=== RUN TestExternalSignerErrors/exit_on_request2520=== PAUSE TestExternalSignerErrors/exit_on_request2521=== RUN TestExternalSignerErrors/wrong_shape2522=== PAUSE TestExternalSignerErrors/wrong_shape2523=== RUN TestExternalSignerErrors/missing_signature_name2524=== PAUSE TestExternalSignerErrors/missing_signature_name2525=== RUN TestExternalSignerErrors/wrong_signature_length2526=== PAUSE TestExternalSignerErrors/wrong_signature_length2527=== CONT TestExternalSignerErrors/invalid_JSON2528=== CONT TestExternalSignerErrors/null_signatures2529=== CONT TestExternalSignerErrors/wrong_signature_name2530=== CONT TestExternalSignerErrors/wrong_id2531=== CONT TestExternalSignerErrors/null2532=== CONT TestExternalSignerErrors/missing_signatures2533=== CONT TestExternalSignerErrors/wrong_shape2534=== CONT TestExternalSignerErrors/missing_signature_name2535=== CONT TestExternalSignerErrors/wrong_signatures_shape2536=== CONT TestExternalSignerErrors/invalid_signature_base642537=== CONT TestExternalSignerErrors/wrong_signature_length2538=== RUN TestSignErrors/nil_key2539=== CONT TestExternalSignerErrors/exit_at_startup2540=== CONT TestExternalSignerErrors/exit_on_request2541=== CONT TestExternalSignerErrors/unrequested_key2542=== CONT TestExternalSignerErrors/too_few_signatures2543--- PASS: TestSign (0.00s)2544=== PAUSE TestSignErrors/nil_key2545=== CONT TestExternalSignerErrors/program_error2546--- PASS: TestSignBatch (0.00s)2547--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2548=== RUN TestSignErrors/nil_narinfo2549--- PASS: TestExternalSignerWrongPublicKey (0.00s)2550=== PAUSE TestSignErrors/nil_narinfo2551--- PASS: TestParseSigningKey (0.00s)2552 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2553 --- PASS: TestParseSigningKey/empty_name (0.00s)2554 --- PASS: TestParseSigningKey/no_colon (0.00s)2555 --- PASS: TestParseSigningKey/wrong_length (0.00s)2556 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2557 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2558=== RUN TestSignErrors/invalid_narinfo2559--- PASS: TestExternalSignerClose (0.01s)2560=== PAUSE TestSignErrors/invalid_narinfo2561=== RUN TestSignErrors/canceled2562=== PAUSE TestSignErrors/canceled2563=== CONT TestSignErrors/nil_key2564=== CONT TestSignErrors/canceled2565=== CONT TestSignErrors/invalid_narinfo2566=== CONT TestSignErrors/nil_narinfo2567--- PASS: TestSignErrors (0.01s)2568 --- PASS: TestSignErrors/nil_key (0.00s)2569 --- PASS: TestSignErrors/canceled (0.00s)2570 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2571 --- PASS: TestSignErrors/nil_narinfo (0.00s)2572--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2573--- PASS: TestExternalSigner (0.01s)2574--- PASS: TestExternalSignerErrors (0.00s)2575 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2576 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)2577 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2578 --- PASS: TestExternalSignerErrors/null (0.00s)2579 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2580 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2581 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2582 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2583 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2584 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2585 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2586 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2587 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2588 --- PASS: TestExternalSignerErrors/program_error (0.00s)2589 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2590 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2591--- PASS: TestExternalSignerCancellation (0.02s)2592PASS2593Running OpenBao signer tests...2594=== RUN TestSign2595=== PAUSE TestSign2596=== RUN TestSignErrors2597=== PAUSE TestSignErrors2598=== RUN TestServe2599=== PAUSE TestServe2600=== RUN TestServeRejectsGarbage2601=== PAUSE TestServeRejectsGarbage2602=== CONT TestSign2603=== CONT TestServeRejectsGarbage2604=== CONT TestServe2605=== CONT TestSignErrors2606--- PASS: TestServeRejectsGarbage (0.00s)2607=== RUN TestSignErrors/invalid_json2608=== PAUSE TestSignErrors/invalid_json2609=== RUN TestSignErrors/no_prefix2610=== PAUSE TestSignErrors/no_prefix2611=== RUN TestSignErrors/invalid_base642612=== PAUSE TestSignErrors/invalid_base642613=== RUN TestSignErrors/http_error2614=== PAUSE TestSignErrors/http_error2615=== CONT TestSignErrors/invalid_json2616=== CONT TestSignErrors/http_error2617=== CONT TestSignErrors/invalid_base642618=== CONT TestSignErrors/no_prefix2619--- PASS: TestServe (0.00s)2620--- PASS: TestSignErrors (0.00s)2621 --- PASS: TestSignErrors/invalid_json (0.00s)2622 --- PASS: TestSignErrors/invalid_base64 (0.00s)2623 --- PASS: TestSignErrors/no_prefix (0.00s)2624 --- PASS: TestSignErrors/http_error (0.00s)2625--- PASS: TestSign (0.00s)2626PASS