niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #261
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestScriptTokenEmptyCommand97=== CONT TestShellSplit98=== CONT TestSetClientTLSDoesNotMutateDefaultTransport99=== CONT TestEncodeNixBase32100=== RUN TestEncodeNixBase32/test_string_hash101=== CONT TestSetClientTLS102=== CONT TestClientSignaturesByStorePath103=== CONT TestPartSizeForNAR104=== CONT TestStreamPushReportsSignatures105=== RUN TestPartSizeForNAR/zero_stays_at_minimum106=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum107=== RUN TestPartSizeForNAR/small_stays_at_minimum108=== PAUSE TestPartSizeForNAR/small_stays_at_minimum109=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum110=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum111=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts112=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts113=== CONT TestStreamPushRequestLine114=== CONT TestStreamPushGivesUpOnDeadServer115=== CONT TestStreamPushIsolatesFailures116=== CONT TestSetClientTLSErrors117=== CONT TestStreamPushBatchesUnderLoad118=== CONT TestStreamPushReportsEveryPath119=== CONT TestScriptTokenScriptFails120=== CONT TestShellSplitErrors121=== CONT TestScriptTokenBadJSON122=== CONT TestFileTokenMissing123=== CONT TestFileTokenEmpty124=== CONT TestFileTokenReadsAndCaches125=== CONT TestScriptTokenEmptyToken126=== CONT TestStaticToken127=== CONT TestScriptTokenCachesUntilRefresh128=== CONT TestScriptTokenNoExpiryRerunsEveryCall129=== CONT TestUploadMultipart_SupersededByPeer130--- PASS: TestScriptTokenEmptyCommand (0.00s)131=== CONT TestFilterOversizedClosures132=== PAUSE TestEncodeNixBase32/test_string_hash133=== CONT TestDumpPathWriterError134=== RUN TestPartSizeForNAR/1_TiB135--- PASS: TestShellSplit (0.00s)136--- PASS: TestClientSignaturesByStorePath (0.00s)137=== RUN TestEncodeNixBase32/empty_input138=== RUN TestUploadMultipart_SupersededByPeer/exists139--- PASS: TestStaticToken (0.00s)140=== PAUSE TestEncodeNixBase32/empty_input141--- PASS: TestFileTokenReadsAndCaches (0.00s)142=== CONT TestUploadMultipart_PartsInParallel143--- PASS: TestShellSplitErrors (0.00s)144=== CONT TestCaseHackSuffix1452026/09/23 13:01:28 ERROR Upload failed error="connection refused" count=201462026/09/23 13:01:28 ERROR Server seems unavailable, giving up on batch untried=17147=== CONT TestDumpPathSingleFile148=== PAUSE TestPartSizeForNAR/1_TiB1492026/09/23 13:01:28 ERROR Upload failed error="bad path" count=3150=== RUN TestPartSizeForNAR/5_TiB_S3_max_object151--- PASS: TestFileTokenEmpty (0.00s)152=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object153=== RUN TestPartSizeForNAR/capped_at_5_GiB154=== PAUSE TestPartSizeForNAR/capped_at_5_GiB155=== PAUSE TestUploadMultipart_SupersededByPeer/exists156=== CONT TestPathInfoCACompatibility157--- PASS: TestScriptTokenScriptFails (0.00s)158=== CONT TestRegisterUploadedObjectReusesConnections159=== RUN TestPathInfoCACompatibility/null_ca_field160=== CONT TestDumpPathMatchesNix161=== RUN TestFilterOversizedClosures/no_limit_keeps_everything162=== PAUSE TestPathInfoCACompatibility/null_ca_field163--- PASS: TestScriptTokenBadJSON (0.01s)164=== RUN TestUploadMultipart_SupersededByPeer/missing165=== CONT TestDoWithRetry_BodyReplayedViaGetBody166--- PASS: TestFileTokenMissing (0.00s)167=== RUN TestSetClientTLSErrors/missing_cert_file168=== PAUSE TestSetClientTLSErrors/missing_cert_file169=== RUN TestSetClientTLSErrors/missing_key_file170=== RUN TestSetClientTLS/rejects_connection_without_client_cert171=== CONT TestResolveStorePath172=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert173=== PAUSE TestUploadMultipart_SupersededByPeer/missing174=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA175=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA176=== RUN TestSetClientTLS/preserves_debug_logging_transport177=== PAUSE TestSetClientTLS/preserves_debug_logging_transport178=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess179=== RUN TestPathInfoCACompatibility/old_string_format_-_text180=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text181=== CONT TestPathInfoHashCompatibility182=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1832026/09/23 13:01:28 WARN Rate limiter enabled after throttle name=server-test rate=5184=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)185=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon1862026/09/23 13:01:28 ERROR Upload failed error=boom count=11872026/09/23 13:01:28 ERROR Upload failed error=boom count=1188=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon189=== CONT TestGetStorePathHash190=== RUN TestGetStorePathHash/valid_store_path191=== PAUSE TestGetStorePathHash/valid_store_path192=== RUN TestGetStorePathHash/basename_without_hyphen_should_error193=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error194=== CONT TestConvertHashToNix32195=== RUN TestConvertHashToNix32/SRI_format_to_Nix32196=== CONT TestEncodeNixBase32WithRealHash197=== CONT TestEncodeNixBase32/test_string_hash198=== CONT TestEncodeNixBase32/empty_input199=== CONT TestPartSizeForNAR/zero_stays_at_minimum200=== CONT TestPartSizeForNAR/1_TiB201=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum202=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts203=== CONT TestPartSizeForNAR/capped_at_5_GiB204=== CONT TestPartSizeForNAR/5_TiB_S3_max_object205=== CONT TestPartSizeForNAR/small_stays_at_minimum206=== CONT TestUploadMultipart_SupersededByPeer/exists207--- PASS: TestScriptTokenEmptyToken (0.03s)208--- PASS: TestDoServerRequestAttachesToken (0.04s)209=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32210=== RUN TestConvertHashToNix32/already_Nix32_format211=== PAUSE TestConvertHashToNix32/already_Nix32_format212=== RUN TestConvertHashToNix32/invalid_format213=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error214=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error215=== CONT TestUploadMultipart_SupersededByPeer/missing2162026/09/23 13:01:28 WARN Rate limiter enabled after throttle name=server-test rate=5217--- PASS: TestStreamPushGivesUpOnDeadServer (0.03s)2182026/09/23 13:01:28 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:40819219--- PASS: TestStreamPushReportsSignatures (0.04s)220--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.04s)221--- PASS: TestCaseHackSuffix (0.03s)222--- PASS: TestResolveStorePath (0.00s)223--- PASS: TestStreamPushReportsEveryPath (0.03s)2242026/09/23 13:01:28 WARN Rate limiter backed off name=server-test rate=5225--- PASS: TestEncodeNixBase32WithRealHash (0.00s)2262026/09/23 13:01:28 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:40819227=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error228=== PAUSE TestSetClientTLSErrors/missing_key_file229=== CONT TestParsePathInfoJSONMultiplePaths230=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths231=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths232=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI233=== CONT TestParsePathInfoJSON234=== CONT TestRateLimiterFeedback235=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive236=== CONT TestSetClientTLS/rejects_connection_without_client_cert237=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive238=== RUN TestPathInfoCACompatibility/new_structured_format_-_text239=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text240=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method241=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method242=== PAUSE TestConvertHashToNix32/invalid_format243=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA244=== CONT TestPathInfoCACompatibility/new_structured_format_-_text245=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive246=== CONT TestPathInfoCACompatibility/old_string_format_-_text247=== CONT TestConvertHashToNix32/invalid_format248=== CONT TestConvertHashToNix32/already_Nix32_format249=== CONT TestConvertHashToNix32/SRI_format_to_Nix32250--- PASS: TestEncodeNixBase32 (0.00s)251 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)252 --- PASS: TestEncodeNixBase32/empty_input (0.00s)253=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error254=== CONT TestGetStorePathHash/valid_store_path255=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error256=== RUN TestSetClientTLSErrors/missing_ca_file257=== PAUSE TestSetClientTLSErrors/missing_ca_file258=== RUN TestSetClientTLSErrors/invalid_ca_file259=== PAUSE TestSetClientTLSErrors/invalid_ca_file260--- PASS: TestPartSizeForNAR (0.01s)261 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)262 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)263 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)264 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)265 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)266 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)267 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)268--- PASS: TestStreamPushIsolatesFailures (0.04s)269--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)270=== CONT TestSetClientTLS/preserves_debug_logging_transport271--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)272 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)273 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)274=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths275=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths276=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI277=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512278=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512279=== CONT TestSetClientTLSErrors/missing_ca_file280=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths281=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)282=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths283=== RUN TestParsePathInfoJSON/Nix_format284=== PAUSE TestParsePathInfoJSON/Nix_format285=== RUN TestParsePathInfoJSON/Lix_format286=== PAUSE TestParsePathInfoJSON/Lix_format287=== RUN TestParsePathInfoJSON/empty_input288=== PAUSE TestParsePathInfoJSON/empty_input289=== RUN TestParsePathInfoJSON/whitespace_only290=== PAUSE TestParsePathInfoJSON/whitespace_only291=== RUN TestParsePathInfoJSON/invalid_JSON292=== PAUSE TestParsePathInfoJSON/invalid_JSON293=== CONT TestParsePathInfoJSON/Nix_format294=== CONT TestSetClientTLSErrors/missing_key_file295=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512296=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI297=== CONT TestParsePathInfoJSON/empty_input298=== CONT TestParsePathInfoJSON/whitespace_only299=== CONT TestParsePathInfoJSON/Lix_format300=== CONT TestParsePathInfoJSON/invalid_JSON301=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon302=== CONT TestPathInfoCACompatibility/null_ca_field303=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method304=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything305=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error306=== CONT TestGetStorePathHash/basename_without_hyphen_should_error307=== CONT TestSetClientTLSErrors/missing_cert_file308=== CONT TestSetClientTLSErrors/invalid_ca_file309--- PASS: TestConvertHashToNix32 (0.00s)310 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)311 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)312 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)313=== RUN TestRateLimiterFeedback/429_enables_limiter314=== PAUSE TestRateLimiterFeedback/429_enables_limiter315=== RUN TestRateLimiterFeedback/503_enables_limiter316=== PAUSE TestRateLimiterFeedback/503_enables_limiter317=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter318=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter319=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter320=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter321=== CONT TestRateLimiterFeedback/429_enables_limiter322=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped323=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped324=== RUN TestFilterOversizedClosures/all_closures_skipped325=== PAUSE TestFilterOversizedClosures/all_closures_skipped326=== CONT TestFilterOversizedClosures/no_limit_keeps_everything327=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter328=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3292026/09/23 13:01:28 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=2000330--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)331 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)332 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)333=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3342026/09/23 13:01:28 WARN Rate limiter enabled after throttle name=server-test rate=53352026/09/23 13:01:28 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:42469336=== CONT TestRateLimiterFeedback/503_enables_limiter337--- PASS: TestPathInfoHashCompatibility (0.00s)338 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)339 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)340 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)341 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)342=== CONT TestFilterOversizedClosures/all_closures_skipped3432026/09/23 13:01:28 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=50344--- PASS: TestFilterOversizedClosures (0.03s)345 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)346 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)347 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)348--- PASS: TestGetStorePathHash (0.00s)349 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)350 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)351 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)352 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)353--- PASS: TestParsePathInfoJSON (0.00s)354 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)355 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)356 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)357 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)358 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)359--- PASS: TestPathInfoCACompatibility (0.03s)360 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)361 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)362 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)363 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)364 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)3652026/09/23 13:01:28 WARN Rate limiter backed off name=server-test rate=53662026/09/23 13:01:28 WARN Rate limiter enabled after throttle name=server-test rate=5367--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)3682026/09/23 13:01:28 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:422573692026/09/23 13:01:28 WARN Rate limiter backed off name=server-test rate=5370--- PASS: TestRateLimiterFeedback (0.00s)371 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)372 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)373 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)374 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)375--- PASS: TestSetClientTLSErrors (0.04s)376 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)377 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)378 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)379 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)380--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)381--- PASS: TestDumpPathSingleFile (0.05s)3822026/09/23 13:01:29 http: TLS handshake error from 127.0.0.1:42898: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.04s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)385 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)387--- PASS: TestRegisterUploadedObjectReusesConnections (0.06s)388--- PASS: TestStreamPushRequestLine (0.07s)389--- PASS: TestDumpPathWriterError (0.08s)390--- PASS: TestStreamPushBatchesUnderLoad (0.11s)391--- PASS: TestDumpPathMatchesNix (0.13s)392--- PASS: TestUploadMultipart_PartsInParallel (0.66s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres675496234/data ... ok406creating subdirectories ... ok407selecting dynamic shared memory implementation ... posix408selecting default "max_connections" ... 100409selecting default "shared_buffers" ... 128MB410selecting default time zone ... UTC411creating configuration files ... ok412running bootstrap script ... ok413performing post-bootstrap initialization ... ok414syncing data to disk ... ok415416initdb: warning: enabling "trust" authentication for local connections417initdb: 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.418419Success. You can now start the database server using:420421 pg_ctl -D /build/postgres675496234/data -l logfile start422423/build/postgres675496234:5432 - no response4242026-09-23 13:01:30.810 UTC [127] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-09-23 13:01:30.811 UTC [127] LOG: listening on Unix socket "/build/postgres675496234/.s.PGSQL.5432"4262026-09-23 13:01:30.815 UTC [134] LOG: database system was shut down at 2026-09-23 13:01:30 UTC4272026-09-23 13:01:30.819 UTC [127] LOG: database system is ready to accept connections428/build/postgres675496234:5432 - accepting connections429{"timestamp":"2026-09-23T13:01:31.014527973Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"bad845cf-89a4-4bef-be82-9f208ff967f2","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":463,"threadName":"rustfs-worker","threadId":"ThreadId(207)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestResolveDBConnectionString467=== PAUSE TestResolveDBConnectionString468=== RUN TestLeadElectsOneAndHandsOver469=== PAUSE TestLeadElectsOneAndHandsOver470=== RUN TestLeadIncumbentWinsAfterRestart4712026-09-23 13:01:31.227 UTC [375] ERROR: relation "goose_db_version" does not exist at character 364722026-09-23 13:01:31.227 UTC [375] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4732026/09/23 13:01:31 OK 20241026095416_initial_model.sql (18.22ms)4742026/09/23 13:01:31 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)4752026/09/23 13:01:31 OK 20251218171726_add_pins.sql (4.73ms)4762026/09/23 13:01:31 OK 20260628120000_add_object_size_and_stats.sql (4.43ms)4772026/09/23 13:01:31 OK 20260905000000_add_claims.sql (5.31ms)4782026/09/23 13:01:31 OK 20260920000000_drop_claims.sql (2.99ms)4792026/09/23 13:01:31 OK 20260923120000_add_pushes.sql (2.2ms)4802026/09/23 13:01:31 goose: successfully migrated database to version: 202609231200004812026/09/23 13:01:31 OK 1_commit_pending_closure.sql (2.51ms)4822026/09/23 13:01:31 OK 2_object_stats_trigger.sql (1.21ms)4832026/09/23 13:01:31 OK 3_commit_push.sql (1.07ms)4842026/09/23 13:01:31 goose: up to current file version: 34852026/09/23 13:01:31 INFO lead: acquired remote=192.0.2.1:12344862026/09/23 13:01:31 INFO lead: released remote=192.0.2.1:12344872026/09/23 13:01:31 INFO lead: acquired remote=192.0.2.1:12344882026/09/23 13:01:31 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (0.85s)490=== RUN TestLeadEndsOnShutdown491=== PAUSE TestLeadEndsOnShutdown492=== RUN TestGCAdvisoryLockBlocksConcurrentRun4932026-09-23 13:01:32.033 UTC [385] ERROR: relation "goose_db_version" does not exist at character 364942026-09-23 13:01:32.033 UTC [385] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4952026/09/23 13:01:32 OK 20241026095416_initial_model.sql (24.7ms)4962026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)4972026/09/23 13:01:32 OK 20251218171726_add_pins.sql (4.64ms)4982026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (5.17ms)4992026/09/23 13:01:32 OK 20260905000000_add_claims.sql (3.77ms)5002026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (2.62ms)5012026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (2.51ms)5022026/09/23 13:01:32 goose: successfully migrated database to version: 202609231200005032026/09/23 13:01:32 OK 1_commit_pending_closure.sql (2.63ms)5042026/09/23 13:01:32 OK 2_object_stats_trigger.sql (1.38ms)5052026/09/23 13:01:32 OK 3_commit_push.sql (1.53ms)5062026/09/23 13:01:32 goose: up to current file version: 3507--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.16s)508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestGCTaskStore_StartNew513=== PAUSE TestGCTaskStore_StartNew514=== RUN TestGCTaskStore_DeduplicateSameParams515=== PAUSE TestGCTaskStore_DeduplicateSameParams516=== RUN TestGCTaskStore_ConflictDifferentParams517=== PAUSE TestGCTaskStore_ConflictDifferentParams518=== RUN TestGCTaskStore_GetEmpty519=== PAUSE TestGCTaskStore_GetEmpty520=== RUN TestGCTaskStore_GetReturnsLatest521=== PAUSE TestGCTaskStore_GetReturnsLatest522=== RUN TestGCTaskStore_CompletedAllowsNewTask523=== PAUSE TestGCTaskStore_CompletedAllowsNewTask524=== RUN TestGCTaskStore_PhaseUpdates525=== PAUSE TestGCTaskStore_PhaseUpdates526=== RUN TestGCTaskStore_Fail527=== PAUSE TestGCTaskStore_Fail528=== RUN TestGracefulShutdownDrainsInflight529=== PAUSE TestGracefulShutdownDrainsInflight530=== RUN TestService_healthCheckHandler531=== PAUSE TestService_healthCheckHandler532=== RUN TestService_readinessHandler533=== PAUSE TestService_readinessHandler534=== RUN TestGenerateLandingPage535=== PAUSE TestGenerateLandingPage536=== RUN TestCacheConfigHandlerMaxNarSize537=== PAUSE TestCacheConfigHandlerMaxNarSize538=== RUN TestCreatePendingClosureRejectsOversizedNAR539=== PAUSE TestCreatePendingClosureRejectsOversizedNAR540=== RUN TestNARDeduplicationMetadataUploadBug541=== PAUSE TestNARDeduplicationMetadataUploadBug542=== RUN TestMetricsInventory543=== PAUSE TestMetricsInventory544=== RUN TestService_NativeMTLS545=== PAUSE TestService_NativeMTLS546=== RUN TestServerTLSConfig547=== PAUSE TestServerTLSConfig548=== RUN TestMultipartCleanup549=== PAUSE TestMultipartCleanup550=== RUN TestObjectStatsTrigger551=== PAUSE TestObjectStatsTrigger552=== RUN TestOrphanedObjectsGC553=== PAUSE TestOrphanedObjectsGC554=== RUN TestOrphanedObjectsGCStressTest555=== PAUSE TestOrphanedObjectsGCStressTest556=== RUN TestResurrectedObjectNotDeleted557=== PAUSE TestResurrectedObjectNotDeleted558=== RUN TestCreatePin_ReservedPins559=== PAUSE TestCreatePin_ReservedPins560=== RUN TestParseSingleRange561=== PAUSE TestParseSingleRange562=== RUN TestProxyHeadersOnlyTrustedOnSocket563=== PAUSE TestProxyHeadersOnlyTrustedOnSocket564=== RUN TestIsValidCachePath565=== PAUSE TestIsValidCachePath566=== RUN TestReadProxyNarinfo567=== PAUSE TestReadProxyNarinfo568=== RUN TestReadProxyNarinfoAlreadyDecompressed569=== PAUSE TestReadProxyNarinfoAlreadyDecompressed570=== RUN TestReadProxyNarStreaming571=== PAUSE TestReadProxyNarStreaming572=== RUN TestReadProxy404573=== PAUSE TestReadProxy404574=== RUN TestReadProxyInvalidPath575=== PAUSE TestReadProxyInvalidPath576=== RUN TestReadProxyHead577=== PAUSE TestReadProxyHead578=== RUN TestReadProxyConditionalGet579=== PAUSE TestReadProxyConditionalGet580=== RUN TestReadProxyRootRedirectsToIndexHTML581=== PAUSE TestReadProxyRootRedirectsToIndexHTML582=== RUN TestReadProxyDisabled583=== PAUSE TestReadProxyDisabled584=== RUN TestReadRedirectNar585=== PAUSE TestReadRedirectNar586=== RUN TestReadRedirectKeepsNarinfoProxied587=== PAUSE TestReadRedirectKeepsNarinfoProxied588=== RUN TestReadProxyRangeRequest589=== PAUSE TestReadProxyRangeRequest590=== RUN TestReadRedirectUsesPublicS3URL591=== PAUSE TestReadRedirectUsesPublicS3URL592=== RUN TestPush_OverlappingRootsStoreOneRowPerKey593=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey594=== RUN TestPush_CompleteCommitsEveryRoot595=== PAUSE TestPush_CompleteCommitsEveryRoot596=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected597=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected598=== RUN TestPush_RejectsBadRequests599=== PAUSE TestPush_RejectsBadRequests600=== RUN TestPush_SignsNarinfosOfItsPendingObjects601=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects602=== RUN TestRedundantMultipartUpload603=== PAUSE TestRedundantMultipartUpload604=== RUN TestCompleteMultipartUpload_ErrorButObjectExists605=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists606=== RUN TestCompletedNarNotReofferedAcrossClosures607=== PAUSE TestCompletedNarNotReofferedAcrossClosures608=== RUN TestPresignedUploadRegisteredBeforeCommit609=== PAUSE TestPresignedUploadRegisteredBeforeCommit610=== RUN TestService_Rustfstest611=== PAUSE TestService_Rustfstest612=== RUN TestParseSize613=== PAUSE TestParseSize614=== RUN TestSkippedUploadsHandler615=== PAUSE TestSkippedUploadsHandler616=== RUN TestSystemdListenerNotActivated617--- PASS: TestSystemdListenerNotActivated (0.00s)618=== RUN TestWatchdogBeatsWhenHealthy619--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)620=== RUN TestWatchdogSkipsWhenUnhealthy6212026/09/23 13:01:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/23 13:01:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/23 13:01:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/23 13:01:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/23 13:01:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/23 13:01:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6272026/09/23 13:01:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6282026/09/23 13:01:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6292026/09/23 13:01:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6302026/09/23 13:01:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"631--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)632=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle633=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle634=== RUN TestProxyWriteTimeout635=== PAUSE TestProxyWriteTimeout636=== RUN TestIsValidUploadKey637=== PAUSE TestIsValidUploadKey638=== RUN TestUploadHandlersRejectInvalidKeys639=== PAUSE TestUploadHandlersRejectInvalidKeys640=== RUN TestUploadHandlersRejectOversizedBody641=== PAUSE TestUploadHandlersRejectOversizedBody642=== RUN TestService_cleanupPendingClosuresHandler643=== PAUSE TestService_cleanupPendingClosuresHandler644=== RUN TestService_createPendingClosureHandler645=== PAUSE TestService_createPendingClosureHandler646=== RUN TestService_verifyS3Integrity647=== PAUSE TestService_verifyS3Integrity648=== RUN TestCompleteMultipartUnregistered649=== PAUSE TestCompleteMultipartUnregistered650=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT651=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT652=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT653=== CONT TestService_AuthMiddleware654=== CONT TestMultipartCleanup655=== CONT TestServerTLSConfig656=== RUN TestServerTLSConfig/no_client_CA657=== CONT TestService_NativeMTLS658=== CONT TestMetricsInventory659=== CONT TestNARDeduplicationMetadataUploadBug660=== CONT TestCreatePendingClosureRejectsOversizedNAR661=== CONT TestCacheConfigHandlerMaxNarSize662=== CONT TestGenerateLandingPage6632026/09/23 13:01:32 INFO Received uploads request method=POST path=/api/pending_closures664=== CONT TestObjectStatsTrigger665--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)666--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)667=== CONT TestGCTaskStore_GetEmpty668--- PASS: TestGCTaskStore_GetEmpty (0.00s)669=== CONT TestReadProxyRangeRequest670=== CONT TestService_readinessHandler671=== CONT TestCompleteMultipartUnregistered672=== CONT TestGracefulShutdownDrainsInflight673=== CONT TestService_verifyS3Integrity6742026/09/23 13:01:32 INFO Starting HTTP server address=127.0.0.1:39355675=== CONT TestGCTaskStore_Fail676--- PASS: TestGCTaskStore_Fail (0.00s)677=== CONT TestGCTaskStore_DeduplicateSameParams678=== CONT TestService_createPendingClosureHandler679=== CONT TestGCTaskStore_PhaseUpdates680=== CONT TestService_cleanupPendingClosuresHandler6812026/09/23 13:01:32 INFO Shutdown signal received, draining in-flight requests timeout=10s682=== CONT TestGCTaskStore_CompletedAllowsNewTask683=== CONT TestGCTaskStore_StartNew684=== CONT TestReadRedirectKeepsNarinfoProxied685=== CONT TestGCTaskStore_GetReturnsLatest686=== CONT TestReadRedirectNar687=== CONT TestIsValidUploadKey688=== RUN TestIsValidUploadKey/narinfo689=== CONT TestGCTaskStore_ConflictDifferentParams690=== PAUSE TestIsValidUploadKey/narinfo691=== RUN TestIsValidUploadKey/nar_zst692=== PAUSE TestIsValidUploadKey/nar_zst693=== CONT TestGCBugBareHashReferences694--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)695--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)696--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)697=== CONT TestUploadHandlersRejectOversizedBody698=== CONT TestUploadHandlersRejectInvalidKeys699=== CONT TestGCMetrics700=== PAUSE TestServerTLSConfig/no_client_CA701=== CONT TestService_healthCheckHandler702=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info703=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info704=== RUN TestServerTLSConfig/missing_CA_file705=== PAUSE TestServerTLSConfig/missing_CA_file706=== RUN TestServerTLSConfig/not_a_PEM_file707=== PAUSE TestServerTLSConfig/not_a_PEM_file708--- PASS: TestGCTaskStore_StartNew (0.00s)709=== RUN TestIsValidUploadKey/nar_xz710=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal711=== PAUSE TestIsValidUploadKey/nar_xz712=== RUN TestIsValidUploadKey/nar_plain713=== PAUSE TestIsValidUploadKey/nar_plain714=== RUN TestIsValidUploadKey/listing715=== PAUSE TestIsValidUploadKey/listing716=== RUN TestIsValidUploadKey/build_log717=== PAUSE TestIsValidUploadKey/build_log718=== RUN TestIsValidUploadKey/build_log_home-manager_file719=== PAUSE TestIsValidUploadKey/build_log_home-manager_file720--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)721--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)722=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal723=== CONT TestProxyWriteTimeout724=== RUN TestProxyWriteTimeout/narinfo725=== RUN TestIsValidUploadKey/build_log_plus_in_name726=== PAUSE TestIsValidUploadKey/build_log_plus_in_name727=== RUN TestIsValidUploadKey/build_log_question_mark728=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key729=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key730=== PAUSE TestProxyWriteTimeout/narinfo731=== PAUSE TestIsValidUploadKey/build_log_question_mark732=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key733=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key734=== CONT TestLeadEndsOnShutdown735=== RUN TestProxyWriteTimeout/1_GiB_nar736=== RUN TestIsValidUploadKey/build_log_equals737=== PAUSE TestIsValidUploadKey/build_log_equals738=== PAUSE TestProxyWriteTimeout/1_GiB_nar739=== RUN TestIsValidUploadKey/realisation740=== PAUSE TestIsValidUploadKey/realisation741=== RUN TestProxyWriteTimeout/10_GiB_nar742=== RUN TestIsValidUploadKey/realisation_plus_in_output743=== PAUSE TestProxyWriteTimeout/10_GiB_nar744=== PAUSE TestIsValidUploadKey/realisation_plus_in_output745=== RUN TestProxyWriteTimeout/unknown_size746=== RUN TestIsValidUploadKey/nix-cache-info747--- PASS: TestGenerateLandingPage (0.01s)748=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle749=== PAUSE TestProxyWriteTimeout/unknown_size750=== PAUSE TestIsValidUploadKey/nix-cache-info751=== RUN TestIsValidUploadKey/index.html752=== PAUSE TestIsValidUploadKey/index.html753=== RUN TestIsValidUploadKey/narinfo_key,_nar_type754=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type755=== RUN TestIsValidUploadKey/nar_key,_narinfo_type756=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type757=== RUN TestIsValidUploadKey/listing_key,_narinfo_type758=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type759=== CONT TestSkippedUploadsHandler760=== RUN TestIsValidUploadKey/traversal761=== PAUSE TestIsValidUploadKey/traversal762=== RUN TestIsValidUploadKey/traversal_nar763=== PAUSE TestIsValidUploadKey/traversal_nar764=== RUN TestIsValidUploadKey/absolute765=== PAUSE TestIsValidUploadKey/absolute766=== RUN TestIsValidUploadKey/empty_key767=== PAUSE TestIsValidUploadKey/empty_key768=== RUN TestIsValidUploadKey/unknown_type769=== PAUSE TestIsValidUploadKey/unknown_type770=== CONT TestLeadElectsOneAndHandsOver7712026/09/23 13:01:32 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000772--- PASS: TestSkippedUploadsHandler (0.00s)773=== CONT TestParseSize774--- PASS: TestParseSize (0.00s)775=== CONT TestResolveDBConnectionString776=== RUN TestResolveDBConnectionString/flag_wins777=== PAUSE TestResolveDBConnectionString/flag_wins778=== RUN TestResolveDBConnectionString/file_when_flag_empty779=== PAUSE TestResolveDBConnectionString/file_when_flag_empty780=== RUN TestResolveDBConnectionString/missing_file_is_an_error781=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error782=== RUN TestResolveDBConnectionString/PGHOST_allows_empty783=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty784=== RUN TestResolveDBConnectionString/nothing_configured785=== PAUSE TestResolveDBConnectionString/nothing_configured786=== CONT TestService_Rustfstest7872026-09-23 13:01:32.479 UTC [452] ERROR: relation "goose_db_version" does not exist at character 367882026-09-23 13:01:32.479 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7892026-09-23 13:01:32.480 UTC [453] ERROR: relation "goose_db_version" does not exist at character 367902026-09-23 13:01:32.480 UTC [453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC791--- PASS: TestGracefulShutdownDrainsInflight (0.14s)792=== CONT TestClientFallsBackToClosures7932026-09-23 13:01:32.519 UTC [456] ERROR: relation "goose_db_version" does not exist at character 367942026-09-23 13:01:32.519 UTC [456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC795=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure796=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure797=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart798=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart799=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts800=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts801=== CONT TestPresignedUploadRegisteredBeforeCommit8022026-09-23 13:01:32.542 UTC [459] ERROR: relation "goose_db_version" does not exist at character 368032026-09-23 13:01:32.542 UTC [459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8042026/09/23 13:01:32 OK 20241026095416_initial_model.sql (38.58ms)8052026-09-23 13:01:32.564 UTC [460] ERROR: relation "goose_db_version" does not exist at character 368062026-09-23 13:01:32.564 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8072026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (4.56ms)8082026-09-23 13:01:32.566 UTC [461] ERROR: relation "goose_db_version" does not exist at character 368092026-09-23 13:01:32.566 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8102026/09/23 13:01:32 OK 20241026095416_initial_model.sql (48.34ms)8112026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (5.14ms)8122026/09/23 13:01:32 OK 20251218171726_add_pins.sql (22.89ms)8132026/09/23 13:01:32 OK 20241026095416_initial_model.sql (45.91ms)8142026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (6.87ms)8152026/09/23 13:01:32 OK 20251218171726_add_pins.sql (17.63ms)8162026/09/23 13:01:32 OK 20241026095416_initial_model.sql (38.1ms)8172026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (13.24ms)8182026/09/23 13:01:32 OK 20251218171726_add_pins.sql (8.24ms)8192026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (9.44ms)8202026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (5.47ms)8212026/09/23 13:01:32 OK 20260905000000_add_claims.sql (8.44ms)8222026/09/23 13:01:32 OK 20241026095416_initial_model.sql (28.8ms)8232026/09/23 13:01:32 OK 20241026095416_initial_model.sql (21.95ms)8242026/09/23 13:01:32 OK 20251218171726_add_pins.sql (6.98ms)8252026/09/23 13:01:32 OK 20260905000000_add_claims.sql (7.38ms)8262026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (9.03ms)8272026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (4.43ms)8282026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (5.67ms)8292026-09-23 13:01:32.622 UTC [462] ERROR: relation "goose_db_version" does not exist at character 368302026-09-23 13:01:32.622 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8312026-09-23 13:01:32.623 UTC [463] ERROR: relation "goose_db_version" does not exist at character 368322026-09-23 13:01:32.623 UTC [463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8332026-09-23 13:01:32.623 UTC [464] ERROR: relation "goose_db_version" does not exist at character 368342026-09-23 13:01:32.623 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8352026-09-23 13:01:32.623 UTC [465] ERROR: relation "goose_db_version" does not exist at character 368362026-09-23 13:01:32.623 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8372026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (13.14ms)8382026-09-23 13:01:32.625 UTC [466] ERROR: relation "goose_db_version" does not exist at character 368392026-09-23 13:01:32.625 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8402026/09/23 13:01:32 OK 20260905000000_add_claims.sql (13.76ms)8412026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (14.96ms)8422026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (11.93ms)8432026/09/23 13:01:32 goose: successfully migrated database to version: 202609231200008442026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (15.6ms)8452026/09/23 13:01:32 OK 20251218171726_add_pins.sql (14.14ms)8462026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (4.69ms)8472026/09/23 13:01:32 OK 1_commit_pending_closure.sql (5.2ms)8482026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (6ms)8492026/09/23 13:01:32 goose: successfully migrated database to version: 202609231200008502026/09/23 13:01:32 OK 20251218171726_add_pins.sql (9.92ms)8512026/09/23 13:01:32 OK 20260905000000_add_claims.sql (7.06ms)8522026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (3.95ms)8532026/09/23 13:01:32 goose: successfully migrated database to version: 202609231200008542026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (7.64ms)8552026/09/23 13:01:32 OK 2_object_stats_trigger.sql (3.32ms)8562026/09/23 13:01:32 OK 3_commit_push.sql (2.46ms)8572026/09/23 13:01:32 goose: up to current file version: 38582026-09-23 13:01:32.640 UTC [467] ERROR: relation "goose_db_version" does not exist at character 368592026-09-23 13:01:32.640 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8602026/09/23 13:01:32 OK 1_commit_pending_closure.sql (6.07ms)8612026/09/23 13:01:32 OK 1_commit_pending_closure.sql (5.01ms)8622026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (5.81ms)8632026-09-23 13:01:32.641 UTC [468] ERROR: relation "goose_db_version" does not exist at character 368642026-09-23 13:01:32.641 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8652026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (8.17ms)8662026/09/23 13:01:32 OK 2_object_stats_trigger.sql (3.48ms)8672026/09/23 13:01:32 OK 20260905000000_add_claims.sql (7.71ms)8682026/09/23 13:01:32 OK 2_object_stats_trigger.sql (3.55ms)8692026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (3.8ms)8702026/09/23 13:01:32 goose: successfully migrated database to version: 202609231200008712026/09/23 13:01:32 OK 3_commit_push.sql (2.79ms)8722026/09/23 13:01:32 goose: up to current file version: 38732026-09-23 13:01:32.648 UTC [469] ERROR: relation "goose_db_version" does not exist at character 368742026-09-23 13:01:32.648 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8752026/09/23 13:01:32 OK 20260905000000_add_claims.sql (5.61ms)8762026/09/23 13:01:32 OK 3_commit_push.sql (3.39ms)8772026/09/23 13:01:32 goose: up to current file version: 38782026-09-23 13:01:32.649 UTC [471] ERROR: relation "goose_db_version" does not exist at character 368792026-09-23 13:01:32.649 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8802026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (4.63ms)8812026-09-23 13:01:32.650 UTC [472] ERROR: relation "goose_db_version" does not exist at character 368822026-09-23 13:01:32.650 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8832026-09-23 13:01:32.650 UTC [470] ERROR: relation "goose_db_version" does not exist at character 368842026-09-23 13:01:32.650 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8852026/09/23 13:01:32 OK 20241026095416_initial_model.sql (13.12ms)8862026/09/23 13:01:32 OK 20241026095416_initial_model.sql (14.9ms)8872026/09/23 13:01:32 OK 20241026095416_initial_model.sql (15.14ms)8882026/09/23 13:01:32 OK 1_commit_pending_closure.sql (6.52ms)8892026/09/23 13:01:32 OK 20241026095416_initial_model.sql (15.3ms)8902026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (2.62ms)8912026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (3.78ms)8922026/09/23 13:01:32 goose: successfully migrated database to version: 202609231200008932026/09/23 13:01:32 OK 20241026095416_initial_model.sql (16.07ms)8942026-09-23 13:01:32.654 UTC [473] ERROR: relation "goose_db_version" does not exist at character 368952026-09-23 13:01:32.654 UTC [473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8962026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (5.62ms)8972026-09-23 13:01:32.655 UTC [474] ERROR: relation "goose_db_version" does not exist at character 368982026-09-23 13:01:32.655 UTC [474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8992026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)9002026/09/23 13:01:32 OK 2_object_stats_trigger.sql (2.42ms)9012026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (2.75ms)9022026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (3.03ms)9032026-09-23 13:01:32.657 UTC [476] ERROR: relation "goose_db_version" does not exist at character 369042026-09-23 13:01:32.657 UTC [476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9052026-09-23 13:01:32.657 UTC [475] ERROR: relation "goose_db_version" does not exist at character 369062026-09-23 13:01:32.657 UTC [475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9072026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (4.14ms)9082026/09/23 13:01:32 OK 3_commit_push.sql (4.28ms)9092026/09/23 13:01:32 goose: up to current file version: 39102026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (5.06ms)9112026/09/23 13:01:32 goose: successfully migrated database to version: 202609231200009122026/09/23 13:01:32 OK 1_commit_pending_closure.sql (5.78ms)9132026/09/23 13:01:32 OK 20251218171726_add_pins.sql (5.9ms)9142026/09/23 13:01:32 OK 20251218171726_add_pins.sql (7.3ms)9152026/09/23 13:01:32 OK 2_object_stats_trigger.sql (2.34ms)9162026-09-23 13:01:32.662 UTC [477] ERROR: relation "goose_db_version" does not exist at character 369172026-09-23 13:01:32.662 UTC [477] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9182026/09/23 13:01:32 OK 20251218171726_add_pins.sql (5.63ms)9192026/09/23 13:01:32 OK 20251218171726_add_pins.sql (6.69ms)9202026/09/23 13:01:32 OK 1_commit_pending_closure.sql (3.92ms)9212026/09/23 13:01:32 OK 20251218171726_add_pins.sql (5.84ms)9222026-09-23 13:01:32.664 UTC [478] ERROR: relation "goose_db_version" does not exist at character 369232026-09-23 13:01:32.664 UTC [478] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9242026-09-23 13:01:32.665 UTC [479] ERROR: relation "goose_db_version" does not exist at character 369252026-09-23 13:01:32.665 UTC [479] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9262026/09/23 13:01:32 OK 3_commit_push.sql (3.22ms)9272026/09/23 13:01:32 goose: up to current file version: 39282026/09/23 13:01:32 OK 20241026095416_initial_model.sql (13.5ms)9292026/09/23 13:01:32 OK 2_object_stats_trigger.sql (3.24ms)9302026/09/23 13:01:32 OK 20241026095416_initial_model.sql (15.09ms)9312026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (6.12ms)9322026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (6.17ms)9332026/09/23 13:01:32 OK 20241026095416_initial_model.sql (11.86ms)9342026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (5.6ms)9352026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (3.54ms)9362026/09/23 13:01:32 OK 3_commit_push.sql (2.53ms)9372026/09/23 13:01:32 goose: up to current file version: 39382026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (7.42ms)9392026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)9402026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (3.35ms)9412026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (8.64ms)9422026/09/23 13:01:32 OK 20260905000000_add_claims.sql (5.27ms)9432026/09/23 13:01:32 OK 20260905000000_add_claims.sql (6.51ms)9442026/09/23 13:01:32 OK 20260905000000_add_claims.sql (5.75ms)9452026/09/23 13:01:32 OK 20251218171726_add_pins.sql (4.61ms)9462026/09/23 13:01:32 OK 20241026095416_initial_model.sql (15.4ms)9472026/09/23 13:01:32 OK 20241026095416_initial_model.sql (13.2ms)9482026/09/23 13:01:32 OK 20251218171726_add_pins.sql (5.07ms)9492026/09/23 13:01:32 OK 20260905000000_add_claims.sql (5.2ms)9502026/09/23 13:01:32 OK 20241026095416_initial_model.sql (14.31ms)9512026/09/23 13:01:32 OK 20251218171726_add_pins.sql (4.66ms)9522026/09/23 13:01:32 OK 20241026095416_initial_model.sql (12.83ms)9532026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (3.38ms)9542026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (2.62ms)9552026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)9562026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (3.19ms)9572026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (3.34ms)9582026/09/23 13:01:32 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9592026/09/23 13:01:32 WARN mTLS auth: subject not in bound subjects subject="CN=reader"960--- PASS: TestService_NativeMTLS (0.33s)961=== CONT TestReadProxyDisabled9622026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (3.26ms)9632026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (3.53ms)9642026/09/23 13:01:32 goose: successfully migrated database to version: 202609231200009652026/09/23 13:01:32 OK 20241026095416_initial_model.sql (13.55ms)9662026/09/23 13:01:32 OK 20260905000000_add_claims.sql (7.08ms)9672026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (3.91ms)9682026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (5.51ms)9692026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (6.77ms)9702026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (3.56ms)9712026/09/23 13:01:32 goose: successfully migrated database to version: 202609231200009722026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (5.54ms)9732026/09/23 13:01:32 OK 20241026095416_initial_model.sql (17.21ms)9742026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (3.6ms)9752026/09/23 13:01:32 goose: successfully migrated database to version: 202609231200009762026/09/23 13:01:32 OK 20251218171726_add_pins.sql (13.9ms)9772026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (14.52ms)9782026/09/23 13:01:32 OK 20251218171726_add_pins.sql (14.24ms)9792026/09/23 13:01:32 OK 20251218171726_add_pins.sql (15.67ms)9802026/09/23 13:01:32 OK 20241026095416_initial_model.sql (21.15ms)9812026/09/23 13:01:32 OK 1_commit_pending_closure.sql (13.55ms)9822026/09/23 13:01:32 OK 20241026095416_initial_model.sql (26.58ms)9832026/09/23 13:01:32 OK 20260905000000_add_claims.sql (13.68ms)9842026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (13.7ms)9852026/09/23 13:01:32 goose: successfully migrated database to version: 202609231200009862026/09/23 13:01:32 OK 1_commit_pending_closure.sql (14.52ms)9872026/09/23 13:01:32 OK 1_commit_pending_closure.sql (13.98ms)9882026/09/23 13:01:32 OK 20241026095416_initial_model.sql (26.29ms)9892026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (15.93ms)9902026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (17.1ms)9912026/09/23 13:01:32 OK 20241026095416_initial_model.sql (24.24ms)9922026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (19.61ms)9932026/09/23 13:01:32 OK 20260905000000_add_claims.sql (18.23ms)9942026/09/23 13:01:32 OK 20251218171726_add_pins.sql (20.83ms)9952026/09/23 13:01:32 OK 2_object_stats_trigger.sql (6.37ms)9962026/09/23 13:01:32 OK 2_object_stats_trigger.sql (5.97ms)9972026/09/23 13:01:32 OK 2_object_stats_trigger.sql (4.97ms)9982026/09/23 13:01:32 OK 20260905000000_add_claims.sql (13.49ms)9992026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (9.29ms)10002026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (10.96ms)10012026/09/23 13:01:32 OK 1_commit_pending_closure.sql (9.87ms)10022026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (8.39ms)10032026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (10.62ms)10042026/09/23 13:01:32 OK 20251210153512_drop_unused_gin_index.sql (7.67ms)10052026/09/23 13:01:32 OK 3_commit_push.sql (5.38ms)10062026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (16.94ms)10072026/09/23 13:01:32 OK 3_commit_push.sql (5.06ms)10082026/09/23 13:01:32 goose: up to current file version: 310092026/09/23 13:01:32 goose: up to current file version: 310102026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (7.45ms)10112026/09/23 13:01:32 OK 2_object_stats_trigger.sql (1.83ms)10122026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (13.84ms)10132026/09/23 13:01:32 OK 20251218171726_add_pins.sql (10.21ms)10142026/09/23 13:01:32 OK 3_commit_push.sql (4.7ms)10152026/09/23 13:01:32 goose: up to current file version: 310162026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (16.92ms)10172026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (8.24ms)10182026/09/23 13:01:32 goose: successfully migrated database to version: 2026092312000010192026/09/23 13:01:32 OK 20251218171726_add_pins.sql (11.24ms)10202026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (5.16ms)10212026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (5.1ms)10222026/09/23 13:01:32 goose: successfully migrated database to version: 2026092312000010232026/09/23 13:01:32 OK 3_commit_push.sql (2.24ms)10242026/09/23 13:01:32 goose: up to current file version: 310252026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (3.88ms)10262026/09/23 13:01:32 goose: successfully migrated database to version: 2026092312000010272026/09/23 13:01:32 OK 20251218171726_add_pins.sql (6ms)10282026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (11.03ms)10292026/09/23 13:01:32 OK 20251218171726_add_pins.sql (5.51ms)10302026/09/23 13:01:32 OK 1_commit_pending_closure.sql (4.28ms)10312026/09/23 13:01:32 OK 20251218171726_add_pins.sql (6.31ms)10322026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)10332026/09/23 13:01:32 OK 20251218171726_add_pins.sql (5.86ms)10342026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (3.19ms)10352026/09/23 13:01:32 goose: successfully migrated database to version: 2026092312000010362026/09/23 13:01:32 OK 20260905000000_add_claims.sql (4.44ms)10372026/09/23 13:01:32 OK 20260905000000_add_claims.sql (5.42ms)10382026/09/23 13:01:32 OK 20260905000000_add_claims.sql (4.76ms)10392026/09/23 13:01:32 OK 1_commit_pending_closure.sql (3.39ms)10402026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (4.82ms)10412026/09/23 13:01:32 OK 1_commit_pending_closure.sql (3.03ms)10422026/09/23 13:01:32 OK 1_commit_pending_closure.sql (3.32ms)10432026/09/23 13:01:32 OK 2_object_stats_trigger.sql (2.8ms)10442026/09/23 13:01:32 OK 2_object_stats_trigger.sql (3.75ms)10452026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (3.97ms)10462026/09/23 13:01:32 OK 2_object_stats_trigger.sql (3.4ms)10472026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (5.6ms)10482026/09/23 13:01:32 OK 20260905000000_add_claims.sql (6.54ms)10492026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (6.49ms)10502026/09/23 13:01:32 OK 20260905000000_add_claims.sql (5.49ms)10512026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (6.62ms)10522026/09/23 13:01:32 OK 20260628120000_add_object_size_and_stats.sql (6.04ms)10532026/09/23 13:01:32 OK 3_commit_push.sql (2.54ms)10542026/09/23 13:01:32 goose: up to current file version: 310552026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (5.88ms)10562026/09/23 13:01:32 OK 2_object_stats_trigger.sql (2.65ms)10572026/09/23 13:01:32 OK 20260905000000_add_claims.sql (5.48ms)10582026/09/23 13:01:32 OK 3_commit_push.sql (2.48ms)10592026/09/23 13:01:32 goose: up to current file version: 310602026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (6.03ms)10612026/09/23 13:01:32 OK 3_commit_push.sql (2.19ms)10622026/09/23 13:01:32 goose: up to current file version: 310632026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (4.71ms)10642026/09/23 13:01:32 goose: successfully migrated database to version: 2026092312000010652026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (4.18ms)10662026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (4.32ms)10672026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (4.28ms)10682026/09/23 13:01:32 goose: successfully migrated database to version: 2026092312000010692026/09/23 13:01:32 OK 3_commit_push.sql (4.2ms)10702026/09/23 13:01:32 goose: up to current file version: 310712026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (3.96ms)10722026/09/23 13:01:32 goose: successfully migrated database to version: 2026092312000010732026/09/23 13:01:32 OK 20260905000000_add_claims.sql (5.19ms)10742026/09/23 13:01:32 OK 20260905000000_add_claims.sql (4.37ms)10752026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (4.82ms)10762026/09/23 13:01:32 OK 20260905000000_add_claims.sql (6.64ms)10772026/09/23 13:01:32 OK 20260905000000_add_claims.sql (6.68ms)10782026/09/23 13:01:32 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1079--- PASS: TestService_AuthMiddleware (0.37s)1080=== CONT TestClientPushesUseOnePush10812026/09/23 13:01:32 OK 1_commit_pending_closure.sql (4.61ms)10822026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (4.31ms)10832026/09/23 13:01:32 goose: successfully migrated database to version: 2026092312000010842026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (4.37ms)10852026/09/23 13:01:32 goose: successfully migrated database to version: 2026092312000010862026/09/23 13:01:32 OK 1_commit_pending_closure.sql (3.5ms)10872026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (3.72ms)10882026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (3.78ms)10892026/09/23 13:01:32 OK 1_commit_pending_closure.sql (3.97ms)10902026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (3.61ms)10912026/09/23 13:01:32 goose: successfully migrated database to version: 2026092312000010922026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (3.49ms)10932026/09/23 13:01:32 OK 2_object_stats_trigger.sql (1.77ms)10942026/09/23 13:01:32 OK 20260920000000_drop_claims.sql (3.82ms)10952026/09/23 13:01:32 OK 1_commit_pending_closure.sql (2.96ms)10962026/09/23 13:01:32 OK 2_object_stats_trigger.sql (2.91ms)10972026/09/23 13:01:32 OK 1_commit_pending_closure.sql (3.18ms)10982026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (3.41ms)10992026/09/23 13:01:32 goose: successfully migrated database to version: 2026092312000011002026/09/23 13:01:32 OK 3_commit_push.sql (2.52ms)11012026/09/23 13:01:32 goose: up to current file version: 311022026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (3.53ms)11032026/09/23 13:01:32 goose: successfully migrated database to version: 2026092312000011042026/09/23 13:01:32 OK 2_object_stats_trigger.sql (3.36ms)11052026/09/23 13:01:32 OK 1_commit_pending_closure.sql (4.4ms)11062026/09/23 13:01:32 OK 2_object_stats_trigger.sql (2.25ms)11072026/09/23 13:01:32 OK 3_commit_push.sql (2.09ms)11082026/09/23 13:01:32 goose: up to current file version: 311092026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (3.54ms)11102026/09/23 13:01:32 goose: successfully migrated database to version: 2026092312000011112026/09/23 13:01:32 OK 20260923120000_add_pushes.sql (3.79ms)11122026/09/23 13:01:32 goose: successfully migrated database to version: 2026092312000011132026/09/23 13:01:32 OK 3_commit_push.sql (2.14ms)11142026/09/23 13:01:32 goose: up to current file version: 311152026/09/23 13:01:32 OK 2_object_stats_trigger.sql (3.34ms)11162026/09/23 13:01:32 OK 1_commit_pending_closure.sql (2.93ms)11172026/09/23 13:01:32 OK 2_object_stats_trigger.sql (1.76ms)11182026/09/23 13:01:32 OK 1_commit_pending_closure.sql (2.82ms)11192026/09/23 13:01:32 OK 3_commit_push.sql (2.84ms)11202026/09/23 13:01:32 goose: up to current file version: 311212026/09/23 13:01:32 OK 1_commit_pending_closure.sql (3.11ms)11222026/09/23 13:01:32 OK 3_commit_push.sql (1.6ms)11232026/09/23 13:01:32 goose: up to current file version: 311242026/09/23 13:01:32 OK 3_commit_push.sql (2.17ms)11252026/09/23 13:01:32 goose: up to current file version: 311262026/09/23 13:01:32 OK 1_commit_pending_closure.sql (3.23ms)11272026/09/23 13:01:32 OK 2_object_stats_trigger.sql (1.7ms)11282026/09/23 13:01:32 OK 2_object_stats_trigger.sql (1.58ms)11292026/09/23 13:01:32 OK 2_object_stats_trigger.sql (1.85ms)11302026/09/23 13:01:32 OK 3_commit_push.sql (2.63ms)11312026/09/23 13:01:32 goose: up to current file version: 311322026/09/23 13:01:32 OK 3_commit_push.sql (2.6ms)11332026/09/23 13:01:32 goose: up to current file version: 311342026/09/23 13:01:32 OK 2_object_stats_trigger.sql (2.89ms)11352026/09/23 13:01:32 OK 3_commit_push.sql (2.14ms)11362026/09/23 13:01:32 goose: up to current file version: 311372026/09/23 13:01:32 OK 3_commit_push.sql (2.11ms)11382026/09/23 13:01:32 goose: up to current file version: 311392026-09-23 13:01:32.960 UTC [485] ERROR: relation "goose_db_version" does not exist at character 3611402026-09-23 13:01:32.960 UTC [485] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11412026/09/23 13:01:32 INFO Received uploads request method=POST path=/api/pending_closures11422026/09/23 13:01:33 OK 20241026095416_initial_model.sql (10.96ms)11432026-09-23 13:01:33.004 UTC [486] ERROR: relation "goose_db_version" does not exist at character 3611442026-09-23 13:01:33.004 UTC [486] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11452026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (2.6ms)11462026/09/23 13:01:33 OK 20251218171726_add_pins.sql (4.06ms)11472026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (3.09ms)1148--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.66s)1149=== CONT TestCompletedNarNotReofferedAcrossClosures11502026/09/23 13:01:33 OK 20260905000000_add_claims.sql (2.88ms)11512026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (2.05ms)11522026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (2.22ms)11532026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000011542026/09/23 13:01:33 OK 20241026095416_initial_model.sql (11.38ms)11552026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (1.32ms)11562026/09/23 13:01:33 OK 1_commit_pending_closure.sql (2.6ms)11572026/09/23 13:01:33 OK 2_object_stats_trigger.sql (1.32ms)11582026/09/23 13:01:33 OK 20251218171726_add_pins.sql (3.06ms)11592026/09/23 13:01:33 OK 3_commit_push.sql (2.01ms)11602026/09/23 13:01:33 goose: up to current file version: 311612026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)11622026/09/23 13:01:33 OK 20260905000000_add_claims.sql (4.96ms)11632026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (3.33ms)11642026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (3.22ms)11652026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000011662026/09/23 13:01:33 OK 1_commit_pending_closure.sql (3.27ms)11672026/09/23 13:01:33 OK 2_object_stats_trigger.sql (1.59ms)11682026/09/23 13:01:33 OK 3_commit_push.sql (1.55ms)11692026/09/23 13:01:33 goose: up to current file version: 31170=== NAME TestNARDeduplicationMetadataUploadBug1171 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1387140286/001/store/27bp4zzldvv5cd2vhfqgq9ln6nn1nbp5-file1.txt1172--- PASS: TestReadProxyRangeRequest (0.72s)1173=== CONT TestReadProxyRootRedirectsToIndexHTML11742026/09/23 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures11752026-09-23 13:01:33.090 UTC [509] ERROR: relation "goose_db_version" does not exist at character 3611762026-09-23 13:01:33.090 UTC [509] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11772026/09/23 13:01:33 OK 20241026095416_initial_model.sql (11.66ms)11782026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)11792026/09/23 13:01:33 OK 20251218171726_add_pins.sql (4.45ms)11802026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (4.43ms)11812026/09/23 13:01:33 INFO lead: acquired remote=192.0.2.1:123411822026/09/23 13:01:33 INFO lead: released remote=192.0.2.1:12341183--- PASS: TestLeadEndsOnShutdown (0.76s)1184=== CONT TestCompleteMultipartUpload_ErrorButObjectExists11852026/09/23 13:01:33 OK 20260905000000_add_claims.sql (4.29ms)11862026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (3.2ms)11872026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (2.26ms)11882026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000011892026/09/23 13:01:33 OK 1_commit_pending_closure.sql (1.96ms)11902026/09/23 13:01:33 OK 2_object_stats_trigger.sql (1.05ms)11912026/09/23 13:01:33 OK 3_commit_push.sql (1.9ms)11922026/09/23 13:01:33 goose: up to current file version: 311932026-09-23 13:01:33.141 UTC [530] ERROR: relation "goose_db_version" does not exist at character 3611942026-09-23 13:01:33.141 UTC [530] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11952026/09/23 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures11962026/09/23 13:01:33 INFO Received cleanup request method=DELETE path=/api/pending_closures11972026/09/23 13:01:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11982026/09/23 13:01:33 INFO Uploading 27bp4zzldvv5cd2vhfqgq9ln6nn1nbp5-file1.txt (160B)11992026/09/23 13:01:33 INFO Aborted multipart uploads count=012002026/09/23 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures12012026/09/23 13:01:33 OK 20241026095416_initial_model.sql (12.7ms)12022026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (2.65ms)12032026/09/23 13:01:33 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12042026/09/23 13:01:33 WARN Failed to register uploaded object key=27bp4zzldvv5cd2vhfqgq9ln6nn1nbp5.ls error="server returned 404: 404 page not found\n"12052026/09/23 13:01:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12062026/09/23 13:01:33 INFO Signed narinfos id=1 count=112072026/09/23 13:01:33 INFO Uploading 1 narinfos12082026/09/23 13:01:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12092026/09/23 13:01:33 WARN Failed to register uploaded object key=27bp4zzldvv5cd2vhfqgq9ln6nn1nbp5.narinfo error="server returned 404: 404 page not found\n"12102026/09/23 13:01:33 OK 20251218171726_add_pins.sql (11.82ms)12112026/09/23 13:01:33 INFO Received cleanup request method=DELETE path=/api/pending_closures12122026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (4.89ms)12132026/09/23 13:01:33 WARN readiness check failed error="closed pool"1214--- PASS: TestService_readinessHandler (0.83s)1215=== CONT TestReadProxyConditionalGet12162026/09/23 13:01:33 INFO Aborted multipart uploads count=112172026/09/23 13:01:33 INFO Completed upload id=112182026/09/23 13:01:33 INFO Upload complete. (78ms)12192026/09/23 13:01:33 OK 20260905000000_add_claims.sql (3.63ms)1220=== NAME TestNARDeduplicationMetadataUploadBug1221 metadata_upload_test.go:54: Retrieved narinfo from S3:1222 StorePath: /build/TestNARDeduplicationMetadataUploadBug1387140286/001/store/27bp4zzldvv5cd2vhfqgq9ln6nn1nbp5-file1.txt1223 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1224 Compression: zstd1225 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1226 NarSize: 1601227 References: 1228 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12292026/09/23 13:01:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12302026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (2.32ms)12312026-09-23 13:01:33.187 UTC [463] ERROR: Closure does not exist: id=112322026-09-23 13:01:33.187 UTC [463] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE12332026-09-23 13:01:33.187 UTC [463] STATEMENT: -- name: CommitPendingClosure :exec1234 SELECT commit_pending_closure($1::bigint)1235 1236--- PASS: TestService_cleanupPendingClosuresHandler (0.83s)1237=== CONT TestReadProxyHead12382026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (2.36ms)12392026/09/23 13:01:33 goose: successfully migrated database to version: 202609231200001240=== NAME TestNARDeduplicationMetadataUploadBug1241 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1242 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1243 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12442026/09/23 13:01:33 OK 1_commit_pending_closure.sql (2.22ms)12452026/09/23 13:01:33 OK 2_object_stats_trigger.sql (2.18ms)12462026-09-23 13:01:33.196 UTC [551] ERROR: relation "goose_db_version" does not exist at character 3612472026-09-23 13:01:33.196 UTC [551] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12482026/09/23 13:01:33 OK 3_commit_push.sql (1.49ms)12492026/09/23 13:01:33 goose: up to current file version: 312502026/09/23 13:01:33 INFO Received cleanup request method=DELETE path=/api/pending_closures12512026/09/23 13:01:33 INFO Aborted multipart uploads count=112522026/09/23 13:01:33 OK 20241026095416_initial_model.sql (14.6ms)12532026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (2.84ms)12542026/09/23 13:01:33 OK 20251218171726_add_pins.sql (4.48ms)1255--- PASS: TestMultipartCleanup (0.87s)1256=== CONT TestRedundantMultipartUpload1257=== NAME TestNARDeduplicationMetadataUploadBug1258 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1387140286/001/store/713zplldizymj18kyj2zv8cimr4x0mgw-file2.txt12592026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (7.07ms)12602026/09/23 13:01:33 OK 20260905000000_add_claims.sql (4.94ms)1261--- PASS: TestMetricsInventory (0.89s)1262=== CONT TestPinProtectsFromGC12632026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (3.71ms)12642026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (3.6ms)12652026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000012662026/09/23 13:01:33 OK 1_commit_pending_closure.sql (3.7ms)12672026/09/23 13:01:33 OK 2_object_stats_trigger.sql (2.76ms)12682026/09/23 13:01:33 OK 3_commit_push.sql (2.79ms)12692026/09/23 13:01:33 goose: up to current file version: 31270--- PASS: TestReadRedirectNar (0.90s)1271=== CONT TestPush_SignsNarinfosOfItsPendingObjects12722026-09-23 13:01:33.261 UTC [576] ERROR: relation "goose_db_version" does not exist at character 3612732026-09-23 13:01:33.261 UTC [576] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12742026-09-23 13:01:33.273 UTC [596] ERROR: relation "goose_db_version" does not exist at character 3612752026-09-23 13:01:33.273 UTC [596] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12762026/09/23 13:01:33 OK 20241026095416_initial_model.sql (26.17ms)12772026/09/23 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures12782026/09/23 13:01:33 OK 20241026095416_initial_model.sql (14.07ms)12792026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (3.77ms)12802026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)12812026/09/23 13:01:33 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12822026/09/23 13:01:33 OK 20251218171726_add_pins.sql (4.41ms)12832026/09/23 13:01:33 OK 20251218171726_add_pins.sql (4.39ms)12842026-09-23 13:01:33.308 UTC [614] ERROR: relation "goose_db_version" does not exist at character 3612852026-09-23 13:01:33.308 UTC [614] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12862026/09/23 13:01:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12872026/09/23 13:01:33 INFO Signed narinfos id=2 count=112882026/09/23 13:01:33 WARN Failed to register uploaded object key=713zplldizymj18kyj2zv8cimr4x0mgw.ls error="server returned 404: 404 page not found\n"12892026/09/23 13:01:33 INFO Uploading 1 narinfos12902026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (6.39ms)12912026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (5.54ms)12922026/09/23 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures12932026/09/23 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures12942026/09/23 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures12952026/09/23 13:01:33 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12962026/09/23 13:01:33 OK 20260905000000_add_claims.sql (5.49ms)12972026/09/23 13:01:33 OK 20260905000000_add_claims.sql (5.64ms)12982026/09/23 13:01:33 WARN Failed to register uploaded object key=713zplldizymj18kyj2zv8cimr4x0mgw.narinfo error="server returned 404: 404 page not found\n"12992026/09/23 13:01:33 INFO Completed upload id=213002026/09/23 13:01:33 INFO Upload complete. (57ms)1301--- PASS: TestObjectStatsTrigger (0.96s)1302=== CONT TestCacheConfigHandler1303=== RUN TestCacheConfigHandler/full_config,_no_issuer1304=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1305=== RUN TestCacheConfigHandler/no_cache_url_configured1306=== PAUSE TestCacheConfigHandler/no_cache_url_configured1307=== RUN TestCacheConfigHandler/no_signing_keys1308=== PAUSE TestCacheConfigHandler/no_signing_keys1309=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1310=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1311=== CONT TestReadProxyInvalidPath13122026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (2.99ms)13132026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (3.06ms)1314=== NAME TestNARDeduplicationMetadataUploadBug1315 metadata_upload_test.go:76: Retrieved narinfo from S3:1316 StorePath: /build/TestNARDeduplicationMetadataUploadBug1387140286/001/store/713zplldizymj18kyj2zv8cimr4x0mgw-file2.txt1317 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1318 Compression: zstd1319 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1320 NarSize: 1601321 References: 1322 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13232026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (3.35ms)13242026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000013252026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (3.42ms)13262026/09/23 13:01:33 goose: successfully migrated database to version: 202609231200001327 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1328 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1329 {"version":1,"root":{"type":"regular","size":44}}13302026/09/23 13:01:33 OK 1_commit_pending_closure.sql (2.87ms)13312026/09/23 13:01:33 OK 1_commit_pending_closure.sql (3ms)13322026/09/23 13:01:33 OK 20241026095416_initial_model.sql (10.44ms)13332026/09/23 13:01:33 OK 2_object_stats_trigger.sql (1.59ms)13342026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (1.3ms)13352026/09/23 13:01:33 OK 2_object_stats_trigger.sql (1.46ms)13362026-09-23 13:01:33.327 UTC [616] ERROR: relation "goose_db_version" does not exist at character 3613372026-09-23 13:01:33.327 UTC [616] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13382026/09/23 13:01:33 OK 3_commit_push.sql (1.47ms)13392026/09/23 13:01:33 goose: up to current file version: 313402026/09/23 13:01:33 OK 3_commit_push.sql (1.61ms)13412026/09/23 13:01:33 goose: up to current file version: 31342--- PASS: TestNARDeduplicationMetadataUploadBug (0.98s)1343=== CONT TestService_ReadScope_PublicByDefault13442026/09/23 13:01:33 OK 20251218171726_add_pins.sql (2.95ms)13452026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)13462026-09-23 13:01:33.336 UTC [618] ERROR: relation "goose_db_version" does not exist at character 3613472026-09-23 13:01:33.336 UTC [618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13482026/09/23 13:01:33 OK 20260905000000_add_claims.sql (4.06ms)13492026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (3.1ms)13502026/09/23 13:01:33 INFO lead: acquired remote=192.0.2.1:123413512026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (3.49ms)13522026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000013532026/09/23 13:01:33 OK 20241026095416_initial_model.sql (12.26ms)13542026/09/23 13:01:33 OK 1_commit_pending_closure.sql (3.58ms)13552026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (4.45ms)13562026/09/23 13:01:33 OK 2_object_stats_trigger.sql (2.84ms)13572026/09/23 13:01:33 OK 20241026095416_initial_model.sql (10.22ms)13582026/09/23 13:01:33 OK 3_commit_push.sql (2.3ms)13592026/09/23 13:01:33 goose: up to current file version: 313602026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)13612026/09/23 13:01:33 OK 20251218171726_add_pins.sql (5.81ms)13622026/09/23 13:01:33 OK 20251218171726_add_pins.sql (4.14ms)13632026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)13642026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (4.34ms)13652026/09/23 13:01:33 OK 20260905000000_add_claims.sql (4.03ms)13662026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (3.28ms)13672026/09/23 13:01:33 OK 20260905000000_add_claims.sql (4.89ms)13682026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (2.94ms)13692026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (3.64ms)13702026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000013712026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (2.7ms)13722026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000013732026/09/23 13:01:33 OK 1_commit_pending_closure.sql (3.43ms)13742026/09/23 13:01:33 OK 1_commit_pending_closure.sql (2.93ms)13752026/09/23 13:01:33 OK 2_object_stats_trigger.sql (2.98ms)13762026/09/23 13:01:33 OK 2_object_stats_trigger.sql (1.81ms)13772026/09/23 13:01:33 OK 3_commit_push.sql (1.48ms)13782026/09/23 13:01:33 goose: up to current file version: 313792026/09/23 13:01:33 OK 3_commit_push.sql (1.55ms)13802026/09/23 13:01:33 goose: up to current file version: 313812026/09/23 13:01:33 INFO Aborted multipart uploads count=013822026/09/23 13:01:33 WARN Force mode enabled - objects will be deleted immediately without grace period13832026/09/23 13:01:33 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=013842026/09/23 13:01:33 INFO Vacuumed table table=pending_closures13852026/09/23 13:01:33 INFO Vacuumed table table=pending_objects13862026/09/23 13:01:33 INFO Vacuumed table table=multipart_uploads13872026/09/23 13:01:33 INFO Vacuumed table table=closures13882026/09/23 13:01:33 INFO Vacuumed table table=objects1389--- PASS: TestGCMetrics (1.04s)1390=== CONT TestReadProxy40413912026-09-23 13:01:33.403 UTC [623] ERROR: relation "goose_db_version" does not exist at character 3613922026-09-23 13:01:33.403 UTC [623] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1393--- PASS: TestReadRedirectKeepsNarinfoProxied (1.06s)1394=== CONT TestPush_RejectsBadRequests13952026-09-23 13:01:33.425 UTC [626] ERROR: relation "goose_db_version" does not exist at character 3613962026-09-23 13:01:33.425 UTC [626] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13972026/09/23 13:01:33 INFO lead: released remote=192.0.2.1:123413982026/09/23 13:01:33 INFO lead: acquired remote=192.0.2.1:123413992026/09/23 13:01:33 INFO lead: released remote=192.0.2.1:12341400--- PASS: TestLeadElectsOneAndHandsOver (1.12s)1401=== CONT TestService_RequireScope_OIDC14022026/09/23 13:01:33 OK 20241026095416_initial_model.sql (153.1ms)14032026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (4.64ms)14042026/09/23 13:01:33 OK 20251218171726_add_pins.sql (5.73ms)14052026-09-23 13:01:33.588 UTC [631] ERROR: relation "goose_db_version" does not exist at character 3614062026-09-23 13:01:33.588 UTC [631] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14072026/09/23 13:01:33 OK 20241026095416_initial_model.sql (28.17ms)14082026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (23.68ms)14092026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (3.38ms)14102026/09/23 13:01:33 OK 20260905000000_add_claims.sql (6.66ms)14112026/09/23 13:01:33 OK 20251218171726_add_pins.sql (5.53ms)1412--- PASS: TestService_healthCheckHandler (1.25s)1413=== CONT TestReadProxyNarStreaming14142026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (4.34ms)14152026/09/23 13:01:33 OK 20241026095416_initial_model.sql (12.47ms)14162026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (6.87ms)14172026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (3.62ms)14182026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000014192026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (2.01ms)14202026/09/23 13:01:33 OK 1_commit_pending_closure.sql (3.64ms)14212026/09/23 13:01:33 OK 20251218171726_add_pins.sql (4.4ms)14222026/09/23 13:01:33 OK 20260905000000_add_claims.sql (5.81ms)14232026/09/23 13:01:33 OK 2_object_stats_trigger.sql (2.19ms)14242026/09/23 13:01:33 OK 3_commit_push.sql (1.99ms)14252026/09/23 13:01:33 goose: up to current file version: 314262026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)14272026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (4.51ms)14282026/09/23 13:01:33 OK 20260905000000_add_claims.sql (4.39ms)14292026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (4.83ms)14302026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000014312026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (3.01ms)14322026/09/23 13:01:33 OK 1_commit_pending_closure.sql (4.17ms)14332026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (3.23ms)14342026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000014352026/09/23 13:01:33 OK 2_object_stats_trigger.sql (2.31ms)14362026/09/23 13:01:33 OK 1_commit_pending_closure.sql (3.18ms)14372026/09/23 13:01:33 OK 3_commit_push.sql (3.22ms)14382026/09/23 13:01:33 goose: up to current file version: 314392026/09/23 13:01:33 OK 2_object_stats_trigger.sql (2.65ms)14402026/09/23 13:01:33 OK 3_commit_push.sql (2.15ms)14412026/09/23 13:01:33 goose: up to current file version: 314422026/09/23 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures14432026/09/23 13:01:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32913/oidc14442026-09-23 13:01:33.655 UTC [634] ERROR: relation "goose_db_version" does not exist at character 3614452026-09-23 13:01:33.655 UTC [634] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14462026/09/23 13:01:33 OK 20241026095416_initial_model.sql (11.54ms)14472026/09/23 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures14482026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (2.97ms)14492026/09/23 13:01:33 OK 20251218171726_add_pins.sql (3.82ms)14502026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (4.33ms)14512026-09-23 13:01:33.691 UTC [637] ERROR: relation "goose_db_version" does not exist at character 3614522026-09-23 13:01:33.691 UTC [637] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14532026/09/23 13:01:33 OK 20260905000000_add_claims.sql (11.02ms)14542026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (3.58ms)14552026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (2.8ms)14562026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000014572026/09/23 13:01:33 OK 1_commit_pending_closure.sql (2.52ms)14582026/09/23 13:01:33 OK 20241026095416_initial_model.sql (8.39ms)14592026/09/23 13:01:33 OK 2_object_stats_trigger.sql (1.7ms)14602026/09/23 13:01:33 OK 3_commit_push.sql (817.29µs)14612026/09/23 13:01:33 goose: up to current file version: 314622026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)1463--- PASS: TestService_Rustfstest (1.28s)1464=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected14652026/09/23 13:01:33 OK 20251218171726_add_pins.sql (3.93ms)14662026-09-23 13:01:33.713 UTC [638] ERROR: relation "goose_db_version" does not exist at character 3614672026-09-23 13:01:33.713 UTC [638] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14682026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (4.11ms)14692026/09/23 13:01:33 OK 20260905000000_add_claims.sql (3.23ms)14702026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (3.17ms)14712026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (3.25ms)14722026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000014732026/09/23 13:01:33 OK 20241026095416_initial_model.sql (10.26ms)14742026/09/23 13:01:33 OK 1_commit_pending_closure.sql (2.04ms)14752026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)14762026/09/23 13:01:33 OK 2_object_stats_trigger.sql (2.66ms)14772026/09/23 13:01:33 OK 20251218171726_add_pins.sql (3.92ms)14782026/09/23 13:01:33 OK 3_commit_push.sql (3.13ms)14792026/09/23 13:01:33 goose: up to current file version: 314802026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (3.93ms)14812026/09/23 13:01:33 OK 20260905000000_add_claims.sql (3.67ms)14822026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (3.79ms)14832026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (3.98ms)14842026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000014852026/09/23 13:01:33 OK 1_commit_pending_closure.sql (3.6ms)14862026/09/23 13:01:33 OK 2_object_stats_trigger.sql (2.76ms)14872026/09/23 13:01:33 OK 3_commit_push.sql (2.25ms)14882026/09/23 13:01:33 goose: up to current file version: 314892026/09/23 13:01:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14902026/09/23 13:01:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14912026/09/23 13:01:33 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1492--- PASS: TestCompleteMultipartUnregistered (1.42s)1493=== CONT TestService_AuthMiddleware_OIDC14942026-09-23 13:01:33.777 UTC [642] ERROR: relation "goose_db_version" does not exist at character 3614952026-09-23 13:01:33.777 UTC [642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14962026/09/23 13:01:33 OK 20241026095416_initial_model.sql (9.86ms)14972026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (1.37ms)14982026/09/23 13:01:33 OK 20251218171726_add_pins.sql (3.16ms)14992026/09/23 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures15002026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (4.14ms)15012026/09/23 13:01:33 OK 20260905000000_add_claims.sql (3.49ms)15022026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (2.06ms)15032026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (1.62ms)15042026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000015052026/09/23 13:01:33 OK 1_commit_pending_closure.sql (1.73ms)15062026/09/23 13:01:33 OK 2_object_stats_trigger.sql (904.19µs)15072026/09/23 13:01:33 OK 3_commit_push.sql (1.03ms)15082026/09/23 13:01:33 goose: up to current file version: 315092026/09/23 13:01:33 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst15102026/09/23 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures1511--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.30s)1512=== CONT TestReadProxyNarinfoAlreadyDecompressed1513--- PASS: TestReadProxyDisabled (1.19s)1514=== CONT TestPush_CompleteCommitsEveryRoot15152026-09-23 13:01:33.901 UTC [715] ERROR: relation "goose_db_version" does not exist at character 3615162026-09-23 13:01:33.901 UTC [715] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15172026/09/23 13:01:33 OK 20241026095416_initial_model.sql (10.84ms)15182026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (3.43ms)15192026/09/23 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures15202026/09/23 13:01:33 OK 20251218171726_add_pins.sql (3.61ms)15212026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)15222026/09/23 13:01:33 OK 20260905000000_add_claims.sql (3.59ms)15232026/09/23 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures15242026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (2.67ms)15252026-09-23 13:01:33.937 UTC [751] ERROR: relation "goose_db_version" does not exist at character 3615262026-09-23 13:01:33.937 UTC [751] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15272026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (1.98ms)15282026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000015292026/09/23 13:01:33 OK 1_commit_pending_closure.sql (1.97ms)15302026/09/23 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures15312026/09/23 13:01:33 OK 2_object_stats_trigger.sql (1.11ms)15322026/09/23 13:01:33 OK 3_commit_push.sql (919.61µs)15332026/09/23 13:01:33 goose: up to current file version: 315342026/09/23 13:01:33 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15352026/09/23 13:01:33 INFO Uploading 2lsb3x40kvzh77wrss8skkddr97r6mmv-shared-dep (136B)15362026/09/23 13:01:33 INFO Uploading gc4fvaqjd6rir1hqkq5i63hvdh077p9i-b (216B)15372026/09/23 13:01:33 WARN Failed to register uploaded object key=2lsb3x40kvzh77wrss8skkddr97r6mmv.ls error="server returned 404: 404 page not found\n"15382026/09/23 13:01:33 WARN Failed to register uploaded object key=gc4fvaqjd6rir1hqkq5i63hvdh077p9i.ls error="server returned 404: 404 page not found\n"15392026/09/23 13:01:33 WARN Failed to register uploaded object key=28pdsq9hhyffaclcg1k42s3s3f6hwdnv.ls error="server returned 404: 404 page not found\n"15402026/09/23 13:01:33 WARN Failed to register uploaded object key=nar/0ydgs5pf41dsxnf2xdz23y24j1rj0rb6kzzdcgvqz8f2sfhhhay1.nar.zst error="server returned 404: 404 page not found\n"15412026/09/23 13:01:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15422026/09/23 13:01:33 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15432026/09/23 13:01:33 OK 20241026095416_initial_model.sql (10.83ms)15442026/09/23 13:01:33 INFO Signed narinfos id=1 count=215452026/09/23 13:01:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15462026/09/23 13:01:33 INFO Signed narinfos id=2 count=215472026/09/23 13:01:33 INFO Uploading 4 narinfos15482026/09/23 13:01:33 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)15492026/09/23 13:01:33 OK 20251218171726_add_pins.sql (3.58ms)1550--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.89s)1551=== CONT TestService_ReadAuthMiddleware15522026/09/23 13:01:33 WARN Failed to register uploaded object key=gc4fvaqjd6rir1hqkq5i63hvdh077p9i.narinfo error="server returned 404: 404 page not found\n"15532026/09/23 13:01:33 WARN Failed to register uploaded object key=28pdsq9hhyffaclcg1k42s3s3f6hwdnv.narinfo error="server returned 404: 404 page not found\n"15542026/09/23 13:01:33 WARN Failed to register uploaded object key=2lsb3x40kvzh77wrss8skkddr97r6mmv.narinfo error="server returned 404: 404 page not found\n"15552026/09/23 13:01:33 OK 20260628120000_add_object_size_and_stats.sql (3.34ms)15562026/09/23 13:01:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15572026/09/23 13:01:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15582026/09/23 13:01:33 WARN Failed to register uploaded object key=2lsb3x40kvzh77wrss8skkddr97r6mmv.narinfo error="server returned 404: 404 page not found\n"15592026/09/23 13:01:33 OK 20260905000000_add_claims.sql (3.36ms)15602026/09/23 13:01:33 OK 20260920000000_drop_claims.sql (2.17ms)15612026/09/23 13:01:33 OK 20260923120000_add_pushes.sql (1.86ms)15622026/09/23 13:01:33 goose: successfully migrated database to version: 2026092312000015632026/09/23 13:01:33 INFO Completed upload id=115642026/09/23 13:01:33 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15652026/09/23 13:01:33 OK 1_commit_pending_closure.sql (8.9ms)15662026/09/23 13:01:33 INFO Completed upload id=215672026/09/23 13:01:33 INFO Upload complete. (91ms)15682026/09/23 13:01:33 OK 2_object_stats_trigger.sql (3.34ms)1569=== NAME TestClientFallsBackToClosures1570 client_pushes_test.go:112: Retrieved narinfo from S3:1571 StorePath: /build/TestClientFallsBackToClosures2920055149/001/store/2lsb3x40kvzh77wrss8skkddr97r6mmv-shared-dep1572 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1573 Compression: zstd1574 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821575 NarSize: 1361576 References: 1577 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15782026/09/23 13:01:33 OK 3_commit_push.sql (2.75ms)15792026/09/23 13:01:33 goose: up to current file version: 31580 client_pushes_test.go:112: Retrieved narinfo from S3:1581 StorePath: /build/TestClientFallsBackToClosures2920055149/001/store/28pdsq9hhyffaclcg1k42s3s3f6hwdnv-a1582 URL: nar/0ydgs5pf41dsxnf2xdz23y24j1rj0rb6kzzdcgvqz8f2sfhhhay1.nar.zst1583 Compression: zstd1584 NarHash: sha256:0ydgs5pf41dsxnf2xdz23y24j1rj0rb6kzzdcgvqz8f2sfhhhay11585 NarSize: 2161586 References: /build/TestClientFallsBackToClosures2920055149/001/store/2lsb3x40kvzh77wrss8skkddr97r6mmv-shared-dep1587 CA: text:sha256:0blfxpf4wxxbk5kvx1avvxpa57ia4a6vfvx9ywmnx3096haghf8z15882026/09/23 13:01:33 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=N2Q1MDQ4NjUtZGUxNi00NmNlLTllNzItYjA4ODMzZjM2ODliLmNmOTJkZWYzLWFkOTctNGNmNC05NGI3LWJjZDAxYjA0YTYyMHgxNzkwMTY4NDkzMzIyOTkxNzYw parts=1015892026/09/23 13:01:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15902026/09/23 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures1591 client_pushes_test.go:112: Retrieved narinfo from S3:1592 StorePath: /build/TestClientFallsBackToClosures2920055149/001/store/gc4fvaqjd6rir1hqkq5i63hvdh077p9i-b1593 URL: nar/0ydgs5pf41dsxnf2xdz23y24j1rj0rb6kzzdcgvqz8f2sfhhhay1.nar.zst1594 Compression: zstd1595 NarHash: sha256:0ydgs5pf41dsxnf2xdz23y24j1rj0rb6kzzdcgvqz8f2sfhhhay11596 NarSize: 2161597 References: /build/TestClientFallsBackToClosures2920055149/001/store/2lsb3x40kvzh77wrss8skkddr97r6mmv-shared-dep1598 CA: text:sha256:0blfxpf4wxxbk5kvx1avvxpa57ia4a6vfvx9ywmnx3096haghf8z15992026/09/23 13:01:33 INFO Completed upload id=116002026/09/23 13:01:33 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016012026/09/23 13:01:33 INFO Received uploads request method=POST path=/api/pending_closures1602--- PASS: TestClientFallsBackToClosures (1.51s)1603=== CONT TestReadProxyNarinfo16042026/09/23 13:01:34 INFO Starting cleanup of old closures method=DELETE path=/api/closures16052026/09/23 13:01:34 INFO Aborted multipart uploads count=016062026/09/23 13:01:34 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=016072026-09-23 13:01:34.033 UTC [811] ERROR: relation "goose_db_version" does not exist at character 3616082026-09-23 13:01:34.033 UTC [811] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16092026/09/23 13:01:34 INFO Vacuumed table table=pending_closures1610--- PASS: TestReadProxyHead (0.85s)1611=== CONT TestPush_OverlappingRootsStoreOneRowPerKey16122026/09/23 13:01:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16132026/09/23 13:01:34 INFO Vacuumed table table=pending_objects16142026/09/23 13:01:34 INFO Vacuumed table table=multipart_uploads16152026/09/23 13:01:34 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=N2Q1MDQ4NjUtZGUxNi00NmNlLTllNzItYjA4ODMzZjM2ODliLjJmYTMwN2E4LWZhNmQtNDc2Yi1hN2YwLWJiYTg0NjIyNTI4M3gxNzkwMTY4NDk0MDA0NDk0OTM516162026/09/23 13:01:34 INFO Vacuumed table table=closures16172026/09/23 13:01:34 INFO Vacuumed table table=objects16182026/09/23 13:01:34 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=N2Q1MDQ4NjUtZGUxNi00NmNlLTllNzItYjA4ODMzZjM2ODliLjJmYTMwN2E4LWZhNmQtNDc2Yi1hN2YwLWJiYTg0NjIyNTI4M3gxNzkwMTY4NDk0MDA0NDk0OTM5 parts=116192026/09/23 13:01:34 OK 20241026095416_initial_model.sql (12.67ms)1620--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.93s)1621=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16222026/09/23 13:01:34 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001623--- PASS: TestService_createPendingClosureHandler (1.70s)1624=== CONT TestIsValidCachePath1625=== RUN TestIsValidCachePath/narinfo1626=== PAUSE TestIsValidCachePath/narinfo1627=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1628=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1629=== RUN TestIsValidCachePath/nar_zst1630=== PAUSE TestIsValidCachePath/nar_zst1631=== RUN TestIsValidCachePath/nar_xz1632=== PAUSE TestIsValidCachePath/nar_xz1633=== RUN TestIsValidCachePath/nar_bz21634=== PAUSE TestIsValidCachePath/nar_bz21635=== RUN TestIsValidCachePath/nar_uncompressed1636=== PAUSE TestIsValidCachePath/nar_uncompressed1637=== RUN TestIsValidCachePath/ls1638=== PAUSE TestIsValidCachePath/ls1639=== RUN TestIsValidCachePath/log1640=== PAUSE TestIsValidCachePath/log1641=== RUN TestIsValidCachePath/realisation1642=== PAUSE TestIsValidCachePath/realisation1643=== RUN TestIsValidCachePath/nix-cache-info1644=== PAUSE TestIsValidCachePath/nix-cache-info1645=== RUN TestIsValidCachePath/index.html1646=== PAUSE TestIsValidCachePath/index.html1647=== RUN TestIsValidCachePath/traversal_parent1648=== PAUSE TestIsValidCachePath/traversal_parent1649=== RUN TestIsValidCachePath/traversal_in_middle1650=== PAUSE TestIsValidCachePath/traversal_in_middle1651=== RUN TestIsValidCachePath/invalid_char_e1652=== PAUSE TestIsValidCachePath/invalid_char_e1653=== RUN TestIsValidCachePath/invalid_char_u1654=== PAUSE TestIsValidCachePath/invalid_char_u1655=== RUN TestIsValidCachePath/random_path1656=== PAUSE TestIsValidCachePath/random_path1657=== RUN TestIsValidCachePath/empty1658=== PAUSE TestIsValidCachePath/empty1659=== RUN TestIsValidCachePath/leading_slash1660=== PAUSE TestIsValidCachePath/leading_slash1661=== RUN TestIsValidCachePath/wrong_extension1662=== PAUSE TestIsValidCachePath/wrong_extension1663=== RUN TestIsValidCachePath/short_hash1664=== PAUSE TestIsValidCachePath/short_hash1665=== CONT TestReadRedirectUsesPublicS3URL16662026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)16672026/09/23 13:01:34 OK 20251218171726_add_pins.sql (5.06ms)1668--- PASS: TestGCBugBareHashReferences (1.71s)1669=== CONT TestService_AuthMiddleware_MTLSProxyHeader16702026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (5.42ms)16712026/09/23 13:01:34 OK 20260905000000_add_claims.sql (5.07ms)1672--- PASS: TestReadProxyConditionalGet (0.89s)1673=== CONT TestCacheStatsHandler16742026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (4.54ms)16752026-09-23 13:01:34.083 UTC [838] ERROR: relation "goose_db_version" does not exist at character 3616762026-09-23 13:01:34.083 UTC [838] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16772026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (3.86ms)16782026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000016792026/09/23 13:01:34 OK 1_commit_pending_closure.sql (3.64ms)16802026/09/23 13:01:34 OK 2_object_stats_trigger.sql (2.55ms)16812026/09/23 13:01:34 OK 3_commit_push.sql (2.39ms)16822026/09/23 13:01:34 goose: up to current file version: 316832026/09/23 13:01:34 INFO Received uploads request method=POST path=/api/pending_closures16842026/09/23 13:01:34 INFO Received uploads request method=POST path=/api/pending_closures16852026/09/23 13:01:34 OK 20241026095416_initial_model.sql (19.79ms)16862026/09/23 13:01:34 INFO Received uploads request method=POST path=/api/pending_closures16872026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (3.82ms)16882026/09/23 13:01:34 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16892026/09/23 13:01:34 INFO Uploading wa9l5rkcqs5cl3rdmzn4pb9swyfw0ka0-a (208B)16902026/09/23 13:01:34 INFO Uploading vwi4a618lvn0chfh04mpw1dshmhbvfz2-shared-dep (136B)16912026/09/23 13:01:34 OK 20251218171726_add_pins.sql (4.36ms)16922026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (6.01ms)16932026/09/23 13:01:34 INFO Received uploads request method=POST path=/api/pending_closures16942026/09/23 13:01:34 WARN Failed to register uploaded object key=9i4lzj9xnm9755sg69d1gr4zbg1rdz9y.ls error="server returned 404: 404 page not found\n"16952026/09/23 13:01:34 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16962026/09/23 13:01:34 WARN Failed to register uploaded object key=nar/07dvz18mmq50qc1d3smvaqgczqs63xz5k4q7ss1852l4cynvqbzq.nar.zst error="server returned 404: 404 page not found\n"16972026/09/23 13:01:34 WARN Failed to register uploaded object key=vwi4a618lvn0chfh04mpw1dshmhbvfz2.ls error="server returned 404: 404 page not found\n"16982026/09/23 13:01:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16992026/09/23 13:01:34 WARN Failed to register uploaded object key=wa9l5rkcqs5cl3rdmzn4pb9swyfw0ka0.ls error="server returned 404: 404 page not found\n"17002026/09/23 13:01:34 INFO Signed narinfos id=1 count=217012026/09/23 13:01:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17022026/09/23 13:01:34 INFO Signed narinfos id=2 count=217032026/09/23 13:01:34 INFO Uploading 4 narinfos17042026/09/23 13:01:34 OK 20260905000000_add_claims.sql (4.25ms)17052026-09-23 13:01:34.132 UTC [859] ERROR: relation "goose_db_version" does not exist at character 3617062026-09-23 13:01:34.132 UTC [859] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17072026/09/23 13:01:34 INFO Received push request method=POST path=/api/pushes17082026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (3.59ms)17092026/09/23 13:01:34 WARN Failed to register uploaded object key=vwi4a618lvn0chfh04mpw1dshmhbvfz2.narinfo error="server returned 404: 404 page not found\n"17102026/09/23 13:01:34 WARN Failed to register uploaded object key=9i4lzj9xnm9755sg69d1gr4zbg1rdz9y.narinfo error="server returned 404: 404 page not found\n"17112026/09/23 13:01:34 WARN Failed to register uploaded object key=wa9l5rkcqs5cl3rdmzn4pb9swyfw0ka0.narinfo error="server returned 404: 404 page not found\n"17122026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (4.11ms)17132026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000017142026/09/23 13:01:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17152026/09/23 13:01:34 WARN Failed to register uploaded object key=vwi4a618lvn0chfh04mpw1dshmhbvfz2.narinfo error="server returned 404: 404 page not found\n"17162026/09/23 13:01:34 OK 1_commit_pending_closure.sql (3.5ms)17172026/09/23 13:01:34 OK 2_object_stats_trigger.sql (2.93ms)17182026-09-23 13:01:34.146 UTC [860] ERROR: relation "goose_db_version" does not exist at character 3617192026-09-23 13:01:34.146 UTC [860] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17202026/09/23 13:01:34 OK 3_commit_push.sql (2.18ms)17212026/09/23 13:01:34 goose: up to current file version: 317222026/09/23 13:01:34 INFO Completed upload id=117232026/09/23 13:01:34 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17242026/09/23 13:01:34 OK 20241026095416_initial_model.sql (11.11ms)17252026/09/23 13:01:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17262026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (2.36ms)17272026/09/23 13:01:34 INFO Completed upload id=217282026/09/23 13:01:34 INFO Signed narinfos id=1 count=117292026/09/23 13:01:34 INFO Upload complete. (100ms)1730--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.90s)1731=== CONT TestResurrectedObjectNotDeleted1732=== NAME TestClientPushesUseOnePush1733 client_pushes_test.go:97: Retrieved narinfo from S3:1734 StorePath: /build/TestClientPushesUseOnePush98520342/001/store/vwi4a618lvn0chfh04mpw1dshmhbvfz2-shared-dep1735 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1736 Compression: zstd1737 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821738 NarSize: 1361739 References: 1740 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17412026/09/23 13:01:34 OK 20251218171726_add_pins.sql (4.24ms)17422026-09-23 13:01:34.159 UTC [861] ERROR: relation "goose_db_version" does not exist at character 3617432026-09-23 13:01:34.159 UTC [861] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1744 client_pushes_test.go:97: Retrieved narinfo from S3:1745 StorePath: /build/TestClientPushesUseOnePush98520342/001/store/wa9l5rkcqs5cl3rdmzn4pb9swyfw0ka0-a1746 URL: nar/07dvz18mmq50qc1d3smvaqgczqs63xz5k4q7ss1852l4cynvqbzq.nar.zst1747 Compression: zstd1748 NarHash: sha256:07dvz18mmq50qc1d3smvaqgczqs63xz5k4q7ss1852l4cynvqbzq1749 NarSize: 2081750 References: /build/TestClientPushesUseOnePush98520342/001/store/vwi4a618lvn0chfh04mpw1dshmhbvfz2-shared-dep1751 CA: text:sha256:0wpgvfrlpvsfmfdjpz7pd1pxkh1xiy4pyaai0006jji87mx4yyhm17522026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (4.64ms)17532026/09/23 13:01:34 OK 20241026095416_initial_model.sql (11.53ms)17542026-09-23 13:01:34.165 UTC [863] ERROR: relation "goose_db_version" does not exist at character 3617552026-09-23 13:01:34.165 UTC [863] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1756 client_pushes_test.go:97: Retrieved narinfo from S3:1757 StorePath: /build/TestClientPushesUseOnePush98520342/001/store/9i4lzj9xnm9755sg69d1gr4zbg1rdz9y-b1758 URL: nar/07dvz18mmq50qc1d3smvaqgczqs63xz5k4q7ss1852l4cynvqbzq.nar.zst1759 Compression: zstd1760 NarHash: sha256:07dvz18mmq50qc1d3smvaqgczqs63xz5k4q7ss1852l4cynvqbzq1761 NarSize: 2081762 References: /build/TestClientPushesUseOnePush98520342/001/store/vwi4a618lvn0chfh04mpw1dshmhbvfz2-shared-dep1763 CA: text:sha256:0wpgvfrlpvsfmfdjpz7pd1pxkh1xiy4pyaai0006jji87mx4yyhm1764 client_pushes_test.go:100: POST /api/pushes calls = 0, want 11765 client_pushes_test.go:104: POST /api/pending_closures calls = 2, want 01766--- FAIL: TestClientPushesUseOnePush (1.45s)1767=== CONT TestOrphanedObjectsGCStressTest17682026/09/23 13:01:34 OK 20260905000000_add_claims.sql (120.31ms)17692026/09/23 13:01:34 OK 20241026095416_initial_model.sql (119ms)17702026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (120.34ms)17712026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (4.82ms)17722026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (3.48ms)17732026-09-23 13:01:34.289 UTC [865] ERROR: relation "goose_db_version" does not exist at character 3617742026-09-23 13:01:34.289 UTC [865] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17752026/09/23 13:01:34 OK 20251218171726_add_pins.sql (5.51ms)17762026/09/23 13:01:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17772026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (3.96ms)17782026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000017792026/09/23 13:01:34 OK 20251218171726_add_pins.sql (16.42ms)17802026/09/23 13:01:34 OK 1_commit_pending_closure.sql (29.14ms)17812026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (30.96ms)17822026/09/23 13:01:34 OK 20241026095416_initial_model.sql (36.34ms)17832026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (19.88ms)17842026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (3.8ms)17852026/09/23 13:01:34 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=N2Q1MDQ4NjUtZGUxNi00NmNlLTllNzItYjA4ODMzZjM2ODliLjhmZjFhMDlkLTAxYmEtNGY5YS04NjJhLTU5ZWQyOTEwMDUxYngxNzkwMTY4NDkzNjg4ODU5ODMx parts=1017862026/09/23 13:01:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17872026/09/23 13:01:34 OK 2_object_stats_trigger.sql (6.07ms)17882026/09/23 13:01:34 OK 20260905000000_add_claims.sql (7.2ms)17892026/09/23 13:01:34 OK 3_commit_push.sql (2.37ms)17902026/09/23 13:01:34 goose: up to current file version: 317912026/09/23 13:01:34 OK 20260905000000_add_claims.sql (6.84ms)1792--- PASS: TestService_ReadScope_PublicByDefault (1.00s)17932026/09/23 13:01:34 OK 20251218171726_add_pins.sql (6.81ms)1794=== CONT TestParseSingleRange1795=== RUN TestParseSingleRange/none1796=== PAUSE TestParseSingleRange/none1797=== RUN TestParseSingleRange/unknown_unit1798=== PAUSE TestParseSingleRange/unknown_unit1799=== RUN TestParseSingleRange/multi-range_ignored1800=== PAUSE TestParseSingleRange/multi-range_ignored1801=== RUN TestParseSingleRange/malformed_no_dash1802=== PAUSE TestParseSingleRange/malformed_no_dash1803=== RUN TestParseSingleRange/malformed_both_empty1804=== PAUSE TestParseSingleRange/malformed_both_empty1805=== RUN TestParseSingleRange/malformed_end_before_start1806=== PAUSE TestParseSingleRange/malformed_end_before_start1807=== RUN TestParseSingleRange/closed1808=== PAUSE TestParseSingleRange/closed1809=== RUN TestParseSingleRange/open-ended1810=== PAUSE TestParseSingleRange/open-ended1811=== RUN TestParseSingleRange/end_clamped_to_size1812=== PAUSE TestParseSingleRange/end_clamped_to_size1813=== RUN TestParseSingleRange/suffix1814=== PAUSE TestParseSingleRange/suffix1815=== RUN TestParseSingleRange/suffix_exceeds_size1816=== PAUSE TestParseSingleRange/suffix_exceeds_size1817=== RUN TestParseSingleRange/single_byte1818=== PAUSE TestParseSingleRange/single_byte1819=== RUN TestParseSingleRange/start_past_EOF1820=== PAUSE TestParseSingleRange/start_past_EOF1821=== RUN TestParseSingleRange/start_far_past_EOF18222026/09/23 13:01:34 INFO Completed upload id=11823=== PAUSE TestParseSingleRange/start_far_past_EOF1824=== CONT TestProxyHeadersOnlyTrustedOnSocket18252026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (5.21ms)1826=== NAME TestPinProtectsFromGC1827 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC4188081886/001/store/0x0qmipsn92nvnpb2kmlgn338qbjbhky-pinned-file.txt1828 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC4188081886/001/store/bd3hjclsskjbzp453w0zd5k5krwh1rjz-unpinned-file.txt18292026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (3.94ms)18302026/09/23 13:01:34 INFO Received uploads request method=POST path=/api/pending_closures18312026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (4.29ms)18322026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000018332026/09/23 13:01:34 INFO Received uploads request method=POST path=/api/pending_closures18342026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (4.37ms)18352026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000018362026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (7.81ms)18372026/09/23 13:01:34 OK 1_commit_pending_closure.sql (3.91ms)18382026/09/23 13:01:34 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo18392026/09/23 13:01:34 WARN Found objects in DB but missing from S3, will re-upload count=118402026-09-23 13:01:34.344 UTC [904] ERROR: relation "goose_db_version" does not exist at character 3618412026-09-23 13:01:34.344 UTC [904] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18422026/09/23 13:01:34 OK 20241026095416_initial_model.sql (21.53ms)18432026/09/23 13:01:34 OK 1_commit_pending_closure.sql (5.04ms)18442026/09/23 13:01:34 OK 2_object_stats_trigger.sql (2.33ms)1845--- PASS: TestService_verifyS3Integrity (1.99s)1846=== CONT TestClientSharedPathCommittedMidPush18472026/09/23 13:01:34 OK 20260905000000_add_claims.sql (7.46ms)18482026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (4.16ms)18492026/09/23 13:01:34 OK 3_commit_push.sql (4.26ms)18502026/09/23 13:01:34 goose: up to current file version: 318512026/09/23 13:01:34 OK 2_object_stats_trigger.sql (5.59ms)18522026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (5.04ms)18532026/09/23 13:01:34 OK 3_commit_push.sql (2.59ms)18542026/09/23 13:01:34 goose: up to current file version: 318552026/09/23 13:01:34 OK 20251218171726_add_pins.sql (7.28ms)18562026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (5.33ms)18572026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000018582026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (7.22ms)18592026/09/23 13:01:34 OK 1_commit_pending_closure.sql (5.87ms)18602026/09/23 13:01:34 OK 20241026095416_initial_model.sql (13.13ms)18612026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (3.12ms)18622026/09/23 13:01:34 OK 2_object_stats_trigger.sql (4.32ms)18632026/09/23 13:01:34 OK 20260905000000_add_claims.sql (7.32ms)18642026/09/23 13:01:34 OK 3_commit_push.sql (2.33ms)18652026/09/23 13:01:34 goose: up to current file version: 318662026/09/23 13:01:34 OK 20251218171726_add_pins.sql (4.75ms)18672026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (5.1ms)1868--- PASS: TestReadProxyInvalidPath (1.06s)1869=== CONT TestCreatePin_ReservedPins18702026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (5.21ms)18712026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (4.71ms)18722026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000018732026/09/23 13:01:34 OK 20260905000000_add_claims.sql (4.81ms)18742026/09/23 13:01:34 OK 1_commit_pending_closure.sql (3.82ms)18752026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (3.8ms)18762026/09/23 13:01:34 OK 2_object_stats_trigger.sql (2.71ms)18772026/09/23 13:01:34 OK 3_commit_push.sql (2.35ms)18782026/09/23 13:01:34 goose: up to current file version: 318792026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (4.19ms)18802026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000018812026/09/23 13:01:34 OK 1_commit_pending_closure.sql (3.03ms)18822026/09/23 13:01:34 OK 2_object_stats_trigger.sql (1.95ms)18832026/09/23 13:01:34 OK 3_commit_push.sql (2.27ms)18842026/09/23 13:01:34 goose: up to current file version: 318852026-09-23 13:01:34.409 UTC [926] ERROR: relation "goose_db_version" does not exist at character 3618862026-09-23 13:01:34.409 UTC [926] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18872026/09/23 13:01:34 INFO Received uploads request method=POST path=/api/pending_closures1888--- PASS: TestReadProxy404 (1.02s)1889=== CONT TestOrphanedObjectsGC18902026-09-23 13:01:34.419 UTC [944] ERROR: relation "goose_db_version" does not exist at character 3618912026-09-23 13:01:34.419 UTC [944] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18922026/09/23 13:01:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18932026/09/23 13:01:34 INFO Uploading 0x0qmipsn92nvnpb2kmlgn338qbjbhky-pinned-file.txt (128B)18942026/09/23 13:01:34 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"18952026/09/23 13:01:34 WARN Failed to register uploaded object key=0x0qmipsn92nvnpb2kmlgn338qbjbhky.ls error="server returned 404: 404 page not found\n"18962026/09/23 13:01:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18972026/09/23 13:01:34 INFO Signed narinfos id=1 count=118982026/09/23 13:01:34 INFO Uploading 1 narinfos18992026-09-23 13:01:34.437 UTC [947] ERROR: relation "goose_db_version" does not exist at character 3619002026-09-23 13:01:34.437 UTC [947] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19012026/09/23 13:01:34 OK 20241026095416_initial_model.sql (12.04ms)19022026/09/23 13:01:34 OK 20241026095416_initial_model.sql (12.43ms)19032026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)19042026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)19052026/09/23 13:01:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19062026/09/23 13:01:34 WARN Failed to register uploaded object key=0x0qmipsn92nvnpb2kmlgn338qbjbhky.narinfo error="server returned 404: 404 page not found\n"19072026/09/23 13:01:34 OK 20251218171726_add_pins.sql (4.45ms)19082026/09/23 13:01:34 OK 20251218171726_add_pins.sql (5.04ms)19092026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (4.64ms)19102026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (4.68ms)19112026/09/23 13:01:34 INFO Completed upload id=119122026/09/23 13:01:34 INFO Upload complete. (85ms)19132026/09/23 13:01:34 OK 20260905000000_add_claims.sql (5.14ms)1914=== RUN TestPush_RejectsBadRequests/no_roots1915=== PAUSE TestPush_RejectsBadRequests/no_roots1916=== RUN TestPush_RejectsBadRequests/no_objects1917=== PAUSE TestPush_RejectsBadRequests/no_objects1918=== RUN TestPush_RejectsBadRequests/bad_root1919=== PAUSE TestPush_RejectsBadRequests/bad_root1920=== RUN TestPush_RejectsBadRequests/root_not_in_objects1921=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1922=== CONT TestClientIntegration19232026/09/23 13:01:34 OK 20260905000000_add_claims.sql (4.42ms)19242026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (3.88ms)19252026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (3.33ms)19262026/09/23 13:01:34 OK 20241026095416_initial_model.sql (13.47ms)19272026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (3.44ms)19282026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000019292026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (3.09ms)19302026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000019312026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (2.71ms)19322026/09/23 13:01:34 OK 1_commit_pending_closure.sql (3.76ms)19332026/09/23 13:01:34 OK 1_commit_pending_closure.sql (3.69ms)19342026/09/23 13:01:34 OK 2_object_stats_trigger.sql (2.03ms)19352026/09/23 13:01:34 OK 20251218171726_add_pins.sql (5.86ms)19362026/09/23 13:01:34 OK 2_object_stats_trigger.sql (2.34ms)19372026/09/23 13:01:34 OK 3_commit_push.sql (2.59ms)19382026/09/23 13:01:34 goose: up to current file version: 319392026/09/23 13:01:34 OK 3_commit_push.sql (2.44ms)19402026/09/23 13:01:34 goose: up to current file version: 319412026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (5.02ms)19422026/09/23 13:01:34 OK 20260905000000_add_claims.sql (5.44ms)19432026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (3.64ms)19442026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (3.49ms)19452026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000019462026/09/23 13:01:34 OK 1_commit_pending_closure.sql (3.11ms)19472026/09/23 13:01:34 OK 2_object_stats_trigger.sql (2.24ms)19482026/09/23 13:01:34 OK 3_commit_push.sql (1.98ms)19492026/09/23 13:01:34 goose: up to current file version: 319502026-09-23 13:01:34.499 UTC [969] ERROR: relation "goose_db_version" does not exist at character 3619512026-09-23 13:01:34.499 UTC [969] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1952--- PASS: TestReadProxyNarStreaming (0.89s)1953=== CONT TestClientErrorHandling1954=== RUN TestClientErrorHandling/InvalidStorePath1955=== PAUSE TestClientErrorHandling/InvalidStorePath1956=== RUN TestClientErrorHandling/InvalidAuthToken1957=== PAUSE TestClientErrorHandling/InvalidAuthToken1958=== RUN TestClientErrorHandling/ServerNotAvailable1959=== PAUSE TestClientErrorHandling/ServerNotAvailable1960=== CONT TestClientWithDependencies19612026/09/23 13:01:34 OK 20241026095416_initial_model.sql (13.28ms)19622026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)19632026/09/23 13:01:34 OK 20251218171726_add_pins.sql (4.47ms)19642026/09/23 13:01:34 INFO Received uploads request method=POST path=/api/pending_closures19652026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (4.06ms)19662026/09/23 13:01:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19672026/09/23 13:01:34 INFO Uploading bd3hjclsskjbzp453w0zd5k5krwh1rjz-unpinned-file.txt (128B)19682026-09-23 13:01:34.534 UTC [989] ERROR: relation "goose_db_version" does not exist at character 3619692026-09-23 13:01:34.534 UTC [989] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19702026/09/23 13:01:34 OK 20260905000000_add_claims.sql (4.71ms)19712026/09/23 13:01:34 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"19722026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (3.58ms)19732026/09/23 13:01:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37961/oidc19742026/09/23 13:01:34 WARN Failed to register uploaded object key=bd3hjclsskjbzp453w0zd5k5krwh1rjz.ls error="server returned 404: 404 page not found\n"19752026/09/23 13:01:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19762026/09/23 13:01:34 INFO Signed narinfos id=2 count=119772026/09/23 13:01:34 INFO Uploading 1 narinfos19782026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (2.92ms)19792026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000019802026/09/23 13:01:34 OK 1_commit_pending_closure.sql (2.96ms)19812026/09/23 13:01:34 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19822026/09/23 13:01:34 WARN Failed to register uploaded object key=bd3hjclsskjbzp453w0zd5k5krwh1rjz.narinfo error="server returned 404: 404 page not found\n"19832026/09/23 13:01:34 OK 2_object_stats_trigger.sql (2.09ms)19842026/09/23 13:01:34 INFO Completed upload id=219852026/09/23 13:01:34 INFO Upload complete. (59ms)19862026/09/23 13:01:34 OK 3_commit_push.sql (2.18ms)19872026/09/23 13:01:34 goose: up to current file version: 319882026/09/23 13:01:34 OK 20241026095416_initial_model.sql (14.93ms)19892026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (2.85ms)19902026/09/23 13:01:34 INFO Received push request method=POST path=/api/pushes19912026/09/23 13:01:34 OK 20251218171726_add_pins.sql (6.82ms)1992=== RUN TestService_RequireScope_OIDC/builder_may_write1993=== PAUSE TestService_RequireScope_OIDC/builder_may_write1994=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1995=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1996=== RUN TestService_RequireScope_OIDC/ops_may_admin1997=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1998=== RUN TestService_RequireScope_OIDC/ops_may_not_write1999=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2000=== RUN TestService_RequireScope_OIDC/reader_may_not_write2001=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2002=== RUN TestService_RequireScope_OIDC/static_token_may_admin2003=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2004=== RUN TestService_RequireScope_OIDC/static_token_may_write2005=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2006=== RUN TestService_RequireScope_OIDC/reader_may_read2007=== PAUSE TestService_RequireScope_OIDC/reader_may_read2008=== RUN TestService_RequireScope_OIDC/writer_implies_read2009=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2010=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2011=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2012=== CONT TestClientMultipleUploads20132026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (6.32ms)20142026/09/23 13:01:34 OK 20260905000000_add_claims.sql (5.14ms)20152026/09/23 13:01:34 INFO Received create pin request method=POST path=/api/pins/myapp20162026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (10.81ms)20172026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (3.47ms)20182026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000020192026-09-23 13:01:34.594 UTC [995] ERROR: relation "goose_db_version" does not exist at character 3620202026-09-23 13:01:34.594 UTC [995] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20212026/09/23 13:01:34 OK 1_commit_pending_closure.sql (3.54ms)20222026/09/23 13:01:34 OK 2_object_stats_trigger.sql (3.38ms)20232026/09/23 13:01:34 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4188081886/001/store/0x0qmipsn92nvnpb2kmlgn338qbjbhky-pinned-file.txt narinfo_key=0x0qmipsn92nvnpb2kmlgn338qbjbhky.narinfo20242026/09/23 13:01:34 INFO Received complete push request method=POST path=/api/pushes/1/complete20252026/09/23 13:01:34 INFO Starting cleanup of old closures method=DELETE path=/api/closures20262026/09/23 13:01:34 INFO Garbage collection started20272026/09/23 13:01:34 OK 3_commit_push.sql (2.56ms)20282026/09/23 13:01:34 goose: up to current file version: 320292026/09/23 13:01:34 INFO Aborted multipart uploads count=02030--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.79s)2031=== CONT TestClientCADerivations20322026/09/23 13:01:34 OK 20241026095416_initial_model.sql (12.96ms)20332026/09/23 13:01:34 WARN Force mode enabled - objects will be deleted immediately without grace period20342026/09/23 13:01:34 INFO Received push request method=POST path=/api/pushes20352026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)20362026/09/23 13:01:34 OK 20251218171726_add_pins.sql (6.06ms)20372026-09-23 13:01:34.626 UTC [1017] ERROR: relation "goose_db_version" does not exist at character 3620382026-09-23 13:01:34.626 UTC [1017] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20392026/09/23 13:01:34 INFO Received complete push request method=POST path=/api/pushes/2/complete20402026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (6.2ms)20412026-09-23 13:01:34.630 UTC [997] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo20422026-09-23 13:01:34.630 UTC [997] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE20432026-09-23 13:01:34.630 UTC [997] STATEMENT: -- name: CommitPush :exec2044 SELECT commit_push($1::bigint)2045 2046--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (0.92s)2047=== CONT TestServerTLSConfig/no_client_CA2048=== CONT TestServerTLSConfig/not_a_PEM_file2049=== CONT TestServerTLSConfig/missing_CA_file2050--- PASS: TestServerTLSConfig (0.01s)2051 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2052 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2053 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2054=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info20552026/09/23 13:01:34 INFO Received uploads request method=POST path=/2056=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20572026/09/23 13:01:34 INFO Received uploads request method=POST path=/2058=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key20592026/09/23 13:01:34 INFO Received request for more parts method=POST path=/2060=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key20612026/09/23 13:01:34 INFO Received complete multipart upload request method=POST path=/2062--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2063 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2064 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2065 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2066 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2067=== CONT TestProxyWriteTimeout/narinfo2068=== CONT TestProxyWriteTimeout/unknown_size2069=== CONT TestProxyWriteTimeout/10_GiB_nar2070=== CONT TestProxyWriteTimeout/1_GiB_nar2071--- PASS: TestProxyWriteTimeout (0.07s)2072 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2073 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2074 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2075 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2076=== CONT TestIsValidUploadKey/narinfo2077=== CONT TestIsValidUploadKey/realisation_plus_in_output2078=== CONT TestIsValidUploadKey/unknown_type2079=== CONT TestIsValidUploadKey/empty_key2080=== CONT TestIsValidUploadKey/absolute2081=== CONT TestIsValidUploadKey/traversal_nar2082=== CONT TestIsValidUploadKey/traversal2083=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2084=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2085=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2086=== CONT TestIsValidUploadKey/index.html2087=== CONT TestIsValidUploadKey/nix-cache-info2088=== CONT TestIsValidUploadKey/build_log_home-manager_file2089=== CONT TestIsValidUploadKey/realisation2090=== CONT TestIsValidUploadKey/build_log_equals2091=== CONT TestIsValidUploadKey/build_log_question_mark2092=== CONT TestIsValidUploadKey/build_log_plus_in_name2093=== CONT TestIsValidUploadKey/nar_plain2094=== CONT TestIsValidUploadKey/build_log2095=== CONT TestIsValidUploadKey/listing2096=== CONT TestIsValidUploadKey/nar_xz2097=== CONT TestIsValidUploadKey/nar_zst2098--- PASS: TestIsValidUploadKey (0.07s)2099 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2100 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2101 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2102 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2103 --- PASS: TestIsValidUploadKey/absolute (0.00s)2104 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2105 --- PASS: TestIsValidUploadKey/traversal (0.00s)2106 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2107 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2108 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2109 --- PASS: TestIsValidUploadKey/index.html (0.00s)2110 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2111 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2112 --- PASS: TestIsValidUploadKey/realisation (0.00s)2113 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2114 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2115 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2116 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2117 --- PASS: TestIsValidUploadKey/build_log (0.00s)2118 --- PASS: TestIsValidUploadKey/listing (0.00s)2119 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2120 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2121=== CONT TestResolveDBConnectionString/flag_wins2122=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2123=== CONT TestResolveDBConnectionString/nothing_configured2124=== CONT TestResolveDBConnectionString/missing_file_is_an_error21252026/09/23 13:01:34 OK 20260905000000_add_claims.sql (5.22ms)2126=== CONT TestResolveDBConnectionString/file_when_flag_empty2127=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure21282026/09/23 13:01:34 INFO Received uploads request method=POST path=/2129--- PASS: TestResolveDBConnectionString (0.00s)2130 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2131 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2132 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2133 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2134 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)21352026/09/23 13:01:34 INFO Received push request method=POST path=/api/pushes21362026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (3.44ms)21372026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (4.22ms)21382026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000021392026/09/23 13:01:34 OK 20241026095416_initial_model.sql (12.19ms)21402026/09/23 13:01:34 OK 1_commit_pending_closure.sql (4.88ms)21412026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (2.94ms)21422026-09-23 13:01:34.650 UTC [1018] ERROR: relation "goose_db_version" does not exist at character 3621432026-09-23 13:01:34.650 UTC [1018] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21442026/09/23 13:01:34 OK 2_object_stats_trigger.sql (2.52ms)21452026/09/23 13:01:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46747/oidc21462026/09/23 13:01:34 OK 20251218171726_add_pins.sql (4.53ms)21472026/09/23 13:01:34 OK 3_commit_push.sql (2.31ms)21482026/09/23 13:01:34 goose: up to current file version: 321492026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (5.07ms)21502026/09/23 13:01:34 INFO Received complete push request method=POST path=/api/pushes/1/complete21512026/09/23 13:01:34 OK 20260905000000_add_claims.sql (4.6ms)21522026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (3.39ms)21532026/09/23 13:01:34 OK 20241026095416_initial_model.sql (12.56ms)21542026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (4.09ms)21552026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000021562026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)2157--- PASS: TestPush_CompleteCommitsEveryRoot (0.81s)21582026/09/23 13:01:34 OK 1_commit_pending_closure.sql (3.88ms)2159=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts21602026/09/23 13:01:34 INFO Received request for more parts method=POST path=/21612026/09/23 13:01:34 OK 20251218171726_add_pins.sql (4.73ms)2162--- PASS: TestService_ReadAuthMiddleware (0.72s)2163=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart21642026/09/23 13:01:34 INFO Received complete multipart upload request method=POST path=/21652026/09/23 13:01:34 OK 2_object_stats_trigger.sql (3.64ms)21662026/09/23 13:01:34 OK 3_commit_push.sql (2.39ms)21672026/09/23 13:01:34 goose: up to current file version: 321682026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (5.26ms)21692026/09/23 13:01:34 OK 20260905000000_add_claims.sql (4.59ms)21702026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (2.87ms)21712026-09-23 13:01:34.690 UTC [1023] ERROR: relation "goose_db_version" does not exist at character 3621722026-09-23 13:01:34.690 UTC [1023] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21732026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (3.35ms)21742026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000021752026/09/23 13:01:34 OK 1_commit_pending_closure.sql (3.31ms)21762026/09/23 13:01:34 OK 2_object_stats_trigger.sql (2.1ms)21772026/09/23 13:01:34 OK 3_commit_push.sql (1.83ms)21782026/09/23 13:01:34 goose: up to current file version: 321792026/09/23 13:01:34 OK 20241026095416_initial_model.sql (9.11ms)21802026/09/23 13:01:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21812026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)21822026/09/23 13:01:34 OK 20251218171726_add_pins.sql (4ms)21832026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (10.28ms)2184--- PASS: TestReadProxyNarinfo (0.73s)21852026/09/23 13:01:34 OK 20260905000000_add_claims.sql (3.52ms)2186=== CONT TestCacheConfigHandler/full_config,_no_issuer2187=== CONT TestCacheConfigHandler/no_signing_keys2188=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2189=== CONT TestCacheConfigHandler/no_cache_url_configured2190--- PASS: TestCacheConfigHandler (0.00s)2191 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2192 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2193 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2194 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2195=== CONT TestIsValidCachePath/narinfo2196=== CONT TestIsValidCachePath/leading_slash2197=== CONT TestIsValidCachePath/empty2198=== CONT TestIsValidCachePath/wrong_extension2199=== CONT TestIsValidCachePath/random_path2200=== CONT TestIsValidCachePath/invalid_char_u2201=== CONT TestIsValidCachePath/invalid_char_e2202=== CONT TestIsValidCachePath/traversal_in_middle2203=== CONT TestIsValidCachePath/traversal_parent2204=== CONT TestIsValidCachePath/index.html2205=== CONT TestIsValidCachePath/nix-cache-info2206=== CONT TestIsValidCachePath/nar_bz22207=== CONT TestIsValidCachePath/nar_xz2208=== CONT TestIsValidCachePath/nar_zst2209=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2210=== CONT TestIsValidCachePath/nar_uncompressed2211=== CONT TestIsValidCachePath/log2212=== CONT TestIsValidCachePath/realisation2213=== CONT TestIsValidCachePath/ls2214=== CONT TestIsValidCachePath/short_hash2215--- PASS: TestIsValidCachePath (0.00s)2216 --- PASS: TestIsValidCachePath/narinfo (0.00s)2217 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2218 --- PASS: TestIsValidCachePath/empty (0.00s)2219 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2220 --- PASS: TestIsValidCachePath/random_path (0.00s)2221 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2222 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2223 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2224 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2225 --- PASS: TestIsValidCachePath/index.html (0.00s)2226 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2227 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2228 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2229 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2230 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2231 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2232 --- PASS: TestIsValidCachePath/log (0.00s)2233 --- PASS: TestIsValidCachePath/realisation (0.00s)2234 --- PASS: TestIsValidCachePath/ls (0.00s)2235 --- PASS: TestIsValidCachePath/short_hash (0.00s)2236=== CONT TestParseSingleRange/none2237=== CONT TestParseSingleRange/start_far_past_EOF2238=== CONT TestParseSingleRange/start_past_EOF2239=== CONT TestParseSingleRange/single_byte2240=== CONT TestParseSingleRange/suffix_exceeds_size2241=== CONT TestParseSingleRange/suffix2242=== CONT TestParseSingleRange/end_clamped_to_size2243=== CONT TestParseSingleRange/open-ended2244=== CONT TestParseSingleRange/closed2245=== CONT TestParseSingleRange/malformed_end_before_start2246=== CONT TestParseSingleRange/malformed_both_empty2247=== CONT TestParseSingleRange/malformed_no_dash2248=== CONT TestParseSingleRange/multi-range_ignored2249=== CONT TestParseSingleRange/unknown_unit2250--- PASS: TestParseSingleRange (0.00s)2251 --- PASS: TestParseSingleRange/none (0.00s)2252 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2253 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2254 --- PASS: TestParseSingleRange/single_byte (0.00s)2255 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2256 --- PASS: TestParseSingleRange/suffix (0.00s)2257 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2258 --- PASS: TestParseSingleRange/open-ended (0.00s)2259 --- PASS: TestParseSingleRange/closed (0.00s)2260 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2261 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2262 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2263 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2264 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2265=== CONT TestPush_RejectsBadRequests/no_roots22662026/09/23 13:01:34 INFO Received push request method=POST path=/api/pushes22672026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (2ms)2268=== CONT TestPush_RejectsBadRequests/bad_root22692026/09/23 13:01:34 INFO Received push request method=POST path=/api/pushes2270=== CONT TestPush_RejectsBadRequests/root_not_in_objects22712026/09/23 13:01:34 INFO Received push request method=POST path=/api/pushes2272=== CONT TestPush_RejectsBadRequests/no_objects22732026/09/23 13:01:34 INFO Received push request method=POST path=/api/pushes2274=== CONT TestClientErrorHandling/InvalidStorePath2275--- PASS: TestPush_RejectsBadRequests (1.04s)2276 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2277 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2278 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2279 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)22802026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (1.86ms)22812026/09/23 13:01:34 goose: successfully migrated database to version: 2026092312000022822026/09/23 13:01:34 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=N2Q1MDQ4NjUtZGUxNi00NmNlLTllNzItYjA4ODMzZjM2ODliLjNhZDdkNzExLTExM2YtNDc1YS04MWY5LTU4YTIyZjNkZDBhMHgxNzkwMTY4NDkzOTM2MDczMzE1 parts=1222832026/09/23 13:01:34 OK 1_commit_pending_closure.sql (1.96ms)22842026/09/23 13:01:34 INFO Received uploads request method=POST path=/api/pending_closures22852026/09/23 13:01:34 OK 2_object_stats_trigger.sql (1.11ms)22862026-09-23 13:01:34.734 UTC [1024] ERROR: relation "goose_db_version" does not exist at character 3622872026-09-23 13:01:34.734 UTC [1024] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22882026/09/23 13:01:34 OK 3_commit_push.sql (1.34ms)22892026/09/23 13:01:34 goose: up to current file version: 32290--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.72s)2291=== CONT TestClientErrorHandling/ServerNotAvailable22922026/09/23 13:01:34 INFO Received push request method=POST path=/api/pushes22932026/09/23 13:01:34 OK 20241026095416_initial_model.sql (11.36ms)22942026/09/23 13:01:34 OK 20251210153512_drop_unused_gin_index.sql (2.74ms)22952026/09/23 13:01:34 OK 20251218171726_add_pins.sql (3.65ms)22962026/09/23 13:01:34 OK 20260628120000_add_object_size_and_stats.sql (3.98ms)2297=== CONT TestClientErrorHandling/InvalidAuthToken22982026/09/23 13:01:34 OK 20260905000000_add_claims.sql (3.84ms)2299=== CONT TestService_RequireScope_OIDC/builder_may_write23002026/09/23 13:01:34 OK 20260920000000_drop_claims.sql (3.28ms)2301=== CONT TestService_RequireScope_OIDC/static_token_may_write2302=== CONT TestService_RequireScope_OIDC/static_token_may_admin2303=== CONT TestService_RequireScope_OIDC/reader_may_not_write2304=== CONT TestService_RequireScope_OIDC/ops_may_not_write2305=== CONT TestService_RequireScope_OIDC/ops_may_admin2306=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2307=== CONT TestService_RequireScope_OIDC/reader_may_read2308=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read23092026/09/23 13:01:34 OK 20260923120000_add_pushes.sql (2.78ms)2310=== CONT TestService_RequireScope_OIDC/writer_implies_read23112026/09/23 13:01:34 goose: successfully migrated database to version: 202609231200002312--- PASS: TestService_RequireScope_OIDC (1.02s)2313 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2314 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2315 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2316 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2317 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2318 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2319 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2320 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2321 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2322 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2323--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.74s)23242026/09/23 13:01:34 OK 1_commit_pending_closure.sql (3.63ms)23252026/09/23 13:01:34 OK 2_object_stats_trigger.sql (1.83ms)23262026/09/23 13:01:34 OK 3_commit_push.sql (2.06ms)23272026/09/23 13:01:34 goose: up to current file version: 323282026/09/23 13:01:34 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"23292026/09/23 13:01:34 WARN mTLS auth: bound subjects configured but subject DN unavailable23302026/09/23 13:01:34 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2331--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.73s)23322026/09/23 13:01:34 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/present23332026-09-23 13:01:34.971 UTC [1066] ERROR: relation "goose_db_version" does not exist at character 3623342026-09-23 13:01:34.971 UTC [1066] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23352026-09-23 13:01:34.998 UTC [1067] ERROR: relation "goose_db_version" does not exist at character 3623362026-09-23 13:01:34.998 UTC [1067] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23372026/09/23 13:01:34 OK 20241026095416_initial_model.sql (10.85ms)23382026/09/23 13:01:35 OK 20251210153512_drop_unused_gin_index.sql (1.44ms)23392026/09/23 13:01:35 OK 20251218171726_add_pins.sql (3.92ms)23402026/09/23 13:01:35 OK 20260628120000_add_object_size_and_stats.sql (4.51ms)23412026/09/23 13:01:35 OK 20260905000000_add_claims.sql (4.14ms)23422026/09/23 13:01:35 OK 20241026095416_initial_model.sql (10.7ms)23432026/09/23 13:01:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23442026/09/23 13:01:35 OK 20260920000000_drop_claims.sql (3.41ms)23452026/09/23 13:01:35 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)23462026/09/23 13:01:35 OK 20260923120000_add_pushes.sql (2.51ms)23472026/09/23 13:01:35 goose: successfully migrated database to version: 2026092312000023482026/09/23 13:01:35 OK 20251218171726_add_pins.sql (2.99ms)23492026/09/23 13:01:35 OK 1_commit_pending_closure.sql (2.07ms)23502026/09/23 13:01:35 OK 20260628120000_add_object_size_and_stats.sql (2.73ms)23512026/09/23 13:01:35 OK 2_object_stats_trigger.sql (1.19ms)23522026/09/23 13:01:35 OK 3_commit_push.sql (898.55µs)23532026/09/23 13:01:35 goose: up to current file version: 323542026/09/23 13:01:35 OK 20260905000000_add_claims.sql (2.51ms)23552026/09/23 13:01:35 OK 20260920000000_drop_claims.sql (1.78ms)2356--- PASS: TestReadRedirectUsesPublicS3URL (0.97s)23572026/09/23 13:01:35 OK 20260923120000_add_pushes.sql (1.33ms)23582026/09/23 13:01:35 goose: successfully migrated database to version: 202609231200002359--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.96s)23602026/09/23 13:01:35 OK 1_commit_pending_closure.sql (1.83ms)23612026/09/23 13:01:35 OK 2_object_stats_trigger.sql (849.65µs)23622026/09/23 13:01:35 OK 3_commit_push.sql (1.14ms)23632026/09/23 13:01:35 goose: up to current file version: 323642026/09/23 13:01:35 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=N2Q1MDQ4NjUtZGUxNi00NmNlLTllNzItYjA4ODMzZjM2ODliLjg2NTQ3YmU5LTFmYzctNGM0Mi05YWFhLWZhZjFiOTY5YWIyY3gxNzkwMTY4NDk0MTE4MDU1NTYy parts=122365--- PASS: TestRedundantMultipartUpload (1.82s)2366--- PASS: TestCacheStatsHandler (0.99s)23672026/09/23 13:01:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=208.035543ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2368--- PASS: TestResurrectedObjectNotDeleted (0.97s)23692026/09/23 13:01:35 INFO Starting HTTP server address=127.0.0.1:3702923702026/09/23 13:01:35 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2702362865/001/proxy.sock23712026/09/23 13:01:35 WARN mTLS auth: subject not in bound subjects subject="CN=someone"23722026/09/23 13:01:35 INFO Shutdown signal received, draining in-flight requests timeout=10s2373--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.81s)2374=== NAME TestClientIntegration2375 client_integration_test.go:286: Created store path: /build/TestClientIntegration763975509/002/store/g1mlr9n81w63l2lcd7ky6hhhdjxiyf0i-test-file.txt23762026/09/23 13:01:35 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=438.762188ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2377=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2378=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2379=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2380=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2381=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2382=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2383=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2384=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2385=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2386=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2387=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured23882026/09/23 13:01:35 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]2389=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected23902026/09/23 13:01:35 WARN Authentication failed token_preview=eyJhbGciOi...K_PuFV_54g token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2391--- PASS: TestService_AuthMiddleware_OIDC (1.52s)2392 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2393 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2394 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2395 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)23962026/09/23 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures2397=== NAME TestClientWithDependencies2398 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3288074049/001/store/haxxynb920ks3i06nf2lfqqdnm7a411d-test-script2399=== NAME TestClientMultipleUploads2400 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2987696174/001/store/8d7v24l58fqf8d3cg6r168jv6z8p8i7z-test-file-0.txt24012026/09/23 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures24022026/09/23 13:01:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24032026/09/23 13:01:35 INFO Uploading g1mlr9n81w63l2lcd7ky6hhhdjxiyf0i-test-file.txt (152B)2404=== NAME TestClientWithDependencies2405 client_integration_test.go:615: Found 1 dependencies (including self)24062026/09/23 13:01:35 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"24072026/09/23 13:01:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign24082026/09/23 13:01:35 WARN Failed to register uploaded object key=g1mlr9n81w63l2lcd7ky6hhhdjxiyf0i.ls error="server returned 404: 404 page not found\n"24092026/09/23 13:01:35 INFO Signed narinfos id=1 count=124102026/09/23 13:01:35 INFO Uploading 1 narinfos24112026/09/23 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures24122026/09/23 13:01:35 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux24132026/09/23 13:01:35 WARN Refused reserved pin name=worker-x86_64-linux24142026/09/23 13:01:35 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux24152026/09/23 13:01:35 INFO Received create pin request method=POST path=/api/pins/my-app24162026/09/23 13:01:35 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux24172026/09/23 13:01:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)2418--- PASS: TestCreatePin_ReservedPins (1.02s)24192026/09/23 13:01:35 INFO Uploading 2r3n8q40mfsf486r0nwbxb6cn9gv9msg-shared-dep (136B)24202026/09/23 13:01:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24212026/09/23 13:01:35 WARN Failed to register uploaded object key=g1mlr9n81w63l2lcd7ky6hhhdjxiyf0i.narinfo error="server returned 404: 404 page not found\n"24222026/09/23 13:01:35 WARN Failed to register uploaded object key=2r3n8q40mfsf486r0nwbxb6cn9gv9msg.ls error="server returned 404: 404 page not found\n"24232026/09/23 13:01:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign24242026/09/23 13:01:35 INFO Signed narinfos id=2 count=124252026/09/23 13:01:35 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"24262026/09/23 13:01:35 INFO Uploading 1 narinfos24272026/09/23 13:01:35 INFO Completed upload id=124282026/09/23 13:01:35 INFO Upload complete. (92ms)2429=== NAME TestClientMultipleUploads2430 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2987696174/001/store/mbj48mfkki9gklws9yw1130ncg7h661h-test-file-1.txt24312026/09/23 13:01:35 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete24322026/09/23 13:01:35 WARN Failed to register uploaded object key=2r3n8q40mfsf486r0nwbxb6cn9gv9msg.narinfo error="server returned 404: 404 page not found\n"24332026/09/23 13:01:35 INFO Completed upload id=224342026/09/23 13:01:35 INFO Upload complete. (54ms)24352026/09/23 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures24362026/09/23 13:01:35 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)24372026/09/23 13:01:35 INFO Uploading 2r3n8q40mfsf486r0nwbxb6cn9gv9msg-shared-dep (136B)24382026/09/23 13:01:35 INFO Uploading jb9n01mzd7sfwa98x41wx5zq0pnxnncq-top (224B)24392026/09/23 13:01:35 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"24402026/09/23 13:01:35 WARN Failed to register uploaded object key=2r3n8q40mfsf486r0nwbxb6cn9gv9msg.ls error="server returned 404: 404 page not found\n"24412026/09/23 13:01:35 WARN Failed to register uploaded object key=nar/10pbh3f2zqj8i6syqfd4im9m7rgfwggnixd9mbvpw1b9mbgmdijd.nar.zst error="server returned 404: 404 page not found\n"24422026/09/23 13:01:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign24432026/09/23 13:01:35 WARN Failed to register uploaded object key=jb9n01mzd7sfwa98x41wx5zq0pnxnncq.ls error="server returned 404: 404 page not found\n"24442026/09/23 13:01:35 INFO Signed narinfos id=1 count=124452026/09/23 13:01:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign24462026/09/23 13:01:35 INFO Signed narinfos id=3 count=124472026/09/23 13:01:35 INFO Uploading 2 narinfos24482026/09/23 13:01:35 WARN Failed to register uploaded object key=2r3n8q40mfsf486r0nwbxb6cn9gv9msg.narinfo error="server returned 404: 404 page not found\n"24492026/09/23 13:01:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24502026/09/23 13:01:35 WARN Failed to register uploaded object key=jb9n01mzd7sfwa98x41wx5zq0pnxnncq.narinfo error="server returned 404: 404 page not found\n"24512026/09/23 13:01:35 INFO Completed upload id=124522026/09/23 13:01:35 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete24532026/09/23 13:01:35 INFO Completed upload id=324542026/09/23 13:01:35 INFO Upload complete. (160ms)2455=== NAME TestClientSharedPathCommittedMidPush2456 client_integration_test.go:680: Retrieved narinfo from S3:2457 StorePath: /build/TestClientSharedPathCommittedMidPush1512953519/001/store/2r3n8q40mfsf486r0nwbxb6cn9gv9msg-shared-dep2458 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2459 Compression: zstd2460 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822461 NarSize: 1362462 References: 2463 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n24642026/09/23 13:01:35 INFO All 1 paths already cached2465=== NAME TestClientIntegration2466 client_integration_test.go:312: Retrieved narinfo from S3:2467 StorePath: /build/TestClientIntegration763975509/002/store/g1mlr9n81w63l2lcd7ky6hhhdjxiyf0i-test-file.txt2468 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2469 Compression: zstd2470 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12471 NarSize: 1522472 References: 2473 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12474=== NAME TestClientMultipleUploads2475 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2987696174/001/store/z8mcy2vncbz6v9jfd4z7j1k2prns4drb-test-file-2.txt2476=== NAME TestClientCADerivations2477 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1105572216/001/store/4mcrfbpw00lm087adi4l30sdhmfkmwsn-ca-test2478=== NAME TestClientSharedPathCommittedMidPush2479 client_integration_test.go:680: Retrieved narinfo from S3:2480 StorePath: /build/TestClientSharedPathCommittedMidPush1512953519/001/store/jb9n01mzd7sfwa98x41wx5zq0pnxnncq-top2481 URL: nar/10pbh3f2zqj8i6syqfd4im9m7rgfwggnixd9mbvpw1b9mbgmdijd.nar.zst2482 Compression: zstd2483 NarHash: sha256:10pbh3f2zqj8i6syqfd4im9m7rgfwggnixd9mbvpw1b9mbgmdijd2484 NarSize: 2242485 References: /build/TestClientSharedPathCommittedMidPush1512953519/001/store/2r3n8q40mfsf486r0nwbxb6cn9gv9msg-shared-dep2486 CA: text:sha256:0fg5j3djvz9z7gscm0wcfkmqj5r7z2ysnpxaqn388m3y8iiyczf02487=== NAME TestClientIntegration2488 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2489 client_integration_test.go:313: Decompressed .ls content (64 bytes):2490 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2491 client_integration_test.go:316: Testing garbage collection...2492--- PASS: TestClientSharedPathCommittedMidPush (1.11s)24932026/09/23 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures24942026/09/23 13:01:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24952026/09/23 13:01:35 INFO Uploading haxxynb920ks3i06nf2lfqqdnm7a411d-test-script (136B)24962026/09/23 13:01:35 WARN Failed to register uploaded object key=haxxynb920ks3i06nf2lfqqdnm7a411d.ls error="server returned 404: 404 page not found\n"24972026/09/23 13:01:35 WARN Failed to register uploaded object key=log/alfh0p0p5pyhl10qwl2q0j84i9fbyx0l-test-script.drv error="server returned 404: 404 page not found\n"24982026/09/23 13:01:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign24992026/09/23 13:01:35 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"25002026/09/23 13:01:35 INFO Signed narinfos id=1 count=125012026/09/23 13:01:35 INFO Uploading 1 narinfos25022026/09/23 13:01:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete25032026/09/23 13:01:35 WARN Failed to register uploaded object key=haxxynb920ks3i06nf2lfqqdnm7a411d.narinfo error="server returned 404: 404 page not found\n"2504=== NAME TestClientCADerivations2505 client_ca_test.go:139: Found 1 dependencies (including self)25062026/09/23 13:01:35 INFO Completed upload id=125072026/09/23 13:01:35 INFO Upload complete. (65ms)25082026/09/23 13:01:35 INFO Starting cleanup of old closures method=DELETE path=/api/closures25092026/09/23 13:01:35 INFO Garbage collection started2510=== NAME TestClientWithDependencies2511 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3288074049/001/store) requires matching store prefix25122026/09/23 13:01:35 INFO Aborted multipart uploads count=02513--- PASS: TestClientWithDependencies (0.99s)25142026/09/23 13:01:35 WARN Force mode enabled - objects will be deleted immediately without grace period25152026/09/23 13:01:35 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2516=== NAME TestOrphanedObjectsGC2517 orphaned_objects_gc_test.go:290: GC Test Summary:2518 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2519 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2520 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2521 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2522 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2523--- PASS: TestOrphanedObjectsGC (1.13s)25242026/09/23 13:01:35 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"25252026/09/23 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures25262026/09/23 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures25272026/09/23 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures25282026/09/23 13:01:35 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)25292026/09/23 13:01:35 INFO Uploading 8d7v24l58fqf8d3cg6r168jv6z8p8i7z-test-file-0.txt (160B)25302026/09/23 13:01:35 INFO Uploading z8mcy2vncbz6v9jfd4z7j1k2prns4drb-test-file-2.txt (160B)25312026/09/23 13:01:35 INFO Uploading mbj48mfkki9gklws9yw1130ncg7h661h-test-file-1.txt (160B)25322026/09/23 13:01:35 INFO Received uploads request method=POST path=/api/pending_closures25332026/09/23 13:01:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25342026/09/23 13:01:35 INFO Uploading 4mcrfbpw00lm087adi4l30sdhmfkmwsn-ca-test (144B)25352026/09/23 13:01:35 WARN Failed to register uploaded object key=z8mcy2vncbz6v9jfd4z7j1k2prns4drb.ls error="server returned 404: 404 page not found\n"25362026/09/23 13:01:35 WARN Failed to register uploaded object key=8d7v24l58fqf8d3cg6r168jv6z8p8i7z.ls error="server returned 404: 404 page not found\n"25372026/09/23 13:01:35 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"25382026/09/23 13:01:35 WARN Failed to register uploaded object key=mbj48mfkki9gklws9yw1130ncg7h661h.ls error="server returned 404: 404 page not found\n"25392026/09/23 13:01:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign25402026/09/23 13:01:35 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"25412026/09/23 13:01:35 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"25422026/09/23 13:01:35 INFO Signed narinfos id=2 count=125432026/09/23 13:01:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign25442026/09/23 13:01:35 INFO Signed narinfos id=3 count=125452026/09/23 13:01:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign25462026/09/23 13:01:35 WARN Failed to register uploaded object key=log/4qx6w920xsyiw8757why8ki1sy7rqiw1-ca-test.drv error="server returned 404: 404 page not found\n"25472026/09/23 13:01:35 INFO Signed narinfos id=1 count=125482026/09/23 13:01:35 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"25492026/09/23 13:01:35 INFO Uploading 3 narinfos25502026/09/23 13:01:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign25512026/09/23 13:01:35 WARN Failed to register uploaded object key=4mcrfbpw00lm087adi4l30sdhmfkmwsn.ls error="server returned 404: 404 page not found\n"25522026/09/23 13:01:35 INFO Signed narinfos id=1 count=125532026/09/23 13:01:35 INFO Uploading 1 narinfos25542026/09/23 13:01:35 WARN Failed to register uploaded object key=z8mcy2vncbz6v9jfd4z7j1k2prns4drb.narinfo error="server returned 404: 404 page not found\n"25552026/09/23 13:01:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete25562026/09/23 13:01:35 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete25572026/09/23 13:01:35 WARN Failed to register uploaded object key=4mcrfbpw00lm087adi4l30sdhmfkmwsn.narinfo error="server returned 404: 404 page not found\n"25582026/09/23 13:01:35 WARN Failed to register uploaded object key=mbj48mfkki9gklws9yw1130ncg7h661h.narinfo error="server returned 404: 404 page not found\n"25592026/09/23 13:01:35 WARN Failed to register uploaded object key=8d7v24l58fqf8d3cg6r168jv6z8p8i7z.narinfo error="server returned 404: 404 page not found\n"25602026/09/23 13:01:35 INFO Completed upload id=325612026/09/23 13:01:35 INFO Completed upload id=125622026/09/23 13:01:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete25632026/09/23 13:01:35 INFO Upload complete. (110ms)25642026/09/23 13:01:35 INFO Completed upload id=125652026/09/23 13:01:35 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete25662026/09/23 13:01:35 INFO Completed upload id=225672026/09/23 13:01:35 INFO Upload complete. (118ms)2568=== NAME TestClientMultipleUploads2569 client_integration_test.go:369: Uploaded 3 paths in 180.398093ms2570=== NAME TestClientCADerivations2571 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1105572216/001/store/4mcrfbpw00lm087adi4l30sdhmfkmwsn-ca-test2572 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2573 Compression: zstd2574 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2575 NarSize: 1442576 References: 2577 Deriver: /build/TestClientCADerivations1105572216/001/store/4qx6w920xsyiw8757why8ki1sy7rqiw1-ca-test.drv2578 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2579 client_ca_test.go:185: Checking for realisation files in S3...2580 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2581 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2582--- PASS: TestClientMultipleUploads (1.07s)25832026/09/23 13:01:35 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=723.620646ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2584=== NAME TestClientCADerivations2585 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2586 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2587 error: binary cache 's3://bucket62?endpoint=http://localhost:36887®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1105572216/001/store'2588 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12589--- PASS: TestClientCADerivations (1.12s)2590--- PASS: TestUploadHandlersRejectOversizedBody (0.16s)2591 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.09s)2592 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.09s)2593 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.44s)25942026/09/23 13:01:36 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=025952026/09/23 13:01:36 INFO Vacuumed table table=pending_closures25962026/09/23 13:01:36 INFO Vacuumed table table=pending_objects25972026/09/23 13:01:36 INFO Vacuumed table table=multipart_uploads25982026/09/23 13:01:36 INFO Vacuumed table table=closures25992026/09/23 13:01:36 INFO Vacuumed table table=objects26002026/09/23 13:01:36 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.472105994s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present26012026/09/23 13:01:36 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02602=== NAME TestPinProtectsFromGC2603 client_integration_test.go:794: Pin successfully protected closure from garbage collection2604--- PASS: TestPinProtectsFromGC (3.37s)26052026/09/23 13:01:36 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=026062026/09/23 13:01:36 INFO Vacuumed table table=pending_closures26072026/09/23 13:01:36 INFO Vacuumed table table=pending_objects26082026/09/23 13:01:36 INFO Vacuumed table table=multipart_uploads26092026/09/23 13:01:36 INFO Vacuumed table table=closures26102026/09/23 13:01:36 INFO Vacuumed table table=objects2611=== NAME TestOrphanedObjectsGCStressTest2612 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2613 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2614 orphaned_objects_gc_test.go:509: Stress test completed successfully:2615 orphaned_objects_gc_test.go:510: - Active objects preserved: 202616 orphaned_objects_gc_test.go:511: - Objects deleted: 2102617 orphaned_objects_gc_test.go:512: - Total GC'd: 2102618--- PASS: TestOrphanedObjectsGCStressTest (3.14s)26192026/09/23 13:01:37 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02620=== NAME TestClientIntegration2621 client_integration_test.go:323: Objects in database after GC:2622 client_integration_test.go:323: Successfully deleted all objects with GC --force2623--- PASS: TestClientIntegration (3.04s)26242026/09/23 13:01:37 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-config26252026/09/23 13:01:38 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.026523ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26262026/09/23 13:01:38 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=423.931479ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26272026/09/23 13:01:38 WARN Rate limiter enabled after throttle name=s3-test rate=526282026/09/23 13:01:38 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2629=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2630 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102631 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002632--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.17s)26332026/09/23 13:01:38 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=844.793235ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26342026/09/23 13:01:39 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.467110746s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26352026/09/23 13:01:40 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"26362026/09/23 13:01:40 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_closures26372026/09/23 13:01:41 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=198.645939ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26382026/09/23 13:01:41 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=366.45312ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26392026/09/23 13:01:41 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=730.393222ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26402026/09/23 13:01:42 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.487015946s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2641--- PASS: TestClientErrorHandling (0.00s)2642 --- PASS: TestClientErrorHandling/InvalidStorePath (0.71s)2643 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.78s)2644 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.15s)2645FAIL26462026-09-23 13:01:44.224 UTC [127] LOG: received smart shutdown request26472026-09-23 13:01:44.230 UTC [127] LOG: background worker "logical replication launcher" (PID 137) exited with exit code 126482026-09-23 13:01:44.248 UTC [132] LOG: shutting down26492026-09-23 13:01:44.249 UTC [132] LOG: checkpoint starting: shutdown immediate26502026-09-23 13:01:45.298 UTC [132] LOG: checkpoint complete: wrote 11388 buffers (69.5%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.222 s, sync=0.808 s, total=1.050 s; sync files=21875, longest=0.077 s, average=0.001 s; distance=297529 kB, estimate=297529 kB; lsn=0/139F42D8, redo lsn=0/139F42D826512026-09-23 13:01:45.392 UTC [127] LOG: database system is shut down