niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #396
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestEncodeNixBase32102=== RUN TestEncodeNixBase32/test_string_hash103=== CONT TestResolveStorePath104=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess105=== CONT TestRateLimiterFeedback106=== RUN TestRateLimiterFeedback/429_enables_limiter107=== CONT TestPathInfoCACompatibility108=== RUN TestPathInfoCACompatibility/null_ca_field109=== PAUSE TestPathInfoCACompatibility/null_ca_field110=== CONT TestParsePathInfoJSONMultiplePaths111=== CONT TestParsePathInfoJSON112=== CONT TestPathInfoHashCompatibility113=== CONT TestGetStorePathHash114=== CONT TestConvertHashToNix32115=== CONT TestEncodeNixBase32WithRealHash116=== CONT TestSetClientTLSErrors117=== CONT TestUploadMultipart_PartsInParallel118=== CONT TestScriptTokenEmptyCommand119=== CONT TestScriptTokenScriptFails120=== CONT TestDumpPathWriterError121=== CONT TestScriptTokenBadJSON122=== CONT TestScriptTokenEmptyToken123=== CONT TestDumpPathSingleFile124=== CONT TestScriptTokenCachesUntilRefresh125=== CONT TestDumpPathMatchesNix126=== CONT TestScriptTokenNoExpiryRerunsEveryCall1272026/10/07 09:35:53 WARN Rate limiter enabled after throttle name=server-test rate=5128=== PAUSE TestEncodeNixBase32/test_string_hash129=== PAUSE TestRateLimiterFeedback/429_enables_limiter130=== RUN TestPathInfoCACompatibility/old_string_format_-_text131=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text132=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive133=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive134=== RUN TestPathInfoCACompatibility/new_structured_format_-_text135=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text136=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method137=== RUN TestGetStorePathHash/valid_store_path138=== PAUSE TestGetStorePathHash/valid_store_path139=== RUN TestGetStorePathHash/basename_without_hyphen_should_error140=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error141=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error142=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths143=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths144=== RUN TestRateLimiterFeedback/503_enables_limiter145--- PASS: TestResolveStorePath (0.01s)146=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method147=== RUN TestParsePathInfoJSON/Nix_format148=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths149=== CONT TestFileTokenEmpty150=== PAUSE TestParsePathInfoJSON/Nix_format151=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error152=== PAUSE TestRateLimiterFeedback/503_enables_limiter153=== RUN TestConvertHashToNix32/SRI_format_to_Nix32154=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths155=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)156--- PASS: TestEncodeNixBase32WithRealHash (0.00s)157=== CONT TestUploadMultipart_SupersededByPeer158=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32159=== CONT TestFileTokenMissing160=== CONT TestFileTokenReadsAndCaches161--- PASS: TestFileTokenEmpty (0.00s)1622026/10/07 09:35:53 WARN Rate limiter enabled after throttle name=server-test rate=51632026/10/07 09:35:53 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:440871642026/10/07 09:35:53 WARN Rate limiter backed off name=server-test rate=51652026/10/07 09:35:53 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:44087166=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun167=== CONT TestStaticToken168=== CONT TestStreamPushGivesUpOnDeadServer169=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)170--- PASS: TestScriptTokenScriptFails (0.00s)171=== RUN TestEncodeNixBase32/empty_input172=== PAUSE TestEncodeNixBase32/empty_input173=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error174--- PASS: TestScriptTokenEmptyCommand (0.03s)175--- PASS: TestStaticToken (0.00s)176--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)177--- PASS: TestDoServerRequestAttachesToken (0.04s)178=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon179=== RUN TestParsePathInfoJSON/Lix_format180=== PAUSE TestParsePathInfoJSON/Lix_format181=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter1822026/10/07 09:35:53 ERROR Upload failed error="connection refused" count=201832026/10/07 09:35:53 ERROR Server seems unavailable, giving up on batch untried=17184=== RUN TestUploadMultipart_SupersededByPeer/exists185=== PAUSE TestUploadMultipart_SupersededByPeer/exists186=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter187=== RUN TestUploadMultipart_SupersededByPeer/missing188=== PAUSE TestUploadMultipart_SupersededByPeer/missing189=== RUN TestConvertHashToNix32/already_Nix32_format190=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter191=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter192=== PAUSE TestConvertHashToNix32/already_Nix32_format193=== CONT TestStreamPushReportsSignatures194=== RUN TestConvertHashToNix32/invalid_format195=== CONT TestCaseHackSuffix196=== CONT TestSetClientTLSDoesNotMutateDefaultTransport197=== CONT TestSetClientTLS198=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error199=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon200=== RUN TestParsePathInfoJSON/empty_input201=== PAUSE TestParsePathInfoJSON/empty_input202=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2032026/10/07 09:35:53 INFO Garbage collection started204=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2052026/10/07 09:35:53 ERROR Upload failed error=boom count=1206=== RUN TestParsePathInfoJSON/whitespace_only207=== CONT TestShellSplitErrors208=== CONT TestStreamPushReportsEveryPath209--- PASS: TestFileTokenMissing (0.00s)210--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)211=== PAUSE TestParsePathInfoJSON/whitespace_only212=== CONT TestStreamPushIsolatesFailures213=== CONT TestClientSignaturesByStorePath214=== CONT TestStreamPushBatchesUnderLoad215=== PAUSE TestConvertHashToNix32/invalid_format216=== CONT TestRegisterUploadedObjectReusesConnections2172026/10/07 09:35:53 ERROR Upload failed error="bad path" count=3218=== CONT TestPartSizeForNAR219=== RUN TestPartSizeForNAR/zero_stays_at_minimum220=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum221=== RUN TestPartSizeForNAR/small_stays_at_minimum222=== PAUSE TestPartSizeForNAR/small_stays_at_minimum223=== CONT TestStreamPushRequestLine224=== CONT TestPathInfoCACompatibility/new_structured_format_-_text225=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2262026/10/07 09:35:53 ERROR Upload failed error=boom count=1227=== RUN TestSetClientTLSErrors/missing_cert_file228=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512229=== PAUSE TestSetClientTLSErrors/missing_cert_file230=== RUN TestSetClientTLSErrors/missing_key_file231=== PAUSE TestSetClientTLSErrors/missing_key_file232=== RUN TestSetClientTLSErrors/missing_ca_file233=== PAUSE TestSetClientTLSErrors/missing_ca_file234=== RUN TestSetClientTLSErrors/invalid_ca_file235=== PAUSE TestSetClientTLSErrors/invalid_ca_file236=== CONT TestFilterOversizedClosures237=== RUN TestFilterOversizedClosures/no_limit_keeps_everything238=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything239=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped240=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped241=== RUN TestFilterOversizedClosures/all_closures_skipped242=== PAUSE TestFilterOversizedClosures/all_closures_skipped243=== CONT TestPathInfoCACompatibility/null_ca_field244=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method245=== CONT TestPathInfoCACompatibility/old_string_format_-_text246=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths247=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths248=== CONT TestEncodeNixBase32/empty_input249=== CONT TestUploadMultipart_SupersededByPeer/exists250=== CONT TestUploadMultipart_SupersededByPeer/missing251=== CONT TestEncodeNixBase32/test_string_hash252=== CONT TestRateLimiterFeedback/429_enables_limiter253=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter254--- PASS: TestStreamPushReportsSignatures (0.00s)255--- PASS: TestShellSplitErrors (0.00s)256--- PASS: TestFileTokenReadsAndCaches (0.00s)257--- PASS: TestStreamPushReportsEveryPath (0.00s)258--- PASS: TestClientSignaturesByStorePath (0.00s)259--- PASS: TestStreamPushIsolatesFailures (0.00s)260--- PASS: TestScriptTokenEmptyToken (0.04s)261=== RUN TestParsePathInfoJSON/invalid_JSON262=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum263=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512264=== CONT TestShellSplit265=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive266=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter267=== PAUSE TestParsePathInfoJSON/invalid_JSON268=== CONT TestRateLimiterFeedback/503_enables_limiter2692026/10/07 09:35:53 INFO Garbage collection started270=== RUN TestSetClientTLS/rejects_connection_without_client_cert271=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert272=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA273=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA274=== CONT TestGetStorePathHash/basename_without_hyphen_should_error275=== CONT TestConvertHashToNix32/SRI_format_to_Nix32276=== CONT TestConvertHashToNix32/already_Nix32_format277--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)278--- PASS: TestScriptTokenBadJSON (0.04s)279--- PASS: TestShellSplit (0.00s)280--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)281 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)282 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)283=== CONT TestConvertHashToNix32/invalid_format284=== CONT TestSetClientTLSErrors/invalid_ca_file285=== RUN TestSetClientTLS/preserves_debug_logging_transport286=== PAUSE TestSetClientTLS/preserves_debug_logging_transport287=== CONT TestGetStorePathHash/valid_store_path288=== CONT TestSetClientTLSErrors/missing_ca_file2892026/10/07 09:35:53 WARN Rate limiter enabled after throttle name=server-test rate=52902026/10/07 09:35:53 WARN Rate limiter enabled after throttle name=server-test rate=52912026/10/07 09:35:53 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:45539292=== CONT TestFilterOversizedClosures/all_closures_skipped293=== CONT TestSetClientTLSErrors/missing_cert_file2942026/10/07 09:35:53 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:36489295=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2962026/10/07 09:35:53 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=2000297=== CONT TestParsePathInfoJSON/Nix_format2982026/10/07 09:35:53 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50299=== CONT TestParsePathInfoJSON/whitespace_only300=== CONT TestParsePathInfoJSON/Lix_format301=== CONT TestParsePathInfoJSON/empty_input302=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum3032026/10/07 09:35:53 WARN Rate limiter backed off name=server-test rate=5304=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error305=== CONT TestSetClientTLS/rejects_connection_without_client_cert3062026/10/07 09:35:53 WARN Rate limiter backed off name=server-test rate=5307=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA308=== CONT TestSetClientTLS/preserves_debug_logging_transport309=== CONT TestParsePathInfoJSON/invalid_JSON310=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512311=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error312=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI313=== CONT TestFilterOversizedClosures/no_limit_keeps_everything314=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts315=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts316=== RUN TestPartSizeForNAR/1_TiB3172026/10/07 09:35:53 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=0318=== PAUSE TestPartSizeForNAR/1_TiB319=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)320=== CONT TestSetClientTLSErrors/missing_key_file321=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon322--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)323=== RUN TestPartSizeForNAR/5_TiB_S3_max_object324=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object325=== RUN TestPartSizeForNAR/capped_at_5_GiB326=== PAUSE TestPartSizeForNAR/capped_at_5_GiB327=== CONT TestPartSizeForNAR/zero_stays_at_minimum328=== CONT TestPartSizeForNAR/5_TiB_S3_max_object329=== CONT TestPartSizeForNAR/1_TiB330=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts331=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum332=== CONT TestPartSizeForNAR/small_stays_at_minimum333=== CONT TestPartSizeForNAR/capped_at_5_GiB334--- PASS: TestConvertHashToNix32 (0.03s)335 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)336 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)337 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)3382026/10/07 09:35:53 WARN Garbage collection finished on another replica. Its statistics are not available here339--- PASS: TestEncodeNixBase32 (0.04s)340 --- PASS: TestEncodeNixBase32/empty_input (0.00s)341 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)342--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)343--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)344--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)345--- PASS: TestPartSizeForNAR (0.01s)346 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)347 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)348 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)349 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)350 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)351 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)352 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)353--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)354 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)355 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)356--- PASS: TestGetStorePathHash (0.04s)357 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)358 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)359 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)360 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)361--- PASS: TestFilterOversizedClosures (0.00s)362 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)363 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)364 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)365--- PASS: TestRateLimiterFeedback (0.04s)366 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)367 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)368 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)369 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)370--- PASS: TestParsePathInfoJSON (0.04s)371 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)372 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)373 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)374 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)375 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)376--- PASS: TestPathInfoHashCompatibility (0.04s)377 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)378 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)379 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)380 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)381--- PASS: TestPathInfoCACompatibility (0.00s)382 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)383 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)384 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)385 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)386 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)387--- PASS: TestSetClientTLSErrors (0.03s)388 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)389 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)391 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3922026/10/07 09:35:53 http: TLS handshake error from 127.0.0.1:60992: remote error: tls: bad certificate393--- PASS: TestDumpPathSingleFile (0.06s)394--- PASS: TestSetClientTLS (0.01s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)397 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)398--- PASS: TestCaseHackSuffix (0.04s)399--- PASS: TestStreamPushRequestLine (0.04s)400--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)401--- PASS: TestDumpPathWriterError (0.09s)402--- PASS: TestDumpPathMatchesNix (0.09s)403--- PASS: TestStreamPushBatchesUnderLoad (0.10s)404--- PASS: TestUploadMultipart_PartsInParallel (0.66s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)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/postgres3520087224/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/postgres3520087224/data -l logfile start434435/build/postgres3520087224:5432 - no response4362026-10-07 09:35:55.118 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-07 09:35:55.119 UTC [129] LOG: listening on Unix socket "/build/postgres3520087224/.s.PGSQL.5432"4382026-10-07 09:35:55.124 UTC [136] LOG: database system was shut down at 2026-10-07 09:35:54 UTC4392026-10-07 09:35:55.128 UTC [129] LOG: database system is ready to accept connections440/build/postgres3520087224:5432 - accepting connections441{"timestamp":"2026-10-07T09:35:55.423834037Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"eb39f3af-d367-49c6-ae57-047b4119942a","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(386)"}442=== RUN TestService_AuthMiddleware443=== PAUSE TestService_AuthMiddleware444=== RUN TestService_AuthMiddleware_MTLSProxyHeader445=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader446=== RUN TestService_AuthMiddleware_MTLSBoundSubjects447=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects448=== RUN TestService_ReadAuthMiddleware449=== PAUSE TestService_ReadAuthMiddleware450=== RUN TestService_AuthMiddleware_OIDC451=== PAUSE TestService_AuthMiddleware_OIDC452=== RUN TestService_RequireScope_OIDC453=== PAUSE TestService_RequireScope_OIDC454=== RUN TestService_ReadScope_PublicByDefault455=== PAUSE TestService_ReadScope_PublicByDefault456=== RUN TestCacheConfigHandler457=== PAUSE TestCacheConfigHandler458=== RUN TestCacheStatsHandler459=== PAUSE TestCacheStatsHandler460=== RUN TestClientCADerivations461=== PAUSE TestClientCADerivations462=== RUN TestClientErrorHandling463=== PAUSE TestClientErrorHandling464=== RUN TestClientIntegration465=== PAUSE TestClientIntegration466=== RUN TestClientMultipleUploads467=== PAUSE TestClientMultipleUploads468=== RUN TestClientWithDependencies469=== PAUSE TestClientWithDependencies470=== RUN TestClientSharedPathCommittedMidPush471=== PAUSE TestClientSharedPathCommittedMidPush472=== RUN TestPinProtectsFromGC473=== PAUSE TestPinProtectsFromGC474=== RUN TestClientPushesUseOnePush475=== PAUSE TestClientPushesUseOnePush476=== RUN TestClientFallsBackToClosures477=== PAUSE TestClientFallsBackToClosures478=== RUN TestDeleteClosuresRacingPins479=== PAUSE TestDeleteClosuresRacingPins480=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock482=== RUN TestResolveDBConnectionString483=== PAUSE TestResolveDBConnectionString484=== RUN TestConnectWaitsForAPeerMigration485=== PAUSE TestConnectWaitsForAPeerMigration486=== RUN TestLeadElectsOneAndHandsOver487=== PAUSE TestLeadElectsOneAndHandsOver488=== RUN TestLeadIncumbentWinsAfterRestart4892026/10/07 09:35:55 INFO lead: acquired remote=192.0.2.1:12344902026/10/07 09:35:56 INFO lead: released remote=192.0.2.1:12344912026/10/07 09:35:56 INFO lead: acquired remote=192.0.2.1:12344922026/10/07 09:35:57 INFO lead: released remote=192.0.2.1:1234493--- PASS: TestLeadIncumbentWinsAfterRestart (1.85s)494=== RUN TestLeadIncumbentAnnouncesAtOnce495=== PAUSE TestLeadIncumbentAnnouncesAtOnce496=== RUN TestLeadEndsOnShutdown497=== PAUSE TestLeadEndsOnShutdown498=== RUN TestLeadEndsWhenItsConnectionHangs4992026/10/07 09:35:57 INFO lead: acquired remote=192.0.2.1:12345002026-10-07 09:35:58.892 UTC [574] FATAL: terminating connection due to administrator command5012026/10/07 09:35:59 INFO lead: acquired remote=192.0.2.1:12345022026/10/07 09:36:00 WARN lead: lock connection lost error="timeout: context deadline exceeded"5032026/10/07 09:36:00 INFO lead: released remote=192.0.2.1:12345042026/10/07 09:36:00 INFO lead: released remote=192.0.2.1:1234505--- PASS: TestLeadEndsWhenItsConnectionHangs (2.92s)506=== RUN TestGCAdvisoryLockBlocksConcurrentRun507=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestSweepRechecksPendingAfterLocking535=== PAUSE TestSweepRechecksPendingAfterLocking536=== RUN TestPushWaitsForSweepHoldingRow537=== PAUSE TestPushWaitsForSweepHoldingRow538=== RUN TestCommitRacingPendingCleanupKeepsObjects539=== PAUSE TestCommitRacingPendingCleanupKeepsObjects540=== RUN TestGCEndsOnShutdown541=== PAUSE TestGCEndsOnShutdown542=== RUN TestGCTaskStore_StartNew543=== PAUSE TestGCTaskStore_StartNew544=== RUN TestGCTaskStore_DeduplicateSameParams545=== PAUSE TestGCTaskStore_DeduplicateSameParams546=== RUN TestGCTaskStore_ConflictDifferentParams547=== PAUSE TestGCTaskStore_ConflictDifferentParams548=== RUN TestGCTaskStore_GetEmpty549=== PAUSE TestGCTaskStore_GetEmpty550=== RUN TestGCTaskStore_GetReturnsLatest551=== PAUSE TestGCTaskStore_GetReturnsLatest552=== RUN TestGCTaskStore_CompletedAllowsNewTask553=== PAUSE TestGCTaskStore_CompletedAllowsNewTask554=== RUN TestGCTaskStore_PhaseUpdates555=== PAUSE TestGCTaskStore_PhaseUpdates556=== RUN TestGCTaskStore_Fail557=== PAUSE TestGCTaskStore_Fail558=== RUN TestGracefulShutdownDrainsInflight559=== PAUSE TestGracefulShutdownDrainsInflight560=== RUN TestService_healthCheckHandler561=== PAUSE TestService_healthCheckHandler562=== RUN TestService_readinessHandler563=== PAUSE TestService_readinessHandler564=== RUN TestGenerateLandingPage565=== PAUSE TestGenerateLandingPage566=== RUN TestCacheConfigHandlerMaxNarSize567=== PAUSE TestCacheConfigHandlerMaxNarSize568=== RUN TestCreatePendingClosureRejectsOversizedNAR569=== PAUSE TestCreatePendingClosureRejectsOversizedNAR570=== RUN TestNARDeduplicationMetadataUploadBug571=== PAUSE TestNARDeduplicationMetadataUploadBug572=== RUN TestMetricsInventory573=== PAUSE TestMetricsInventory574=== RUN TestMetricsCommit575=== PAUSE TestMetricsCommit576=== RUN TestService_NativeMTLS577=== PAUSE TestService_NativeMTLS578=== RUN TestServerTLSConfig579=== PAUSE TestServerTLSConfig580=== RUN TestMultipartCleanup581=== PAUSE TestMultipartCleanup582=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded584=== RUN TestPendingCleanupUsesOneCutoff585=== PAUSE TestPendingCleanupUsesOneCutoff586=== RUN TestObjectStatsTrigger587=== PAUSE TestObjectStatsTrigger588=== RUN TestObjectStatsLargeCommit589=== PAUSE TestObjectStatsLargeCommit590=== RUN TestOrphanedObjectsGC591=== PAUSE TestOrphanedObjectsGC592=== RUN TestOrphanedObjectsGCStressTest593=== PAUSE TestOrphanedObjectsGCStressTest594=== RUN TestCreatePin_ReservedPins595=== PAUSE TestCreatePin_ReservedPins596=== RUN TestPresentReportsOnlyClosureRoots597=== PAUSE TestPresentReportsOnlyClosureRoots598=== RUN TestPresentRefreshesOnlyStaleClosures599=== PAUSE TestPresentRefreshesOnlyStaleClosures600=== RUN TestPresentNotReportedWhileGCDeletesClosure601=== PAUSE TestPresentNotReportedWhileGCDeletesClosure602=== RUN TestParseSingleRange603=== PAUSE TestParseSingleRange604=== RUN TestProxyHeadersOnlyTrustedOnSocket6052026/10/07 09:36:00 INFO Starting HTTP server address=127.0.0.1:352496062026/10/07 09:36:00 INFO Starting HTTP server address=proxy.sock6072026/10/07 09:36:00 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6082026/10/07 09:36:00 INFO Shutdown signal received, draining in-flight requests timeout=10s609--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.12s)610=== RUN TestIsValidCachePath611=== PAUSE TestIsValidCachePath612=== RUN TestReadProxyNarinfo613=== PAUSE TestReadProxyNarinfo614=== RUN TestReadProxyNarinfoAlreadyDecompressed615=== PAUSE TestReadProxyNarinfoAlreadyDecompressed616=== RUN TestReadProxyContentNegotiation617=== PAUSE TestReadProxyContentNegotiation618=== RUN TestReadProxyNarStreaming619=== PAUSE TestReadProxyNarStreaming620=== RUN TestReadProxy404621=== PAUSE TestReadProxy404622=== RUN TestReadProxyInvalidPath623=== PAUSE TestReadProxyInvalidPath624=== RUN TestReadProxyHead625=== PAUSE TestReadProxyHead626=== RUN TestReadProxyOutlastsServerWriteTimeout627=== PAUSE TestReadProxyOutlastsServerWriteTimeout628=== RUN TestReadProxyConditionalGet629=== PAUSE TestReadProxyConditionalGet630=== RUN TestReadProxyRootRedirectsToIndexHTML631=== PAUSE TestReadProxyRootRedirectsToIndexHTML632=== RUN TestReadProxyDisabled633=== PAUSE TestReadProxyDisabled634=== RUN TestReadRedirectNar635=== PAUSE TestReadRedirectNar636=== RUN TestReadRedirectKeepsNarinfoProxied637=== PAUSE TestReadRedirectKeepsNarinfoProxied638=== RUN TestReadProxyRangeRequest639=== PAUSE TestReadProxyRangeRequest640=== RUN TestReadRedirectUsesPublicS3URL641=== PAUSE TestReadRedirectUsesPublicS3URL642=== RUN TestPush_OverlappingRootsStoreOneRowPerKey643=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey644=== RUN TestPush_CompleteCommitsEveryRoot645=== PAUSE TestPush_CompleteCommitsEveryRoot646=== RUN TestPush_RepeatedRootCommitsOnce647=== PAUSE TestPush_RepeatedRootCommitsOnce648=== RUN TestPush_CompleteWaitsForCleanupOfThePush649=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush650=== RUN TestPush_RootsAreLockedInByteOrder651=== PAUSE TestPush_RootsAreLockedInByteOrder652=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit653=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit654=== RUN TestPush_RejectsBadRequests655=== PAUSE TestPush_RejectsBadRequests656=== RUN TestPush_SignsNarinfosOfItsPendingObjects657=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects658=== RUN TestRedundantMultipartUpload659=== PAUSE TestRedundantMultipartUpload660=== RUN TestCompleteMultipartUpload_ErrorButObjectExists661=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists662=== RUN TestCompletedNarNotReofferedAcrossClosures663=== PAUSE TestCompletedNarNotReofferedAcrossClosures664=== RUN TestPresignedUploadRegisteredBeforeCommit665=== PAUSE TestPresignedUploadRegisteredBeforeCommit666=== RUN TestService_Rustfstest667=== PAUSE TestService_Rustfstest668=== RUN TestParseSize669=== PAUSE TestParseSize670=== RUN TestSkippedUploadsHandler671=== PAUSE TestSkippedUploadsHandler672=== RUN TestSystemdListenerNotActivated673--- PASS: TestSystemdListenerNotActivated (0.00s)674=== RUN TestWatchdogBeatsWhenHealthy675--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)676=== RUN TestWatchdogSkipsWhenUnhealthy6772026/10/07 09:36:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6782026/10/07 09:36:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6792026/10/07 09:36:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6802026/10/07 09:36:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6812026/10/07 09:36:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6822026/10/07 09:36:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6832026/10/07 09:36:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6842026/10/07 09:36:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6852026/10/07 09:36:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6862026/10/07 09:36:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"687--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)688=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle689=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle690=== RUN TestProxyWriteTimeout691=== PAUSE TestProxyWriteTimeout692=== RUN TestPendingClosureWriteTimeout693=== PAUSE TestPendingClosureWriteTimeout694=== RUN TestIsValidUploadKey695=== PAUSE TestIsValidUploadKey696=== RUN TestUploadHandlersRejectInvalidKeys697=== PAUSE TestUploadHandlersRejectInvalidKeys698=== RUN TestUploadHandlersRejectOversizedBody699=== PAUSE TestUploadHandlersRejectOversizedBody700=== RUN TestService_cleanupPendingClosuresHandler701=== PAUSE TestService_cleanupPendingClosuresHandler702=== RUN TestService_createPendingClosureHandler703=== PAUSE TestService_createPendingClosureHandler704=== RUN TestService_verifyS3Integrity705=== PAUSE TestService_verifyS3Integrity706=== RUN TestCompleteMultipartUnregistered707=== PAUSE TestCompleteMultipartUnregistered708=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT709=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT710=== CONT TestService_AuthMiddleware711=== CONT TestReadProxyDisabled712=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT713=== CONT TestCompleteMultipartUnregistered714=== CONT TestService_verifyS3Integrity715=== CONT TestService_createPendingClosureHandler716=== CONT TestService_cleanupPendingClosuresHandler717=== CONT TestUploadHandlersRejectOversizedBody718=== CONT TestUploadHandlersRejectInvalidKeys719=== CONT TestIsValidUploadKey720=== RUN TestIsValidUploadKey/narinfo721=== CONT TestPendingClosureWriteTimeout722=== CONT TestProxyWriteTimeout723=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle724=== CONT TestSkippedUploadsHandler725=== CONT TestParseSize726=== CONT TestService_Rustfstest727=== CONT TestPresignedUploadRegisteredBeforeCommit728=== CONT TestCompletedNarNotReofferedAcrossClosures729=== CONT TestCompleteMultipartUpload_ErrorButObjectExists730=== CONT TestRedundantMultipartUpload731=== CONT TestPush_SignsNarinfosOfItsPendingObjects732=== CONT TestPush_RejectsBadRequests733=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit734=== CONT TestPush_RootsAreLockedInByteOrder735=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info736=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info737=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal738=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal739=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key740=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key741=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key742=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key7432026/10/07 09:36:00 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000744=== PAUSE TestIsValidUploadKey/narinfo745=== RUN TestIsValidUploadKey/nar_zst746=== PAUSE TestIsValidUploadKey/nar_zst747=== RUN TestIsValidUploadKey/nar_xz748=== CONT TestPush_RepeatedRootCommitsOnce749=== RUN TestProxyWriteTimeout/narinfo750--- PASS: TestParseSize (0.00s)751=== CONT TestPush_CompleteWaitsForCleanupOfThePush752=== RUN TestPendingClosureWriteTimeout/empty753=== PAUSE TestPendingClosureWriteTimeout/empty754=== RUN TestPendingClosureWriteTimeout/400_objects755=== PAUSE TestPendingClosureWriteTimeout/400_objects756=== RUN TestPendingClosureWriteTimeout/670k_objects757=== PAUSE TestIsValidUploadKey/nar_xz758=== PAUSE TestProxyWriteTimeout/narinfo759=== RUN TestIsValidUploadKey/nar_plain760=== RUN TestProxyWriteTimeout/1_GiB_nar761=== PAUSE TestPendingClosureWriteTimeout/670k_objects762=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline763=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline764=== PAUSE TestIsValidUploadKey/nar_plain765=== PAUSE TestProxyWriteTimeout/1_GiB_nar766=== CONT TestPush_CompleteCommitsEveryRoot767=== RUN TestIsValidUploadKey/listing768=== PAUSE TestIsValidUploadKey/listing769=== RUN TestIsValidUploadKey/build_log770=== PAUSE TestIsValidUploadKey/build_log771=== RUN TestProxyWriteTimeout/10_GiB_nar772=== PAUSE TestProxyWriteTimeout/10_GiB_nar773=== RUN TestIsValidUploadKey/build_log_home-manager_file774=== PAUSE TestIsValidUploadKey/build_log_home-manager_file775=== RUN TestIsValidUploadKey/build_log_plus_in_name776=== RUN TestProxyWriteTimeout/unknown_size777=== PAUSE TestProxyWriteTimeout/unknown_size778=== PAUSE TestIsValidUploadKey/build_log_plus_in_name779=== CONT TestPush_OverlappingRootsStoreOneRowPerKey780=== RUN TestIsValidUploadKey/build_log_question_mark781=== PAUSE TestIsValidUploadKey/build_log_question_mark782=== RUN TestIsValidUploadKey/build_log_equals783=== PAUSE TestIsValidUploadKey/build_log_equals784=== RUN TestIsValidUploadKey/realisation785=== PAUSE TestIsValidUploadKey/realisation786=== RUN TestIsValidUploadKey/realisation_plus_in_output787=== PAUSE TestIsValidUploadKey/realisation_plus_in_output788=== RUN TestIsValidUploadKey/nix-cache-info789=== PAUSE TestIsValidUploadKey/nix-cache-info790=== RUN TestIsValidUploadKey/index.html791=== PAUSE TestIsValidUploadKey/index.html792=== RUN TestIsValidUploadKey/narinfo_key,_nar_type793=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type794=== RUN TestIsValidUploadKey/nar_key,_narinfo_type795=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type796=== RUN TestIsValidUploadKey/listing_key,_narinfo_type797=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type798=== RUN TestIsValidUploadKey/traversal799=== PAUSE TestIsValidUploadKey/traversal800=== RUN TestIsValidUploadKey/traversal_nar801=== PAUSE TestIsValidUploadKey/traversal_nar802=== RUN TestIsValidUploadKey/absolute803=== PAUSE TestIsValidUploadKey/absolute804=== RUN TestIsValidUploadKey/empty_key805=== PAUSE TestIsValidUploadKey/empty_key806=== RUN TestIsValidUploadKey/unknown_type807=== PAUSE TestIsValidUploadKey/unknown_type808=== CONT TestReadRedirectUsesPublicS3URL809--- PASS: TestSkippedUploadsHandler (0.09s)810=== CONT TestReadProxyRangeRequest811=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure812=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure813=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart814=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart815=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts816=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts817=== CONT TestReadRedirectKeepsNarinfoProxied8182026/10/07 09:36:01 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"819--- PASS: TestService_AuthMiddleware (0.49s)820=== CONT TestReadRedirectNar821--- PASS: TestReadProxyDisabled (0.52s)822=== CONT TestGCTaskStore_StartNew823--- PASS: TestGCTaskStore_StartNew (0.00s)824=== CONT TestReadProxyRootRedirectsToIndexHTML8252026/10/07 09:36:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8262026/10/07 09:36:01 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst827--- PASS: TestCompleteMultipartUnregistered (0.54s)828=== CONT TestReadProxyConditionalGet8292026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures8302026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures8312026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures832--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.62s)833=== CONT TestReadProxyOutlastsServerWriteTimeout8342026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures835--- PASS: TestService_Rustfstest (0.65s)836=== CONT TestReadProxyHead8372026/10/07 09:36:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8382026/10/07 09:36:01 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTc3YzJhZjQtN2JhZi00Njc1LWIxNzktYzM0MzNkZWU2NGQxLjUwNzNlNThjLWE1MGItNDA4YS05Y2E0LTAwNjIwYjhmZDU1M3gxNzkxMzY1NzYxMjgwMzA0MjE38392026/10/07 09:36:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8402026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures8412026/10/07 09:36:01 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTc3YzJhZjQtN2JhZi00Njc1LWIxNzktYzM0MzNkZWU2NGQxLjUwNzNlNThjLWE1MGItNDA4YS05Y2E0LTAwNjIwYjhmZDU1M3gxNzkxMzY1NzYxMjgwMzA0MjE3 parts=1842--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.68s)843=== CONT TestReadProxyInvalidPath8442026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures8452026/10/07 09:36:01 INFO Received cleanup request method=DELETE path=/api/pending_closures8462026/10/07 09:36:01 INFO Aborted multipart uploads count=0 kept=08472026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures8482026/10/07 09:36:01 INFO Received cleanup request method=DELETE path=/api/pending_closures8492026/10/07 09:36:01 INFO Aborted multipart uploads count=1 kept=08502026/10/07 09:36:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8512026-10-07 09:36:01.367 UTC [655] ERROR: Closure does not exist: id=18522026-10-07 09:36:01.367 UTC [655] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE8532026-10-07 09:36:01.367 UTC [655] STATEMENT: -- name: CommitPendingClosure :one854 SELECT commit_pending_closure($1::bigint)::bigint855 856--- PASS: TestService_cleanupPendingClosuresHandler (0.72s)857=== CONT TestReadProxy4048582026/10/07 09:36:01 INFO Received push request method=POST path=/api/pushes8592026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures8602026/10/07 09:36:01 INFO Received push request method=POST path=/api/pushes8612026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures8622026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures8632026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures8642026/10/07 09:36:01 INFO Received complete push request method=POST path=/api/pushes/1/complete8652026/10/07 09:36:01 INFO Completed push id=1 objects=4 duration=7.807386ms866--- PASS: TestPush_RepeatedRootCommitsOnce (0.71s)867=== CONT TestReadProxyNarStreaming868=== RUN TestPush_RejectsBadRequests/no_roots869=== PAUSE TestPush_RejectsBadRequests/no_roots870=== RUN TestPush_RejectsBadRequests/no_objects871=== PAUSE TestPush_RejectsBadRequests/no_objects872=== RUN TestPush_RejectsBadRequests/bad_root873=== PAUSE TestPush_RejectsBadRequests/bad_root874=== RUN TestPush_RejectsBadRequests/root_not_in_objects875=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects876=== CONT TestReadProxyContentNegotiation8772026/10/07 09:36:01 INFO Received push request method=POST path=/api/pushes8782026/10/07 09:36:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8792026/10/07 09:36:01 INFO Signed narinfos id=1 count=18802026/10/07 09:36:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8812026/10/07 09:36:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8822026/10/07 09:36:01 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8832026/10/07 09:36:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8842026/10/07 09:36:01 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8852026/10/07 09:36:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8862026/10/07 09:36:01 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18872026/10/07 09:36:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8882026/10/07 09:36:01 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo889--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.86s)890=== CONT TestReadProxyNarinfoAlreadyDecompressed8912026/10/07 09:36:01 INFO Received push request method=POST path=/api/pushes8922026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures8932026/10/07 09:36:01 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8942026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures8952026-10-07 09:36:01.560 UTC [709] ERROR: could not obtain lock on row in relation "closures"8962026-10-07 09:36:01.560 UTC [709] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8972026-10-07 09:36:01.561 UTC [709] ERROR: could not obtain lock on row in relation "closures"8982026-10-07 09:36:01.561 UTC [709] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8992026-10-07 09:36:01.561 UTC [709] ERROR: could not obtain lock on row in relation "closures"9002026-10-07 09:36:01.561 UTC [709] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9012026-10-07 09:36:01.562 UTC [709] ERROR: could not obtain lock on row in relation "closures"9022026-10-07 09:36:01.562 UTC [709] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9032026-10-07 09:36:01.562 UTC [709] ERROR: could not obtain lock on row in relation "closures"9042026-10-07 09:36:01.562 UTC [709] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT905--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.92s)906=== CONT TestReadProxyNarinfo907--- PASS: TestPush_RootsAreLockedInByteOrder (0.92s)908=== CONT TestIsValidCachePath909=== RUN TestIsValidCachePath/narinfo910=== PAUSE TestIsValidCachePath/narinfo911=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars912=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars913=== RUN TestIsValidCachePath/nar_zst914=== PAUSE TestIsValidCachePath/nar_zst915=== RUN TestIsValidCachePath/nar_xz916=== PAUSE TestIsValidCachePath/nar_xz917=== RUN TestIsValidCachePath/nar_bz2918=== PAUSE TestIsValidCachePath/nar_bz2919=== RUN TestIsValidCachePath/nar_uncompressed920=== PAUSE TestIsValidCachePath/nar_uncompressed921=== RUN TestIsValidCachePath/ls922=== PAUSE TestIsValidCachePath/ls923=== RUN TestIsValidCachePath/log924=== PAUSE TestIsValidCachePath/log925=== RUN TestIsValidCachePath/realisation926=== PAUSE TestIsValidCachePath/realisation927=== RUN TestIsValidCachePath/nix-cache-info928=== PAUSE TestIsValidCachePath/nix-cache-info9292026/10/07 09:36:01 INFO Received push request method=POST path=/api/pushes930=== RUN TestIsValidCachePath/index.html931=== PAUSE TestIsValidCachePath/index.html932=== RUN TestIsValidCachePath/traversal_parent933=== PAUSE TestIsValidCachePath/traversal_parent934=== RUN TestIsValidCachePath/traversal_in_middle935=== PAUSE TestIsValidCachePath/traversal_in_middle936=== RUN TestIsValidCachePath/invalid_char_e937=== PAUSE TestIsValidCachePath/invalid_char_e938=== RUN TestIsValidCachePath/invalid_char_u939=== PAUSE TestIsValidCachePath/invalid_char_u940=== RUN TestIsValidCachePath/random_path941=== PAUSE TestIsValidCachePath/random_path942=== RUN TestIsValidCachePath/empty943=== PAUSE TestIsValidCachePath/empty944=== RUN TestIsValidCachePath/leading_slash945=== PAUSE TestIsValidCachePath/leading_slash946=== RUN TestIsValidCachePath/wrong_extension947=== PAUSE TestIsValidCachePath/wrong_extension948=== RUN TestIsValidCachePath/short_hash949=== PAUSE TestIsValidCachePath/short_hash950=== CONT TestParseSingleRange951=== RUN TestParseSingleRange/none952=== PAUSE TestParseSingleRange/none953=== RUN TestParseSingleRange/unknown_unit954=== PAUSE TestParseSingleRange/unknown_unit955=== RUN TestParseSingleRange/multi-range_ignored956=== PAUSE TestParseSingleRange/multi-range_ignored957=== RUN TestParseSingleRange/malformed_no_dash958=== PAUSE TestParseSingleRange/malformed_no_dash959=== RUN TestParseSingleRange/malformed_both_empty960=== PAUSE TestParseSingleRange/malformed_both_empty961=== RUN TestParseSingleRange/malformed_end_before_start962=== PAUSE TestParseSingleRange/malformed_end_before_start963=== RUN TestParseSingleRange/closed964=== PAUSE TestParseSingleRange/closed965=== RUN TestParseSingleRange/open-ended966=== PAUSE TestParseSingleRange/open-ended967=== RUN TestParseSingleRange/end_clamped_to_size968=== PAUSE TestParseSingleRange/end_clamped_to_size969=== RUN TestParseSingleRange/suffix970=== PAUSE TestParseSingleRange/suffix971=== RUN TestParseSingleRange/suffix_exceeds_size972=== PAUSE TestParseSingleRange/suffix_exceeds_size973=== RUN TestParseSingleRange/single_byte974=== PAUSE TestParseSingleRange/single_byte975=== RUN TestParseSingleRange/start_past_EOF976=== PAUSE TestParseSingleRange/start_past_EOF977=== RUN TestParseSingleRange/start_far_past_EOF978=== PAUSE TestParseSingleRange/start_far_past_EOF979=== CONT TestPresentNotReportedWhileGCDeletesClosure980=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh981=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh982=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale983=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale984=== CONT TestPresentRefreshesOnlyStaleClosures9852026/10/07 09:36:01 INFO Received complete push request method=POST path=/api/pushes/1/complete9862026/10/07 09:36:01 INFO Completed push id=1 objects=4 duration=7.201597ms9872026/10/07 09:36:01 INFO Received push request method=POST path=/api/pushes9882026/10/07 09:36:01 INFO Received push request method=POST path=/api/pushes9892026/10/07 09:36:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete990--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.90s)9912026/10/07 09:36:01 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YTc3YzJhZjQtN2JhZi00Njc1LWIxNzktYzM0MzNkZWU2NGQxLjAzMDFkMzdjLWEyMmUtNDkzYy05MzFhLTIzNmUyMTM0NGU3ZngxNzkxMzY1NzYxMjExMjMzNjUw parts=10992=== CONT TestPresentReportsOnlyClosureRoots9932026/10/07 09:36:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9942026/10/07 09:36:01 INFO Completed upload id=1 objects=2 duration=5.974437ms9952026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures996--- PASS: TestReadRedirectUsesPublicS3URL (0.91s)997=== CONT TestCreatePin_ReservedPins9982026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures9992026/10/07 09:36:01 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10002026/10/07 09:36:01 WARN Found objects in DB but missing from S3, will re-upload count=11001--- PASS: TestService_verifyS3Integrity (1.01s)1002=== CONT TestOrphanedObjectsGCStressTest1003--- PASS: TestReadRedirectKeepsNarinfoProxied (0.82s)1004=== CONT TestOrphanedObjectsGC10052026/10/07 09:36:01 INFO Aborted multipart uploads count=0 kept=010062026/10/07 09:36:01 WARN Force mode enabled - objects will be deleted immediately without grace period10072026/10/07 09:36:01 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=010082026/10/07 09:36:01 INFO Vacuumed table table=pending_closures10092026/10/07 09:36:01 INFO Vacuumed table table=pending_objects1010--- PASS: TestReadProxyRangeRequest (0.94s)1011=== CONT TestObjectStatsLargeCommit10122026/10/07 09:36:01 INFO Vacuumed table table=multipart_uploads10132026/10/07 09:36:01 INFO Vacuumed table table=closures10142026/10/07 09:36:01 INFO Vacuumed table table=objects10152026/10/07 09:36:01 INFO Received complete push request method=POST path=/api/pushes/2/complete10162026-10-07 09:36:01.692 UTC [690] ERROR: Push does not exist: id=110172026-10-07 09:36:01.692 UTC [690] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10182026-10-07 09:36:01.692 UTC [690] STATEMENT: SELECT commit_push($1)1019--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.04s)1020=== CONT TestObjectStatsTrigger10212026/10/07 09:36:01 INFO Completed push id=2 objects=4 duration=3.099139ms1022--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.05s)1023=== CONT TestPendingCleanupUsesOneCutoff10242026/10/07 09:36:01 INFO Received push request method=POST path=/api/pushes10252026/10/07 09:36:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46033/oidc1026--- PASS: TestReadRedirectNar (0.61s)1027=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded10282026/10/07 09:36:01 INFO Received complete push request method=POST path=/api/pushes/1/complete10292026/10/07 09:36:01 INFO Completed push id=1 objects=6 duration=11.347685ms1030--- PASS: TestPush_CompleteCommitsEveryRoot (1.03s)1031=== CONT TestMultipartCleanup1032--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.61s)1033=== CONT TestServerTLSConfig1034=== RUN TestServerTLSConfig/no_client_CA1035=== PAUSE TestServerTLSConfig/no_client_CA1036=== RUN TestServerTLSConfig/missing_CA_file1037=== PAUSE TestServerTLSConfig/missing_CA_file1038=== RUN TestServerTLSConfig/not_a_PEM_file1039=== PAUSE TestServerTLSConfig/not_a_PEM_file1040=== CONT TestService_NativeMTLS1041--- PASS: TestReadProxyConditionalGet (0.62s)1042=== CONT TestMetricsCommit10432026/10/07 09:36:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10442026/10/07 09:36:01 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YTc3YzJhZjQtN2JhZi00Njc1LWIxNzktYzM0MzNkZWU2NGQxLjNhOWE4N2I0LWQxZGYtNGVhNS1hNzliLTAwNjUwNGUwNzJhOHgxNzkxMzY1NzYxMzM0MjU1NzEx parts=1210452026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures10462026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures10472026/10/07 09:36:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1048--- PASS: TestReadProxyHead (0.56s)1049=== CONT TestMetricsInventory1050--- PASS: TestReadProxyInvalidPath (0.55s)1051=== CONT TestNARDeduplicationMetadataUploadBug10522026/10/07 09:36:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10532026/10/07 09:36:01 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YTc3YzJhZjQtN2JhZi00Njc1LWIxNzktYzM0MzNkZWU2NGQxLmZjMmUzZWM1LTUwYzQtNDEyMi1hODM1LTljZWY1ZTY2MGVlMngxNzkxMzY1NzYxNDQ2MTY3MDU3 parts=1010542026/10/07 09:36:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10552026/10/07 09:36:01 INFO Completed upload id=1 objects=2 duration=6.124687ms10562026/10/07 09:36:01 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010572026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures10582026/10/07 09:36:01 INFO Starting cleanup of old closures method=DELETE path=/api/closures10592026/10/07 09:36:01 INFO Aborted multipart uploads count=0 kept=010602026/10/07 09:36:01 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YTc3YzJhZjQtN2JhZi00Njc1LWIxNzktYzM0MzNkZWU2NGQxLjdhM2FlZWY1LWNjMzAtNGY1Yi04M2Q5LTFhNDkyOTYyNDMwZHgxNzkxMzY1NzYxNDAxNjAyMTU5 parts=1210612026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures1062--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.27s)1063=== CONT TestCreatePendingClosureRejectsOversizedNAR10642026/10/07 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures1065--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1066=== CONT TestGCTaskStore_PhaseUpdates1067--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1068=== CONT TestGCTaskStore_CompletedAllowsNewTask1069--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1070=== CONT TestGCTaskStore_GetReturnsLatest1071--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1072=== CONT TestGCTaskStore_GetEmpty1073--- PASS: TestGCTaskStore_GetEmpty (0.00s)1074=== CONT TestGCTaskStore_ConflictDifferentParams1075--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1076=== CONT TestGCTaskStore_DeduplicateSameParams1077--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1078=== CONT TestLeadElectsOneAndHandsOver10792026/10/07 09:36:01 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=010802026/10/07 09:36:01 INFO Vacuumed table table=pending_closures10812026/10/07 09:36:01 INFO Vacuumed table table=pending_objects10822026/10/07 09:36:01 INFO Vacuumed table table=multipart_uploads1083--- PASS: TestReadProxy404 (0.56s)1084=== CONT TestGCEndsOnShutdown1085=== RUN TestGCEndsOnShutdown/before_the_run1086=== PAUSE TestGCEndsOnShutdown/before_the_run1087=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1088=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1089=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1090=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1091=== CONT TestCommitRacingPendingCleanupKeepsObjects10922026/10/07 09:36:01 INFO Vacuumed table table=closures10932026/10/07 09:36:01 INFO Vacuumed table table=objects1094--- PASS: TestReadProxyNarStreaming (0.49s)1095=== CONT TestPushWaitsForSweepHoldingRow10962026/10/07 09:36:01 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001097--- PASS: TestService_createPendingClosureHandler (1.31s)1098=== CONT TestSweepRechecksPendingAfterLocking1099--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.49s)1100=== CONT TestGetExistingObjectsLocksRows1101--- PASS: TestReadProxyContentNegotiation (0.55s)1102=== CONT TestRegisterCompletedObjectNeedsPendingRow1103--- PASS: TestPresentRefreshesOnlyStaleClosures (0.49s)1104=== CONT TestSweepSkipsRowsLockedByPush1105--- PASS: TestPresentReportsOnlyClosureRoots (0.45s)1106=== CONT TestFailedS3DeleteKeepsTombstone11072026/10/07 09:36:02 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1108--- PASS: TestReadProxyNarinfo (0.55s)1109=== CONT TestForceGCDuringPushOffersSweptObject1110=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1111=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1112=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1113=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1114=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1115--- PASS: TestObjectStatsTrigger (0.55s)1116=== CONT TestGCSweepDeliversEachKeyOnce11172026/10/07 09:36:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11182026/10/07 09:36:02 WARN Refused reserved pin name=worker-x86_64-linux11192026/10/07 09:36:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11202026/10/07 09:36:02 INFO Received create pin request method=POST path=/api/pins/my-app11212026/10/07 09:36:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1122--- PASS: TestCreatePin_ReservedPins (0.62s)1123=== CONT TestTombstonedObjectOfferedWithoutWaiting11242026/10/07 09:36:02 INFO Received uploads request method=POST path=/api/pending_closures11252026/10/07 09:36:02 INFO Received uploads request method=POST path=/api/pending_closures11262026/10/07 09:36:02 INFO Received uploads request method=POST path=/api/pending_closures11272026/10/07 09:36:02 INFO Received cleanup request method=DELETE path=/api/pending_closures11282026/10/07 09:36:02 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11292026/10/07 09:36:02 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1130--- PASS: TestService_NativeMTLS (0.57s)1131=== CONT TestGCSweepSkipsPendingObjects1132--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.59s)1133=== CONT TestGCTaskStore_Fail1134--- PASS: TestGCTaskStore_Fail (0.00s)1135=== CONT TestDeduplicatedObjectsRecordedAsPending11362026/10/07 09:36:02 INFO Received uploads request method=POST path=/api/pending_closures11372026/10/07 09:36:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11382026/10/07 09:36:02 INFO Received push request method=POST path=/api/pushes11392026/10/07 09:36:02 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTc3YzJhZjQtN2JhZi00Njc1LWIxNzktYzM0MzNkZWU2NGQxLjU3MzE4MDExLTllYjYtNDE1Ny04MmE0LTY2MTA4NDRmYzkxOXgxNzkxMzY1NzYxODU2Mjc0NjUw error="Get \"http://127.0.0.1:1/bucket12/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11402026/10/07 09:36:02 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTc3YzJhZjQtN2JhZi00Njc1LWIxNzktYzM0MzNkZWU2NGQxLmNiYjcwNmRmLWQyNWItNDBjZC05MWIyLWEzNWU1MmUzMGU5YngxNzkxMzY1NzYxODQ3Njc3MzU0 parts=1211412026/10/07 09:36:02 INFO Received cleanup request method=DELETE path=/api/pending_closures11422026/10/07 09:36:02 INFO Aborted multipart uploads count=1 kept=011432026/10/07 09:36:02 INFO Received complete push request method=POST path=/api/pushes/1/complete1144--- PASS: TestRedundantMultipartUpload (1.78s)1145=== CONT TestCacheConfigHandlerMaxNarSize1146--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1147=== CONT TestPushDedupSurvivesConcurrentGC11482026/10/07 09:36:02 INFO Completed push id=1 objects=4 duration=10.469455ms11492026/10/07 09:36:02 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11502026/10/07 09:36:02 INFO Completed upload id=2 objects=2 duration=1.73487ms1151--- PASS: TestMetricsCommit (0.64s)1152=== CONT TestGenerateLandingPage1153--- PASS: TestGenerateLandingPage (0.00s)1154=== CONT TestGCMetrics1155--- PASS: TestMetricsInventory (0.59s)1156=== CONT TestService_readinessHandler1157=== NAME TestOrphanedObjectsGC1158 orphaned_objects_gc_test.go:287: GC Test Summary:1159 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1160 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1161 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1162 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1163 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1164--- PASS: TestOrphanedObjectsGC (0.79s)1165=== CONT TestGCBugBareHashReferences11662026/10/07 09:36:02 INFO lead: acquired remote=192.0.2.1:123411672026/10/07 09:36:02 INFO Received cleanup request method=DELETE path=/api/pending_closures11682026/10/07 09:36:02 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket49/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11692026/10/07 09:36:02 INFO Aborted multipart uploads count=0 kept=111702026/10/07 09:36:02 INFO Received cleanup request method=DELETE path=/api/pending_closures11712026/10/07 09:36:02 INFO Aborted multipart uploads count=1 kept=01172=== NAME TestNARDeduplicationMetadataUploadBug1173 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2570400553/001/store/pivhcclhx9qhi0ra70yr918pfm5w4fdx-file1.txt1174--- PASS: TestMultipartCleanup (0.75s)1175=== CONT TestService_healthCheckHandler11762026/10/07 09:36:02 INFO Received uploads request method=POST path=/api/pending_closures11772026/10/07 09:36:02 INFO Aborted multipart uploads count=0 kept=011782026/10/07 09:36:02 WARN Force mode enabled - objects will be deleted immediately without grace period11792026/10/07 09:36:02 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=011802026/10/07 09:36:02 INFO Vacuumed table table=pending_closures11812026/10/07 09:36:02 INFO Vacuumed table table=pending_objects11822026/10/07 09:36:02 INFO Vacuumed table table=multipart_uploads11832026/10/07 09:36:02 INFO Vacuumed table table=closures11842026/10/07 09:36:02 INFO Vacuumed table table=objects1185--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.65s)1186=== CONT TestGCAdvisoryLockBlocksConcurrentRun11872026/10/07 09:36:02 INFO Aborted multipart uploads count=0 kept=011882026/10/07 09:36:02 WARN Force mode enabled - objects will be deleted immediately without grace period11892026/10/07 09:36:02 INFO Received push request method=POST path=/api/pushes11902026/10/07 09:36:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11912026/10/07 09:36:02 INFO Uploading pivhcclhx9qhi0ra70yr918pfm5w4fdx-file1.txt (160B)11922026/10/07 09:36:02 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"1193--- PASS: TestGetExistingObjectsLocksRows (0.61s)11942026/10/07 09:36:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1195=== CONT TestGracefulShutdownDrainsInflight11962026/10/07 09:36:02 WARN Failed to register uploaded object key=pivhcclhx9qhi0ra70yr918pfm5w4fdx.ls error="server returned 404: 404 page not found\n"11972026/10/07 09:36:02 INFO Starting HTTP server address=127.0.0.1:3378111982026/10/07 09:36:02 INFO Signed narinfos id=1 count=111992026/10/07 09:36:02 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=012002026/10/07 09:36:02 INFO Shutdown signal received, draining in-flight requests timeout=10s12012026/10/07 09:36:02 INFO Uploading 1 narinfos12022026/10/07 09:36:02 INFO Vacuumed table table=pending_closures12032026/10/07 09:36:02 INFO Received complete push request method=POST path=/api/pushes/1/complete12042026/10/07 09:36:02 WARN Failed to register uploaded object key=pivhcclhx9qhi0ra70yr918pfm5w4fdx.narinfo error="server returned 404: 404 page not found\n"12052026/10/07 09:36:02 INFO Vacuumed table table=pending_objects12062026/10/07 09:36:02 INFO Vacuumed table table=multipart_uploads12072026/10/07 09:36:02 INFO Vacuumed table table=closures12082026/10/07 09:36:02 INFO Vacuumed table table=objects1209--- PASS: TestSweepRechecksPendingAfterLocking (0.67s)1210=== CONT TestLeadEndsOnShutdown12112026/10/07 09:36:02 INFO Completed push id=1 objects=3 duration=8.943375ms12122026/10/07 09:36:02 INFO Upload complete. (75ms)1213--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.61s)1214=== CONT TestLeadIncumbentAnnouncesAtOnce1215=== NAME TestNARDeduplicationMetadataUploadBug1216 metadata_upload_test.go:54: Retrieved narinfo from S3:1217 StorePath: /build/TestNARDeduplicationMetadataUploadBug2570400553/001/store/pivhcclhx9qhi0ra70yr918pfm5w4fdx-file1.txt1218 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1219 Compression: zstd1220 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1221 NarSize: 1601222 References: 1223 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1224 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1225 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1226 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12272026/10/07 09:36:02 INFO Received uploads request method=POST path=/api/pending_closures1228--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1229=== CONT TestClientIntegration12302026/10/07 09:36:02 INFO Aborted multipart uploads count=0 kept=01231=== NAME TestNARDeduplicationMetadataUploadBug1232 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2570400553/001/store/qdw4631hlrw314d5s41cqzsgkhkl2bvf-file2.txt12332026/10/07 09:36:02 WARN Force mode enabled - objects will be deleted immediately without grace period12342026/10/07 09:36:02 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=012352026/10/07 09:36:02 INFO Vacuumed table table=pending_closures12362026/10/07 09:36:02 INFO Vacuumed table table=pending_objects12372026/10/07 09:36:02 INFO Vacuumed table table=multipart_uploads12382026/10/07 09:36:02 INFO Vacuumed table table=closures12392026/10/07 09:36:02 INFO Vacuumed table table=objects12402026/10/07 09:36:02 INFO Received uploads request method=POST path=/api/pending_closures12412026/10/07 09:36:02 INFO Aborted multipart uploads count=0 kept=012422026/10/07 09:36:02 WARN Force mode enabled - objects will be deleted immediately without grace period12432026/10/07 09:36:02 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=012442026/10/07 09:36:02 INFO Vacuumed table table=pending_closures12452026/10/07 09:36:02 INFO Vacuumed table table=pending_objects12462026/10/07 09:36:02 INFO Vacuumed table table=multipart_uploads12472026/10/07 09:36:02 INFO Vacuumed table table=closures12482026/10/07 09:36:02 INFO Vacuumed table table=objects1249--- PASS: TestSweepSkipsRowsLockedByPush (0.66s)1250=== CONT TestConnectWaitsForAPeerMigration12512026/10/07 09:36:02 INFO Aborted multipart uploads count=0 kept=012522026/10/07 09:36:02 INFO Received uploads request method=POST path=/api/pending_closures12532026/10/07 09:36:02 WARN Force mode enabled - objects will be deleted immediately without grace period1254--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.50s)1255=== CONT TestService_ReadScope_PublicByDefault12562026/10/07 09:36:02 INFO Aborted multipart uploads count=0 kept=012572026/10/07 09:36:02 WARN Force mode enabled - objects will be deleted immediately without grace period12582026/10/07 09:36:02 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=012592026/10/07 09:36:02 INFO Vacuumed table table=pending_closures12602026/10/07 09:36:02 INFO Vacuumed table table=pending_objects12612026/10/07 09:36:02 INFO Vacuumed table table=multipart_uploads12622026/10/07 09:36:02 INFO Vacuumed table table=closures12632026/10/07 09:36:02 INFO Vacuumed table table=objects12642026/10/07 09:36:02 INFO Received push request method=POST path=/api/pushes1265--- PASS: TestGCSweepDeliversEachKeyOnce (0.53s)1266=== CONT TestResolveDBConnectionString1267=== RUN TestResolveDBConnectionString/flag_wins12682026/10/07 09:36:02 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."1269=== PAUSE TestResolveDBConnectionString/flag_wins12702026/10/07 09:36:02 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1271=== RUN TestResolveDBConnectionString/file_when_flag_empty1272=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1273=== RUN TestResolveDBConnectionString/missing_file_is_an_error1274=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1275=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1276=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1277=== RUN TestResolveDBConnectionString/nothing_configured1278=== PAUSE TestResolveDBConnectionString/nothing_configured1279=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12802026/10/07 09:36:02 INFO Received uploads request method=POST path=/api/pending_closures12812026/10/07 09:36:02 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1282--- PASS: TestFailedS3DeleteKeepsTombstone (0.69s)1283=== CONT TestDeleteClosuresRacingPins12842026/10/07 09:36:02 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12852026/10/07 09:36:02 INFO Signed narinfos id=2 count=112862026/10/07 09:36:02 INFO Uploading 1 narinfos12872026/10/07 09:36:02 WARN Failed to register uploaded object key=qdw4631hlrw314d5s41cqzsgkhkl2bvf.ls error="server returned 404: 404 page not found\n"1288--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.45s)1289=== CONT TestClientErrorHandling1290=== RUN TestClientErrorHandling/InvalidStorePath1291=== PAUSE TestClientErrorHandling/InvalidStorePath1292=== RUN TestClientErrorHandling/InvalidAuthToken1293=== PAUSE TestClientErrorHandling/InvalidAuthToken1294=== RUN TestClientErrorHandling/ServerNotAvailable1295=== PAUSE TestClientErrorHandling/ServerNotAvailable1296=== CONT TestClientFallsBackToClosures12972026/10/07 09:36:02 INFO Received complete push request method=POST path=/api/pushes/2/complete12982026/10/07 09:36:02 WARN Failed to register uploaded object key=qdw4631hlrw314d5s41cqzsgkhkl2bvf.narinfo error="server returned 404: 404 page not found\n"12992026/10/07 09:36:02 INFO Completed push id=2 objects=3 duration=2.187259ms13002026/10/07 09:36:02 INFO Upload complete. (77ms)1301=== NAME TestNARDeduplicationMetadataUploadBug1302 metadata_upload_test.go:76: Retrieved narinfo from S3:1303 StorePath: /build/TestNARDeduplicationMetadataUploadBug2570400553/001/store/qdw4631hlrw314d5s41cqzsgkhkl2bvf-file2.txt1304 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1305 Compression: zstd1306 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1307 NarSize: 1601308 References: 1309 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1310 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1311 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1312 {"version":1,"root":{"type":"regular","size":44}}13132026/10/07 09:36:02 INFO Received uploads request method=POST path=/api/pending_closures1314--- PASS: TestNARDeduplicationMetadataUploadBug (0.92s)1315=== CONT TestClientCADerivations13162026/10/07 09:36:02 INFO Aborted multipart uploads count=0 kept=013172026/10/07 09:36:02 WARN Force mode enabled - objects will be deleted immediately without grace period13182026/10/07 09:36:02 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=013192026/10/07 09:36:02 INFO Vacuumed table table=pending_closures13202026/10/07 09:36:02 INFO Vacuumed table table=pending_objects13212026/10/07 09:36:02 INFO Vacuumed table table=multipart_uploads13222026/10/07 09:36:02 INFO Vacuumed table table=closures13232026/10/07 09:36:02 INFO Received uploads request method=POST path=/api/pending_closures13242026/10/07 09:36:02 INFO Vacuumed table table=objects13252026/10/07 09:36:02 INFO Aborted multipart uploads count=0 kept=013262026/10/07 09:36:02 WARN Force mode enabled - objects will be deleted immediately without grace period1327--- PASS: TestGCSweepSkipsPendingObjects (0.53s)1328=== CONT TestClientPushesUseOnePush13292026/10/07 09:36:02 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=013302026/10/07 09:36:02 INFO Vacuumed table table=pending_closures13312026/10/07 09:36:02 INFO Vacuumed table table=pending_objects13322026/10/07 09:36:02 INFO Vacuumed table table=multipart_uploads13332026/10/07 09:36:02 INFO Vacuumed table table=closures13342026/10/07 09:36:02 INFO Vacuumed table table=objects1335--- PASS: TestGCMetrics (0.43s)1336=== CONT TestCacheStatsHandler13372026/10/07 09:36:02 WARN readiness check failed error="closed pool"1338--- PASS: TestService_readinessHandler (0.45s)1339=== CONT TestPinProtectsFromGC1340--- PASS: TestService_healthCheckHandler (0.40s)1341=== CONT TestCacheConfigHandler1342=== RUN TestCacheConfigHandler/full_config,_no_issuer1343=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1344=== RUN TestCacheConfigHandler/no_cache_url_configured1345=== PAUSE TestCacheConfigHandler/no_cache_url_configured1346=== RUN TestCacheConfigHandler/no_signing_keys1347=== PAUSE TestCacheConfigHandler/no_signing_keys1348=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1349=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1350=== CONT TestClientSharedPathCommittedMidPush1351--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.81s)1352=== CONT TestClientWithDependencies13532026/10/07 09:36:02 INFO Aborted multipart uploads count=0 kept=013542026/10/07 09:36:02 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=013552026/10/07 09:36:02 INFO Vacuumed table table=pending_closures13562026/10/07 09:36:02 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"1357--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.37s)1358=== CONT TestClientMultipleUploads13592026/10/07 09:36:02 INFO Vacuumed table table=pending_objects13602026/10/07 09:36:02 INFO Vacuumed table table=multipart_uploads13612026/10/07 09:36:02 INFO Vacuumed table table=closures13622026/10/07 09:36:02 INFO Vacuumed table table=objects13632026/10/07 09:36:02 INFO lead: acquired remote=192.0.2.1:123413642026/10/07 09:36:02 INFO lead: released remote=192.0.2.1:12341365--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.34s)1366=== CONT TestService_ReadAuthMiddleware13672026/10/07 09:36:02 INFO Aborted multipart uploads count=0 kept=013682026/10/07 09:36:02 WARN Force mode enabled - objects will be deleted immediately without grace period13692026/10/07 09:36:02 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=013702026/10/07 09:36:02 INFO Vacuumed table table=pending_closures13712026/10/07 09:36:02 INFO lead: acquired remote=192.0.2.1:123413722026/10/07 09:36:02 INFO Vacuumed table table=pending_objects13732026/10/07 09:36:02 INFO Vacuumed table table=multipart_uploads13742026/10/07 09:36:02 INFO Vacuumed table table=closures13752026/10/07 09:36:02 INFO Vacuumed table table=objects1376--- PASS: TestPushDedupSurvivesConcurrentGC (0.56s)1377=== CONT TestService_RequireScope_OIDC1378--- PASS: TestService_ReadScope_PublicByDefault (0.27s)1379=== CONT TestService_AuthMiddleware_OIDC1380--- PASS: TestPushWaitsForSweepHoldingRow (1.10s)1381=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1382=== NAME TestClientIntegration1383 client_integration_test.go:286: Created store path: /build/TestClientIntegration1494998533/002/store/n6j5m8hpkdval8gk0kab8px1hfv3nhwc-test-file.txt13842026/10/07 09:36:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36099/oidc13852026/10/07 09:36:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45003/oidc1386--- PASS: TestGCBugBareHashReferences (0.68s)1387=== CONT TestService_AuthMiddleware_MTLSProxyHeader13882026/10/07 09:36:03 INFO Received push request method=POST path=/api/pushes13892026/10/07 09:36:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13902026/10/07 09:36:03 INFO Uploading n6j5m8hpkdval8gk0kab8px1hfv3nhwc-test-file.txt (152B)13912026/10/07 09:36:03 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13922026/10/07 09:36:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13932026/10/07 09:36:03 WARN Failed to register uploaded object key=n6j5m8hpkdval8gk0kab8px1hfv3nhwc.ls error="server returned 404: 404 page not found\n"13942026/10/07 09:36:03 INFO Signed narinfos id=1 count=113952026/10/07 09:36:03 INFO Uploading 1 narinfos13962026/10/07 09:36:03 INFO Received complete push request method=POST path=/api/pushes/1/complete13972026/10/07 09:36:03 WARN Failed to register uploaded object key=n6j5m8hpkdval8gk0kab8px1hfv3nhwc.narinfo error="server returned 404: 404 page not found\n"13982026/10/07 09:36:03 INFO Completed push id=1 objects=3 duration=9.316735ms13992026/10/07 09:36:03 INFO Upload complete. (65ms)1400--- PASS: TestCacheStatsHandler (0.32s)1401=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14022026/10/07 09:36:03 INFO Received uploads request method=POST path=/1403=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14042026/10/07 09:36:03 INFO Received request for more parts method=POST path=/1405=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14062026/10/07 09:36:03 INFO Received uploads request method=POST path=/1407=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14082026/10/07 09:36:03 INFO Received complete multipart upload request method=POST path=/1409--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1410 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1411 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1412 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1413 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1414=== CONT TestPendingClosureWriteTimeout/empty1415=== CONT TestPendingClosureWriteTimeout/400_objects1416=== CONT TestPendingClosureWriteTimeout/670k_objects1417=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline14182026/10/07 09:36:03 INFO All 1 paths already cached1419=== NAME TestClientIntegration1420 client_integration_test.go:312: Retrieved narinfo from S3:1421 StorePath: /build/TestClientIntegration1494998533/002/store/n6j5m8hpkdval8gk0kab8px1hfv3nhwc-test-file.txt1422 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1423 Compression: zstd1424 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11425 NarSize: 1521426 References: 1427 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11428 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1429 client_integration_test.go:313: Decompressed .ls content (64 bytes):1430 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1431 client_integration_test.go:316: Testing garbage collection...1432=== NAME TestClientCADerivations1433 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4030572674/001/store/xrpimc65l1hzqhy7jnf5lngvc9ml41ms-ca-test14342026/10/07 09:36:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures14352026/10/07 09:36:03 INFO Garbage collection started14362026/10/07 09:36:03 INFO Aborted multipart uploads count=0 kept=014372026/10/07 09:36:03 WARN Force mode enabled - objects will be deleted immediately without grace period1438 client_ca_test.go:139: Found 1 dependencies (including self)14392026/10/07 09:36:03 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=014402026/10/07 09:36:03 INFO Vacuumed table table=pending_closures1441=== NAME TestPinProtectsFromGC1442 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3397462851/001/store/9linyh1nk13l8rvva5mya5z7x63vr1cc-pinned-file.txt1443 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3397462851/001/store/7cm5nafs6z87pcs9i1vc8b19vf8i49n9-unpinned-file.txt14442026/10/07 09:36:03 INFO Vacuumed table table=pending_objects14452026/10/07 09:36:03 INFO Vacuumed table table=multipart_uploads14462026/10/07 09:36:03 INFO Vacuumed table table=closures14472026/10/07 09:36:03 INFO Vacuumed table table=objects14482026/10/07 09:36:03 INFO Received uploads request method=POST path=/api/pending_closures14492026/10/07 09:36:03 INFO Received uploads request method=POST path=/api/pending_closures1450--- PASS: TestService_ReadAuthMiddleware (0.35s)1451=== CONT TestProxyWriteTimeout/narinfo1452=== CONT TestProxyWriteTimeout/unknown_size1453=== CONT TestProxyWriteTimeout/1_GiB_nar1454=== CONT TestProxyWriteTimeout/10_GiB_nar1455--- PASS: TestProxyWriteTimeout (0.09s)1456 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1457 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1458 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1459 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)14602026/10/07 09:36:03 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)1461=== CONT TestIsValidUploadKey/narinfo14622026/10/07 09:36:03 INFO Uploading dlisrc8xi64ssm0983bny6hq4qlm434v-shared-dep (136B)1463=== CONT TestIsValidUploadKey/absolute14642026/10/07 09:36:03 INFO Uploading pn6wfzm6gwwzvzsph6pfmmxrsg3b4i11-a (216B)1465=== CONT TestIsValidUploadKey/traversal_nar1466=== CONT TestIsValidUploadKey/traversal1467=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1468=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1469=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1470=== CONT TestIsValidUploadKey/index.html1471=== CONT TestIsValidUploadKey/nix-cache-info1472=== CONT TestIsValidUploadKey/realisation_plus_in_output1473=== CONT TestIsValidUploadKey/realisation1474=== CONT TestIsValidUploadKey/build_log_equals1475=== CONT TestIsValidUploadKey/build_log_question_mark1476=== CONT TestIsValidUploadKey/build_log_plus_in_name1477=== CONT TestIsValidUploadKey/build_log_home-manager_file1478=== CONT TestIsValidUploadKey/build_log1479=== CONT TestIsValidUploadKey/empty_key1480=== CONT TestIsValidUploadKey/listing1481=== CONT TestIsValidUploadKey/nar_zst1482=== CONT TestIsValidUploadKey/nar_plain1483=== CONT TestIsValidUploadKey/unknown_type1484=== CONT TestIsValidUploadKey/nar_xz1485--- PASS: TestIsValidUploadKey (0.09s)1486 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1487 --- PASS: TestIsValidUploadKey/absolute (0.00s)1488 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1489 --- PASS: TestIsValidUploadKey/traversal (0.00s)1490 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1491 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1492 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1493 --- PASS: TestIsValidUploadKey/index.html (0.00s)1494 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1495 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1496 --- PASS: TestIsValidUploadKey/realisation (0.00s)1497 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1498 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1499 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1500 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1501 --- PASS: TestIsValidUploadKey/build_log (0.00s)1502 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1503 --- PASS: TestIsValidUploadKey/listing (0.00s)1504 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1505 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1506 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1507 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1508=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15092026/10/07 09:36:03 INFO Received uploads request method=POST path=/15102026/10/07 09:36:03 WARN Failed to register uploaded object key=123y8gblz2rcxva04cyqhw6hz4213sr0.ls error="server returned 404: 404 page not found\n"15112026/10/07 09:36:03 WARN Failed to register uploaded object key=nar/1pbby0sjkf5j5i9pv1w7iz50gv6j0f2l3r6787xlqpqz3wqcp8p2.nar.zst error="server returned 404: 404 page not found\n"15122026/10/07 09:36:03 WARN Failed to register uploaded object key=pn6wfzm6gwwzvzsph6pfmmxrsg3b4i11.ls error="server returned 404: 404 page not found\n"15132026/10/07 09:36:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15142026/10/07 09:36:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15152026/10/07 09:36:03 WARN Failed to register uploaded object key=dlisrc8xi64ssm0983bny6hq4qlm434v.ls error="server returned 404: 404 page not found\n"15162026/10/07 09:36:03 INFO Signed narinfos id=1 count=215172026/10/07 09:36:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15182026/10/07 09:36:03 INFO Signed narinfos id=2 count=215192026/10/07 09:36:03 INFO Uploading 4 narinfos15202026/10/07 09:36:03 WARN Failed to register uploaded object key=123y8gblz2rcxva04cyqhw6hz4213sr0.narinfo error="server returned 404: 404 page not found\n"15212026/10/07 09:36:03 WARN Failed to register uploaded object key=pn6wfzm6gwwzvzsph6pfmmxrsg3b4i11.narinfo error="server returned 404: 404 page not found\n"15222026/10/07 09:36:03 WARN Failed to register uploaded object key=dlisrc8xi64ssm0983bny6hq4qlm434v.narinfo error="server returned 404: 404 page not found\n"15232026/10/07 09:36:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15242026/10/07 09:36:03 WARN Failed to register uploaded object key=dlisrc8xi64ssm0983bny6hq4qlm434v.narinfo error="server returned 404: 404 page not found\n"1525=== NAME TestClientMultipleUploads1526 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1796172854/001/store/d8psciy919528kyilkw3pmsjmxih6jic-test-file-0.txt1527--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.55s)15282026/10/07 09:36:03 INFO Completed upload id=2 objects=6 duration=4.735778ms1529=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15302026/10/07 09:36:03 INFO Received request for more parts method=POST path=/15312026/10/07 09:36:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15322026/10/07 09:36:03 INFO Completed upload id=1 objects=6 duration=763.76µs15332026/10/07 09:36:03 INFO Upload complete. (69ms)15342026/10/07 09:36:03 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15352026/10/07 09:36:03 WARN mTLS auth: bound subjects configured but subject DN unavailable1536=== NAME TestClientFallsBackToClosures15372026/10/07 09:36:03 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1538 client_pushes_test.go:112: Retrieved narinfo from S3:1539 StorePath: /build/TestClientFallsBackToClosures2397154987/001/store/dlisrc8xi64ssm0983bny6hq4qlm434v-shared-dep1540 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1541 Compression: zstd1542 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821543 NarSize: 1361544 References: 1545 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1546--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.28s)1547=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15482026/10/07 09:36:03 INFO Received complete multipart upload request method=POST path=/15492026/10/07 09:36:03 INFO Received push request method=POST path=/api/pushes1550=== NAME TestClientFallsBackToClosures1551 client_pushes_test.go:112: Retrieved narinfo from S3:1552 StorePath: /build/TestClientFallsBackToClosures2397154987/001/store/pn6wfzm6gwwzvzsph6pfmmxrsg3b4i11-a1553 URL: nar/1pbby0sjkf5j5i9pv1w7iz50gv6j0f2l3r6787xlqpqz3wqcp8p2.nar.zst1554 Compression: zstd1555 NarHash: sha256:1pbby0sjkf5j5i9pv1w7iz50gv6j0f2l3r6787xlqpqz3wqcp8p21556 NarSize: 2161557 References: /build/TestClientFallsBackToClosures2397154987/001/store/dlisrc8xi64ssm0983bny6hq4qlm434v-shared-dep1558 CA: text:sha256:1mldllmfg4rxb3jmihl1akazvc850vgqmvlbdrmkpq8yw0grvz5515592026/10/07 09:36:03 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)1560 client_pushes_test.go:112: Retrieved narinfo from S3:15612026/10/07 09:36:03 INFO Uploading wbxmnzmr2m8rzmxhcc3mwifqdasjinbk-shared-dep (136B)1562 StorePath: /build/TestClientFallsBackToClosures2397154987/001/store/123y8gblz2rcxva04cyqhw6hz4213sr0-b1563 URL: nar/1pbby0sjkf5j5i9pv1w7iz50gv6j0f2l3r6787xlqpqz3wqcp8p2.nar.zst15642026/10/07 09:36:03 INFO Uploading w590fkk3fhv8wfk6zigzid2n906137wa-a (208B)1565 Compression: zstd1566 NarHash: sha256:1pbby0sjkf5j5i9pv1w7iz50gv6j0f2l3r6787xlqpqz3wqcp8p21567 NarSize: 2161568 References: /build/TestClientFallsBackToClosures2397154987/001/store/dlisrc8xi64ssm0983bny6hq4qlm434v-shared-dep1569 CA: text:sha256:1mldllmfg4rxb3jmihl1akazvc850vgqmvlbdrmkpq8yw0grvz5515702026/10/07 09:36:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15712026/10/07 09:36:03 WARN Failed to register uploaded object key=nar/0xsisi4gmja6nx8g50gniqpfvw0b0zc2plfnv4mnsz450s7k5gx4.nar.zst error="server returned 404: 404 page not found\n"1572--- PASS: TestClientFallsBackToClosures (0.55s)1573=== CONT TestPush_RejectsBadRequests/no_roots15742026/10/07 09:36:03 WARN Failed to register uploaded object key=jd5v73p7blyqvqxaymz72lh4kb80fkgg.ls error="server returned 404: 404 page not found\n"15752026/10/07 09:36:03 INFO Received push request method=POST path=/api/pushes1576=== CONT TestPush_RejectsBadRequests/no_objects15772026/10/07 09:36:03 INFO Received push request method=POST path=/api/pushes1578=== CONT TestPush_RejectsBadRequests/bad_root15792026/10/07 09:36:03 INFO Received push request method=POST path=/api/pushes1580=== CONT TestPush_RejectsBadRequests/root_not_in_objects15812026/10/07 09:36:03 INFO Received push request method=POST path=/api/pushes1582=== CONT TestIsValidCachePath/narinfo1583=== CONT TestIsValidCachePath/index.html1584=== CONT TestIsValidCachePath/short_hash1585=== CONT TestIsValidCachePath/wrong_extension1586=== CONT TestIsValidCachePath/leading_slash1587--- PASS: TestPush_RejectsBadRequests (0.82s)1588 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1589 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1590 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1591 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)15922026/10/07 09:36:03 WARN Failed to register uploaded object key=wbxmnzmr2m8rzmxhcc3mwifqdasjinbk.ls error="server returned 404: 404 page not found\n"1593=== CONT TestIsValidCachePath/empty1594=== CONT TestIsValidCachePath/random_path1595=== CONT TestIsValidCachePath/invalid_char_u1596=== CONT TestIsValidCachePath/invalid_char_e1597=== CONT TestIsValidCachePath/traversal_in_middle1598=== CONT TestIsValidCachePath/traversal_parent1599=== CONT TestIsValidCachePath/nar_uncompressed16002026/10/07 09:36:03 WARN Failed to register uploaded object key=w590fkk3fhv8wfk6zigzid2n906137wa.ls error="server returned 404: 404 page not found\n"1601=== CONT TestIsValidCachePath/nix-cache-info16022026/10/07 09:36:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1603=== CONT TestIsValidCachePath/realisation1604=== CONT TestIsValidCachePath/log1605=== CONT TestIsValidCachePath/ls1606=== CONT TestIsValidCachePath/nar_xz1607=== CONT TestIsValidCachePath/nar_bz21608=== CONT TestIsValidCachePath/nar_zst1609=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1610--- PASS: TestIsValidCachePath (0.00s)1611 --- PASS: TestIsValidCachePath/narinfo (0.00s)1612 --- PASS: TestIsValidCachePath/index.html (0.00s)1613 --- PASS: TestIsValidCachePath/short_hash (0.00s)1614 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1615 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1616 --- PASS: TestIsValidCachePath/empty (0.00s)1617 --- PASS: TestIsValidCachePath/random_path (0.00s)1618 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1619 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1620 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1621 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1622 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1623 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1624 --- PASS: TestIsValidCachePath/realisation (0.00s)1625 --- PASS: TestIsValidCachePath/log (0.00s)1626 --- PASS: TestIsValidCachePath/ls (0.00s)1627 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1628 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1629 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1630 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)16312026/10/07 09:36:03 INFO Signed narinfos id=1 count=31632=== CONT TestParseSingleRange/none1633=== CONT TestParseSingleRange/open-ended1634=== CONT TestParseSingleRange/start_far_past_EOF1635=== CONT TestParseSingleRange/start_past_EOF16362026/10/07 09:36:03 INFO Uploading 3 narinfos1637=== CONT TestParseSingleRange/single_byte1638=== CONT TestParseSingleRange/suffix_exceeds_size1639=== CONT TestParseSingleRange/suffix1640=== CONT TestParseSingleRange/end_clamped_to_size1641=== CONT TestParseSingleRange/closed1642=== CONT TestParseSingleRange/malformed_end_before_start1643=== CONT TestParseSingleRange/malformed_both_empty1644=== CONT TestParseSingleRange/multi-range_ignored1645=== CONT TestParseSingleRange/unknown_unit1646=== CONT TestParseSingleRange/malformed_no_dash1647--- PASS: TestParseSingleRange (0.00s)1648 --- PASS: TestParseSingleRange/none (0.00s)1649 --- PASS: TestParseSingleRange/open-ended (0.00s)1650 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1651 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1652 --- PASS: TestParseSingleRange/single_byte (0.00s)1653 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1654 --- PASS: TestParseSingleRange/suffix (0.00s)1655 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1656 --- PASS: TestParseSingleRange/closed (0.00s)1657 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1658 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1659 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1660 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1661 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1662=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh16632026/10/07 09:36:03 WARN Failed to register uploaded object key=wbxmnzmr2m8rzmxhcc3mwifqdasjinbk.narinfo error="server returned 404: 404 page not found\n"16642026/10/07 09:36:03 WARN Failed to register uploaded object key=jd5v73p7blyqvqxaymz72lh4kb80fkgg.narinfo error="server returned 404: 404 page not found\n"1665=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1666=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1667=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1668=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1669=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1670=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1671=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1672=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1673=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1674=== NAME TestClientWithDependencies1675 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1576936779/001/store/vrwxdpnpg1p03x5f4svdlk0d67ljnhww-test-script16762026/10/07 09:36:03 INFO Received complete push request method=POST path=/api/pushes/1/complete16772026/10/07 09:36:03 WARN Failed to register uploaded object key=w590fkk3fhv8wfk6zigzid2n906137wa.narinfo error="server returned 404: 404 page not found\n"16782026/10/07 09:36:03 INFO Completed push id=1 objects=8 duration=4.729617ms16792026/10/07 09:36:03 INFO Upload complete. (59ms)1680=== NAME TestClientPushesUseOnePush1681 client_pushes_test.go:97: Retrieved narinfo from S3:1682 StorePath: /build/TestClientPushesUseOnePush762675434/001/store/wbxmnzmr2m8rzmxhcc3mwifqdasjinbk-shared-dep1683 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1684 Compression: zstd1685 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821686 NarSize: 1361687 References: 1688 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1689 client_pushes_test.go:97: Retrieved narinfo from S3:1690 StorePath: /build/TestClientPushesUseOnePush762675434/001/store/w590fkk3fhv8wfk6zigzid2n906137wa-a1691 URL: nar/0xsisi4gmja6nx8g50gniqpfvw0b0zc2plfnv4mnsz450s7k5gx4.nar.zst1692 Compression: zstd1693 NarHash: sha256:0xsisi4gmja6nx8g50gniqpfvw0b0zc2plfnv4mnsz450s7k5gx41694 NarSize: 2081695 References: /build/TestClientPushesUseOnePush762675434/001/store/wbxmnzmr2m8rzmxhcc3mwifqdasjinbk-shared-dep1696 CA: text:sha256:1sgjr9p915h119il8dva6ylp99ga58s155srmx7m4hlcvbclfk0s1697 client_pushes_test.go:97: Retrieved narinfo from S3:1698 StorePath: /build/TestClientPushesUseOnePush762675434/001/store/jd5v73p7blyqvqxaymz72lh4kb80fkgg-b1699 URL: nar/0xsisi4gmja6nx8g50gniqpfvw0b0zc2plfnv4mnsz450s7k5gx4.nar.zst1700 Compression: zstd1701 NarHash: sha256:0xsisi4gmja6nx8g50gniqpfvw0b0zc2plfnv4mnsz450s7k5gx41702 NarSize: 2081703 References: /build/TestClientPushesUseOnePush762675434/001/store/wbxmnzmr2m8rzmxhcc3mwifqdasjinbk-shared-dep1704 CA: text:sha256:1sgjr9p915h119il8dva6ylp99ga58s155srmx7m4hlcvbclfk0s1705=== NAME TestClientMultipleUploads1706 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1796172854/001/store/sjhvyckj8w4zwdnz2kvzl79vmchlgbyv-test-file-1.txt1707--- PASS: TestClientPushesUseOnePush (0.50s)1708=== CONT TestServerTLSConfig/no_client_CA1709=== CONT TestServerTLSConfig/not_a_PEM_file1710=== CONT TestServerTLSConfig/missing_CA_file1711=== CONT TestGCEndsOnShutdown/before_the_run1712--- PASS: TestServerTLSConfig (0.00s)1713 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1714 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1715 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1716--- PASS: TestObjectStatsLargeCommit (1.69s)1717=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark17182026/10/07 09:36:03 INFO Received push request method=POST path=/api/pushes17192026/10/07 09:36:03 INFO Received push request method=POST path=/api/pushes1720=== RUN TestService_RequireScope_OIDC/builder_may_write1721=== PAUSE TestService_RequireScope_OIDC/builder_may_write1722=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1723=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1724=== RUN TestService_RequireScope_OIDC/ops_may_admin1725=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1726=== RUN TestService_RequireScope_OIDC/ops_may_not_write1727=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1728=== RUN TestService_RequireScope_OIDC/reader_may_not_write1729=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1730=== RUN TestService_RequireScope_OIDC/static_token_may_admin1731=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1732=== RUN TestService_RequireScope_OIDC/static_token_may_write1733=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1734=== RUN TestService_RequireScope_OIDC/reader_may_read1735=== PAUSE TestService_RequireScope_OIDC/reader_may_read1736=== RUN TestService_RequireScope_OIDC/writer_implies_read1737=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1738=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1739=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1740=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1741=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1742=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1743=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1744=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1745=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1746=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1747=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1748=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17492026/10/07 09:36:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17502026/10/07 09:36:03 INFO Uploading xrpimc65l1hzqhy7jnf5lngvc9ml41ms-ca-test (144B)17512026/10/07 09:36:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17522026/10/07 09:36:03 INFO Uploading 9linyh1nk13l8rvva5mya5z7x63vr1cc-pinned-file.txt (128B)1753=== NAME TestClientWithDependencies1754 client_integration_test.go:615: Found 1 dependencies (including self)17552026/10/07 09:36:03 WARN Failed to register uploaded object key=xrpimc65l1hzqhy7jnf5lngvc9ml41ms.ls error="server returned 404: 404 page not found\n"17562026/10/07 09:36:03 WARN Failed to register uploaded object key=log/a7cr7219xi9b0s28m9zg1hjqrp22cziw-ca-test.drv error="server returned 404: 404 page not found\n"17572026/10/07 09:36:03 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17582026/10/07 09:36:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17592026/10/07 09:36:03 INFO Signed narinfos id=1 count=117602026/10/07 09:36:03 INFO Uploading 1 narinfos17612026/10/07 09:36:03 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17622026/10/07 09:36:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17632026/10/07 09:36:03 WARN Failed to register uploaded object key=9linyh1nk13l8rvva5mya5z7x63vr1cc.ls error="server returned 404: 404 page not found\n"17642026/10/07 09:36:03 INFO Signed narinfos id=1 count=117652026/10/07 09:36:03 INFO Uploading 1 narinfos17662026/10/07 09:36:03 INFO Received complete push request method=POST path=/api/pushes/1/complete17672026/10/07 09:36:03 WARN Failed to register uploaded object key=xrpimc65l1hzqhy7jnf5lngvc9ml41ms.narinfo error="server returned 404: 404 page not found\n"1768--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.26s)1769=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1770=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17712026/10/07 09:36:03 INFO Received complete push request method=POST path=/api/pushes/1/complete17722026/10/07 09:36:03 WARN Failed to register uploaded object key=9linyh1nk13l8rvva5mya5z7x63vr1cc.narinfo error="server returned 404: 404 page not found\n"17732026/10/07 09:36:03 INFO Completed push id=1 objects=4 duration=11.376285ms17742026/10/07 09:36:03 INFO Upload complete. (100ms)1775=== NAME TestClientMultipleUploads17762026/10/07 09:36:03 INFO Received push request method=POST path=/api/pushes1777 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1796172854/001/store/29qmy7lcgfnidnxigcgpc5gf7r8qykzk-test-file-2.txt1778=== CONT TestResolveDBConnectionString/flag_wins1779=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1780=== CONT TestResolveDBConnectionString/nothing_configured1781=== CONT TestResolveDBConnectionString/missing_file_is_an_error1782=== CONT TestResolveDBConnectionString/file_when_flag_empty1783=== CONT TestClientErrorHandling/InvalidStorePath1784--- PASS: TestResolveDBConnectionString (0.00s)1785 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1786 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1787 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1788 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1789 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1790=== NAME TestClientCADerivations1791 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4030572674/001/store/xrpimc65l1hzqhy7jnf5lngvc9ml41ms-ca-test1792 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1793 Compression: zstd1794 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1795 NarSize: 1441796 References: 1797 Deriver: /build/TestClientCADerivations4030572674/001/store/a7cr7219xi9b0s28m9zg1hjqrp22cziw-ca-test.drv1798 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1799 client_ca_test.go:185: Checking for realisation files in S3...1800 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1801 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache18022026/10/07 09:36:03 INFO Completed push id=1 objects=3 duration=13.048943ms18032026/10/07 09:36:03 INFO Upload complete. (90ms)18042026/10/07 09:36:03 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)18052026/10/07 09:36:03 INFO Uploading lg23hf47db5yj7m5wgd3pbsqz3f6ikdj-shared-dep (136B)18062026/10/07 09:36:03 INFO Uploading hcvzhjy9phrnvanc7fgj1cmqcwgla5nb-top (224B)18072026/10/07 09:36:03 WARN Failed to register uploaded object key=lg23hf47db5yj7m5wgd3pbsqz3f6ikdj.ls error="server returned 404: 404 page not found\n"18082026/10/07 09:36:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18092026/10/07 09:36:03 WARN Failed to register uploaded object key=hcvzhjy9phrnvanc7fgj1cmqcwgla5nb.ls error="server returned 404: 404 page not found\n"18102026/10/07 09:36:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18112026/10/07 09:36:03 WARN Failed to register uploaded object key=nar/0py97d02ma6ksf2s4mnxmm0729v6045yma452bz1vj8jb2371hgx.nar.zst error="server returned 404: 404 page not found\n"18122026/10/07 09:36:03 INFO Signed narinfos id=1 count=218132026/10/07 09:36:03 INFO Uploading 2 narinfos18142026/10/07 09:36:03 INFO Received complete push request method=POST path=/api/pushes/1/complete18152026/10/07 09:36:03 WARN Failed to register uploaded object key=lg23hf47db5yj7m5wgd3pbsqz3f6ikdj.narinfo error="server returned 404: 404 page not found\n"18162026/10/07 09:36:03 WARN Failed to register uploaded object key=hcvzhjy9phrnvanc7fgj1cmqcwgla5nb.narinfo error="server returned 404: 404 page not found\n"18172026/10/07 09:36:03 INFO Received uploads request method=POST path=/api/pending_closures18182026/10/07 09:36:03 INFO Completed push id=1 objects=6 duration=19.6434ms18192026/10/07 09:36:03 INFO Upload complete. (80ms)1820=== NAME TestClientSharedPathCommittedMidPush1821 client_integration_test.go:680: Retrieved narinfo from S3:1822 StorePath: /build/TestClientSharedPathCommittedMidPush3694394140/001/store/lg23hf47db5yj7m5wgd3pbsqz3f6ikdj-shared-dep1823 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1824 Compression: zstd1825 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821826 NarSize: 1361827 References: 1828 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1829 client_integration_test.go:680: Retrieved narinfo from S3:1830 StorePath: /build/TestClientSharedPathCommittedMidPush3694394140/001/store/hcvzhjy9phrnvanc7fgj1cmqcwgla5nb-top1831 URL: nar/0py97d02ma6ksf2s4mnxmm0729v6045yma452bz1vj8jb2371hgx.nar.zst1832 Compression: zstd1833 NarHash: sha256:0py97d02ma6ksf2s4mnxmm0729v6045yma452bz1vj8jb2371hgx1834 NarSize: 2241835 References: /build/TestClientSharedPathCommittedMidPush3694394140/001/store/lg23hf47db5yj7m5wgd3pbsqz3f6ikdj-shared-dep1836 CA: text:sha256:1fw9947krczl656qagv5b67srzc9ajawyq33n4c9i3nsrp6kq85l1837--- PASS: TestClientSharedPathCommittedMidPush (0.53s)1838=== CONT TestClientErrorHandling/ServerNotAvailable1839=== NAME TestClientCADerivations18402026/10/07 09:36:03 INFO Received push request method=POST path=/api/pushes1841 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features18422026/10/07 09:36:03 INFO Received push request method=POST path=/api/pushes1843 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable18442026/10/07 09:36:03 INFO Received push request method=POST path=/api/pushes1845 error: binary cache 's3://bucket79?endpoint=http://localhost:41137®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4030572674/001/store'1846 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 118472026/10/07 09:36:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18482026/10/07 09:36:03 INFO Uploading 7cm5nafs6z87pcs9i1vc8b19vf8i49n9-unpinned-file.txt (128B)18492026/10/07 09:36:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18502026/10/07 09:36:03 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18512026/10/07 09:36:03 INFO Uploading vrwxdpnpg1p03x5f4svdlk0d67ljnhww-test-script (136B)18522026/10/07 09:36:03 INFO Uploading sjhvyckj8w4zwdnz2kvzl79vmchlgbyv-test-file-1.txt (160B)18532026/10/07 09:36:03 INFO Uploading 29qmy7lcgfnidnxigcgpc5gf7r8qykzk-test-file-2.txt (160B)18542026/10/07 09:36:03 INFO Uploading d8psciy919528kyilkw3pmsjmxih6jic-test-file-0.txt (160B)1855--- PASS: TestClientCADerivations (0.74s)1856=== CONT TestClientErrorHandling/InvalidAuthToken18572026/10/07 09:36:03 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18582026/10/07 09:36:03 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18592026/10/07 09:36:03 WARN Failed to register uploaded object key=7cm5nafs6z87pcs9i1vc8b19vf8i49n9.ls error="server returned 404: 404 page not found\n"18602026/10/07 09:36:03 INFO Signed narinfos id=2 count=118612026/10/07 09:36:03 INFO Uploading 1 narinfos18622026/10/07 09:36:03 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18632026/10/07 09:36:03 WARN Failed to register uploaded object key=sjhvyckj8w4zwdnz2kvzl79vmchlgbyv.ls error="server returned 404: 404 page not found\n"18642026/10/07 09:36:03 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18652026/10/07 09:36:03 WARN Failed to register uploaded object key=log/4v1w8q35q0wrhafvspggk1x6mas41bxh-test-script.drv error="server returned 404: 404 page not found\n"18662026/10/07 09:36:03 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18672026/10/07 09:36:03 WARN Failed to register uploaded object key=29qmy7lcgfnidnxigcgpc5gf7r8qykzk.ls error="server returned 404: 404 page not found\n"18682026/10/07 09:36:03 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18692026/10/07 09:36:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18702026/10/07 09:36:03 WARN Failed to register uploaded object key=vrwxdpnpg1p03x5f4svdlk0d67ljnhww.ls error="server returned 404: 404 page not found\n"18712026/10/07 09:36:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18722026/10/07 09:36:03 WARN Failed to register uploaded object key=d8psciy919528kyilkw3pmsjmxih6jic.ls error="server returned 404: 404 page not found\n"18732026/10/07 09:36:03 INFO Signed narinfos id=1 count=118742026/10/07 09:36:03 INFO Signed narinfos id=1 count=318752026/10/07 09:36:03 INFO Uploading 1 narinfos18762026/10/07 09:36:03 INFO Uploading 3 narinfos18772026/10/07 09:36:03 INFO Received complete push request method=POST path=/api/pushes/2/complete18782026/10/07 09:36:03 WARN Failed to register uploaded object key=7cm5nafs6z87pcs9i1vc8b19vf8i49n9.narinfo error="server returned 404: 404 page not found\n"18792026/10/07 09:36:03 INFO Completed push id=2 objects=3 duration=3.003159ms18802026/10/07 09:36:03 INFO Upload complete. (118ms)18812026/10/07 09:36:03 INFO Received complete push request method=POST path=/api/pushes/1/complete18822026/10/07 09:36:03 WARN Failed to register uploaded object key=vrwxdpnpg1p03x5f4svdlk0d67ljnhww.narinfo error="server returned 404: 404 page not found\n"18832026/10/07 09:36:03 WARN Failed to register uploaded object key=d8psciy919528kyilkw3pmsjmxih6jic.narinfo error="server returned 404: 404 page not found\n"18842026/10/07 09:36:03 WARN Failed to register uploaded object key=sjhvyckj8w4zwdnz2kvzl79vmchlgbyv.narinfo error="server returned 404: 404 page not found\n"18852026/10/07 09:36:03 INFO Received complete push request method=POST path=/api/pushes/1/complete18862026/10/07 09:36:03 WARN Failed to register uploaded object key=29qmy7lcgfnidnxigcgpc5gf7r8qykzk.narinfo error="server returned 404: 404 page not found\n"18872026/10/07 09:36:03 INFO Completed push id=1 objects=4 duration=7.258436ms18882026/10/07 09:36:03 INFO Upload complete. (142ms)18892026/10/07 09:36:03 INFO Completed push id=1 objects=9 duration=6.793837ms18902026/10/07 09:36:03 INFO Upload complete. (131ms)1891=== NAME TestClientMultipleUploads1892 client_integration_test.go:369: Uploaded 3 paths in 164.535301ms1893=== NAME TestClientWithDependencies1894 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1576936779/001/store) requires matching store prefix1895--- PASS: TestClientWithDependencies (0.65s)1896=== CONT TestCacheConfigHandler/full_config,_no_issuer1897=== CONT TestCacheConfigHandler/no_signing_keys1898=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1899=== CONT TestCacheConfigHandler/no_cache_url_configured1900--- PASS: TestCacheConfigHandler (0.00s)1901 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1902 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1903 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1904 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1905=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1906=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19072026/10/07 09:36:03 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]1908=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1909=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19102026/10/07 09:36:03 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/present1911--- PASS: TestClientMultipleUploads (0.63s)1912=== CONT TestService_RequireScope_OIDC/builder_may_write19132026/10/07 09:36:03 WARN Authentication failed token_preview=eyJhbGciOi...j2EeO27uTg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1914=== CONT TestService_RequireScope_OIDC/reader_may_read1915=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1916=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1917--- PASS: TestService_AuthMiddleware_OIDC (0.32s)1918 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1919 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1920 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1921 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1922=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19232026/10/07 09:36:03 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1924=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1925=== CONT TestService_RequireScope_OIDC/writer_implies_read1926=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1927=== CONT TestService_RequireScope_OIDC/static_token_may_write1928=== CONT TestService_RequireScope_OIDC/reader_may_not_write1929=== CONT TestService_RequireScope_OIDC/static_token_may_admin1930=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1931=== CONT TestService_RequireScope_OIDC/ops_may_admin1932=== CONT TestService_RequireScope_OIDC/ops_may_not_write1933--- PASS: TestService_RequireScope_OIDC (0.39s)1934 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1935 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1936 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1937 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1938 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1939 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1940 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1941 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1942 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1943 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1944 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1945 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1946 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1947 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)19482026/10/07 09:36:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures19492026/10/07 09:36:03 INFO Garbage collection started19502026/10/07 09:36:03 INFO Aborted multipart uploads count=0 kept=019512026/10/07 09:36:03 WARN Force mode enabled - objects will be deleted immediately without grace period19522026/10/07 09:36:03 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=019532026/10/07 09:36:03 INFO Vacuumed table table=pending_closures19542026/10/07 09:36:03 INFO Vacuumed table table=pending_objects19552026/10/07 09:36:03 INFO Aborted multipart uploads count=0 kept=019562026/10/07 09:36:03 INFO Vacuumed table table=multipart_uploads19572026/10/07 09:36:03 INFO Vacuumed table table=closures19582026/10/07 09:36:03 INFO Vacuumed table table=objects19592026/10/07 09:36:03 WARN Force mode enabled - objects will be deleted immediately without grace period19602026/10/07 09:36:03 INFO Received uploads request method=POST path=/api/pending_closures19612026/10/07 09:36:03 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.68705ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19622026/10/07 09:36:03 INFO Aborted multipart uploads count=0 kept=019632026/10/07 09:36:03 WARN Force mode enabled - objects will be deleted immediately without grace period19642026/10/07 09:36:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019652026/10/07 09:36:03 INFO Vacuumed table table=pending_closures19662026/10/07 09:36:03 INFO lead: released remote=192.0.2.1:123419672026/10/07 09:36:03 INFO Vacuumed table table=pending_objects19682026/10/07 09:36:03 INFO Vacuumed table table=multipart_uploads19692026/10/07 09:36:03 INFO Vacuumed table table=closures19702026/10/07 09:36:03 INFO Vacuumed table table=objects19712026/10/07 09:36:03 INFO Aborted multipart uploads count=0 kept=019722026/10/07 09:36:03 WARN Force mode enabled - objects will be deleted immediately without grace period19732026/10/07 09:36:03 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:41137/bucket95/?delete=\": context canceled"1974--- PASS: TestGCEndsOnShutdown (0.00s)1975 --- PASS: TestGCEndsOnShutdown/before_the_run (0.27s)1976 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.29s)1977 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.34s)19782026/10/07 09:36:03 INFO Received uploads request method=POST path=/api/pending_closures19792026/10/07 09:36:03 INFO lead: acquired remote=192.0.2.1:123419802026/10/07 09:36:03 INFO Aborted multipart uploads count=0 kept=019812026/10/07 09:36:03 WARN Force mode enabled - objects will be deleted immediately without grace period19822026/10/07 09:36:03 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=019832026/10/07 09:36:03 INFO Vacuumed table table=pending_closures19842026/10/07 09:36:03 INFO Vacuumed table table=pending_objects19852026/10/07 09:36:03 INFO Vacuumed table table=multipart_uploads19862026/10/07 09:36:03 INFO Vacuumed table table=closures19872026/10/07 09:36:03 INFO Vacuumed table table=objects1988=== NAME TestOrphanedObjectsGCStressTest1989 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1990--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1991 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.31s)1992 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.39s)1993=== NAME TestOrphanedObjectsGCStressTest1994 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion19952026/10/07 09:36:03 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19962026/10/07 09:36:03 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=431.570275ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19972026/10/07 09:36:03 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19982026/10/07 09:36:04 INFO lead: released remote=192.0.2.1:12341999--- PASS: TestLeadEndsOnShutdown (1.41s)2000--- PASS: TestDeleteClosuresRacingPins (1.27s)2001--- PASS: TestUploadHandlersRejectOversizedBody (0.19s)2002 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2003 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2004 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.78s)2005=== NAME TestOrphanedObjectsGCStressTest2006 orphaned_objects_gc_test.go:503: Stress test completed successfully:2007 orphaned_objects_gc_test.go:504: - Active objects preserved: 202008 orphaned_objects_gc_test.go:505: - Objects deleted: 2102009 orphaned_objects_gc_test.go:506: - Total GC'd: 2102010--- PASS: TestOrphanedObjectsGCStressTest (2.47s)2011--- PASS: TestPendingClosureWriteTimeout (0.09s)2012 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2013 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2014 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2015 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.03s)2016--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2017 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.92s)2018 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.94s)20192026/10/07 09:36:04 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=761.747056ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20202026/10/07 09:36:04 INFO lead: released remote=192.0.2.1:12342021--- PASS: TestLeadElectsOneAndHandsOver (2.88s)20222026/10/07 09:36:05 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.682514157s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20232026/10/07 09:36:05 WARN Rate limiter enabled after throttle name=s3-test rate=520242026/10/07 09:36:05 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2025=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2026 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102027 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002028--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.60s)20292026/10/07 09:36:05 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02030=== NAME TestClientIntegration2031 client_integration_test.go:323: Objects in database after GC:2032 client_integration_test.go:323: Successfully deleted all objects with GC --force2033--- PASS: TestClientIntegration (2.58s)20342026/10/07 09:36:05 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020352026/10/07 09:36:05 INFO Received create pin request method=POST path=/api/pins/myapp20362026/10/07 09:36:05 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3397462851/001/store/9linyh1nk13l8rvva5mya5z7x63vr1cc-pinned-file.txt narinfo_key=9linyh1nk13l8rvva5mya5z7x63vr1cc.narinfo20372026/10/07 09:36:05 INFO Starting cleanup of old closures method=DELETE path=/api/closures20382026/10/07 09:36:05 INFO Garbage collection started20392026/10/07 09:36:05 INFO Aborted multipart uploads count=0 kept=020402026/10/07 09:36:05 WARN Force mode enabled - objects will be deleted immediately without grace period20412026/10/07 09:36:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020422026/10/07 09:36:05 INFO Vacuumed table table=pending_closures20432026/10/07 09:36:05 INFO Vacuumed table table=pending_objects20442026/10/07 09:36:05 INFO Vacuumed table table=multipart_uploads20452026/10/07 09:36:05 INFO Vacuumed table table=closures20462026/10/07 09:36:05 INFO Vacuumed table table=objects2047--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.77s)20482026/10/07 09:36:06 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-config20492026/10/07 09:36:06 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.511776ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20502026/10/07 09:36:07 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=410.918914ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20512026/10/07 09:36:07 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=794.662454ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2052=== NAME TestPinProtectsFromGC2053 client_integration_test.go:840: Pin successfully protected closure from garbage collection2054--- PASS: TestPinProtectsFromGC (4.72s)2055--- PASS: TestConnectWaitsForAPeerMigration (5.18s)20562026/10/07 09:36:08 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.699918573s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20572026/10/07 09:36:08 INFO Aborted multipart uploads count=1 kept=020582026/10/07 09:36:08 INFO Received cleanup request method=DELETE path=/api/pending_closures20592026/10/07 09:36:08 INFO Aborted multipart uploads count=1 kept=02060--- PASS: TestPendingCleanupUsesOneCutoff (6.65s)20612026/10/07 09:36:10 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"20622026/10/07 09:36:10 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-config20632026/10/07 09:36:10 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=191.984885ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20642026/10/07 09:36:10 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=405.049475ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20652026/10/07 09:36:10 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=847.926314ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20662026/10/07 09:36:11 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.59899854s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20672026/10/07 09:36:13 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_closures20682026/10/07 09:36:13 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.688588ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20692026/10/07 09:36:13 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=407.328206ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20702026/10/07 09:36:13 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=863.250073ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20712026/10/07 09:36:14 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.55351336s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2072--- PASS: TestClientErrorHandling (0.00s)2073 --- PASS: TestClientErrorHandling/InvalidStorePath (0.35s)2074 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.36s)2075 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.88s)2076PASS2077{"timestamp":"2026-10-07T09:36:16.333210613Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:37036","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(398)"}2078{"timestamp":"2026-10-07T09:36:16.333341353Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:36196","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(398)"}20792026-10-07 09:36:16.763 UTC [129] LOG: received smart shutdown request20802026-10-07 09:36:16.767 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120812026-10-07 09:36:16.779 UTC [134] LOG: shutting down20822026-10-07 09:36:16.780 UTC [134] LOG: checkpoint starting: shutdown immediate20832026-10-07 09:36:18.377 UTC [134] LOG: checkpoint complete: wrote 10577 buffers (64.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.262 s, sync=1.267 s, total=1.598 s; sync files=34045, longest=0.006 s, average=0.001 s; distance=531533 kB, estimate=531533 kB; lsn=0/21E79428, redo lsn=0/21E7942820842026-10-07 09:36:18.436 UTC [129] LOG: database system is shut down2085Running OIDC tests...2086=== RUN TestAudienceForIssuer2087=== PAUSE TestAudienceForIssuer2088=== RUN TestGlobMatch2089=== PAUSE TestGlobMatch2090=== RUN TestValidateToken_ValidToken2091=== PAUSE TestValidateToken_ValidToken2092=== RUN TestValidateToken_WrongAudience2093=== PAUSE TestValidateToken_WrongAudience2094=== RUN TestValidateToken_Expired2095=== PAUSE TestValidateToken_Expired2096=== RUN TestValidateToken_BoundClaimsMismatch2097=== PAUSE TestValidateToken_BoundClaimsMismatch2098=== RUN TestValidateToken_BoundSubjectMismatch2099=== PAUSE TestValidateToken_BoundSubjectMismatch2100=== RUN TestValidateToken_MultipleProviders2101=== PAUSE TestValidateToken_MultipleProviders2102=== RUN TestValidateToken_NoMatchingProvider2103=== PAUSE TestValidateToken_NoMatchingProvider2104=== RUN TestValidateToken_KubernetesServiceAccount2105=== PAUSE TestValidateToken_KubernetesServiceAccount2106=== RUN TestNewValidator_KubernetesRequiresCA2107=== PAUSE TestNewValidator_KubernetesRequiresCA2108=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2109=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2110=== RUN TestPins_ReservedForMatchingRule2111=== PAUSE TestPins_ReservedForMatchingRule2112=== RUN TestPins_TopLevelShorthand2113=== PAUSE TestPins_TopLevelShorthand2114=== RUN TestPins_ConfigValidation2115=== PAUSE TestPins_ConfigValidation2116=== RUN TestScopes_LegacyProviderDefaultsToWrite2117=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2118=== RUN TestScopes_Rules2119=== PAUSE TestScopes_Rules2120=== RUN TestScopes_ConfigValidation2121=== PAUSE TestScopes_ConfigValidation2122=== CONT TestAudienceForIssuer2123=== CONT TestValidateToken_BoundClaimsMismatch2124=== CONT TestValidateToken_Expired2125=== CONT TestValidateToken_KubernetesServiceAccount2126=== CONT TestValidateToken_MultipleProviders2127=== CONT TestValidateToken_NoMatchingProvider2128=== CONT TestPins_ConfigValidation2129=== CONT TestScopes_ConfigValidation2130=== CONT TestScopes_Rules2131=== CONT TestScopes_LegacyProviderDefaultsToWrite2132=== CONT TestValidateToken_ValidToken2133=== CONT TestValidateToken_WrongAudience2134=== CONT TestGlobMatch2135=== RUN TestGlobMatch/foo_foo2136=== CONT TestValidateToken_BoundSubjectMismatch2137=== CONT TestPins_ReservedForMatchingRule2138=== CONT TestPins_TopLevelShorthand2139=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2140=== CONT TestNewValidator_KubernetesRequiresCA2141--- PASS: TestAudienceForIssuer (0.00s)2142=== PAUSE TestGlobMatch/foo_foo2143=== RUN TestGlobMatch/foo_bar2144=== PAUSE TestGlobMatch/foo_bar2145=== RUN TestGlobMatch/*_2146=== PAUSE TestGlobMatch/*_2147=== RUN TestGlobMatch/*_anything2148=== PAUSE TestGlobMatch/*_anything2149=== RUN TestGlobMatch/foo*_foo2150=== PAUSE TestGlobMatch/foo*_foo2151=== RUN TestGlobMatch/foo*_foobar2152=== PAUSE TestGlobMatch/foo*_foobar2153=== RUN TestGlobMatch/foo*_bar2154=== PAUSE TestGlobMatch/foo*_bar2155=== RUN TestGlobMatch/*bar_bar2156=== PAUSE TestGlobMatch/*bar_bar2157=== RUN TestGlobMatch/*bar_foobar2158=== PAUSE TestGlobMatch/*bar_foobar2159=== RUN TestGlobMatch/*bar_foo2160=== PAUSE TestGlobMatch/*bar_foo2161=== RUN TestGlobMatch/foo*bar_foobar2162=== PAUSE TestGlobMatch/foo*bar_foobar2163=== RUN TestGlobMatch/foo*bar_foo123bar2164=== PAUSE TestGlobMatch/foo*bar_foo123bar2165=== RUN TestGlobMatch/foo*bar_foobarbaz2166=== PAUSE TestGlobMatch/foo*bar_foobarbaz2167=== RUN TestGlobMatch/*/*_foo/bar2168=== PAUSE TestGlobMatch/*/*_foo/bar2169=== RUN TestGlobMatch/*/*_foo2170=== PAUSE TestGlobMatch/*/*_foo2171=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2172=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2173=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02174=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02175=== RUN TestGlobMatch/refs/*/main_refs/heads/main2176=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2177=== RUN TestGlobMatch/fo?_foo2178=== PAUSE TestGlobMatch/fo?_foo2179=== RUN TestGlobMatch/fo?_fo2180=== PAUSE TestGlobMatch/fo?_fo2181=== RUN TestGlobMatch/fo?_fooo2182=== PAUSE TestGlobMatch/fo?_fooo2183=== RUN TestGlobMatch/?oo_foo2184=== PAUSE TestGlobMatch/?oo_foo2185=== RUN TestGlobMatch/?oo_boo2186=== PAUSE TestGlobMatch/?oo_boo2187=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2188=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2189=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2190=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2191=== CONT TestGlobMatch/foo_foo2192=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2193=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2194=== CONT TestGlobMatch/?oo_boo2195=== CONT TestGlobMatch/foo*bar_foo123bar2196--- PASS: TestPins_ConfigValidation (0.00s)2197=== CONT TestGlobMatch/foo*bar_foobar2198=== CONT TestGlobMatch/refs/*/main_refs/heads/main2199=== CONT TestGlobMatch/*bar_foo2200=== CONT TestGlobMatch/fo?_fooo2201=== CONT TestGlobMatch/*bar_foobar2202=== CONT TestGlobMatch/fo?_foo2203=== CONT TestGlobMatch/*/*_foo2204=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02205=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2206=== CONT TestGlobMatch/*/*_foo/bar2207=== CONT TestGlobMatch/foo*bar_foobarbaz2208=== CONT TestGlobMatch/*bar_bar2209=== CONT TestGlobMatch/foo*_bar2210=== CONT TestGlobMatch/foo*_foobar2211=== CONT TestGlobMatch/foo*_foo2212=== CONT TestGlobMatch/*_anything2213=== CONT TestGlobMatch/*_2214=== CONT TestGlobMatch/foo_bar2215--- PASS: TestScopes_ConfigValidation (0.00s)2216=== CONT TestGlobMatch/?oo_foo2217=== CONT TestGlobMatch/fo?_fo2218--- PASS: TestGlobMatch (0.00s)2219 --- PASS: TestGlobMatch/foo_foo (0.00s)2220 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2221 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2222 --- PASS: TestGlobMatch/?oo_boo (0.00s)2223 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2224 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2225 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2226 --- PASS: TestGlobMatch/*bar_foo (0.00s)2227 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2228 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2229 --- PASS: TestGlobMatch/fo?_foo (0.00s)2230 --- PASS: TestGlobMatch/*/*_foo (0.00s)2231 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2232 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2233 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2234 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2235 --- PASS: TestGlobMatch/*bar_bar (0.00s)2236 --- PASS: TestGlobMatch/foo*_bar (0.00s)2237 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2238 --- PASS: TestGlobMatch/foo*_foo (0.00s)2239 --- PASS: TestGlobMatch/*_anything (0.00s)2240 --- PASS: TestGlobMatch/*_ (0.00s)2241 --- PASS: TestGlobMatch/foo_bar (0.00s)2242 --- PASS: TestGlobMatch/?oo_foo (0.00s)2243 --- PASS: TestGlobMatch/fo?_fo (0.00s)22442026/10/07 09:36:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45861/oidc22452026/10/07 09:36:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36085/oidc22462026/10/07 09:36:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43833/oidc2247--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.03s)2248--- PASS: TestValidateToken_WrongAudience (0.03s)22492026/10/07 09:36:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34595/oidc22502026/10/07 09:36:21 http: TLS handshake error from 127.0.0.1:50718: remote error: tls: bad certificate2251--- PASS: TestNewValidator_KubernetesRequiresCA (0.03s)2252--- PASS: TestScopes_Rules (0.04s)2253--- PASS: TestValidateToken_Expired (0.04s)22542026/10/07 09:36:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41959/oidc22552026/10/07 09:36:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34637/oidc2256--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)2257--- PASS: TestPins_ReservedForMatchingRule (0.05s)22582026/10/07 09:36:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42713/oidc2259--- PASS: TestPins_TopLevelShorthand (0.06s)22602026/10/07 09:36:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46687/oidc2261--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)22622026/10/07 09:36:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33331/oidc2263--- PASS: TestValidateToken_ValidToken (0.08s)22642026/10/07 09:36:21 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:366612265--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)22662026/10/07 09:36:21 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232267--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.09s)22682026/10/07 09:36:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45629/oidc22692026/10/07 09:36:21 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:42795/oidc2270--- PASS: TestValidateToken_MultipleProviders (0.14s)22712026/10/07 09:36:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42023/oidc2272--- PASS: TestValidateToken_NoMatchingProvider (0.16s)2273PASS2274Running hook tests...2275=== RUN TestSendPathsEmpty2276=== PAUSE TestSendPathsEmpty2277=== RUN TestQueueEnqueueAndFetch2278=== PAUSE TestQueueEnqueueAndFetch2279=== RUN TestQueueDeduplication2280=== PAUSE TestQueueDeduplication2281=== RUN TestQueueRemove2282=== PAUSE TestQueueRemove2283=== RUN TestQueueFetchBatchLimit2284=== PAUSE TestQueueFetchBatchLimit2285=== RUN TestQueueRetryMovesToBack2286=== PAUSE TestQueueRetryMovesToBack2287=== RUN TestQueueFetchRemoveLifecycle2288=== PAUSE TestQueueFetchRemoveLifecycle2289=== RUN TestQueueConcurrentWriters2290=== PAUSE TestQueueConcurrentWriters2291=== RUN TestQueueRemoveLargeClosure2292=== PAUSE TestQueueRemoveLargeClosure2293=== RUN TestServerClientIntegration2294--- PASS: TestServerClientIntegration (0.00s)2295=== RUN TestServerQueueError22962026/10/07 09:36:21 ERROR Failed to queue paths error="permission denied" count=12297--- PASS: TestServerQueueError (0.00s)2298=== RUN TestGetListenerSocketActivation2299 server_test.go:219: === RUN TestGetListenerSocketActivation2300 --- PASS: TestGetListenerSocketActivation (0.00s)2301 PASS2302 2303--- PASS: TestGetListenerSocketActivation (0.01s)2304=== RUN TestDrainIsolatesPoisonPath2305=== PAUSE TestDrainIsolatesPoisonPath2306=== RUN TestRunNotBlockedByPoisonHead2307=== PAUSE TestRunNotBlockedByPoisonHead2308=== RUN TestDrainGivesUpWhenServerDown2309=== PAUSE TestDrainGivesUpWhenServerDown2310=== RUN TestFailedPathPrunedByLaterClosure2311=== PAUSE TestFailedPathPrunedByLaterClosure2312=== RUN TestWorkerUploadsAndRemoves2313=== PAUSE TestWorkerUploadsAndRemoves2314=== RUN TestWorkerSkipsGCdPaths2315=== PAUSE TestWorkerSkipsGCdPaths2316=== RUN TestWorkerPrunesClosureDeps2317=== PAUSE TestWorkerPrunesClosureDeps2318=== RUN TestDrainTimeout2319=== PAUSE TestDrainTimeout2320=== CONT TestSendPathsEmpty2321=== CONT TestDrainGivesUpWhenServerDown2322=== CONT TestDrainTimeout2323=== CONT TestWorkerPrunesClosureDeps2324=== CONT TestWorkerSkipsGCdPaths2325--- PASS: TestSendPathsEmpty (0.00s)2326=== CONT TestDrainIsolatesPoisonPath2327=== CONT TestQueueRemoveLargeClosure2328=== CONT TestFailedPathPrunedByLaterClosure2329=== CONT TestQueueConcurrentWriters2330=== CONT TestQueueFetchRemoveLifecycle2331=== CONT TestQueueRetryMovesToBack2332=== CONT TestQueueFetchBatchLimit2333=== CONT TestQueueRemove2334=== CONT TestQueueDeduplication2335=== CONT TestWorkerUploadsAndRemoves2336=== CONT TestQueueEnqueueAndFetch2337=== CONT TestRunNotBlockedByPoisonHead23382026/10/07 09:36:21 INFO Uploading batch count=223392026/10/07 09:36:21 INFO Uploading batch count=223402026/10/07 09:36:21 ERROR Upload failed error="upload failed" count=223412026/10/07 09:36:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3116128384/002/a23422026/10/07 09:36:21 INFO Upload queue status pending=223432026/10/07 09:36:21 INFO Upload queue status pending=223442026/10/07 09:36:21 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1529892075/002/nonexistent23452026/10/07 09:36:21 INFO Uploading batch count=123462026/10/07 09:36:21 ERROR Upload failed error="upload failed" count=123472026/10/07 09:36:21 INFO Uploading batch count=223482026/10/07 09:36:21 INFO Uploading batch count=423492026/10/07 09:36:21 ERROR Upload failed error="upload failed" count=423502026/10/07 09:36:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3116128384/002/b23512026/10/07 09:36:21 INFO Uploading batch count=123522026/10/07 09:36:21 INFO Uploading batch count=123532026/10/07 09:36:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath4134213566/002/bbb23542026/10/07 09:36:21 INFO Upload queue status pending=22355--- PASS: TestQueueRemove (0.02s)23562026/10/07 09:36:21 INFO Uploading batch count=223572026/10/07 09:36:21 ERROR Upload failed error="upload failed" count=223582026/10/07 09:36:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3116128384/002/c23592026/10/07 09:36:21 INFO Uploading batch count=123602026/10/07 09:36:21 INFO Upload queue status pending=32361--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2362--- PASS: TestQueueRetryMovesToBack (0.02s)2363--- PASS: TestQueueFetchBatchLimit (0.02s)23642026/10/07 09:36:21 INFO Uploading batch count=123652026/10/07 09:36:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3116128384/002/d23662026/10/07 09:36:21 INFO Uploading batch count=123672026/10/07 09:36:21 ERROR Upload failed error="upload failed" count=12368--- PASS: TestQueueDeduplication (0.02s)2369--- PASS: TestQueueEnqueueAndFetch (0.02s)23702026/10/07 09:36:21 INFO Uploading batch count=123712026/10/07 09:36:21 ERROR Upload failed error="upload failed" count=123722026/10/07 09:36:21 INFO Uploading batch count=223732026/10/07 09:36:21 ERROR Upload failed error="upload failed" count=223742026/10/07 09:36:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3116128384/002/e23752026/10/07 09:36:21 INFO Uploading batch count=123762026/10/07 09:36:21 ERROR Upload failed error="upload failed" count=123772026/10/07 09:36:21 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3116128384/002/f2378--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)23792026/10/07 09:36:21 ERROR Drain finished with paths left in queue remaining=1023802026/10/07 09:36:21 INFO Uploading batch count=123812026/10/07 09:36:21 ERROR Upload failed error="upload failed" count=123822026/10/07 09:36:21 ERROR Drain finished with paths left in queue remaining=12383--- PASS: TestWorkerSkipsGCdPaths (0.04s)2384--- PASS: TestDrainGivesUpWhenServerDown (0.04s)2385--- PASS: TestDrainIsolatesPoisonPath (0.04s)2386--- PASS: TestWorkerUploadsAndRemoves (0.04s)2387--- PASS: TestWorkerPrunesClosureDeps (0.04s)2388--- PASS: TestQueueRemoveLargeClosure (0.06s)23892026/10/07 09:36:21 ERROR Upload failed error="context deadline exceeded" count=223902026/10/07 09:36:21 ERROR Drain finished with paths left in queue remaining=42391--- PASS: TestDrainTimeout (0.22s)2392--- PASS: TestQueueConcurrentWriters (0.27s)23932026/10/07 09:36:22 INFO Uploading batch count=123942026/10/07 09:36:22 INFO Uploading batch count=123952026/10/07 09:36:22 INFO Uploading batch count=123962026/10/07 09:36:22 ERROR Upload failed error="upload failed" count=123972026/10/07 09:36:22 INFO Uploading batch count=123982026/10/07 09:36:22 ERROR Upload failed error="upload failed" count=123992026/10/07 09:36:22 INFO Uploading batch count=124002026/10/07 09:36:22 ERROR Upload failed error="upload failed" count=124012026/10/07 09:36:22 INFO Uploading batch count=124022026/10/07 09:36:22 ERROR Upload failed error="upload failed" count=124032026/10/07 09:36:22 ERROR Drain finished with paths left in queue remaining=12404--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2405PASS2406Running signing tests...2407=== RUN TestExternalSigner2408=== PAUSE TestExternalSigner2409=== RUN TestExternalSignerWrongPublicKey2410=== PAUSE TestExternalSignerWrongPublicKey2411=== RUN TestExternalSignerErrors2412=== PAUSE TestExternalSignerErrors2413=== RUN TestExternalSignerRestartsAfterCrash2414=== PAUSE TestExternalSignerRestartsAfterCrash2415=== RUN TestExternalSignerProgramErrorKeepsProcess2416=== PAUSE TestExternalSignerProgramErrorKeepsProcess2417=== RUN TestExternalSignerClose2418=== PAUSE TestExternalSignerClose2419=== RUN TestExternalSignerRejectsInvalidPublicKey2420=== PAUSE TestExternalSignerRejectsInvalidPublicKey2421=== RUN TestExternalSignerCancellation2422=== PAUSE TestExternalSignerCancellation2423=== RUN TestGenerateFingerprint2424=== PAUSE TestGenerateFingerprint2425=== RUN TestParseSigningKey2426=== PAUSE TestParseSigningKey2427=== RUN TestSign2428=== PAUSE TestSign2429=== RUN TestSignBatch2430=== PAUSE TestSignBatch2431=== RUN TestNilKeyPublicKey2432=== PAUSE TestNilKeyPublicKey2433=== RUN TestSignErrors2434=== PAUSE TestSignErrors2435=== CONT TestExternalSigner2436=== CONT TestExternalSignerCancellation2437=== CONT TestSignBatch2438=== CONT TestNilKeyPublicKey2439=== CONT TestParseSigningKey2440=== CONT TestSign2441=== RUN TestParseSigningKey/valid_32-byte_key2442=== PAUSE TestParseSigningKey/valid_32-byte_key2443=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2444=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2445=== CONT TestExternalSignerProgramErrorKeepsProcess2446=== CONT TestExternalSignerRejectsInvalidPublicKey2447=== RUN TestExternalSignerRejectsInvalidPublicKey/#002448=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002449=== CONT TestExternalSignerClose2450=== CONT TestGenerateFingerprint2451=== CONT TestExternalSignerErrors2452=== CONT TestExternalSignerRestartsAfterCrash2453=== CONT TestExternalSignerWrongPublicKey2454=== CONT TestSignErrors2455--- PASS: TestNilKeyPublicKey (0.00s)2456=== RUN TestParseSigningKey/no_colon2457=== PAUSE TestParseSigningKey/no_colon2458=== RUN TestParseSigningKey/empty_name2459=== PAUSE TestParseSigningKey/empty_name2460=== RUN TestParseSigningKey/invalid_base642461=== PAUSE TestParseSigningKey/invalid_base642462=== RUN TestParseSigningKey/wrong_length2463=== PAUSE TestParseSigningKey/wrong_length2464=== CONT TestParseSigningKey/valid_32-byte_key2465=== RUN TestSignErrors/nil_key2466=== PAUSE TestSignErrors/nil_key2467=== RUN TestExternalSignerErrors/wrong_shape2468=== PAUSE TestExternalSignerErrors/wrong_shape2469=== RUN TestExternalSignerErrors/wrong_signature_name2470=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2471=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2472=== RUN TestSignErrors/nil_narinfo2473=== PAUSE TestSignErrors/nil_narinfo2474=== RUN TestSignErrors/invalid_narinfo2475=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2476=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2477=== CONT TestParseSigningKey/no_colon2478=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2479=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2480=== RUN TestGenerateFingerprint/basic_with_references2481=== PAUSE TestGenerateFingerprint/basic_with_references2482=== RUN TestGenerateFingerprint/no_references2483=== PAUSE TestGenerateFingerprint/no_references2484=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2485=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2486--- PASS: TestSignBatch (0.00s)2487--- PASS: TestSign (0.00s)2488=== CONT TestParseSigningKey/invalid_base642489=== CONT TestParseSigningKey/empty_name2490=== PAUSE TestExternalSignerErrors/wrong_signature_name2491=== CONT TestParseSigningKey/wrong_length2492--- PASS: TestParseSigningKey (0.00s)2493 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2494 --- PASS: TestParseSigningKey/no_colon (0.00s)2495 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2496 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2497 --- PASS: TestParseSigningKey/empty_name (0.00s)2498 --- PASS: TestParseSigningKey/wrong_length (0.00s)2499=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2500=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2501=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2502=== CONT TestExternalSignerRejectsInvalidPublicKey/#002503=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2504=== PAUSE TestSignErrors/invalid_narinfo2505=== RUN TestSignErrors/canceled2506=== PAUSE TestSignErrors/canceled2507=== CONT TestSignErrors/nil_key2508=== CONT TestSignErrors/canceled2509=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2510=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2511=== RUN TestGenerateFingerprint/invalid_nar_hash_length2512=== CONT TestSignErrors/invalid_narinfo2513=== RUN TestExternalSignerErrors/invalid_signature_base642514=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2515=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2516=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2517--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2518 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2519 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2520 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2521 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2522 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2523=== CONT TestSignErrors/nil_narinfo2524--- PASS: TestSignErrors (0.00s)2525 --- PASS: TestSignErrors/nil_key (0.00s)2526 --- PASS: TestSignErrors/canceled (0.00s)2527 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2528 --- PASS: TestSignErrors/nil_narinfo (0.00s)2529=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2530=== PAUSE TestExternalSignerErrors/invalid_signature_base642531=== RUN TestGenerateFingerprint/invalid_store_path_prefix2532=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2533=== RUN TestExternalSignerErrors/exit_at_startup2534=== PAUSE TestExternalSignerErrors/exit_at_startup2535=== RUN TestExternalSignerErrors/exit_on_request2536=== PAUSE TestExternalSignerErrors/exit_on_request2537=== RUN TestExternalSignerErrors/null_signatures2538=== RUN TestGenerateFingerprint/invalid_reference_prefix2539=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2540=== PAUSE TestExternalSignerErrors/null_signatures2541=== CONT TestGenerateFingerprint/basic_with_references2542=== CONT TestGenerateFingerprint/invalid_nar_hash_length2543=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2544=== CONT TestGenerateFingerprint/invalid_store_path_prefix2545=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2546=== CONT TestGenerateFingerprint/invalid_reference_prefix2547=== CONT TestGenerateFingerprint/no_references2548--- PASS: TestGenerateFingerprint (0.00s)2549 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2550 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2551 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2552 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2553 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2554 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2555 --- PASS: TestGenerateFingerprint/no_references (0.00s)2556=== RUN TestExternalSignerErrors/missing_signature_name2557=== PAUSE TestExternalSignerErrors/missing_signature_name2558=== RUN TestExternalSignerErrors/wrong_signature_length2559=== PAUSE TestExternalSignerErrors/wrong_signature_length2560=== RUN TestExternalSignerErrors/program_error2561=== PAUSE TestExternalSignerErrors/program_error2562=== RUN TestExternalSignerErrors/null2563=== PAUSE TestExternalSignerErrors/null2564--- PASS: TestExternalSignerClose (0.00s)2565=== RUN TestExternalSignerErrors/missing_signatures2566=== PAUSE TestExternalSignerErrors/missing_signatures2567=== RUN TestExternalSignerErrors/wrong_signatures_shape2568=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2569=== RUN TestExternalSignerErrors/too_few_signatures2570=== PAUSE TestExternalSignerErrors/too_few_signatures2571=== RUN TestExternalSignerErrors/unrequested_key2572=== PAUSE TestExternalSignerErrors/unrequested_key2573=== RUN TestExternalSignerErrors/invalid_JSON2574=== PAUSE TestExternalSignerErrors/invalid_JSON2575--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2576=== RUN TestExternalSignerErrors/wrong_id2577=== PAUSE TestExternalSignerErrors/wrong_id2578=== CONT TestExternalSignerErrors/wrong_shape2579=== CONT TestExternalSignerErrors/program_error2580=== CONT TestExternalSignerErrors/too_few_signatures2581=== CONT TestExternalSignerErrors/wrong_id2582=== CONT TestExternalSignerErrors/invalid_JSON2583=== CONT TestExternalSignerErrors/unrequested_key2584=== CONT TestExternalSignerErrors/wrong_signatures_shape2585=== CONT TestExternalSignerErrors/missing_signatures2586=== CONT TestExternalSignerErrors/missing_signature_name2587=== CONT TestExternalSignerErrors/null2588=== CONT TestExternalSignerErrors/wrong_signature_length2589=== CONT TestExternalSignerErrors/invalid_signature_base642590=== CONT TestExternalSignerErrors/exit_on_request2591=== CONT TestExternalSignerErrors/null_signatures2592=== CONT TestExternalSignerErrors/exit_at_startup2593=== CONT TestExternalSignerErrors/wrong_signature_name2594--- PASS: TestExternalSignerWrongPublicKey (0.00s)2595--- PASS: TestExternalSigner (0.01s)2596--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2597--- PASS: TestExternalSignerErrors (0.00s)2598 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2599 --- PASS: TestExternalSignerErrors/program_error (0.00s)2600 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2601 --- PASS: TestExternalSignerErrors/null (0.00s)2602 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2603 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2604 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2605 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2606 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2607 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2608 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2609 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2610 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2611 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2612 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2613 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2614--- PASS: TestExternalSignerCancellation (0.02s)2615PASS2616Running OpenBao signer tests...2617=== RUN TestSign2618=== PAUSE TestSign2619=== RUN TestSignErrors2620=== PAUSE TestSignErrors2621=== RUN TestServe2622=== PAUSE TestServe2623=== RUN TestServeRejectsGarbage2624=== PAUSE TestServeRejectsGarbage2625=== CONT TestSign2626=== CONT TestServe2627=== CONT TestSignErrors2628=== CONT TestServeRejectsGarbage2629=== RUN TestSignErrors/http_error2630=== PAUSE TestSignErrors/http_error2631--- PASS: TestServe (0.00s)2632--- PASS: TestServeRejectsGarbage (0.00s)2633=== RUN TestSignErrors/invalid_json2634=== PAUSE TestSignErrors/invalid_json2635=== RUN TestSignErrors/no_prefix2636=== PAUSE TestSignErrors/no_prefix2637=== RUN TestSignErrors/invalid_base642638=== PAUSE TestSignErrors/invalid_base642639=== CONT TestSignErrors/http_error2640=== CONT TestSignErrors/invalid_json2641=== CONT TestSignErrors/no_prefix2642=== CONT TestSignErrors/invalid_base642643--- PASS: TestSign (0.00s)2644--- PASS: TestSignErrors (0.00s)2645 --- PASS: TestSignErrors/invalid_json (0.00s)2646 --- PASS: TestSignErrors/http_error (0.00s)2647 --- PASS: TestSignErrors/no_prefix (0.00s)2648 --- PASS: TestSignErrors/invalid_base64 (0.00s)2649PASS