niks3-go-unit-tests
x86_64-linux.go-unit-tests
· build #111
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestCaseHackSuffix6=== PAUSE TestCaseHackSuffix7=== RUN TestFilterOversizedClosures8=== PAUSE TestFilterOversizedClosures9=== RUN TestPartSizeForNAR10=== PAUSE TestPartSizeForNAR11=== RUN TestUploadMultipart_SupersededByPeer12=== PAUSE TestUploadMultipart_SupersededByPeer13=== RUN TestDumpPathMatchesNix14=== PAUSE TestDumpPathMatchesNix15=== RUN TestDumpPathSingleFile16=== PAUSE TestDumpPathSingleFile17=== RUN TestDumpPathWriterError18=== PAUSE TestDumpPathWriterError19=== RUN TestEncodeNixBase3220=== PAUSE TestEncodeNixBase3221=== RUN TestEncodeNixBase32WithRealHash22=== PAUSE TestEncodeNixBase32WithRealHash23=== RUN TestConvertHashToNix3224=== PAUSE TestConvertHashToNix3225=== RUN TestGetStorePathHash26=== PAUSE TestGetStorePathHash27=== RUN TestPathInfoHashCompatibility28=== PAUSE TestPathInfoHashCompatibility29=== RUN TestParsePathInfoJSON30=== PAUSE TestParsePathInfoJSON31=== RUN TestParsePathInfoJSONMultiplePaths32=== PAUSE TestParsePathInfoJSONMultiplePaths33=== RUN TestPathInfoCACompatibility34=== PAUSE TestPathInfoCACompatibility35=== RUN TestRateLimiterFeedback36=== PAUSE TestRateLimiterFeedback37=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess38=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess39=== RUN TestResolveStorePath40=== PAUSE TestResolveStorePath41=== RUN TestDoWithRetry_BodyReplayedViaGetBody42=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody43=== RUN TestShellSplit44=== PAUSE TestShellSplit45=== RUN TestShellSplitErrors46=== PAUSE TestShellSplitErrors47=== RUN TestSetClientTLS48=== PAUSE TestSetClientTLS49=== RUN TestSetClientTLSDoesNotMutateDefaultTransport50=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport51=== RUN TestSetClientTLSErrors52=== PAUSE TestSetClientTLSErrors53=== RUN TestStaticToken54=== PAUSE TestStaticToken55=== RUN TestFileTokenReadsAndCaches56=== PAUSE TestFileTokenReadsAndCaches57=== RUN TestFileTokenMissing58=== PAUSE TestFileTokenMissing59=== RUN TestFileTokenEmpty60=== PAUSE TestFileTokenEmpty61=== RUN TestScriptTokenNoExpiryRerunsEveryCall62=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall63=== RUN TestScriptTokenCachesUntilRefresh64=== PAUSE TestScriptTokenCachesUntilRefresh65=== RUN TestScriptTokenEmptyToken66=== PAUSE TestScriptTokenEmptyToken67=== RUN TestScriptTokenBadJSON68=== PAUSE TestScriptTokenBadJSON69=== RUN TestScriptTokenScriptFails70=== PAUSE TestScriptTokenScriptFails71=== RUN TestScriptTokenEmptyCommand72=== PAUSE TestScriptTokenEmptyCommand73=== CONT TestDoServerRequestAttachesToken74=== CONT TestResolveStorePath75=== CONT TestEncodeNixBase32WithRealHash76--- PASS: TestEncodeNixBase32WithRealHash (0.00s)77=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess78=== CONT TestRateLimiterFeedback79=== RUN TestRateLimiterFeedback/429_enables_limiter80=== CONT TestScriptTokenCachesUntilRefresh81=== PAUSE TestRateLimiterFeedback/429_enables_limiter82=== RUN TestRateLimiterFeedback/503_enables_limiter83--- PASS: TestResolveStorePath (0.00s)84=== CONT TestDumpPathWriterError852026/07/19 13:53:41 WARN Rate limiter enabled after throttle name=server-test rate=586=== PAUSE TestRateLimiterFeedback/503_enables_limiter87=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter88=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter89=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter90=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter91=== CONT TestScriptTokenEmptyCommand92--- PASS: TestScriptTokenEmptyCommand (0.00s)93=== CONT TestPartSizeForNAR94=== RUN TestPartSizeForNAR/zero_stays_at_minimum95=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum96=== RUN TestPartSizeForNAR/small_stays_at_minimum97=== PAUSE TestPartSizeForNAR/small_stays_at_minimum98=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum99=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum100=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts101=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts102=== RUN TestPartSizeForNAR/1_TiB103=== PAUSE TestPartSizeForNAR/1_TiB104=== RUN TestPartSizeForNAR/5_TiB_S3_max_object105=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object106=== RUN TestPartSizeForNAR/capped_at_5_GiB107=== PAUSE TestPartSizeForNAR/capped_at_5_GiB108=== CONT TestUploadMultipart_SupersededByPeer109=== RUN TestUploadMultipart_SupersededByPeer/exists110=== PAUSE TestUploadMultipart_SupersededByPeer/exists111=== RUN TestUploadMultipart_SupersededByPeer/missing112=== PAUSE TestUploadMultipart_SupersededByPeer/missing113=== CONT TestShellSplitErrors114--- PASS: TestShellSplitErrors (0.00s)115=== CONT TestSetClientTLS116=== CONT TestScriptTokenBadJSON117=== CONT TestScriptTokenEmptyToken118=== CONT TestPathInfoCACompatibility119=== RUN TestPathInfoCACompatibility/null_ca_field120=== CONT TestParsePathInfoJSONMultiplePaths121=== PAUSE TestPathInfoCACompatibility/null_ca_field122=== RUN TestPathInfoCACompatibility/old_string_format_-_text123=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text124=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths125=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths126=== CONT TestPathInfoHashCompatibility127=== CONT TestGetStorePathHash128=== CONT TestConvertHashToNix32129=== CONT TestFileTokenMissing130=== CONT TestSetClientTLSDoesNotMutateDefaultTransport131=== CONT TestFileTokenReadsAndCaches132=== CONT TestFilterOversizedClosures133=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths134=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths135=== CONT TestStaticToken136=== CONT TestScriptTokenNoExpiryRerunsEveryCall137=== CONT TestFileTokenEmpty138=== CONT TestDumpPathMatchesNix139=== CONT TestEncodeNixBase32140=== CONT TestScriptTokenScriptFails141=== CONT TestDumpPathSingleFile142=== CONT TestParsePathInfoJSON143=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive144--- PASS: TestDoServerRequestAttachesToken (0.00s)145=== CONT TestSetClientTLSErrors146=== RUN TestFilterOversizedClosures/no_limit_keeps_everything147=== RUN TestGetStorePathHash/valid_store_path148=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)149--- PASS: TestFileTokenReadsAndCaches (0.00s)150--- PASS: TestStaticToken (0.00s)151=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)152=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon153=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon154=== CONT TestDoWithRetry_BodyReplayedViaGetBody155=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI156=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI157=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512158=== CONT TestCaseHackSuffix159=== CONT TestShellSplit160=== RUN TestEncodeNixBase32/test_string_hash161=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive162=== RUN TestConvertHashToNix32/SRI_format_to_Nix32163=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32164=== CONT TestPartSizeForNAR/zero_stays_at_minimum165=== RUN TestConvertHashToNix32/already_Nix32_format166=== PAUSE TestConvertHashToNix32/already_Nix32_format167=== RUN TestConvertHashToNix32/invalid_format168=== PAUSE TestConvertHashToNix32/invalid_format169=== CONT TestRateLimiterFeedback/429_enables_limiter170=== CONT TestPartSizeForNAR/capped_at_5_GiB171=== CONT TestPartSizeForNAR/5_TiB_S3_max_object172=== CONT TestPartSizeForNAR/1_TiB173=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum174=== CONT TestPartSizeForNAR/small_stays_at_minimum175=== CONT TestUploadMultipart_SupersededByPeer/missing176=== CONT TestUploadMultipart_SupersededByPeer/exists177=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything178=== RUN TestParsePathInfoJSON/Nix_format1792026/07/19 13:53:41 WARN Rate limiter enabled after throttle name=server-test rate=5180=== PAUSE TestParsePathInfoJSON/Nix_format181--- PASS: TestFileTokenMissing (0.00s)1822026/07/19 13:53:41 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:332051832026/07/19 13:53:41 WARN Rate limiter backed off name=server-test rate=5184=== RUN TestSetClientTLSErrors/missing_cert_file1852026/07/19 13:53:41 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33205186=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter187=== RUN TestPathInfoCACompatibility/new_structured_format_-_text188=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512189=== CONT TestRateLimiterFeedback/503_enables_limiter190=== PAUSE TestEncodeNixBase32/test_string_hash191=== PAUSE TestGetStorePathHash/valid_store_path192=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts193=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter194=== RUN TestSetClientTLS/rejects_connection_without_client_cert195=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped196=== RUN TestParsePathInfoJSON/Lix_format197--- PASS: TestScriptTokenEmptyToken (0.01s)198=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths199=== PAUSE TestSetClientTLSErrors/missing_cert_file200=== RUN TestSetClientTLSErrors/missing_key_file2012026/07/19 13:53:41 WARN Rate limiter enabled after throttle name=server-test rate=5202=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2032026/07/19 13:53:41 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:40759204=== RUN TestEncodeNixBase32/empty_input205=== RUN TestGetStorePathHash/basename_without_hyphen_should_error206=== CONT TestConvertHashToNix32/SRI_format_to_Nix32207=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert208=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA209--- PASS: TestScriptTokenScriptFails (0.00s)210--- PASS: TestShellSplit (0.00s)211--- PASS: TestFileTokenEmpty (0.00s)212=== PAUSE TestEncodeNixBase32/empty_input213--- PASS: TestScriptTokenBadJSON (0.01s)214=== PAUSE TestSetClientTLSErrors/missing_key_file2152026/07/19 13:53:41 WARN Rate limiter backed off name=server-test rate=5216=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error217=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error218=== PAUSE TestParsePathInfoJSON/Lix_format219=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text220=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512221=== RUN TestParsePathInfoJSON/empty_input222=== PAUSE TestParsePathInfoJSON/empty_input223=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped224=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI225=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method2262026/07/19 13:53:41 WARN Rate limiter enabled after throttle name=server-test rate=52272026/07/19 13:53:41 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:46221228=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method229=== CONT TestPathInfoCACompatibility/null_ca_field230=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive231=== CONT TestPathInfoCACompatibility/new_structured_format_-_text232=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method2332026/07/19 13:53:41 WARN Rate limiter backed off name=server-test rate=5234=== CONT TestConvertHashToNix32/invalid_format235=== CONT TestPathInfoCACompatibility/old_string_format_-_text236=== CONT TestConvertHashToNix32/already_Nix32_format237--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)238=== RUN TestSetClientTLSErrors/missing_ca_file239=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error240=== RUN TestParsePathInfoJSON/whitespace_only241=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error242=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error243=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error244=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error245=== CONT TestGetStorePathHash/valid_store_path246=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon247=== CONT TestEncodeNixBase32/test_string_hash248=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)249=== CONT TestEncodeNixBase32/empty_input250=== RUN TestFilterOversizedClosures/all_closures_skipped251=== PAUSE TestFilterOversizedClosures/all_closures_skipped252=== CONT TestFilterOversizedClosures/no_limit_keeps_everything253=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2542026/07/19 13:53:41 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=2000255=== CONT TestFilterOversizedClosures/all_closures_skipped2562026/07/19 13:53:41 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50257--- PASS: TestPartSizeForNAR (0.00s)258 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)259 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)260 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)261 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)262 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)263 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)264 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)265--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)266=== PAUSE TestSetClientTLSErrors/missing_ca_file267--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)268 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)269 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)270=== PAUSE TestParsePathInfoJSON/whitespace_only271=== RUN TestParsePathInfoJSON/invalid_JSON272=== PAUSE TestParsePathInfoJSON/invalid_JSON273=== CONT TestParsePathInfoJSON/Nix_format274=== CONT TestGetStorePathHash/basename_without_hyphen_should_error275=== CONT TestParsePathInfoJSON/whitespace_only276=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA277=== RUN TestSetClientTLSErrors/invalid_ca_file278=== PAUSE TestSetClientTLSErrors/invalid_ca_file279--- PASS: TestRateLimiterFeedback (0.00s)280 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)281 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)282 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)283 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)284--- PASS: TestPathInfoCACompatibility (0.01s)285 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)286 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)287 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)288 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)289 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)290--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)291=== CONT TestParsePathInfoJSON/invalid_JSON292--- PASS: TestPathInfoHashCompatibility (0.01s)293 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)294 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)295 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)296 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)297=== CONT TestParsePathInfoJSON/empty_input298--- PASS: TestEncodeNixBase32 (0.01s)299 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)300 --- PASS: TestEncodeNixBase32/empty_input (0.00s)301=== CONT TestParsePathInfoJSON/Lix_format302--- PASS: TestFilterOversizedClosures (0.01s)303 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)304 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)305 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)306--- PASS: TestGetStorePathHash (0.01s)307 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)308 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)309 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)310 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)311=== RUN TestSetClientTLS/preserves_debug_logging_transport312=== PAUSE TestSetClientTLS/preserves_debug_logging_transport313=== CONT TestSetClientTLS/rejects_connection_without_client_cert314=== CONT TestSetClientTLS/preserves_debug_logging_transport315=== CONT TestSetClientTLSErrors/missing_cert_file316=== CONT TestSetClientTLSErrors/invalid_ca_file317=== CONT TestSetClientTLSErrors/missing_ca_file318=== CONT TestSetClientTLSErrors/missing_key_file319--- PASS: TestConvertHashToNix32 (0.00s)320 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)321 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)322 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)323=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA324--- PASS: TestParsePathInfoJSON (0.01s)325 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)326 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)327 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)328 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)329 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)330--- PASS: TestSetClientTLSErrors (0.01s)331 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)332 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)333 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)334 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)335--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)3362026/07/19 13:53:41 http: TLS handshake error from 127.0.0.1:35658: remote error: tls: bad certificate337--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)338 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)339 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)340--- PASS: TestSetClientTLS (0.02s)341 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.00s)342 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)343 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)344--- PASS: TestDumpPathWriterError (0.03s)345--- PASS: TestCaseHackSuffix (0.03s)346--- PASS: TestDumpPathSingleFile (0.04s)347--- PASS: TestDumpPathMatchesNix (0.07s)348--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)349PASS350Running server tests...351The files belonging to this database system will be owned by user "nixbld".352This user must also own the server process.353354The database cluster will be initialized with locale "C".355The default database encoding has accordingly been set to "SQL_ASCII".356The default text search configuration will be set to "english".357358Data page checksums are enabled.359360creating directory /build/postgres2704336244/data ... ok361creating subdirectories ... ok362selecting dynamic shared memory implementation ... posix363selecting default "max_connections" ... 100364selecting default "shared_buffers" ... 128MB365selecting default time zone ... UTC366creating configuration files ... ok367running bootstrap script ... ok368performing post-bootstrap initialization ... ok369syncing data to disk ... ok370371initdb: warning: enabling "trust" authentication for local connections372initdb: 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.373374Success. You can now start the database server using:375376 pg_ctl -D /build/postgres2704336244/data -l logfile start377378/build/postgres2704336244:5432 - no response3792026-07-19 13:53:43.425 UTC [112] LOG: starting PostgreSQL 18.4 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit3802026-07-19 13:53:43.426 UTC [112] LOG: listening on Unix socket "/build/postgres2704336244/.s.PGSQL.5432"3812026-07-19 13:53:43.431 UTC [119] LOG: database system was shut down at 2026-07-19 13:53:43 UTC3822026-07-19 13:53:43.435 UTC [112] LOG: database system is ready to accept connections383/build/postgres2704336244:5432 - accepting connections384{"timestamp":"2026-07-19T13:53:43.821066157Z","level":"ERROR","fields":{"message":"list_path_raw: revjob err VolumeNotFound"},"target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":486,"threadName":"rustfs-worker","threadId":"ThreadId(766)"}385386thread 'rustfs-worker' (786) panicked at /build/rustfs-1.0.0-beta.7-vendor/source-registry-0/reqwest-0.13.4/src/async_impl/client.rs:2507:38:387Client::new(): reqwest::Error { kind: Builder, source: General("No CA certificates were loaded from the system") }388note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace389=== RUN TestService_AuthMiddleware390=== PAUSE TestService_AuthMiddleware391=== RUN TestService_AuthMiddleware_MTLSProxyHeader392=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader393=== RUN TestService_AuthMiddleware_MTLSBoundSubjects394=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects395=== RUN TestService_ReadAuthMiddleware396=== PAUSE TestService_ReadAuthMiddleware397=== RUN TestService_AuthMiddleware_OIDC398=== PAUSE TestService_AuthMiddleware_OIDC399=== RUN TestCacheConfigHandler400=== PAUSE TestCacheConfigHandler401=== RUN TestCacheStatsHandler402=== PAUSE TestCacheStatsHandler403=== RUN TestClientCADerivations404=== PAUSE TestClientCADerivations405=== RUN TestClientErrorHandling406=== PAUSE TestClientErrorHandling407=== RUN TestClientIntegration408=== PAUSE TestClientIntegration409=== RUN TestClientMultipleUploads410=== PAUSE TestClientMultipleUploads411=== RUN TestClientWithDependencies412=== PAUSE TestClientWithDependencies413=== RUN TestPinProtectsFromGC414=== PAUSE TestPinProtectsFromGC415=== RUN TestGCAdvisoryLockBlocksConcurrentRun4162026-07-19 13:53:43.923 UTC [913] ERROR: relation "goose_db_version" does not exist at character 364172026-07-19 13:53:43.923 UTC [913] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4182026/07/19 13:53:43 OK 20241026095416_initial_model.sql (7.21ms)4192026/07/19 13:53:43 OK 20251210153512_drop_unused_gin_index.sql (1.18ms)4202026/07/19 13:53:43 OK 20251218171726_add_pins.sql (2.12ms)4212026/07/19 13:53:43 OK 20260628120000_add_object_size_and_stats.sql (1.85ms)4222026/07/19 13:53:43 goose: successfully migrated database to version: 202606281200004232026/07/19 13:53:43 OK 1_commit_pending_closure.sql (1.33ms)4242026/07/19 13:53:43 OK 2_object_stats_trigger.sql (586.95µs)4252026/07/19 13:53:43 goose: up to current file version: 2426--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.13s)427=== RUN TestGCBugBareHashReferences428=== PAUSE TestGCBugBareHashReferences429=== RUN TestGCMetrics430=== PAUSE TestGCMetrics431=== RUN TestGCTaskStore_StartNew432=== PAUSE TestGCTaskStore_StartNew433=== RUN TestGCTaskStore_DeduplicateSameParams434=== PAUSE TestGCTaskStore_DeduplicateSameParams435=== RUN TestGCTaskStore_ConflictDifferentParams436=== PAUSE TestGCTaskStore_ConflictDifferentParams437=== RUN TestGCTaskStore_GetEmpty438=== PAUSE TestGCTaskStore_GetEmpty439=== RUN TestGCTaskStore_GetReturnsLatest440=== PAUSE TestGCTaskStore_GetReturnsLatest441=== RUN TestGCTaskStore_CompletedAllowsNewTask442=== PAUSE TestGCTaskStore_CompletedAllowsNewTask443=== RUN TestGCTaskStore_PhaseUpdates444=== PAUSE TestGCTaskStore_PhaseUpdates445=== RUN TestGCTaskStore_Fail446=== PAUSE TestGCTaskStore_Fail447=== RUN TestGracefulShutdownDrainsInflight448=== PAUSE TestGracefulShutdownDrainsInflight449=== RUN TestService_healthCheckHandler450=== PAUSE TestService_healthCheckHandler451=== RUN TestGenerateLandingPage452=== PAUSE TestGenerateLandingPage453=== RUN TestCacheConfigHandlerMaxNarSize454=== PAUSE TestCacheConfigHandlerMaxNarSize455=== RUN TestCreatePendingClosureRejectsOversizedNAR456=== PAUSE TestCreatePendingClosureRejectsOversizedNAR457=== RUN TestNARDeduplicationMetadataUploadBug458=== PAUSE TestNARDeduplicationMetadataUploadBug459=== RUN TestMetricsInventory460=== PAUSE TestMetricsInventory461=== RUN TestService_NativeMTLS462=== PAUSE TestService_NativeMTLS463=== RUN TestServerTLSConfig464=== PAUSE TestServerTLSConfig465=== RUN TestMultipartCleanup466=== PAUSE TestMultipartCleanup467=== RUN TestObjectStatsTrigger468=== PAUSE TestObjectStatsTrigger469=== RUN TestOrphanedObjectsGC470=== PAUSE TestOrphanedObjectsGC471=== RUN TestOrphanedObjectsGCStressTest472=== PAUSE TestOrphanedObjectsGCStressTest473=== RUN TestResurrectedObjectNotDeleted474=== PAUSE TestResurrectedObjectNotDeleted475=== RUN TestParseSingleRange476=== PAUSE TestParseSingleRange477=== RUN TestIsValidCachePath478=== PAUSE TestIsValidCachePath479=== RUN TestReadProxyNarinfo480=== PAUSE TestReadProxyNarinfo481=== RUN TestReadProxyNarinfoAlreadyDecompressed482=== PAUSE TestReadProxyNarinfoAlreadyDecompressed483=== RUN TestReadProxyNarStreaming484=== PAUSE TestReadProxyNarStreaming485=== RUN TestReadProxy404486=== PAUSE TestReadProxy404487=== RUN TestReadProxyInvalidPath488=== PAUSE TestReadProxyInvalidPath489=== RUN TestReadProxyHead490=== PAUSE TestReadProxyHead491=== RUN TestReadProxyConditionalGet492=== PAUSE TestReadProxyConditionalGet493=== RUN TestReadProxyRootRedirectsToIndexHTML494=== PAUSE TestReadProxyRootRedirectsToIndexHTML495=== RUN TestReadProxyDisabled496=== PAUSE TestReadProxyDisabled497=== RUN TestReadProxyRangeRequest498=== PAUSE TestReadProxyRangeRequest499=== RUN TestRedundantMultipartUpload500=== PAUSE TestRedundantMultipartUpload501=== RUN TestCompleteMultipartUpload_ErrorButObjectExists502=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists503=== RUN TestCompletedNarNotReofferedAcrossClosures504=== PAUSE TestCompletedNarNotReofferedAcrossClosures505=== RUN TestPresignedUploadRegisteredBeforeCommit506=== PAUSE TestPresignedUploadRegisteredBeforeCommit507=== RUN TestService_Rustfstest508=== PAUSE TestService_Rustfstest509=== RUN TestParseSize510=== PAUSE TestParseSize511=== RUN TestSkippedUploadsHandler512=== PAUSE TestSkippedUploadsHandler513=== RUN TestSystemdListenerNotActivated514--- PASS: TestSystemdListenerNotActivated (0.00s)515=== RUN TestWatchdogBeatsWhenHealthy516--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)517=== RUN TestWatchdogSkipsWhenUnhealthy5182026/07/19 13:53:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5192026/07/19 13:53:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5202026/07/19 13:53:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5212026/07/19 13:53:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5222026/07/19 13:53:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5232026/07/19 13:53:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5242026/07/19 13:53:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5252026/07/19 13:53:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5262026/07/19 13:53:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5272026/07/19 13:53:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"528--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)529=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle530=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle531=== RUN TestProxyWriteTimeout532=== PAUSE TestProxyWriteTimeout533=== RUN TestIsValidUploadKey534=== PAUSE TestIsValidUploadKey535=== RUN TestUploadHandlersRejectInvalidKeys536=== PAUSE TestUploadHandlersRejectInvalidKeys537=== RUN TestUploadHandlersRejectOversizedBody538=== PAUSE TestUploadHandlersRejectOversizedBody539=== RUN TestService_cleanupPendingClosuresHandler540=== PAUSE TestService_cleanupPendingClosuresHandler541=== RUN TestService_createPendingClosureHandler542=== PAUSE TestService_createPendingClosureHandler543=== RUN TestService_verifyS3Integrity544=== PAUSE TestService_verifyS3Integrity545=== RUN TestCompleteMultipartUnregistered546=== PAUSE TestCompleteMultipartUnregistered547=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT548=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT549=== CONT TestService_AuthMiddleware550=== CONT TestService_createPendingClosureHandler551=== CONT TestCompleteMultipartUnregistered552=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT553=== CONT TestServerTLSConfig554=== RUN TestServerTLSConfig/no_client_CA555=== CONT TestService_cleanupPendingClosuresHandler556=== CONT TestUploadHandlersRejectOversizedBody557=== CONT TestUploadHandlersRejectInvalidKeys558=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info559=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info560=== CONT TestIsValidUploadKey561=== CONT TestProxyWriteTimeout562=== RUN TestProxyWriteTimeout/narinfo563=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle564=== CONT TestSkippedUploadsHandler565=== CONT TestParseSize566=== CONT TestService_Rustfstest567=== CONT TestPresignedUploadRegisteredBeforeCommit568=== CONT TestCompletedNarNotReofferedAcrossClosures569=== CONT TestCompleteMultipartUpload_ErrorButObjectExists570=== CONT TestRedundantMultipartUpload571=== CONT TestReadProxyRangeRequest572=== CONT TestReadProxyDisabled573=== CONT TestReadProxyRootRedirectsToIndexHTML574=== CONT TestReadProxyConditionalGet575=== CONT TestReadProxyHead576=== CONT TestReadProxyInvalidPath577=== PAUSE TestServerTLSConfig/no_client_CA578=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal579=== RUN TestIsValidUploadKey/narinfo580=== PAUSE TestIsValidUploadKey/narinfo581=== RUN TestIsValidUploadKey/nar_zst582=== PAUSE TestIsValidUploadKey/nar_zst583=== RUN TestIsValidUploadKey/nar_xz584=== PAUSE TestIsValidUploadKey/nar_xz585=== RUN TestIsValidUploadKey/nar_plain586=== PAUSE TestIsValidUploadKey/nar_plain587=== RUN TestIsValidUploadKey/listing588=== PAUSE TestIsValidUploadKey/listing589=== RUN TestIsValidUploadKey/build_log590=== PAUSE TestIsValidUploadKey/build_log591=== RUN TestIsValidUploadKey/build_log_home-manager_file592=== PAUSE TestIsValidUploadKey/build_log_home-manager_file593=== RUN TestIsValidUploadKey/build_log_plus_in_name594=== PAUSE TestIsValidUploadKey/build_log_plus_in_name595=== RUN TestIsValidUploadKey/build_log_question_mark596=== PAUSE TestProxyWriteTimeout/narinfo597--- PASS: TestParseSize (0.00s)598=== CONT TestReadProxy4045992026/07/19 13:53:44 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000600=== PAUSE TestIsValidUploadKey/build_log_question_mark601=== RUN TestIsValidUploadKey/build_log_equals602=== PAUSE TestIsValidUploadKey/build_log_equals603=== RUN TestIsValidUploadKey/realisation604=== PAUSE TestIsValidUploadKey/realisation605=== RUN TestIsValidUploadKey/realisation_plus_in_output606=== PAUSE TestIsValidUploadKey/realisation_plus_in_output607=== RUN TestIsValidUploadKey/nix-cache-info608=== PAUSE TestIsValidUploadKey/nix-cache-info609=== RUN TestIsValidUploadKey/index.html610=== PAUSE TestIsValidUploadKey/index.html611=== RUN TestIsValidUploadKey/narinfo_key,_nar_type612=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type613=== RUN TestIsValidUploadKey/nar_key,_narinfo_type614=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type615=== RUN TestIsValidUploadKey/listing_key,_narinfo_type616=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type617=== RUN TestIsValidUploadKey/traversal618=== PAUSE TestIsValidUploadKey/traversal619=== RUN TestIsValidUploadKey/traversal_nar620=== PAUSE TestIsValidUploadKey/traversal_nar621=== RUN TestIsValidUploadKey/absolute622=== PAUSE TestIsValidUploadKey/absolute623=== RUN TestIsValidUploadKey/empty_key624=== PAUSE TestIsValidUploadKey/empty_key625=== RUN TestIsValidUploadKey/unknown_type626=== PAUSE TestIsValidUploadKey/unknown_type627=== CONT TestReadProxyNarStreaming628=== RUN TestServerTLSConfig/missing_CA_file629=== PAUSE TestServerTLSConfig/missing_CA_file630=== RUN TestProxyWriteTimeout/1_GiB_nar631=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal632=== PAUSE TestProxyWriteTimeout/1_GiB_nar633=== RUN TestProxyWriteTimeout/10_GiB_nar634=== PAUSE TestProxyWriteTimeout/10_GiB_nar635=== RUN TestProxyWriteTimeout/unknown_size636=== PAUSE TestProxyWriteTimeout/unknown_size637=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key638=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key639=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key640=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key641=== RUN TestServerTLSConfig/not_a_PEM_file642=== PAUSE TestServerTLSConfig/not_a_PEM_file643=== CONT TestReadProxyNarinfo644=== CONT TestReadProxyNarinfoAlreadyDecompressed645=== CONT TestIsValidCachePath646=== RUN TestIsValidCachePath/narinfo647=== PAUSE TestIsValidCachePath/narinfo648=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars649=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars650=== RUN TestIsValidCachePath/nar_zst651=== PAUSE TestIsValidCachePath/nar_zst652=== RUN TestIsValidCachePath/nar_xz653=== PAUSE TestIsValidCachePath/nar_xz654=== RUN TestIsValidCachePath/nar_bz2655=== PAUSE TestIsValidCachePath/nar_bz2656=== RUN TestIsValidCachePath/nar_uncompressed657=== PAUSE TestIsValidCachePath/nar_uncompressed658=== RUN TestIsValidCachePath/ls659=== PAUSE TestIsValidCachePath/ls660=== RUN TestIsValidCachePath/log661=== PAUSE TestIsValidCachePath/log662=== RUN TestIsValidCachePath/realisation663=== PAUSE TestIsValidCachePath/realisation664=== RUN TestIsValidCachePath/nix-cache-info665=== PAUSE TestIsValidCachePath/nix-cache-info666=== RUN TestIsValidCachePath/index.html667=== PAUSE TestIsValidCachePath/index.html668=== RUN TestIsValidCachePath/traversal_parent669=== PAUSE TestIsValidCachePath/traversal_parent670=== RUN TestIsValidCachePath/traversal_in_middle671=== PAUSE TestIsValidCachePath/traversal_in_middle672=== RUN TestIsValidCachePath/invalid_char_e673=== PAUSE TestIsValidCachePath/invalid_char_e674=== RUN TestIsValidCachePath/invalid_char_u675=== PAUSE TestIsValidCachePath/invalid_char_u676=== RUN TestIsValidCachePath/random_path677=== PAUSE TestIsValidCachePath/random_path678=== RUN TestIsValidCachePath/empty679=== PAUSE TestIsValidCachePath/empty680=== RUN TestIsValidCachePath/leading_slash681=== PAUSE TestIsValidCachePath/leading_slash682=== RUN TestIsValidCachePath/wrong_extension683=== PAUSE TestIsValidCachePath/wrong_extension684=== RUN TestIsValidCachePath/short_hash685=== PAUSE TestIsValidCachePath/short_hash686=== CONT TestParseSingleRange687=== RUN TestParseSingleRange/none688=== PAUSE TestParseSingleRange/none689=== RUN TestParseSingleRange/unknown_unit690=== PAUSE TestParseSingleRange/unknown_unit691=== RUN TestParseSingleRange/multi-range_ignored692=== PAUSE TestParseSingleRange/multi-range_ignored693=== RUN TestParseSingleRange/malformed_no_dash694=== PAUSE TestParseSingleRange/malformed_no_dash695=== RUN TestParseSingleRange/malformed_both_empty696=== PAUSE TestParseSingleRange/malformed_both_empty697=== RUN TestParseSingleRange/malformed_end_before_start698=== PAUSE TestParseSingleRange/malformed_end_before_start699=== RUN TestParseSingleRange/closed700=== PAUSE TestParseSingleRange/closed701=== RUN TestParseSingleRange/open-ended702=== PAUSE TestParseSingleRange/open-ended703=== RUN TestParseSingleRange/end_clamped_to_size704=== PAUSE TestParseSingleRange/end_clamped_to_size705=== RUN TestParseSingleRange/suffix706=== PAUSE TestParseSingleRange/suffix707=== RUN TestParseSingleRange/suffix_exceeds_size708=== PAUSE TestParseSingleRange/suffix_exceeds_size709=== RUN TestParseSingleRange/single_byte710=== PAUSE TestParseSingleRange/single_byte711=== RUN TestParseSingleRange/start_past_EOF712=== PAUSE TestParseSingleRange/start_past_EOF713=== RUN TestParseSingleRange/start_far_past_EOF714=== PAUSE TestParseSingleRange/start_far_past_EOF715=== CONT TestResurrectedObjectNotDeleted716--- PASS: TestSkippedUploadsHandler (0.11s)717=== CONT TestOrphanedObjectsGCStressTest7182026-07-19 13:53:44.356 UTC [985] ERROR: relation "goose_db_version" does not exist at character 367192026-07-19 13:53:44.356 UTC [985] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7202026-07-19 13:53:44.377 UTC [986] ERROR: relation "goose_db_version" does not exist at character 367212026-07-19 13:53:44.377 UTC [986] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7222026-07-19 13:53:44.382 UTC [987] ERROR: relation "goose_db_version" does not exist at character 367232026-07-19 13:53:44.382 UTC [987] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC724=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure725=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure726=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart727=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart728=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts729=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts730=== CONT TestOrphanedObjectsGC7312026-07-19 13:53:44.414 UTC [993] ERROR: relation "goose_db_version" does not exist at character 367322026-07-19 13:53:44.414 UTC [993] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7332026-07-19 13:53:44.415 UTC [994] ERROR: relation "goose_db_version" does not exist at character 367342026-07-19 13:53:44.415 UTC [994] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7352026-07-19 13:53:44.416 UTC [995] ERROR: relation "goose_db_version" does not exist at character 367362026-07-19 13:53:44.416 UTC [995] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7372026/07/19 13:53:44 OK 20241026095416_initial_model.sql (33.66ms)7382026-07-19 13:53:44.422 UTC [996] ERROR: relation "goose_db_version" does not exist at character 367392026-07-19 13:53:44.422 UTC [996] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7402026/07/19 13:53:44 OK 20241026095416_initial_model.sql (24.8ms)7412026-07-19 13:53:44.426 UTC [997] ERROR: relation "goose_db_version" does not exist at character 367422026-07-19 13:53:44.426 UTC [997] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7432026/07/19 13:53:44 OK 20241026095416_initial_model.sql (32.47ms)7442026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (14.64ms)7452026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (11.19ms)7462026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (4.11ms)7472026/07/19 13:53:44 OK 20251218171726_add_pins.sql (5.58ms)7482026-07-19 13:53:44.448 UTC [998] ERROR: relation "goose_db_version" does not exist at character 367492026-07-19 13:53:44.448 UTC [998] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7502026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (5.9ms)7512026/07/19 13:53:44 goose: successfully migrated database to version: 202606281200007522026/07/19 13:53:44 OK 20251218171726_add_pins.sql (10.29ms)7532026/07/19 13:53:44 OK 20251218171726_add_pins.sql (14.1ms)7542026/07/19 13:53:44 OK 20241026095416_initial_model.sql (17.58ms)7552026/07/19 13:53:44 OK 1_commit_pending_closure.sql (4.42ms)7562026/07/19 13:53:44 OK 20241026095416_initial_model.sql (19.63ms)7572026/07/19 13:53:44 OK 20241026095416_initial_model.sql (17.69ms)7582026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (3.13ms)7592026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.76ms)7602026/07/19 13:53:44 goose: up to current file version: 27612026/07/19 13:53:44 OK 20241026095416_initial_model.sql (19ms)7622026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (2.85ms)7632026/07/19 13:53:44 OK 20241026095416_initial_model.sql (18.1ms)7642026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (2.71ms)7652026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (7.82ms)7662026/07/19 13:53:44 goose: successfully migrated database to version: 202606281200007672026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (9.38ms)7682026/07/19 13:53:44 goose: successfully migrated database to version: 202606281200007692026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (3.2ms)7702026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (4.39ms)7712026/07/19 13:53:44 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"772--- PASS: TestService_AuthMiddleware (0.28s)773=== CONT TestObjectStatsTrigger7742026/07/19 13:53:44 OK 20251218171726_add_pins.sql (5.25ms)7752026/07/19 13:53:44 OK 20251218171726_add_pins.sql (6.99ms)7762026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.4ms)7772026/07/19 13:53:44 OK 20251218171726_add_pins.sql (5.08ms)7782026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.12ms)7792026/07/19 13:53:44 goose: up to current file version: 27802026/07/19 13:53:44 OK 1_commit_pending_closure.sql (5.66ms)7812026-07-19 13:53:44.468 UTC [999] ERROR: relation "goose_db_version" does not exist at character 367822026-07-19 13:53:44.468 UTC [999] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7832026/07/19 13:53:44 OK 20251218171726_add_pins.sql (6.83ms)7842026/07/19 13:53:44 OK 20251218171726_add_pins.sql (6.56ms)7852026-07-19 13:53:44.469 UTC [1000] ERROR: relation "goose_db_version" does not exist at character 367862026-07-19 13:53:44.469 UTC [1000] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7872026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures7882026/07/19 13:53:44 OK 2_object_stats_trigger.sql (3.19ms)7892026/07/19 13:53:44 goose: up to current file version: 27902026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (7.77ms)7912026/07/19 13:53:44 goose: successfully migrated database to version: 202606281200007922026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (7.92ms)7932026/07/19 13:53:44 goose: successfully migrated database to version: 202606281200007942026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures7952026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (17.32ms)7962026/07/19 13:53:44 goose: successfully migrated database to version: 202606281200007972026/07/19 13:53:44 OK 1_commit_pending_closure.sql (13.05ms)7982026/07/19 13:53:44 OK 20241026095416_initial_model.sql (23.27ms)7992026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (15.86ms)8002026/07/19 13:53:44 goose: successfully migrated database to version: 202606281200008012026/07/19 13:53:44 OK 1_commit_pending_closure.sql (13.49ms)8022026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (15.71ms)8032026/07/19 13:53:44 goose: successfully migrated database to version: 202606281200008042026/07/19 13:53:44 OK 1_commit_pending_closure.sql (5.97ms)8052026/07/19 13:53:44 OK 2_object_stats_trigger.sql (3.45ms)8062026/07/19 13:53:44 goose: up to current file version: 28072026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.87ms)8082026/07/19 13:53:44 OK 2_object_stats_trigger.sql (4.29ms)8092026/07/19 13:53:44 goose: up to current file version: 28102026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (3.89ms)8112026/07/19 13:53:44 OK 1_commit_pending_closure.sql (5.17ms)8122026/07/19 13:53:44 OK 2_object_stats_trigger.sql (3.18ms)8132026-07-19 13:53:44.491 UTC [1003] ERROR: relation "goose_db_version" does not exist at character 368142026-07-19 13:53:44.491 UTC [1003] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8152026/07/19 13:53:44 goose: up to current file version: 28162026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures8172026/07/19 13:53:44 INFO Received cleanup request method=DELETE path=/api/pending_closures8182026/07/19 13:53:44 OK 2_object_stats_trigger.sql (3.58ms)8192026/07/19 13:53:44 goose: up to current file version: 28202026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures8212026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures8222026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures8232026/07/19 13:53:44 OK 2_object_stats_trigger.sql (4.49ms)8242026/07/19 13:53:44 goose: up to current file version: 28252026/07/19 13:53:44 INFO Aborted multipart uploads count=08262026-07-19 13:53:44.496 UTC [1004] ERROR: relation "goose_db_version" does not exist at character 368272026-07-19 13:53:44.496 UTC [1004] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC828--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.31s)829=== CONT TestMultipartCleanup8302026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures831--- PASS: TestService_Rustfstest (0.31s)832=== CONT TestService_verifyS3Integrity8332026/07/19 13:53:44 OK 20251218171726_add_pins.sql (7.62ms)8342026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures835{"timestamp":"2026-07-19T13:53:44.503782427Z","level":"ERROR","fields":{"message":"system path read failed","path_kind":"data_usage","operation":"read_primary","reason":"config_not_found","object":"buckets/.usage.json","error":"Config not found"},"target":"rustfs_ecstore::data_usage","filename":"crates/ecstore/src/data_usage.rs","line_number":126,"threadName":"rustfs-worker","threadId":"ThreadId(766)"}8362026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (7.96ms)8372026/07/19 13:53:44 goose: successfully migrated database to version: 202606281200008382026/07/19 13:53:44 OK 20241026095416_initial_model.sql (21.83ms)8392026/07/19 13:53:44 INFO Received cleanup request method=DELETE path=/api/pending_closures8402026/07/19 13:53:44 OK 20241026095416_initial_model.sql (22.65ms)8412026/07/19 13:53:44 INFO Aborted multipart uploads count=18422026/07/19 13:53:44 OK 1_commit_pending_closure.sql (4.44ms)8432026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (3.13ms)8442026/07/19 13:53:44 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8452026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures8462026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (3.72ms)8472026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.32ms)8482026/07/19 13:53:44 goose: up to current file version: 2849--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.32s)8502026/07/19 13:53:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete851=== CONT TestService_healthCheckHandler8522026-07-19 13:53:44.515 UTC [993] ERROR: Closure does not exist: id=18532026-07-19 13:53:44.515 UTC [993] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE8542026-07-19 13:53:44.515 UTC [993] STATEMENT: -- name: CommitPendingClosure :exec855 SELECT commit_pending_closure($1::bigint)856 857--- PASS: TestService_cleanupPendingClosuresHandler (0.33s)858=== CONT TestService_NativeMTLS8592026/07/19 13:53:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8602026-07-19 13:53:44.519 UTC [1011] ERROR: relation "goose_db_version" does not exist at character 368612026-07-19 13:53:44.519 UTC [1011] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8622026/07/19 13:53:44 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst863--- PASS: TestCompleteMultipartUnregistered (0.33s)864=== CONT TestMetricsInventory8652026/07/19 13:53:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete866{"timestamp":"2026-07-19T13:53:44.525001406Z","level":"ERROR","fields":{"message":"complete_multipart_upload part error: \"part.1 not found\""},"target":"rustfs_ecstore::set_disk","filename":"crates/ecstore/src/set_disk.rs","line_number":3463,"threadName":"rustfs-worker","threadId":"ThreadId(766)"}867{"timestamp":"2026-07-19T13:53:44.525033566Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket9, object=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst"},"target":"rustfs_ecstore::set_disk","filename":"crates/ecstore/src/set_disk.rs","line_number":3534,"threadName":"rustfs-worker","threadId":"ThreadId(766)"}8682026/07/19 13:53:44 OK 20251218171726_add_pins.sql (14.42ms)8692026/07/19 13:53:44 WARN CompleteMultipartUpload errored but object exists; treating as success error="One or more of the specified parts could not be found. The part may not have been uploaded, or the specified entity tag may not match the part's entity tag." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjIwNDFmMDUtZDhlYS00M2Y0LTkyNTAtZWIyMjExZjE5N2E2LmQ2NjgyNDE3LWU4OWItNGJlOS04OWQ5LWIyMTgzMjBjZjFkNXgxNzg0NDY5MjI0NTA4NDEwNzM08702026/07/19 13:53:44 OK 20251218171726_add_pins.sql (17.76ms)8712026/07/19 13:53:44 OK 20241026095416_initial_model.sql (24.36ms)8722026/07/19 13:53:44 OK 20241026095416_initial_model.sql (20.43ms)8732026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (3.51ms)8742026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (3.68ms)8752026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (10.8ms)8762026/07/19 13:53:44 goose: successfully migrated database to version: 202606281200008772026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (6.16ms)8782026/07/19 13:53:44 goose: successfully migrated database to version: 202606281200008792026/07/19 13:53:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjIwNDFmMDUtZDhlYS00M2Y0LTkyNTAtZWIyMjExZjE5N2E2LmQ2NjgyNDE3LWU4OWItNGJlOS04OWQ5LWIyMTgzMjBjZjFkNXgxNzg0NDY5MjI0NTA4NDEwNzM0 parts=1880--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.35s)881=== CONT TestNARDeduplicationMetadataUploadBug8822026/07/19 13:53:44 OK 20251218171726_add_pins.sql (4.29ms)8832026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.79ms)8842026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.92ms)8852026/07/19 13:53:44 OK 20251218171726_add_pins.sql (5.36ms)8862026-07-19 13:53:44.544 UTC [1019] ERROR: relation "goose_db_version" does not exist at character 368872026-07-19 13:53:44.544 UTC [1019] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8882026/07/19 13:53:44 OK 2_object_stats_trigger.sql (4.18ms)8892026/07/19 13:53:44 goose: up to current file version: 28902026-07-19 13:53:44.544 UTC [1022] ERROR: relation "goose_db_version" does not exist at character 368912026-07-19 13:53:44.544 UTC [1022] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8922026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (5.32ms)8932026/07/19 13:53:44 goose: successfully migrated database to version: 202606281200008942026-07-19 13:53:44.545 UTC [1020] ERROR: relation "goose_db_version" does not exist at character 368952026-07-19 13:53:44.545 UTC [1020] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8962026/07/19 13:53:44 OK 2_object_stats_trigger.sql (4.26ms)8972026/07/19 13:53:44 goose: up to current file version: 28982026-07-19 13:53:44.545 UTC [1021] ERROR: relation "goose_db_version" does not exist at character 368992026-07-19 13:53:44.545 UTC [1021] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9002026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (5.82ms)9012026/07/19 13:53:44 goose: successfully migrated database to version: 202606281200009022026-07-19 13:53:44.547 UTC [1024] ERROR: relation "goose_db_version" does not exist at character 369032026-07-19 13:53:44.547 UTC [1024] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9042026/07/19 13:53:44 OK 20241026095416_initial_model.sql (14.43ms)9052026-07-19 13:53:44.548 UTC [1026] ERROR: relation "goose_db_version" does not exist at character 369062026-07-19 13:53:44.548 UTC [1026] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC907--- PASS: TestReadProxy404 (0.36s)9082026/07/19 13:53:44 OK 1_commit_pending_closure.sql (4.14ms)909=== CONT TestCreatePendingClosureRejectsOversizedNAR9102026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures911--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)912=== CONT TestCacheConfigHandlerMaxNarSize913--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)914=== CONT TestGenerateLandingPage9152026/07/19 13:53:44 OK 1_commit_pending_closure.sql (4.16ms)9162026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.81ms)9172026/07/19 13:53:44 goose: up to current file version: 29182026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (4.28ms)919--- PASS: TestGenerateLandingPage (0.00s)920=== CONT TestGCTaskStore_CompletedAllowsNewTask921--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)922=== CONT TestGracefulShutdownDrainsInflight9232026/07/19 13:53:44 INFO Starting HTTP server address=127.0.0.1:351339242026/07/19 13:53:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9252026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.9ms)9262026/07/19 13:53:44 goose: up to current file version: 29272026/07/19 13:53:44 INFO Shutdown signal received, draining in-flight requests timeout=10s928--- PASS: TestReadProxyRangeRequest (0.36s)929=== CONT TestGCTaskStore_Fail930--- PASS: TestGCTaskStore_Fail (0.00s)931=== CONT TestGCTaskStore_PhaseUpdates932--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)933=== CONT TestGCTaskStore_GetEmpty934--- PASS: TestGCTaskStore_GetEmpty (0.00s)935=== CONT TestGCTaskStore_GetReturnsLatest936--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)9372026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures938=== CONT TestGCTaskStore_ConflictDifferentParams9392026-07-19 13:53:44.556 UTC [1027] ERROR: relation "goose_db_version" does not exist at character 369402026-07-19 13:53:44.556 UTC [1027] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC941--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)942=== CONT TestClientErrorHandling943=== RUN TestClientErrorHandling/InvalidStorePath944=== PAUSE TestClientErrorHandling/InvalidStorePath945=== RUN TestClientErrorHandling/InvalidAuthToken946=== PAUSE TestClientErrorHandling/InvalidAuthToken947=== RUN TestClientErrorHandling/ServerNotAvailable9482026-07-19 13:53:44.556 UTC [1029] ERROR: relation "goose_db_version" does not exist at character 369492026-07-19 13:53:44.556 UTC [1029] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC950=== PAUSE TestClientErrorHandling/ServerNotAvailable951=== CONT TestGCTaskStore_StartNew952--- PASS: TestGCTaskStore_StartNew (0.00s)953=== CONT TestGCMetrics9542026/07/19 13:53:44 OK 20251218171726_add_pins.sql (6.13ms)9552026-07-19 13:53:44.558 UTC [1030] ERROR: relation "goose_db_version" does not exist at character 369562026-07-19 13:53:44.558 UTC [1030] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC957--- PASS: TestReadProxyHead (0.33s)958=== CONT TestGCTaskStore_DeduplicateSameParams959--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)960=== CONT TestGCBugBareHashReferences9612026-07-19 13:53:44.561 UTC [1031] ERROR: relation "goose_db_version" does not exist at character 369622026-07-19 13:53:44.561 UTC [1031] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9632026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (7.94ms)9642026/07/19 13:53:44 goose: successfully migrated database to version: 202606281200009652026/07/19 13:53:44 OK 20241026095416_initial_model.sql (16.52ms)9662026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.84ms)9672026/07/19 13:53:44 OK 2_object_stats_trigger.sql (11.09ms)9682026/07/19 13:53:44 goose: up to current file version: 29692026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (12.3ms)9702026/07/19 13:53:44 OK 20241026095416_initial_model.sql (18.46ms)9712026/07/19 13:53:44 OK 20241026095416_initial_model.sql (29.98ms)9722026/07/19 13:53:44 OK 20241026095416_initial_model.sql (29.63ms)9732026/07/19 13:53:44 OK 20241026095416_initial_model.sql (28.8ms)9742026/07/19 13:53:44 OK 20241026095416_initial_model.sql (20.9ms)9752026/07/19 13:53:44 OK 20241026095416_initial_model.sql (28.1ms)9762026/07/19 13:53:44 OK 20241026095416_initial_model.sql (28.08ms)9772026/07/19 13:53:44 OK 20241026095416_initial_model.sql (16.3ms)9782026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)9792026/07/19 13:53:44 OK 20241026095416_initial_model.sql (18.39ms)9802026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (2.26ms)9812026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (4.03ms)9822026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (4.03ms)9832026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (3.67ms)9842026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)9852026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (3.82ms)9862026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (4.95ms)9872026/07/19 13:53:44 OK 20251218171726_add_pins.sql (10.21ms)9882026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (3.9ms)9892026/07/19 13:53:44 OK 20251218171726_add_pins.sql (6.09ms)990--- PASS: TestReadProxyConditionalGet (0.39s)991=== CONT TestPinProtectsFromGC9922026/07/19 13:53:44 OK 20251218171726_add_pins.sql (6.7ms)9932026/07/19 13:53:44 OK 20251218171726_add_pins.sql (7.09ms)9942026/07/19 13:53:44 OK 20251218171726_add_pins.sql (7.06ms)9952026/07/19 13:53:44 OK 20251218171726_add_pins.sql (7.02ms)9962026/07/19 13:53:44 OK 20251218171726_add_pins.sql (6.98ms)9972026/07/19 13:53:44 OK 20251218171726_add_pins.sql (5.73ms)9982026/07/19 13:53:44 OK 20251218171726_add_pins.sql (8.21ms)9992026/07/19 13:53:44 OK 20251218171726_add_pins.sql (8.42ms)10002026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (7.21ms)10012026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000010022026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (7.71ms)10032026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000010042026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (7.9ms)10052026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000010062026/07/19 13:53:44 OK 1_commit_pending_closure.sql (5.59ms)10072026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (6.96ms)10082026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (8.45ms)10092026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000010102026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000010112026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (7.02ms)10122026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000010132026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (8.24ms)10142026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000010152026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.63ms)10162026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (6.92ms)10172026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000010182026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.48ms)10192026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (10.03ms)10202026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000010212026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (8.91ms)10222026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000010232026/07/19 13:53:44 OK 1_commit_pending_closure.sql (2.95ms)10242026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.43ms)10252026/07/19 13:53:44 goose: up to current file version: 210262026/07/19 13:53:44 OK 2_object_stats_trigger.sql (3.26ms)10272026/07/19 13:53:44 goose: up to current file version: 210282026/07/19 13:53:44 OK 1_commit_pending_closure.sql (4.26ms)10292026/07/19 13:53:44 OK 1_commit_pending_closure.sql (4.1ms)10302026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.98ms)10312026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.88ms)10322026/07/19 13:53:44 goose: up to current file version: 210332026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.82ms)10342026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.9ms)10352026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.55ms)10362026/07/19 13:53:44 goose: up to current file version: 210372026/07/19 13:53:44 OK 1_commit_pending_closure.sql (4.05ms)10382026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.38ms)10392026/07/19 13:53:44 goose: up to current file version: 210402026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.28ms)10412026/07/19 13:53:44 goose: up to current file version: 210422026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.34ms)10432026/07/19 13:53:44 goose: up to current file version: 210442026/07/19 13:53:44 OK 2_object_stats_trigger.sql (3.3ms)10452026/07/19 13:53:44 goose: up to current file version: 210462026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.64ms)10472026/07/19 13:53:44 goose: up to current file version: 210482026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures1049--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.38s)1050=== CONT TestService_AuthMiddleware_OIDC10512026/07/19 13:53:44 OK 2_object_stats_trigger.sql (3.68ms)10522026/07/19 13:53:44 goose: up to current file version: 21053--- PASS: TestReadProxyDisabled (0.38s)1054=== CONT TestClientWithDependencies1055--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.32s)1056=== CONT TestClientMultipleUploads10572026/07/19 13:53:44 INFO OIDC provider initialized name=test1058--- PASS: TestReadProxyInvalidPath (0.41s)1059=== CONT TestClientCADerivations1060--- PASS: TestReadProxyNarStreaming (0.32s)1061=== CONT TestClientIntegration1062--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1063=== CONT TestCacheStatsHandler1064--- PASS: TestReadProxyNarinfo (0.32s)1065=== CONT TestCacheConfigHandler1066=== RUN TestCacheConfigHandler/full_config,_no_issuer1067=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1068=== RUN TestCacheConfigHandler/no_cache_url_configured1069=== PAUSE TestCacheConfigHandler/no_cache_url_configured1070=== RUN TestCacheConfigHandler/no_signing_keys1071=== PAUSE TestCacheConfigHandler/no_signing_keys1072=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1073=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1074=== CONT TestService_AuthMiddleware_MTLSBoundSubjects10752026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures10762026-07-19 13:53:44.652 UTC [1053] ERROR: relation "goose_db_version" does not exist at character 3610772026-07-19 13:53:44.652 UTC [1053] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10782026-07-19 13:53:44.660 UTC [1055] ERROR: relation "goose_db_version" does not exist at character 3610792026-07-19 13:53:44.660 UTC [1055] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10802026-07-19 13:53:44.660 UTC [1054] ERROR: relation "goose_db_version" does not exist at character 3610812026-07-19 13:53:44.660 UTC [1054] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10822026-07-19 13:53:44.662 UTC [1056] ERROR: relation "goose_db_version" does not exist at character 3610832026-07-19 13:53:44.662 UTC [1056] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10842026-07-19 13:53:44.664 UTC [1057] ERROR: relation "goose_db_version" does not exist at character 3610852026-07-19 13:53:44.664 UTC [1057] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10862026-07-19 13:53:44.668 UTC [1058] ERROR: relation "goose_db_version" does not exist at character 3610872026-07-19 13:53:44.668 UTC [1058] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1088--- PASS: TestResurrectedObjectNotDeleted (0.38s)1089=== CONT TestService_ReadAuthMiddleware10902026/07/19 13:53:44 OK 20241026095416_initial_model.sql (25.09ms)10912026-07-19 13:53:44.690 UTC [1060] ERROR: relation "goose_db_version" does not exist at character 3610922026-07-19 13:53:44.690 UTC [1060] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10932026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (5.88ms)10942026/07/19 13:53:44 OK 20241026095416_initial_model.sql (20.25ms)10952026/07/19 13:53:44 OK 20241026095416_initial_model.sql (15.18ms)10962026/07/19 13:53:44 OK 20241026095416_initial_model.sql (15.11ms)10972026/07/19 13:53:44 OK 20241026095416_initial_model.sql (15.14ms)10982026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)10992026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (2.8ms)11002026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)11012026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (2.74ms)11022026/07/19 13:53:44 OK 20241026095416_initial_model.sql (12.95ms)11032026/07/19 13:53:44 OK 20251218171726_add_pins.sql (7.65ms)11042026/07/19 13:53:44 OK 20251218171726_add_pins.sql (4.36ms)11052026/07/19 13:53:44 OK 20251218171726_add_pins.sql (4.58ms)11062026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (3.49ms)11072026/07/19 13:53:44 OK 20251218171726_add_pins.sql (5.55ms)11082026/07/19 13:53:44 OK 20251218171726_add_pins.sql (5.68ms)11092026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (6.1ms)11102026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000011112026-07-19 13:53:44.708 UTC [1062] ERROR: relation "goose_db_version" does not exist at character 3611122026-07-19 13:53:44.708 UTC [1062] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11132026-07-19 13:53:44.709 UTC [1063] ERROR: relation "goose_db_version" does not exist at character 3611142026-07-19 13:53:44.709 UTC [1063] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11152026/07/19 13:53:44 OK 20251218171726_add_pins.sql (8.02ms)11162026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (8.52ms)11172026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000011182026/07/19 13:53:44 OK 1_commit_pending_closure.sql (16.34ms)11192026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (19.97ms)11202026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000011212026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (21.35ms)11222026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000011232026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (20.07ms)11242026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000011252026/07/19 13:53:44 OK 1_commit_pending_closure.sql (15.99ms)11262026/07/19 13:53:44 OK 20241026095416_initial_model.sql (29.16ms)11272026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (16.42ms)11282026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000011292026/07/19 13:53:44 OK 1_commit_pending_closure.sql (2.91ms)11302026/07/19 13:53:44 OK 2_object_stats_trigger.sql (4.64ms)11312026/07/19 13:53:44 goose: up to current file version: 211322026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.92ms)11332026/07/19 13:53:44 goose: up to current file version: 211342026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.55ms)11352026/07/19 13:53:44 goose: up to current file version: 211362026/07/19 13:53:44 OK 1_commit_pending_closure.sql (5.98ms)11372026/07/19 13:53:44 OK 1_commit_pending_closure.sql (5.53ms)11382026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (2.94ms)11392026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures11402026/07/19 13:53:44 OK 1_commit_pending_closure.sql (5.45ms)11412026/07/19 13:53:44 OK 2_object_stats_trigger.sql (5.08ms)11422026/07/19 13:53:44 goose: up to current file version: 211432026/07/19 13:53:44 OK 2_object_stats_trigger.sql (5.22ms)11442026/07/19 13:53:44 goose: up to current file version: 211452026/07/19 13:53:44 OK 2_object_stats_trigger.sql (4.71ms)11462026/07/19 13:53:44 goose: up to current file version: 211472026/07/19 13:53:44 OK 20251218171726_add_pins.sql (6.92ms)11482026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures1149--- PASS: TestService_healthCheckHandler (0.23s)1150=== CONT TestService_AuthMiddleware_MTLSProxyHeader11512026/07/19 13:53:44 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11522026/07/19 13:53:44 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1153--- PASS: TestService_NativeMTLS (0.23s)11542026/07/19 13:53:44 OK 20241026095416_initial_model.sql (13.04ms)1155=== CONT TestIsValidUploadKey/narinfo11562026/07/19 13:53:44 OK 20241026095416_initial_model.sql (13.02ms)1157=== CONT TestIsValidUploadKey/realisation_plus_in_output1158=== CONT TestIsValidUploadKey/unknown_type1159=== CONT TestIsValidUploadKey/empty_key1160=== CONT TestIsValidUploadKey/absolute1161=== CONT TestIsValidUploadKey/traversal_nar1162=== CONT TestIsValidUploadKey/traversal1163=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1164=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1165=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1166=== CONT TestIsValidUploadKey/index.html1167=== CONT TestIsValidUploadKey/nix-cache-info1168=== CONT TestIsValidUploadKey/build_log_home-manager_file1169=== CONT TestIsValidUploadKey/realisation1170=== CONT TestIsValidUploadKey/build_log_equals1171=== CONT TestIsValidUploadKey/build_log_question_mark1172=== CONT TestIsValidUploadKey/build_log_plus_in_name1173=== CONT TestIsValidUploadKey/nar_plain1174=== CONT TestIsValidUploadKey/build_log1175=== CONT TestIsValidUploadKey/listing1176=== CONT TestIsValidUploadKey/nar_xz1177=== CONT TestIsValidUploadKey/nar_zst1178--- PASS: TestIsValidUploadKey (0.11s)1179 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1180 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1181 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1182 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1183 --- PASS: TestIsValidUploadKey/absolute (0.00s)1184 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1185 --- PASS: TestIsValidUploadKey/traversal (0.00s)1186 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1187 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1188 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1189 --- PASS: TestIsValidUploadKey/index.html (0.00s)1190 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1191 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1192 --- PASS: TestIsValidUploadKey/realisation (0.00s)1193 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1194 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1195 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1196 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1197 --- PASS: TestIsValidUploadKey/build_log (0.00s)1198 --- PASS: TestIsValidUploadKey/listing (0.00s)1199 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1200 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1201=== CONT TestProxyWriteTimeout/narinfo1202=== CONT TestProxyWriteTimeout/10_GiB_nar1203=== CONT TestProxyWriteTimeout/unknown_size1204=== CONT TestProxyWriteTimeout/1_GiB_nar1205--- PASS: TestProxyWriteTimeout (0.11s)1206 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1207 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1208 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1209 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1210=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info12112026/07/19 13:53:44 INFO Received uploads request method=POST path=/1212=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key12132026/07/19 13:53:44 INFO Received request for more parts method=POST path=/1214=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key12152026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (5.29ms)12162026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000012172026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (2.46ms)12182026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)12192026/07/19 13:53:44 INFO Received complete multipart upload request method=POST path=/1220=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal12212026/07/19 13:53:44 INFO Received uploads request method=POST path=/1222--- PASS: TestUploadHandlersRejectInvalidKeys (0.11s)1223 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1224 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1225 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1226 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1227=== CONT TestServerTLSConfig/no_client_CA1228=== CONT TestServerTLSConfig/missing_CA_file1229=== CONT TestServerTLSConfig/not_a_PEM_file1230--- PASS: TestServerTLSConfig (0.11s)1231 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1232 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1233 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1234=== CONT TestIsValidCachePath/narinfo1235=== CONT TestIsValidCachePath/index.html1236=== CONT TestIsValidCachePath/short_hash1237=== CONT TestIsValidCachePath/wrong_extension1238=== CONT TestIsValidCachePath/leading_slash1239=== CONT TestIsValidCachePath/empty1240=== CONT TestIsValidCachePath/random_path1241=== CONT TestIsValidCachePath/invalid_char_u1242=== CONT TestIsValidCachePath/invalid_char_e1243=== CONT TestIsValidCachePath/traversal_parent1244=== CONT TestIsValidCachePath/nar_uncompressed1245=== CONT TestIsValidCachePath/nix-cache-info1246=== CONT TestIsValidCachePath/realisation1247=== CONT TestIsValidCachePath/log1248=== CONT TestIsValidCachePath/ls1249=== CONT TestIsValidCachePath/nar_xz1250=== CONT TestIsValidCachePath/nar_bz21251=== CONT TestIsValidCachePath/nar_zst1252=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1253=== CONT TestIsValidCachePath/traversal_in_middle1254--- PASS: TestIsValidCachePath (0.00s)1255 --- PASS: TestIsValidCachePath/narinfo (0.00s)1256 --- PASS: TestIsValidCachePath/index.html (0.00s)1257 --- PASS: TestIsValidCachePath/short_hash (0.00s)1258 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1259 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1260 --- PASS: TestIsValidCachePath/empty (0.00s)1261 --- PASS: TestIsValidCachePath/random_path (0.00s)1262 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1263 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1264 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1265 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1266 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1267 --- PASS: TestIsValidCachePath/realisation (0.00s)1268 --- PASS: TestIsValidCachePath/log (0.00s)1269 --- PASS: TestIsValidCachePath/ls (0.00s)1270 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1271 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1272 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1273 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1274 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1275=== CONT TestParseSingleRange/none1276=== CONT TestParseSingleRange/open-ended1277=== CONT TestParseSingleRange/start_far_past_EOF1278=== CONT TestParseSingleRange/start_past_EOF1279=== CONT TestParseSingleRange/single_byte1280=== CONT TestParseSingleRange/suffix_exceeds_size1281=== CONT TestParseSingleRange/suffix1282=== CONT TestParseSingleRange/end_clamped_to_size1283=== CONT TestParseSingleRange/multi-range_ignored1284=== CONT TestParseSingleRange/malformed_no_dash1285=== CONT TestParseSingleRange/closed1286=== CONT TestParseSingleRange/unknown_unit1287=== CONT TestParseSingleRange/malformed_end_before_start1288=== CONT TestParseSingleRange/malformed_both_empty1289--- PASS: TestParseSingleRange (0.00s)1290 --- PASS: TestParseSingleRange/none (0.00s)1291 --- PASS: TestParseSingleRange/open-ended (0.00s)1292 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1293 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1294 --- PASS: TestParseSingleRange/single_byte (0.00s)1295 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1296 --- PASS: TestParseSingleRange/suffix (0.00s)1297 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1298 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1299 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1300 --- PASS: TestParseSingleRange/closed (0.00s)1301 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1302 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1303 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1304=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure13052026-07-19 13:53:44.748 UTC [1065] ERROR: relation "goose_db_version" does not exist at character 3613062026-07-19 13:53:44.748 UTC [1065] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13072026/07/19 13:53:44 INFO Received uploads request method=POST path=/13082026/07/19 13:53:44 OK 1_commit_pending_closure.sql (4.79ms)13092026/07/19 13:53:44 OK 20251218171726_add_pins.sql (6.56ms)13102026/07/19 13:53:44 OK 20251218171726_add_pins.sql (6.6ms)13112026/07/19 13:53:44 OK 2_object_stats_trigger.sql (3.3ms)13122026/07/19 13:53:44 goose: up to current file version: 21313--- PASS: TestMetricsInventory (0.24s)1314=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts13152026/07/19 13:53:44 INFO Received request for more parts method=POST path=/13162026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (5.61ms)13172026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000013182026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (6.89ms)13192026/07/19 13:53:44 goose: successfully migrated database to version: 202606281200001320--- PASS: TestObjectStatsTrigger (0.30s)1321=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart13222026/07/19 13:53:44 INFO Received complete multipart upload request method=POST path=/13232026/07/19 13:53:44 INFO Created nix-cache-info in bucket bucket=bucket3213242026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.66ms)13252026/07/19 13:53:44 OK 1_commit_pending_closure.sql (19.41ms)13262026/07/19 13:53:44 OK 2_object_stats_trigger.sql (21.05ms)13272026/07/19 13:53:44 goose: up to current file version: 213282026/07/19 13:53:44 OK 20241026095416_initial_model.sql (25.23ms)13292026/07/19 13:53:44 OK 2_object_stats_trigger.sql (4.92ms)13302026/07/19 13:53:44 goose: up to current file version: 213312026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (2.84ms)13322026/07/19 13:53:44 OK 20251218171726_add_pins.sql (3.37ms)13332026-07-19 13:53:44.793 UTC [1070] ERROR: relation "goose_db_version" does not exist at character 3613342026-07-19 13:53:44.793 UTC [1070] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13352026-07-19 13:53:44.793 UTC [1073] ERROR: relation "goose_db_version" does not exist at character 3613362026-07-19 13:53:44.793 UTC [1073] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13372026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (4.49ms)13382026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000013392026-07-19 13:53:44.794 UTC [1072] ERROR: relation "goose_db_version" does not exist at character 3613402026-07-19 13:53:44.794 UTC [1072] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13412026-07-19 13:53:44.794 UTC [1071] ERROR: relation "goose_db_version" does not exist at character 3613422026-07-19 13:53:44.794 UTC [1071] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13432026-07-19 13:53:44.794 UTC [1080] ERROR: relation "goose_db_version" does not exist at character 3613442026-07-19 13:53:44.794 UTC [1080] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13452026-07-19 13:53:44.794 UTC [1074] ERROR: relation "goose_db_version" does not exist at character 3613462026-07-19 13:53:44.794 UTC [1074] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13472026/07/19 13:53:44 INFO Aborted multipart uploads count=013482026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.08ms)13492026-07-19 13:53:44.798 UTC [1092] ERROR: relation "goose_db_version" does not exist at character 3613502026-07-19 13:53:44.798 UTC [1092] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13512026/07/19 13:53:44 WARN Force mode enabled - objects will be deleted immediately without grace period13522026/07/19 13:53:44 OK 2_object_stats_trigger.sql (1.9ms)13532026/07/19 13:53:44 goose: up to current file version: 213542026/07/19 13:53:44 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=013552026/07/19 13:53:44 INFO Vacuumed table table=pending_closures13562026/07/19 13:53:44 INFO Vacuumed table table=pending_objects13572026/07/19 13:53:44 INFO Vacuumed table table=multipart_uploads13582026/07/19 13:53:44 INFO Vacuumed table table=closures13592026/07/19 13:53:44 INFO Vacuumed table table=objects1360=== CONT TestClientErrorHandling/InvalidStorePath1361=== NAME TestNARDeduplicationMetadataUploadBug13622026/07/19 13:53:44 INFO Created nix-cache-info in bucket bucket=bucket351363 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug843451434/001/store/0padsyici49g62klwi74l6fi9pgr569s-file1.txt1364=== CONT TestClientErrorHandling/ServerNotAvailable13652026-07-19 13:53:44.809 UTC [1093] ERROR: relation "goose_db_version" does not exist at character 3613662026-07-19 13:53:44.809 UTC [1093] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1367--- PASS: TestGCMetrics (0.25s)1368=== CONT TestClientErrorHandling/InvalidAuthToken13692026/07/19 13:53:44 OK 20241026095416_initial_model.sql (11.22ms)13702026/07/19 13:53:44 OK 20241026095416_initial_model.sql (11.91ms)13712026/07/19 13:53:44 OK 20241026095416_initial_model.sql (12.59ms)13722026/07/19 13:53:44 OK 20241026095416_initial_model.sql (12.3ms)13732026/07/19 13:53:44 OK 20241026095416_initial_model.sql (12.37ms)13742026/07/19 13:53:44 OK 20241026095416_initial_model.sql (12.41ms)13752026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)13762026/07/19 13:53:44 OK 20241026095416_initial_model.sql (10.2ms)13772026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)13782026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (1.43ms)13792026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)13802026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (1.58ms)13812026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)13822026/07/19 13:53:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13832026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (3.32ms)13842026/07/19 13:53:44 OK 20251218171726_add_pins.sql (5.29ms)13852026/07/19 13:53:44 OK 20251218171726_add_pins.sql (3.77ms)13862026/07/19 13:53:44 OK 20251218171726_add_pins.sql (3.87ms)13872026/07/19 13:53:44 OK 20251218171726_add_pins.sql (4.06ms)13882026/07/19 13:53:44 OK 20251218171726_add_pins.sql (3.96ms)13892026/07/19 13:53:44 OK 20251218171726_add_pins.sql (3.84ms)13902026/07/19 13:53:44 OK 20251218171726_add_pins.sql (2.98ms)13912026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (3.85ms)13922026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (4.13ms)13932026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000013942026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000013952026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (4.03ms)13962026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000013972026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)13982026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000013992026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (4.23ms)14002026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000014012026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (3.66ms)14022026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000014032026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)14042026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000014052026/07/19 13:53:44 OK 20241026095416_initial_model.sql (9.31ms)14062026/07/19 13:53:44 OK 1_commit_pending_closure.sql (2.61ms)14072026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.21ms)14082026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.61ms)14092026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.74ms)14102026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.35ms)14112026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (3.06ms)14122026/07/19 13:53:44 OK 1_commit_pending_closure.sql (2.87ms)14132026/07/19 13:53:44 OK 1_commit_pending_closure.sql (3.04ms)14142026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.03ms)14152026/07/19 13:53:44 goose: up to current file version: 214162026/07/19 13:53:44 OK 2_object_stats_trigger.sql (1.85ms)14172026/07/19 13:53:44 goose: up to current file version: 214182026/07/19 13:53:44 OK 2_object_stats_trigger.sql (1.91ms)14192026/07/19 13:53:44 goose: up to current file version: 214202026/07/19 13:53:44 OK 2_object_stats_trigger.sql (1.69ms)14212026/07/19 13:53:44 goose: up to current file version: 214222026/07/19 13:53:44 OK 2_object_stats_trigger.sql (1.97ms)14232026/07/19 13:53:44 goose: up to current file version: 214242026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.03ms)14252026/07/19 13:53:44 goose: up to current file version: 214262026/07/19 13:53:44 OK 20251218171726_add_pins.sql (2.63ms)14272026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.03ms)14282026/07/19 13:53:44 goose: up to current file version: 21429=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1430=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1431=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1432=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1433=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1434=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1435=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1436=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1437=== CONT TestCacheConfigHandler/full_config,_no_issuer1438=== CONT TestCacheConfigHandler/no_signing_keys1439=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1440=== CONT TestCacheConfigHandler/no_cache_url_configured14412026/07/19 13:53:44 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"1442--- PASS: TestCacheConfigHandler (0.00s)1443 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1444 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1445 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1446 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)14472026/07/19 13:53:44 WARN mTLS auth: bound subjects configured but subject DN unavailable1448=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token14492026/07/19 13:53:44 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1450--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.21s)1451=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected14522026/07/19 13:53:44 INFO Created nix-cache-info in bucket bucket=bucket3614532026/07/19 13:53:44 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]1454=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected14552026/07/19 13:53:44 INFO Created nix-cache-info in bucket bucket=bucket3714562026/07/19 13:53:44 INFO Created nix-cache-info in bucket bucket=bucket3914572026/07/19 13:53:44 INFO Created nix-cache-info in bucket bucket=bucket4214582026/07/19 13:53:44 INFO OIDC auth successful provider=test14592026/07/19 13:53:44 WARN Authentication failed token_preview=eyJhbGciOi...IXSuNZt3Zw token_length=702 oidc_error="bound claims validation failed: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1460=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1461--- PASS: TestService_AuthMiddleware_OIDC (0.22s)1462 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1463 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1464 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1465 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)14662026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (6.84ms)14672026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000014682026/07/19 13:53:44 OK 1_commit_pending_closure.sql (2.39ms)14692026/07/19 13:53:44 OK 2_object_stats_trigger.sql (1.98ms)14702026/07/19 13:53:44 goose: up to current file version: 21471--- PASS: TestCacheStatsHandler (0.22s)14722026/07/19 13:53:44 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YjIwNDFmMDUtZDhlYS00M2Y0LTkyNTAtZWIyMjExZjE5N2E2Ljk0NTE2ZmNlLTgzY2UtNDQ2My04MDFjLTk2ZjU4NmVkODUyMXgxNzg0NDY5MjI0NTA0OTkxNzg2 parts=1014732026/07/19 13:53:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14742026/07/19 13:53:44 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1475--- PASS: TestService_ReadAuthMiddleware (0.16s)14762026/07/19 13:53:44 INFO Completed upload id=114772026/07/19 13:53:44 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014782026-07-19 13:53:44.851 UTC [1159] ERROR: relation "goose_db_version" does not exist at character 3614792026-07-19 13:53:44.851 UTC [1159] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14802026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures14812026/07/19 13:53:44 INFO Starting cleanup of old closures method=DELETE path=/api/closures14822026/07/19 13:53:44 INFO Received cleanup request method=DELETE path=/api/pending_closures14832026/07/19 13:53:44 INFO Aborted multipart uploads count=114842026/07/19 13:53:44 INFO Aborted multipart uploads count=014852026/07/19 13:53:44 OK 20241026095416_initial_model.sql (9.11ms)1486--- PASS: TestMultipartCleanup (0.37s)14872026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)14882026/07/19 13:53:44 OK 20251218171726_add_pins.sql (2.59ms)1489=== NAME TestClientMultipleUploads1490 client_integration_test.go:338: Created store path 0: /build/TestClientMultipleUploads781983143/001/store/30jzv5jvjjj0fsp1hsndy6bcl9m30j8n-test-file-0.txt14912026/07/19 13:53:44 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=014922026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (3ms)14932026/07/19 13:53:44 goose: successfully migrated database to version: 202606281200001494=== NAME TestClientIntegration1495 client_integration_test.go:276: Created store path: /build/TestClientIntegration3912713474/002/store/rjwbvsjqs9rcc1661y2smw64d5i34cvs-test-file.txt14962026/07/19 13:53:44 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14972026/07/19 13:53:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14982026/07/19 13:53:44 OK 1_commit_pending_closure.sql (26.11ms)14992026/07/19 13:53:44 INFO Vacuumed table table=pending_closures15002026/07/19 13:53:44 OK 2_object_stats_trigger.sql (2.24ms)15012026/07/19 13:53:44 goose: up to current file version: 21502=== NAME TestPinProtectsFromGC1503 client_integration_test.go:646: Pinned store path: /build/TestPinProtectsFromGC1928702268/001/store/r28z3xmpcnkz1whcb6ha100h37w6wq52-pinned-file.txt1504 client_integration_test.go:647: Unpinned store path: /build/TestPinProtectsFromGC1928702268/001/store/hmzif7cpwchifa2arqibjq95piqg8yn8-unpinned-file.txt15052026/07/19 13:53:44 INFO Vacuumed table table=pending_objects1506--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.17s)15072026-07-19 13:53:44.911 UTC [1352] ERROR: relation "goose_db_version" does not exist at character 3615082026-07-19 13:53:44.911 UTC [1352] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1509=== NAME TestClientMultipleUploads15102026/07/19 13:53:44 INFO Vacuumed table table=multipart_uploads1511 client_integration_test.go:338: Created store path 1: /build/TestClientMultipleUploads781983143/001/store/cicjrln9bgmcnwm8y6w5kxqxyj4rhb5q-test-file-1.txt15122026-07-19 13:53:44.913 UTC [1361] ERROR: relation "goose_db_version" does not exist at character 3615132026-07-19 13:53:44.913 UTC [1361] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15142026/07/19 13:53:44 INFO Vacuumed table table=closures15152026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures15162026/07/19 13:53:44 INFO Vacuumed table table=objects15172026/07/19 13:53:44 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-config1518=== NAME TestClientCADerivations15192026/07/19 13:53:44 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YjIwNDFmMDUtZDhlYS00M2Y0LTkyNTAtZWIyMjExZjE5N2E2LjVhYjJlNjMzLTY4ZjAtNDI3Yy1iM2JiLTA2YjUzNjgzZjlkNXgxNzg0NDY5MjI0NTYyNjY5MTU2 parts=121520 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3133163643/001/store/hiiyppf72j087s5ysazspmxgbijv7gin-ca-test15212026/07/19 13:53:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15222026/07/19 13:53:44 INFO Uploading 0padsyici49g62klwi74l6fi9pgr569s-file1.txt (160B)15232026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures15242026/07/19 13:53:44 OK 20241026095416_initial_model.sql (9.27ms)15252026/07/19 13:53:44 OK 20241026095416_initial_model.sql (8.27ms)15262026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (1.14ms)15272026/07/19 13:53:44 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)1528=== NAME TestClientWithDependencies1529 client_integration_test.go:593: Built derivation: /build/TestClientWithDependencies4781385/001/store/n5qk8xk8crfa3gx34cpklj64d6mx8x3j-test-script15302026/07/19 13:53:44 OK 20251218171726_add_pins.sql (2.5ms)15312026/07/19 13:53:44 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15322026/07/19 13:53:44 OK 20251218171726_add_pins.sql (2.51ms)1533--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.74s)15342026/07/19 13:53:44 WARN Failed to register uploaded object key=0padsyici49g62klwi74l6fi9pgr569s.ls error="server returned 404: 404 page not found\n"15352026/07/19 13:53:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15362026/07/19 13:53:44 INFO Signed narinfos id=1 count=115372026/07/19 13:53:44 INFO Uploading 1 narinfos1538=== NAME TestOrphanedObjectsGC1539 orphaned_objects_gc_test.go:290: GC Test Summary:1540 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1541 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1542 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1543 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1544 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1545--- PASS: TestOrphanedObjectsGC (0.55s)15462026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (5.89ms)15472026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000015482026/07/19 13:53:44 OK 20260628120000_add_object_size_and_stats.sql (5.74ms)15492026/07/19 13:53:44 goose: successfully migrated database to version: 2026062812000015502026/07/19 13:53:44 OK 1_commit_pending_closure.sql (1.65ms)15512026/07/19 13:53:44 OK 1_commit_pending_closure.sql (1.59ms)15522026/07/19 13:53:44 OK 2_object_stats_trigger.sql (580.87µs)15532026/07/19 13:53:44 goose: up to current file version: 215542026/07/19 13:53:44 OK 2_object_stats_trigger.sql (755.31µs)15552026/07/19 13:53:44 goose: up to current file version: 215562026/07/19 13:53:44 WARN Failed to register uploaded object key=0padsyici49g62klwi74l6fi9pgr569s.narinfo error="server returned 404: 404 page not found\n"15572026/07/19 13:53:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15582026/07/19 13:53:44 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1559=== NAME TestClientMultipleUploads1560 client_integration_test.go:338: Created store path 2: /build/TestClientMultipleUploads781983143/001/store/g0dyij9awdmz6nrs34a0l705a9bwkchw-test-file-2.txt15612026/07/19 13:53:44 INFO Completed upload id=115622026/07/19 13:53:44 INFO Upload complete. (104ms)1563=== NAME TestNARDeduplicationMetadataUploadBug1564 metadata_upload_test.go:54: Retrieved narinfo from S3:1565 StorePath: /build/TestNARDeduplicationMetadataUploadBug843451434/001/store/0padsyici49g62klwi74l6fi9pgr569s-file1.txt1566 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1567 Compression: zstd1568 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1569 NarSize: 1601570 References: 1571 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1572 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1573 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1574 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}15752026/07/19 13:53:44 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001576--- PASS: TestService_createPendingClosureHandler (0.77s)1577=== NAME TestClientCADerivations1578 client_ca_test.go:139: Found 1 dependencies (including self)1579=== NAME TestClientWithDependencies1580 client_integration_test.go:595: Found 1 dependencies (including self)15812026/07/19 13:53:44 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15822026/07/19 13:53:44 INFO Received uploads request method=POST path=/api/pending_closures15832026/07/19 13:53:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15842026/07/19 13:53:44 INFO Uploading rjwbvsjqs9rcc1661y2smw64d5i34cvs-test-file.txt (152B)15852026/07/19 13:53:44 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15862026/07/19 13:53:44 WARN Failed to register uploaded object key=rjwbvsjqs9rcc1661y2smw64d5i34cvs.ls error="server returned 404: 404 page not found\n"15872026/07/19 13:53:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15882026/07/19 13:53:44 INFO Signed narinfos id=1 count=115892026/07/19 13:53:44 INFO Uploading 1 narinfos15902026/07/19 13:53:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15912026/07/19 13:53:44 WARN Failed to register uploaded object key=rjwbvsjqs9rcc1661y2smw64d5i34cvs.narinfo error="server returned 404: 404 page not found\n"1592=== NAME TestNARDeduplicationMetadataUploadBug1593 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug843451434/001/store/5w3yfg13cr5nw21jlp668a1ipwzyll0c-file2.txt15942026/07/19 13:53:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15952026/07/19 13:53:44 INFO Completed upload id=115962026/07/19 13:53:44 INFO Upload complete. (89ms)1597=== NAME TestClientIntegration1598 client_integration_test.go:292: Retrieved narinfo from S3:1599 StorePath: /build/TestClientIntegration3912713474/002/store/rjwbvsjqs9rcc1661y2smw64d5i34cvs-test-file.txt1600 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1601 Compression: zstd1602 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11603 NarSize: 1521604 References: 1605 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11606 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1607 client_integration_test.go:293: Decompressed .ls content (64 bytes):1608 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1609 client_integration_test.go:296: Testing garbage collection...16102026/07/19 13:53:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YjIwNDFmMDUtZDhlYS00M2Y0LTkyNTAtZWIyMjExZjE5N2E2LmVkODMwZjMwLTkwNmUtNDUyYi04YzlkLTY5ZTkyYTNhMjQzNHgxNzg0NDY5MjI0NjMxMDE4Njkx parts=121611--- PASS: TestGCBugBareHashReferences (0.45s)1612--- PASS: TestRedundantMultipartUpload (0.72s)16132026/07/19 13:53:45 INFO Received uploads request method=POST path=/api/pending_closures16142026/07/19 13:53:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.044164ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config16152026/07/19 13:53:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16162026/07/19 13:53:45 INFO Uploading r28z3xmpcnkz1whcb6ha100h37w6wq52-pinned-file.txt (128B)16172026/07/19 13:53:45 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16182026/07/19 13:53:45 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16192026/07/19 13:53:45 WARN Failed to register uploaded object key=r28z3xmpcnkz1whcb6ha100h37w6wq52.ls error="server returned 404: 404 page not found\n"16202026/07/19 13:53:45 INFO Received uploads request method=POST path=/api/pending_closures16212026/07/19 13:53:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16222026/07/19 13:53:45 INFO Signed narinfos id=1 count=116232026/07/19 13:53:45 INFO Uploading 1 narinfos16242026/07/19 13:53:45 WARN Failed to register uploaded object key=r28z3xmpcnkz1whcb6ha100h37w6wq52.narinfo error="server returned 404: 404 page not found\n"16252026/07/19 13:53:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16262026/07/19 13:53:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16272026/07/19 13:53:45 INFO Uploading n5qk8xk8crfa3gx34cpklj64d6mx8x3j-test-script (136B)16282026/07/19 13:53:45 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16292026/07/19 13:53:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures16302026/07/19 13:53:45 INFO Garbage collection started16312026/07/19 13:53:45 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16322026/07/19 13:53:45 WARN Failed to register uploaded object key=log/nq2p11pki00zaxdh976i8ranv9fmas21-test-script.drv error="server returned 404: 404 page not found\n"16332026/07/19 13:53:45 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16342026/07/19 13:53:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16352026/07/19 13:53:45 WARN Failed to register uploaded object key=n5qk8xk8crfa3gx34cpklj64d6mx8x3j.ls error="server returned 404: 404 page not found\n"16362026/07/19 13:53:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16372026/07/19 13:53:45 INFO Completed upload id=116382026/07/19 13:53:45 INFO Signed narinfos id=1 count=116392026/07/19 13:53:45 INFO Upload complete. (94ms)16402026/07/19 13:53:45 INFO Uploading 1 narinfos16412026/07/19 13:53:45 WARN Failed to register uploaded object key=n5qk8xk8crfa3gx34cpklj64d6mx8x3j.narinfo error="server returned 404: 404 page not found\n"16422026/07/19 13:53:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16432026/07/19 13:53:45 INFO Aborted multipart uploads count=016442026/07/19 13:53:45 WARN Force mode enabled - objects will be deleted immediately without grace period16452026/07/19 13:53:45 INFO Completed upload id=116462026/07/19 13:53:45 INFO Upload complete. (52ms)16472026/07/19 13:53:45 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1648=== NAME TestClientWithDependencies1649 client_integration_test.go:597: Skipping nix copy test - isolated store (/build/TestClientWithDependencies4781385/001/store) requires matching store prefix16502026/07/19 13:53:45 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YjIwNDFmMDUtZDhlYS00M2Y0LTkyNTAtZWIyMjExZjE5N2E2LmMyMWZhM2IxLWE0ODItNGQ2My05ZTBmLWM1NDc4NjliN2YyZXgxNzg0NDY5MjI0NzQwOTU4NDE1 parts=1016512026/07/19 13:53:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16522026/07/19 13:53:45 INFO Completed upload id=11653--- PASS: TestClientWithDependencies (0.44s)16542026/07/19 13:53:45 INFO Received uploads request method=POST path=/api/pending_closures16552026/07/19 13:53:45 INFO Received uploads request method=POST path=/api/pending_closures16562026/07/19 13:53:45 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16572026/07/19 13:53:45 WARN Found objects in DB but missing from S3, will re-upload count=11658--- PASS: TestService_verifyS3Integrity (0.56s)16592026/07/19 13:53:45 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16602026/07/19 13:53:45 INFO Received uploads request method=POST path=/api/pending_closures16612026/07/19 13:53:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16622026/07/19 13:53:45 INFO Uploading hiiyppf72j087s5ysazspmxgbijv7gin-ca-test (144B)16632026/07/19 13:53:45 INFO Received uploads request method=POST path=/api/pending_closures16642026/07/19 13:53:45 WARN Failed to register uploaded object key=log/zmaz0m32hccz6viybp25710lh8mfxbwf-ca-test.drv error="server returned 404: 404 page not found\n"16652026/07/19 13:53:45 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16662026/07/19 13:53:45 INFO Received uploads request method=POST path=/api/pending_closures16672026/07/19 13:53:45 WARN Failed to register uploaded object key=hiiyppf72j087s5ysazspmxgbijv7gin.ls error="server returned 404: 404 page not found\n"16682026/07/19 13:53:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16692026/07/19 13:53:45 INFO Received uploads request method=POST path=/api/pending_closures16702026/07/19 13:53:45 INFO Signed narinfos id=1 count=116712026/07/19 13:53:45 INFO Uploading 1 narinfos16722026/07/19 13:53:45 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16732026/07/19 13:53:45 INFO Uploading g0dyij9awdmz6nrs34a0l705a9bwkchw-test-file-2.txt (160B)16742026/07/19 13:53:45 INFO Uploading cicjrln9bgmcnwm8y6w5kxqxyj4rhb5q-test-file-1.txt (160B)16752026/07/19 13:53:45 INFO Uploading 30jzv5jvjjj0fsp1hsndy6bcl9m30j8n-test-file-0.txt (160B)16762026/07/19 13:53:45 WARN Failed to register uploaded object key=hiiyppf72j087s5ysazspmxgbijv7gin.narinfo error="server returned 404: 404 page not found\n"16772026/07/19 13:53:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16782026/07/19 13:53:45 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16792026/07/19 13:53:45 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16802026/07/19 13:53:45 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"16812026/07/19 13:53:45 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16822026/07/19 13:53:45 INFO Completed upload id=116832026/07/19 13:53:45 INFO Upload complete. (96ms)16842026/07/19 13:53:45 WARN Failed to register uploaded object key=30jzv5jvjjj0fsp1hsndy6bcl9m30j8n.ls error="server returned 404: 404 page not found\n"16852026/07/19 13:53:45 WARN Failed to register uploaded object key=g0dyij9awdmz6nrs34a0l705a9bwkchw.ls error="server returned 404: 404 page not found\n"16862026/07/19 13:53:45 WARN Failed to register uploaded object key=cicjrln9bgmcnwm8y6w5kxqxyj4rhb5q.ls error="server returned 404: 404 page not found\n"16872026/07/19 13:53:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16882026/07/19 13:53:45 INFO Signed narinfos id=1 count=116892026/07/19 13:53:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign1690=== NAME TestClientCADerivations1691 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3133163643/001/store/hiiyppf72j087s5ysazspmxgbijv7gin-ca-test1692 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1693 Compression: zstd1694 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n16952026/07/19 13:53:45 INFO Signed narinfos id=2 count=11696 NarSize: 1441697 References: 1698 Deriver: /build/TestClientCADerivations3133163643/001/store/zmaz0m32hccz6viybp25710lh8mfxbwf-ca-test.drv1699 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1700 client_ca_test.go:185: Checking for realisation files in S3...17012026/07/19 13:53:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign17022026/07/19 13:53:45 INFO Signed narinfos id=3 count=117032026/07/19 13:53:45 INFO Uploading 3 narinfos1704 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1705 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17062026/07/19 13:53:45 WARN Failed to register uploaded object key=cicjrln9bgmcnwm8y6w5kxqxyj4rhb5q.narinfo error="server returned 404: 404 page not found\n"17072026/07/19 13:53:45 INFO Received uploads request method=POST path=/api/pending_closures17082026/07/19 13:53:45 WARN Failed to register uploaded object key=g0dyij9awdmz6nrs34a0l705a9bwkchw.narinfo error="server returned 404: 404 page not found\n"17092026/07/19 13:53:45 WARN Failed to register uploaded object key=30jzv5jvjjj0fsp1hsndy6bcl9m30j8n.narinfo error="server returned 404: 404 page not found\n"17102026/07/19 13:53:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17112026/07/19 13:53:45 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17122026/07/19 13:53:45 WARN Failed to register uploaded object key=5w3yfg13cr5nw21jlp668a1ipwzyll0c.ls error="server returned 404: 404 page not found\n"17132026/07/19 13:53:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17142026/07/19 13:53:45 INFO Completed upload id=117152026/07/19 13:53:45 INFO Signed narinfos id=2 count=117162026/07/19 13:53:45 INFO Uploading 1 narinfos17172026/07/19 13:53:45 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17182026/07/19 13:53:45 INFO Completed upload id=217192026/07/19 13:53:45 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete17202026/07/19 13:53:45 INFO Completed upload id=317212026/07/19 13:53:45 INFO Upload complete. (116ms)1722=== NAME TestClientMultipleUploads1723 client_integration_test.go:349: Uploaded 3 paths in 153.549791ms17242026/07/19 13:53:45 WARN Failed to register uploaded object key=5w3yfg13cr5nw21jlp668a1ipwzyll0c.narinfo error="server returned 404: 404 page not found\n"17252026/07/19 13:53:45 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17262026/07/19 13:53:45 INFO Completed upload id=217272026/07/19 13:53:45 INFO Upload complete. (74ms)1728=== NAME TestNARDeduplicationMetadataUploadBug1729 metadata_upload_test.go:76: Retrieved narinfo from S3:1730 StorePath: /build/TestNARDeduplicationMetadataUploadBug843451434/001/store/5w3yfg13cr5nw21jlp668a1ipwzyll0c-file2.txt1731 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1732 Compression: zstd1733 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1734 NarSize: 1601735 References: 1736 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1737 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1738 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1739 {"version":1,"root":{"type":"regular","size":44}}17402026/07/19 13:53:45 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1741--- PASS: TestClientMultipleUploads (0.49s)1742--- PASS: TestNARDeduplicationMetadataUploadBug (0.57s)17432026/07/19 13:53:45 INFO Received uploads request method=POST path=/api/pending_closures17442026/07/19 13:53:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17452026/07/19 13:53:45 INFO Uploading hmzif7cpwchifa2arqibjq95piqg8yn8-unpinned-file.txt (128B)17462026/07/19 13:53:45 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17472026/07/19 13:53:45 WARN Failed to register uploaded object key=hmzif7cpwchifa2arqibjq95piqg8yn8.ls error="server returned 404: 404 page not found\n"17482026/07/19 13:53:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17492026/07/19 13:53:45 INFO Signed narinfos id=2 count=117502026/07/19 13:53:45 INFO Uploading 1 narinfos17512026/07/19 13:53:45 WARN Failed to register uploaded object key=hmzif7cpwchifa2arqibjq95piqg8yn8.narinfo error="server returned 404: 404 page not found\n"17522026/07/19 13:53:45 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17532026/07/19 13:53:45 INFO Completed upload id=217542026/07/19 13:53:45 INFO Upload complete. (80ms)17552026/07/19 13:53:45 INFO Received create pin request method=POST path=/api/pins/myapp17562026/07/19 13:53:45 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1928702268/001/store/r28z3xmpcnkz1whcb6ha100h37w6wq52-pinned-file.txt narinfo_key=r28z3xmpcnkz1whcb6ha100h37w6wq52.narinfo17572026/07/19 13:53:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures17582026/07/19 13:53:45 INFO Garbage collection started17592026/07/19 13:53:45 INFO Aborted multipart uploads count=017602026/07/19 13:53:45 WARN Force mode enabled - objects will be deleted immediately without grace period17612026/07/19 13:53:45 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=424.426912ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1762=== NAME TestClientCADerivations1763 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1764 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1765 error: binary cache 's3://bucket42?endpoint=http://localhost:45895®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3133163643/001/store'1766 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11767--- PASS: TestClientCADerivations (0.61s)1768--- PASS: TestUploadHandlersRejectOversizedBody (0.20s)1769 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)1770 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)1771 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.76s)1772=== NAME TestOrphanedObjectsGCStressTest1773 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1774 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion17752026/07/19 13:53:45 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=824.210263ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17762026/07/19 13:53:45 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=017772026/07/19 13:53:45 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=017782026/07/19 13:53:45 INFO Vacuumed table table=pending_closures17792026/07/19 13:53:45 INFO Vacuumed table table=pending_closures17802026/07/19 13:53:45 INFO Vacuumed table table=pending_objects17812026/07/19 13:53:45 INFO Vacuumed table table=multipart_uploads17822026/07/19 13:53:45 INFO Vacuumed table table=pending_objects17832026/07/19 13:53:45 INFO Vacuumed table table=multipart_uploads17842026/07/19 13:53:45 INFO Vacuumed table table=closures17852026/07/19 13:53:45 INFO Vacuumed table table=closures17862026/07/19 13:53:45 INFO Vacuumed table table=objects17872026/07/19 13:53:45 INFO Vacuumed table table=objects1788 orphaned_objects_gc_test.go:509: Stress test completed successfully:1789 orphaned_objects_gc_test.go:510: - Active objects preserved: 201790 orphaned_objects_gc_test.go:511: - Objects deleted: 2101791 orphaned_objects_gc_test.go:512: - Total GC'd: 2101792--- PASS: TestOrphanedObjectsGCStressTest (1.43s)17932026/07/19 13:53:46 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.681627789s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17942026/07/19 13:53:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01795=== NAME TestClientIntegration1796 client_integration_test.go:303: Objects in database after GC:1797 client_integration_test.go:303: Successfully deleted all objects with GC --force1798--- PASS: TestClientIntegration (2.43s)17992026/07/19 13:53:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01800=== NAME TestPinProtectsFromGC1801 client_integration_test.go:709: Pin successfully protected closure from garbage collection1802--- PASS: TestPinProtectsFromGC (2.61s)18032026/07/19 13:53:48 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"18042026/07/19 13:53:48 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_closures18052026/07/19 13:53:48 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.034961ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18062026/07/19 13:53:48 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=385.826234ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18072026/07/19 13:53:48 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=822.345551ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18082026/07/19 13:53:49 WARN Rate limiter enabled after throttle name=s3-test rate=518092026/07/19 13:53:49 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1810=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1811 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101812 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001813--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.02s)18142026/07/19 13:53:49 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.501166359s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1815--- PASS: TestClientErrorHandling (0.00s)1816 --- PASS: TestClientErrorHandling/InvalidStorePath (0.17s)1817 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.28s)1818 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.39s)1819PASS1820{"timestamp":"2026-07-19T13:53:51.695167722Z","level":"ERROR","fields":{"message":"Unknown connection IO error:Cancelled","peer_addr":"127.0.0.1:37192"},"target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":973,"threadName":"rustfs-worker","threadId":"ThreadId(763)"}18212026-07-19 13:53:51.853 UTC [112] LOG: received smart shutdown request18222026-07-19 13:53:51.857 UTC [112] LOG: background worker "logical replication launcher" (PID 122) exited with exit code 118232026-07-19 13:53:51.863 UTC [117] LOG: shutting down18242026-07-19 13:53:51.864 UTC [117] LOG: checkpoint starting: shutdown immediate18252026-07-19 13:53:53.350 UTC [117] LOG: checkpoint complete: wrote 10956 buffers (66.9%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 13 recycled; write=0.260 s, sync=1.213 s, total=1.486 s; sync files=15167, longest=0.002 s, average=0.001 s; distance=208460 kB, estimate=208460 kB; lsn=0/E2F2318, redo lsn=0/E2F231818262026-07-19 13:53:53.437 UTC [112] LOG: database system is shut down1827Running OIDC tests...1828=== RUN TestGlobMatch1829=== PAUSE TestGlobMatch1830=== RUN TestAudienceForIssuer1831=== PAUSE TestAudienceForIssuer1832=== RUN TestValidateToken_ValidToken1833=== PAUSE TestValidateToken_ValidToken1834=== RUN TestValidateToken_WrongAudience1835=== PAUSE TestValidateToken_WrongAudience1836=== RUN TestValidateToken_Expired1837=== PAUSE TestValidateToken_Expired1838=== RUN TestValidateToken_BoundClaimsMismatch1839=== PAUSE TestValidateToken_BoundClaimsMismatch1840=== RUN TestValidateToken_BoundSubjectMismatch1841=== PAUSE TestValidateToken_BoundSubjectMismatch1842=== RUN TestValidateToken_MultipleProviders1843=== PAUSE TestValidateToken_MultipleProviders1844=== RUN TestValidateToken_NoMatchingProvider1845=== PAUSE TestValidateToken_NoMatchingProvider1846=== CONT TestGlobMatch1847=== RUN TestGlobMatch/foo_foo1848=== PAUSE TestGlobMatch/foo_foo1849=== CONT TestValidateToken_BoundClaimsMismatch1850=== RUN TestGlobMatch/foo_bar1851=== PAUSE TestGlobMatch/foo_bar1852=== CONT TestValidateToken_WrongAudience1853=== CONT TestAudienceForIssuer1854--- PASS: TestAudienceForIssuer (0.00s)1855=== CONT TestValidateToken_MultipleProviders1856=== CONT TestValidateToken_Expired1857=== CONT TestValidateToken_NoMatchingProvider1858=== CONT TestValidateToken_BoundSubjectMismatch1859=== CONT TestValidateToken_ValidToken1860=== RUN TestGlobMatch/*_1861=== PAUSE TestGlobMatch/*_1862=== RUN TestGlobMatch/*_anything1863=== PAUSE TestGlobMatch/*_anything1864=== RUN TestGlobMatch/foo*_foo1865=== PAUSE TestGlobMatch/foo*_foo1866=== RUN TestGlobMatch/foo*_foobar1867=== PAUSE TestGlobMatch/foo*_foobar1868=== RUN TestGlobMatch/foo*_bar1869=== PAUSE TestGlobMatch/foo*_bar1870=== RUN TestGlobMatch/*bar_bar1871=== PAUSE TestGlobMatch/*bar_bar1872=== RUN TestGlobMatch/*bar_foobar1873=== PAUSE TestGlobMatch/*bar_foobar1874=== RUN TestGlobMatch/*bar_foo1875=== PAUSE TestGlobMatch/*bar_foo1876=== RUN TestGlobMatch/foo*bar_foobar1877=== PAUSE TestGlobMatch/foo*bar_foobar1878=== RUN TestGlobMatch/foo*bar_foo123bar1879=== PAUSE TestGlobMatch/foo*bar_foo123bar1880=== RUN TestGlobMatch/foo*bar_foobarbaz1881=== PAUSE TestGlobMatch/foo*bar_foobarbaz1882=== RUN TestGlobMatch/*/*_foo/bar1883=== PAUSE TestGlobMatch/*/*_foo/bar1884=== RUN TestGlobMatch/*/*_foo1885=== PAUSE TestGlobMatch/*/*_foo1886=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1887=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1888=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01889=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01890=== RUN TestGlobMatch/refs/*/main_refs/heads/main1891=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1892=== RUN TestGlobMatch/fo?_foo1893=== PAUSE TestGlobMatch/fo?_foo1894=== RUN TestGlobMatch/fo?_fo1895=== PAUSE TestGlobMatch/fo?_fo1896=== RUN TestGlobMatch/fo?_fooo1897=== PAUSE TestGlobMatch/fo?_fooo1898=== RUN TestGlobMatch/?oo_foo1899=== PAUSE TestGlobMatch/?oo_foo1900=== RUN TestGlobMatch/?oo_boo1901=== PAUSE TestGlobMatch/?oo_boo1902=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1903=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1904=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1905=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1906=== CONT TestGlobMatch/foo_foo1907=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1908=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1909=== CONT TestGlobMatch/?oo_boo1910=== CONT TestGlobMatch/foo*bar_foobar1911=== CONT TestGlobMatch/*/*_foo/bar1912=== CONT TestGlobMatch/*_1913=== CONT TestGlobMatch/foo*_bar1914=== CONT TestGlobMatch/foo_bar1915=== CONT TestGlobMatch/?oo_foo1916=== CONT TestGlobMatch/fo?_fooo1917=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1918=== CONT TestGlobMatch/*/*_foo1919=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01920=== CONT TestGlobMatch/fo?_fo1921=== CONT TestGlobMatch/fo?_foo1922=== CONT TestGlobMatch/refs/*/main_refs/heads/main1923=== CONT TestGlobMatch/foo*bar_foo123bar1924=== CONT TestGlobMatch/foo*bar_foobarbaz19252026/07/19 13:53:54 INFO OIDC provider initialized name=test1926=== CONT TestGlobMatch/foo*_foobar1927=== CONT TestGlobMatch/foo*_foo1928=== CONT TestGlobMatch/*bar_foobar1929=== CONT TestGlobMatch/*_anything19302026/07/19 13:53:54 INFO OIDC provider initialized name=test1931=== CONT TestGlobMatch/*bar_bar19322026/07/19 13:53:54 INFO OIDC provider initialized name=test1933=== CONT TestGlobMatch/*bar_foo1934--- PASS: TestGlobMatch (0.01s)1935 --- PASS: TestGlobMatch/foo_foo (0.00s)1936 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1937 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1938 --- PASS: TestGlobMatch/?oo_boo (0.00s)1939 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1940 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1941 --- PASS: TestGlobMatch/*_ (0.00s)1942 --- PASS: TestGlobMatch/foo*_bar (0.00s)1943 --- PASS: TestGlobMatch/foo_bar (0.00s)1944 --- PASS: TestGlobMatch/?oo_foo (0.00s)1945 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1946 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1947 --- PASS: TestGlobMatch/*/*_foo (0.00s)1948 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1949 --- PASS: TestGlobMatch/fo?_fo (0.00s)1950 --- PASS: TestGlobMatch/fo?_foo (0.00s)1951 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1952 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1953 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1954 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1955 --- PASS: TestGlobMatch/foo*_foo (0.00s)1956 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1957 --- PASS: TestGlobMatch/*_anything (0.00s)1958 --- PASS: TestGlobMatch/*bar_bar (0.00s)1959 --- PASS: TestGlobMatch/*bar_foo (0.00s)19602026/07/19 13:53:54 INFO OIDC provider initialized name=provider119612026/07/19 13:53:54 INFO OIDC provider initialized name=test19622026/07/19 13:53:54 INFO OIDC provider initialized name=provider119632026/07/19 13:53:54 INFO OIDC provider initialized name=test19642026/07/19 13:53:54 INFO OIDC provider initialized name=provider21965--- PASS: TestValidateToken_WrongAudience (0.01s)1966--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1967--- PASS: TestValidateToken_ValidToken (0.01s)1968--- PASS: TestValidateToken_Expired (0.01s)1969--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1970--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1971--- PASS: TestValidateToken_MultipleProviders (0.01s)1972PASS1973Running hook tests...1974=== RUN TestSendPathsEmpty1975=== PAUSE TestSendPathsEmpty1976=== RUN TestQueueEnqueueAndFetch1977=== PAUSE TestQueueEnqueueAndFetch1978=== RUN TestQueueDeduplication1979=== PAUSE TestQueueDeduplication1980=== RUN TestQueueRemove1981=== PAUSE TestQueueRemove1982=== RUN TestQueueFetchBatchLimit1983=== PAUSE TestQueueFetchBatchLimit1984=== RUN TestQueueFetchRemoveLifecycle1985=== PAUSE TestQueueFetchRemoveLifecycle1986=== RUN TestQueueConcurrentWriters1987=== PAUSE TestQueueConcurrentWriters1988=== RUN TestServerClientIntegration1989=== PAUSE TestServerClientIntegration1990=== RUN TestServerQueueError1991=== PAUSE TestServerQueueError1992=== RUN TestGetListenerSocketActivation1993 server_test.go:210: === RUN TestGetListenerSocketActivation1994 --- PASS: TestGetListenerSocketActivation (0.00s)1995 PASS1996 1997--- PASS: TestGetListenerSocketActivation (0.01s)1998=== RUN TestWorkerUploadsAndRemoves1999=== PAUSE TestWorkerUploadsAndRemoves2000=== RUN TestWorkerSkipsGCdPaths2001=== PAUSE TestWorkerSkipsGCdPaths2002=== RUN TestWorkerPrunesClosureDeps2003=== PAUSE TestWorkerPrunesClosureDeps2004=== CONT TestSendPathsEmpty2005=== CONT TestWorkerUploadsAndRemoves2006=== CONT TestServerQueueError2007--- PASS: TestSendPathsEmpty (0.00s)2008=== CONT TestWorkerPrunesClosureDeps2009=== CONT TestWorkerSkipsGCdPaths2010=== CONT TestQueueConcurrentWriters2011=== CONT TestQueueDeduplication20122026/07/19 13:53:54 ERROR Failed to queue paths error="permission denied" count=12013=== CONT TestQueueEnqueueAndFetch2014=== CONT TestQueueFetchRemoveLifecycle2015=== CONT TestServerClientIntegration2016=== CONT TestQueueFetchBatchLimit2017=== CONT TestQueueRemove2018--- PASS: TestServerQueueError (0.00s)2019--- PASS: TestServerClientIntegration (0.00s)2020--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2021--- PASS: TestQueueFetchBatchLimit (0.01s)2022--- PASS: TestQueueEnqueueAndFetch (0.01s)2023--- PASS: TestQueueRemove (0.01s)2024--- PASS: TestQueueDeduplication (0.01s)20252026/07/19 13:53:54 INFO Upload queue status pending=220262026/07/19 13:53:54 INFO Uploading batch count=220272026/07/19 13:53:54 INFO Upload queue status pending=220282026/07/19 13:53:54 INFO Upload queue status pending=220292026/07/19 13:53:54 INFO Uploading batch count=120302026/07/19 13:53:54 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths4039262804/002/nonexistent20312026/07/19 13:53:54 INFO Uploading batch count=12032--- PASS: TestWorkerUploadsAndRemoves (0.07s)2033--- PASS: TestWorkerPrunesClosureDeps (0.07s)2034--- PASS: TestWorkerSkipsGCdPaths (0.07s)2035--- PASS: TestQueueConcurrentWriters (0.24s)2036PASS