niks3-go-unit-tests log

succeeded `niks3-go-unit-tests` `aarch64-linux.go-unit-tests` · build #103 · raw

1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestCaseHackSuffix6=== PAUSE TestCaseHackSuffix7=== RUN TestPartSizeForNAR8=== PAUSE TestPartSizeForNAR9=== RUN TestUploadMultipart_SupersededByPeer10=== PAUSE TestUploadMultipart_SupersededByPeer11=== RUN TestDumpPathMatchesNix12=== PAUSE TestDumpPathMatchesNix13=== RUN TestDumpPathSingleFile14=== PAUSE TestDumpPathSingleFile15=== RUN TestDumpPathWriterError16=== PAUSE TestDumpPathWriterError17=== RUN TestEncodeNixBase3218=== PAUSE TestEncodeNixBase3219=== RUN TestEncodeNixBase32WithRealHash20=== PAUSE TestEncodeNixBase32WithRealHash21=== RUN TestConvertHashToNix3222=== PAUSE TestConvertHashToNix3223=== RUN TestGetStorePathHash24=== PAUSE TestGetStorePathHash25=== RUN TestPathInfoHashCompatibility26=== PAUSE TestPathInfoHashCompatibility27=== RUN TestParsePathInfoJSON28=== PAUSE TestParsePathInfoJSON29=== RUN TestParsePathInfoJSONMultiplePaths30=== PAUSE TestParsePathInfoJSONMultiplePaths31=== RUN TestPathInfoCACompatibility32=== PAUSE TestPathInfoCACompatibility33=== RUN TestRateLimiterFeedback34=== PAUSE TestRateLimiterFeedback35=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess36=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess37=== RUN TestResolveStorePath38=== PAUSE TestResolveStorePath39=== RUN TestDoWithRetry_BodyReplayedViaGetBody40=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody41=== RUN TestShellSplit42=== PAUSE TestShellSplit43=== RUN TestShellSplitErrors44=== PAUSE TestShellSplitErrors45=== RUN TestSetClientTLS46=== PAUSE TestSetClientTLS47=== RUN TestSetClientTLSDoesNotMutateDefaultTransport48=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport49=== RUN TestSetClientTLSErrors50=== PAUSE TestSetClientTLSErrors51=== RUN TestStaticToken52=== PAUSE TestStaticToken53=== RUN TestFileTokenReadsAndCaches54=== PAUSE TestFileTokenReadsAndCaches55=== RUN TestFileTokenMissing56=== PAUSE TestFileTokenMissing57=== RUN TestFileTokenEmpty58=== PAUSE TestFileTokenEmpty59=== RUN TestScriptTokenNoExpiryRerunsEveryCall60=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall61=== RUN TestScriptTokenCachesUntilRefresh62=== PAUSE TestScriptTokenCachesUntilRefresh63=== RUN TestScriptTokenEmptyToken64=== PAUSE TestScriptTokenEmptyToken65=== RUN TestScriptTokenBadJSON66=== PAUSE TestScriptTokenBadJSON67=== RUN TestScriptTokenScriptFails68=== PAUSE TestScriptTokenScriptFails69=== RUN TestScriptTokenEmptyCommand70=== PAUSE TestScriptTokenEmptyCommand71=== CONT TestDoServerRequestAttachesToken72=== CONT TestSetClientTLS73=== CONT TestFileTokenEmpty74=== CONT TestDumpPathWriterError75=== CONT TestStaticToken76=== CONT TestShellSplitErrors77=== CONT TestShellSplit78=== CONT TestDoWithRetry_BodyReplayedViaGetBody79=== CONT TestResolveStorePath80=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess81=== CONT TestRateLimiterFeedback82=== RUN TestRateLimiterFeedback/429_enables_limiter83=== PAUSE TestRateLimiterFeedback/429_enables_limiter84=== RUN TestRateLimiterFeedback/503_enables_limiter85=== PAUSE TestRateLimiterFeedback/503_enables_limiter86=== CONT TestPathInfoCACompatibility87=== CONT TestParsePathInfoJSONMultiplePaths88=== CONT TestParsePathInfoJSON89=== CONT TestScriptTokenNoExpiryRerunsEveryCall90=== CONT TestScriptTokenEmptyCommand91=== CONT TestScriptTokenScriptFails92=== CONT TestScriptTokenBadJSON93=== CONT TestScriptTokenEmptyToken94=== CONT TestScriptTokenCachesUntilRefresh95=== CONT TestConvertHashToNix3296=== CONT TestGetStorePathHash97=== CONT TestUploadMultipart_SupersededByPeer98=== CONT TestDumpPathSingleFile99=== CONT TestDumpPathMatchesNix100=== CONT TestEncodeNixBase32WithRealHash101=== CONT TestFileTokenReadsAndCaches102=== CONT TestSetClientTLSErrors103=== CONT TestSetClientTLSDoesNotMutateDefaultTransport104=== CONT TestFileTokenMissing105=== CONT TestPartSizeForNAR106=== CONT TestEncodeNixBase32107=== CONT TestCaseHackSuffix108=== CONT TestPathInfoHashCompatibility109--- PASS: TestShellSplitErrors (0.00s)110=== RUN TestPathInfoCACompatibility/null_ca_field111=== PAUSE TestPathInfoCACompatibility/null_ca_field112--- PASS: TestStaticToken (0.01s)113=== RUN TestGetStorePathHash/valid_store_path114=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths115=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter116=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter117=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter118=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter119=== RUN TestEncodeNixBase32/test_string_hash120=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths121=== PAUSE TestEncodeNixBase32/test_string_hash122=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1232026/07/19 09:49:03 WARN Rate limiter enabled after throttle name=server-test rate=5124--- PASS: TestShellSplit (0.01s)125--- PASS: TestFileTokenEmpty (0.01s)126--- PASS: TestScriptTokenEmptyCommand (0.00s)127--- PASS: TestEncodeNixBase32WithRealHash (0.00s)128--- PASS: TestResolveStorePath (0.00s)129=== RUN TestPathInfoCACompatibility/old_string_format_-_text130=== RUN TestEncodeNixBase32/empty_input131=== PAUSE TestGetStorePathHash/valid_store_path132=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)133=== RUN TestPartSizeForNAR/zero_stays_at_minimum134=== CONT TestRateLimiterFeedback/429_enables_limiter135=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter136=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter137=== CONT TestRateLimiterFeedback/503_enables_limiter138=== RUN TestParsePathInfoJSON/Nix_format139=== RUN TestUploadMultipart_SupersededByPeer/exists140=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths141=== RUN TestGetStorePathHash/basename_without_hyphen_should_error142=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text143=== PAUSE TestParsePathInfoJSON/Nix_format144=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths145=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)146=== RUN TestConvertHashToNix32/SRI_format_to_Nix32147=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error148=== PAUSE TestEncodeNixBase32/empty_input149=== PAUSE TestUploadMultipart_SupersededByPeer/exists150=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive151=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive152=== RUN TestPathInfoCACompatibility/new_structured_format_-_text153=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text154=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method155=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method156=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths157=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum158=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32159--- PASS: TestFileTokenMissing (0.01s)160=== CONT TestEncodeNixBase32/test_string_hash161=== CONT TestEncodeNixBase32/empty_input162=== RUN TestParsePathInfoJSON/Lix_format163=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error164=== RUN TestUploadMultipart_SupersededByPeer/missing165=== RUN TestSetClientTLSErrors/missing_cert_file166=== CONT TestPathInfoCACompatibility/null_ca_field167=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon168=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method169=== CONT TestPathInfoCACompatibility/new_structured_format_-_text170=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive171=== CONT TestPathInfoCACompatibility/old_string_format_-_text172--- PASS: TestScriptTokenScriptFails (0.01s)173=== PAUSE TestParsePathInfoJSON/Lix_format1742026/07/19 09:49:03 WARN Rate limiter enabled after throttle name=server-test rate=5175=== RUN TestPartSizeForNAR/small_stays_at_minimum1762026/07/19 09:49:03 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:39985177=== RUN TestConvertHashToNix32/already_Nix32_format1782026/07/19 09:49:03 WARN Rate limiter enabled after throttle name=server-test rate=5179=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error1802026/07/19 09:49:03 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:345071812026/07/19 09:49:03 WARN Rate limiter enabled after throttle name=server-test rate=5182=== PAUSE TestUploadMultipart_SupersededByPeer/missing183=== PAUSE TestSetClientTLSErrors/missing_cert_file1842026/07/19 09:49:03 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:35783185--- PASS: TestScriptTokenBadJSON (0.01s)186--- PASS: TestFileTokenReadsAndCaches (0.01s)187=== CONT TestUploadMultipart_SupersededByPeer/exists188--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)189 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)190 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.01s)1912026/07/19 09:49:03 WARN Rate limiter backed off name=server-test rate=5192=== RUN TestParsePathInfoJSON/empty_input1932026/07/19 09:49:03 WARN Rate limiter backed off name=server-test rate=5194=== PAUSE TestPartSizeForNAR/small_stays_at_minimum195=== PAUSE TestConvertHashToNix32/already_Nix32_format1962026/07/19 09:49:03 WARN Rate limiter backed off name=server-test rate=5197=== CONT TestUploadMultipart_SupersededByPeer/missing1982026/07/19 09:49:03 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34507199=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error200=== RUN TestSetClientTLSErrors/missing_key_file201=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error202=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon203--- PASS: TestScriptTokenEmptyToken (0.03s)204--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)205=== PAUSE TestParsePathInfoJSON/empty_input206=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum207=== RUN TestConvertHashToNix32/invalid_format208=== PAUSE TestSetClientTLSErrors/missing_key_file209=== CONT TestGetStorePathHash/valid_store_path210=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error211=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error212=== CONT TestGetStorePathHash/basename_without_hyphen_should_error213--- PASS: TestEncodeNixBase32 (0.01s)214 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)215 --- PASS: TestEncodeNixBase32/empty_input (0.00s)216--- PASS: TestDoServerRequestAttachesToken (0.04s)217=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum218=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI219=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI220=== PAUSE TestConvertHashToNix32/invalid_format221=== RUN TestParsePathInfoJSON/whitespace_only222=== RUN TestSetClientTLSErrors/missing_ca_file223=== PAUSE TestSetClientTLSErrors/missing_ca_file224=== RUN TestSetClientTLS/rejects_connection_without_client_cert225=== RUN TestSetClientTLSErrors/invalid_ca_file226=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts227=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512228=== CONT TestConvertHashToNix32/SRI_format_to_Nix32229=== CONT TestConvertHashToNix32/invalid_format230=== CONT TestConvertHashToNix32/already_Nix32_format231=== PAUSE TestParsePathInfoJSON/whitespace_only232--- PASS: TestPathInfoCACompatibility (0.01s)233 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)234 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)235 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)236 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)237 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)238=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert239=== PAUSE TestSetClientTLSErrors/invalid_ca_file240=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA241=== CONT TestSetClientTLSErrors/missing_cert_file242=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512243=== RUN TestParsePathInfoJSON/invalid_JSON244--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.03s)245=== CONT TestSetClientTLSErrors/invalid_ca_file246=== CONT TestSetClientTLSErrors/missing_ca_file247=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts248=== CONT TestSetClientTLSErrors/missing_key_file249=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA250=== RUN TestSetClientTLS/preserves_debug_logging_transport251=== PAUSE TestSetClientTLS/preserves_debug_logging_transport252=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)253=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512254=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI255=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon256=== PAUSE TestParsePathInfoJSON/invalid_JSON257=== CONT TestParsePathInfoJSON/Nix_format258=== CONT TestParsePathInfoJSON/whitespace_only259=== CONT TestParsePathInfoJSON/empty_input260=== RUN TestPartSizeForNAR/1_TiB261=== CONT TestSetClientTLS/rejects_connection_without_client_cert262=== CONT TestSetClientTLS/preserves_debug_logging_transport263=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA264=== CONT TestParsePathInfoJSON/Lix_format265--- PASS: TestGetStorePathHash (0.03s)266 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)267 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)268 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)269 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)270--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)271=== CONT TestParsePathInfoJSON/invalid_JSON272=== PAUSE TestPartSizeForNAR/1_TiB273--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)274=== RUN TestPartSizeForNAR/5_TiB_S3_max_object275--- PASS: TestRateLimiterFeedback (0.00s)276 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.02s)277 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.02s)278 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.02s)279 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.02s)280=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object281--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)282 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)283 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)284=== RUN TestPartSizeForNAR/capped_at_5_GiB285--- PASS: TestConvertHashToNix32 (0.03s)286 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)287 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)288 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)289=== PAUSE TestPartSizeForNAR/capped_at_5_GiB290=== CONT TestPartSizeForNAR/capped_at_5_GiB291=== CONT TestPartSizeForNAR/zero_stays_at_minimum292=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts293=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum294=== CONT TestPartSizeForNAR/5_TiB_S3_max_object295=== CONT TestPartSizeForNAR/small_stays_at_minimum296--- PASS: TestParsePathInfoJSON (0.03s)297 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)298 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)299 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)300 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)301 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)302--- PASS: TestPathInfoHashCompatibility (0.03s)303 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)304 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)305 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)306 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)307=== CONT TestPartSizeForNAR/1_TiB308--- PASS: TestPartSizeForNAR (0.04s)309 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)310 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)311 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)312 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)313 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)314 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)315 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)316--- PASS: TestSetClientTLSErrors (0.03s)317 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)318 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)319 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)320 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)3212026/07/19 09:49:03 http: TLS handshake error from 127.0.0.1:42606: remote error: tls: bad certificate322--- PASS: TestSetClientTLS (0.04s)323 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.00s)324 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)325 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)326--- PASS: TestDumpPathSingleFile (0.06s)327--- PASS: TestCaseHackSuffix (0.06s)328--- PASS: TestDumpPathWriterError (0.08s)329--- PASS: TestDumpPathMatchesNix (0.14s)330--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)331PASS332Running server tests...333The files belonging to this database system will be owned by user "nixbld".334This user must also own the server process.335336The database cluster will be initialized with locale "C".337The default database encoding has accordingly been set to "SQL_ASCII".338The default text search configuration will be set to "english".339340Data page checksums are enabled.341342creating directory /build/postgres531884281/data ... ok343creating subdirectories ... ok344selecting dynamic shared memory implementation ... posix345selecting default "max_connections" ... 100346selecting default "shared_buffers" ... 128MB347selecting default time zone ... UTC348creating configuration files ... ok349running bootstrap script ... ok350performing post-bootstrap initialization ... ok351syncing data to disk ... ok352353initdb: warning: enabling "trust" authentication for local connections354initdb: 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.355356Success. You can now start the database server using:357358 pg_ctl -D /build/postgres531884281/data -l logfile start359360/build/postgres531884281:5432 - no response3612026-07-19 09:49:04.979 UTC [205] LOG: starting PostgreSQL 18.4 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit3622026-07-19 09:49:04.979 UTC [205] LOG: listening on Unix socket "/build/postgres531884281/.s.PGSQL.5432"3632026-07-19 09:49:04.984 UTC [212] LOG: database system was shut down at 2026-07-19 09:49:04 UTC3642026-07-19 09:49:04.987 UTC [205] LOG: database system is ready to accept connections365/build/postgres531884281:5432 - accepting connections366=== RUN TestService_AuthMiddleware367=== PAUSE TestService_AuthMiddleware368=== RUN TestService_AuthMiddleware_MTLSProxyHeader369=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader370=== RUN TestService_AuthMiddleware_MTLSBoundSubjects371=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects372=== RUN TestService_ReadAuthMiddleware373=== PAUSE TestService_ReadAuthMiddleware374=== RUN TestService_AuthMiddleware_OIDC375=== PAUSE TestService_AuthMiddleware_OIDC376=== RUN TestCacheConfigHandler377=== PAUSE TestCacheConfigHandler378=== RUN TestCacheStatsHandler379=== PAUSE TestCacheStatsHandler380=== RUN TestClientCADerivations381=== PAUSE TestClientCADerivations382=== RUN TestClientErrorHandling383=== PAUSE TestClientErrorHandling384=== RUN TestClientIntegration385=== PAUSE TestClientIntegration386=== RUN TestClientMultipleUploads387=== PAUSE TestClientMultipleUploads388=== RUN TestClientWithDependencies389=== PAUSE TestClientWithDependencies390=== RUN TestPinProtectsFromGC391=== PAUSE TestPinProtectsFromGC392=== RUN TestGCAdvisoryLockBlocksConcurrentRun393{"timestamp":"2026-07-19T09:49:05.180474583Z","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(303)"}394395thread 'rustfs-worker' (603) panicked at /build/rustfs-1.0.0-beta.7-vendor/source-registry-0/reqwest-0.13.4/src/async_impl/client.rs:2507:38:396Client::new(): reqwest::Error { kind: Builder, source: General("No CA certificates were loaded from the system") }397note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace3982026-07-19 09:49:05.292 UTC [622] ERROR: relation "goose_db_version" does not exist at character 363992026-07-19 09:49:05.292 UTC [622] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4002026/07/19 09:49:05 OK 20241026095416_initial_model.sql (13.97ms)4012026/07/19 09:49:05 OK 20251210153512_drop_unused_gin_index.sql (3.09ms)4022026/07/19 09:49:05 OK 20251218171726_add_pins.sql (4.49ms)4032026/07/19 09:49:05 OK 20260628120000_add_object_size_and_stats.sql (3.96ms)4042026/07/19 09:49:05 goose: successfully migrated database to version: 202606281200004052026/07/19 09:49:05 OK 1_commit_pending_closure.sql (2.29ms)4062026/07/19 09:49:05 OK 2_object_stats_trigger.sql (1.02ms)4072026/07/19 09:49:05 goose: up to current file version: 2408--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.17s)409=== RUN TestGCBugBareHashReferences410=== PAUSE TestGCBugBareHashReferences411=== RUN TestGCMetrics412=== PAUSE TestGCMetrics413=== RUN TestGCTaskStore_StartNew414=== PAUSE TestGCTaskStore_StartNew415=== RUN TestGCTaskStore_DeduplicateSameParams416=== PAUSE TestGCTaskStore_DeduplicateSameParams417=== RUN TestGCTaskStore_ConflictDifferentParams418=== PAUSE TestGCTaskStore_ConflictDifferentParams419=== RUN TestGCTaskStore_GetEmpty420=== PAUSE TestGCTaskStore_GetEmpty421=== RUN TestGCTaskStore_GetReturnsLatest422=== PAUSE TestGCTaskStore_GetReturnsLatest423=== RUN TestGCTaskStore_CompletedAllowsNewTask424=== PAUSE TestGCTaskStore_CompletedAllowsNewTask425=== RUN TestGCTaskStore_PhaseUpdates426=== PAUSE TestGCTaskStore_PhaseUpdates427=== RUN TestGCTaskStore_Fail428=== PAUSE TestGCTaskStore_Fail429=== RUN TestGracefulShutdownDrainsInflight430=== PAUSE TestGracefulShutdownDrainsInflight431=== RUN TestService_healthCheckHandler432=== PAUSE TestService_healthCheckHandler433=== RUN TestGenerateLandingPage434=== PAUSE TestGenerateLandingPage435=== RUN TestNARDeduplicationMetadataUploadBug436=== PAUSE TestNARDeduplicationMetadataUploadBug437=== RUN TestMetricsInventory438=== PAUSE TestMetricsInventory439=== RUN TestService_NativeMTLS440=== PAUSE TestService_NativeMTLS441=== RUN TestServerTLSConfig442=== PAUSE TestServerTLSConfig443=== RUN TestMultipartCleanup444=== PAUSE TestMultipartCleanup445=== RUN TestObjectStatsTrigger446=== PAUSE TestObjectStatsTrigger447=== RUN TestOrphanedObjectsGC448=== PAUSE TestOrphanedObjectsGC449=== RUN TestOrphanedObjectsGCStressTest450=== PAUSE TestOrphanedObjectsGCStressTest451=== RUN TestResurrectedObjectNotDeleted452=== PAUSE TestResurrectedObjectNotDeleted453=== RUN TestParseSingleRange454=== PAUSE TestParseSingleRange455=== RUN TestIsValidCachePath456=== PAUSE TestIsValidCachePath457=== RUN TestReadProxyNarinfo458=== PAUSE TestReadProxyNarinfo459=== RUN TestReadProxyNarinfoAlreadyDecompressed460=== PAUSE TestReadProxyNarinfoAlreadyDecompressed461=== RUN TestReadProxyNarStreaming462=== PAUSE TestReadProxyNarStreaming463=== RUN TestReadProxy404464=== PAUSE TestReadProxy404465=== RUN TestReadProxyInvalidPath466=== PAUSE TestReadProxyInvalidPath467=== RUN TestReadProxyHead468=== PAUSE TestReadProxyHead469=== RUN TestReadProxyConditionalGet470=== PAUSE TestReadProxyConditionalGet471=== RUN TestReadProxyRootRedirectsToIndexHTML472=== PAUSE TestReadProxyRootRedirectsToIndexHTML473=== RUN TestReadProxyDisabled474=== PAUSE TestReadProxyDisabled475=== RUN TestReadProxyRangeRequest476=== PAUSE TestReadProxyRangeRequest477=== RUN TestRedundantMultipartUpload478=== PAUSE TestRedundantMultipartUpload479=== RUN TestCompleteMultipartUpload_ErrorButObjectExists480=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists481=== RUN TestCompletedNarNotReofferedAcrossClosures482=== PAUSE TestCompletedNarNotReofferedAcrossClosures483=== RUN TestPresignedUploadRegisteredBeforeCommit484=== PAUSE TestPresignedUploadRegisteredBeforeCommit485=== RUN TestService_Rustfstest486=== PAUSE TestService_Rustfstest487=== RUN TestSystemdListenerNotActivated488--- PASS: TestSystemdListenerNotActivated (0.00s)489=== RUN TestWatchdogBeatsWhenHealthy490--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)491=== RUN TestWatchdogSkipsWhenUnhealthy4922026/07/19 09:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4932026/07/19 09:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4942026/07/19 09:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4952026/07/19 09:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4962026/07/19 09:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4972026/07/19 09:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4982026/07/19 09:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4992026/07/19 09:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5002026/07/19 09:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5012026/07/19 09:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"502--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)503=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle504=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle505=== RUN TestProxyWriteTimeout506=== PAUSE TestProxyWriteTimeout507=== RUN TestIsValidUploadKey508=== PAUSE TestIsValidUploadKey509=== RUN TestUploadHandlersRejectInvalidKeys510=== PAUSE TestUploadHandlersRejectInvalidKeys511=== RUN TestUploadHandlersRejectOversizedBody512=== PAUSE TestUploadHandlersRejectOversizedBody513=== RUN TestService_cleanupPendingClosuresHandler514=== PAUSE TestService_cleanupPendingClosuresHandler515=== RUN TestService_createPendingClosureHandler516=== PAUSE TestService_createPendingClosureHandler517=== RUN TestService_verifyS3Integrity518=== PAUSE TestService_verifyS3Integrity519=== RUN TestCompleteMultipartUnregistered520=== PAUSE TestCompleteMultipartUnregistered521=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT522=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT523=== CONT TestService_cleanupPendingClosuresHandler524=== CONT TestNARDeduplicationMetadataUploadBug525=== CONT TestService_AuthMiddleware526=== CONT TestReadProxy404527=== CONT TestGCTaskStore_PhaseUpdates528--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)529=== CONT TestReadProxyInvalidPath530=== CONT TestReadProxyNarStreaming531=== CONT TestReadProxyNarinfoAlreadyDecompressed532=== CONT TestUploadHandlersRejectOversizedBody533=== CONT TestReadProxyNarinfo534=== CONT TestUploadHandlersRejectInvalidKeys535=== CONT TestIsValidUploadKey536=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info537=== RUN TestIsValidUploadKey/narinfo538=== CONT TestProxyWriteTimeout539=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info540=== PAUSE TestIsValidUploadKey/narinfo541=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle542=== RUN TestProxyWriteTimeout/narinfo543=== CONT TestGCTaskStore_DeduplicateSameParams544--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)545=== CONT TestService_Rustfstest546=== CONT TestGCTaskStore_StartNew547--- PASS: TestGCTaskStore_StartNew (0.00s)548=== CONT TestPresignedUploadRegisteredBeforeCommit549=== CONT TestGCMetrics550=== CONT TestCompletedNarNotReofferedAcrossClosures551=== CONT TestGCBugBareHashReferences552=== CONT TestCompleteMultipartUpload_ErrorButObjectExists553=== CONT TestPinProtectsFromGC554=== CONT TestGCTaskStore_GetEmpty555--- PASS: TestGCTaskStore_GetEmpty (0.00s)556=== CONT TestRedundantMultipartUpload557=== CONT TestClientWithDependencies558=== CONT TestParseSingleRange559=== CONT TestReadProxyRangeRequest560=== CONT TestClientMultipleUploads561=== CONT TestReadProxyDisabled562=== CONT TestResurrectedObjectNotDeleted563=== CONT TestClientIntegration564=== CONT TestReadProxyRootRedirectsToIndexHTML565=== CONT TestOrphanedObjectsGCStressTest566=== CONT TestClientErrorHandling567=== CONT TestReadProxyHead568=== RUN TestClientErrorHandling/InvalidStorePath569=== CONT TestOrphanedObjectsGC570=== PAUSE TestClientErrorHandling/InvalidStorePath571=== RUN TestClientErrorHandling/InvalidAuthToken572=== PAUSE TestClientErrorHandling/InvalidAuthToken573=== CONT TestClientCADerivations574=== CONT TestObjectStatsTrigger575=== CONT TestCacheStatsHandler576=== CONT TestService_ReadAuthMiddleware577=== CONT TestService_AuthMiddleware_MTLSBoundSubjects578=== CONT TestCacheConfigHandler579=== CONT TestMultipartCleanup580=== CONT TestService_AuthMiddleware_MTLSProxyHeader581=== CONT TestService_AuthMiddleware_OIDC582=== CONT TestServerTLSConfig583=== CONT TestService_NativeMTLS584=== CONT TestMetricsInventory585=== CONT TestGracefulShutdownDrainsInflight586=== CONT TestGCTaskStore_Fail587=== CONT TestReadProxyConditionalGet588=== CONT TestGCTaskStore_GetReturnsLatest589=== CONT TestGCTaskStore_CompletedAllowsNewTask590=== CONT TestCompleteMultipartUnregistered591=== CONT TestGenerateLandingPage592=== CONT TestService_verifyS3Integrity593=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT594=== CONT TestService_healthCheckHandler595=== CONT TestService_createPendingClosureHandler596=== CONT TestIsValidCachePath597=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal598=== CONT TestGCTaskStore_ConflictDifferentParams599=== RUN TestIsValidUploadKey/nar_zst600=== PAUSE TestProxyWriteTimeout/narinfo601=== RUN TestParseSingleRange/none602=== PAUSE TestParseSingleRange/none603=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal604--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)605--- PASS: TestGCTaskStore_Fail (0.00s)606=== RUN TestParseSingleRange/unknown_unit607=== RUN TestProxyWriteTimeout/1_GiB_nar608=== PAUSE TestParseSingleRange/unknown_unit609=== RUN TestIsValidCachePath/narinfo610=== RUN TestClientErrorHandling/ServerNotAvailable611=== RUN TestCacheConfigHandler/full_config,_no_issuer612=== RUN TestServerTLSConfig/no_client_CA613--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)614--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)615=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key616=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key617=== RUN TestParseSingleRange/multi-range_ignored618=== PAUSE TestParseSingleRange/multi-range_ignored619=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key620=== RUN TestParseSingleRange/malformed_no_dash621=== PAUSE TestIsValidCachePath/narinfo622=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars623=== PAUSE TestIsValidUploadKey/nar_zst624=== RUN TestIsValidUploadKey/nar_xz625=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars6262026/07/19 09:49:05 INFO Starting HTTP server address=127.0.0.1:44511627=== RUN TestIsValidCachePath/nar_zst628=== PAUSE TestIsValidUploadKey/nar_xz629=== PAUSE TestProxyWriteTimeout/1_GiB_nar630=== RUN TestProxyWriteTimeout/10_GiB_nar631=== PAUSE TestProxyWriteTimeout/10_GiB_nar632=== PAUSE TestCacheConfigHandler/full_config,_no_issuer633=== RUN TestCacheConfigHandler/no_cache_url_configured634=== PAUSE TestCacheConfigHandler/no_cache_url_configured635=== PAUSE TestServerTLSConfig/no_client_CA636=== RUN TestServerTLSConfig/missing_CA_file637=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key638=== PAUSE TestClientErrorHandling/ServerNotAvailable639=== PAUSE TestParseSingleRange/malformed_no_dash640=== PAUSE TestIsValidCachePath/nar_zst641=== RUN TestIsValidCachePath/nar_xz642=== RUN TestIsValidUploadKey/nar_plain6432026/07/19 09:49:05 INFO Shutdown signal received, draining in-flight requests timeout=10s644=== RUN TestProxyWriteTimeout/unknown_size645=== RUN TestCacheConfigHandler/no_signing_keys646=== PAUSE TestServerTLSConfig/missing_CA_file647=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info648=== RUN TestServerTLSConfig/not_a_PEM_file649=== PAUSE TestServerTLSConfig/not_a_PEM_file650=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key651=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key6522026/07/19 09:49:05 INFO Received request for more parts method=POST path=/653=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal6542026/07/19 09:49:05 INFO Received uploads request method=POST path=/6552026/07/19 09:49:05 INFO Received complete multipart upload request method=POST path=/656=== CONT TestClientErrorHandling/InvalidStorePath6572026/07/19 09:49:05 INFO Received uploads request method=POST path=/6582026/07/19 09:49:05 INFO OIDC provider initialized name=test659=== CONT TestClientErrorHandling/ServerNotAvailable660=== CONT TestClientErrorHandling/InvalidAuthToken661=== RUN TestParseSingleRange/malformed_both_empty662=== PAUSE TestParseSingleRange/malformed_both_empty663=== PAUSE TestIsValidCachePath/nar_xz664=== PAUSE TestIsValidUploadKey/nar_plain665=== PAUSE TestProxyWriteTimeout/unknown_size666=== PAUSE TestCacheConfigHandler/no_signing_keys667=== CONT TestServerTLSConfig/no_client_CA668=== CONT TestServerTLSConfig/not_a_PEM_file669=== CONT TestServerTLSConfig/missing_CA_file670--- PASS: TestUploadHandlersRejectInvalidKeys (0.11s)671 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)672 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)673 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)674 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)675=== RUN TestParseSingleRange/malformed_end_before_start676=== PAUSE TestParseSingleRange/malformed_end_before_start677=== RUN TestIsValidCachePath/nar_bz2678=== RUN TestIsValidUploadKey/listing679=== CONT TestProxyWriteTimeout/narinfo680=== CONT TestProxyWriteTimeout/unknown_size681=== CONT TestProxyWriteTimeout/10_GiB_nar682=== CONT TestProxyWriteTimeout/1_GiB_nar683=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator684=== RUN TestParseSingleRange/closed685=== PAUSE TestIsValidCachePath/nar_bz2686=== PAUSE TestIsValidUploadKey/listing687=== RUN TestIsValidUploadKey/build_log688=== PAUSE TestIsValidUploadKey/build_log689--- PASS: TestProxyWriteTimeout (0.11s)690 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)691 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)692 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)693 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)694=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator695=== CONT TestCacheConfigHandler/full_config,_no_issuer696=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator697=== PAUSE TestParseSingleRange/closed698=== RUN TestParseSingleRange/open-ended699=== RUN TestIsValidCachePath/nar_uncompressed700=== PAUSE TestIsValidCachePath/nar_uncompressed701=== RUN TestIsValidUploadKey/build_log_home-manager_file702=== CONT TestCacheConfigHandler/no_signing_keys703=== CONT TestCacheConfigHandler/no_cache_url_configured704--- PASS: TestCacheConfigHandler (0.11s)705 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)706 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)707 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)708 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)709=== PAUSE TestParseSingleRange/open-ended710=== RUN TestIsValidCachePath/ls711=== PAUSE TestIsValidUploadKey/build_log_home-manager_file712--- PASS: TestServerTLSConfig (0.11s)713 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)714 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)715 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)716=== RUN TestParseSingleRange/end_clamped_to_size717=== PAUSE TestParseSingleRange/end_clamped_to_size718=== PAUSE TestIsValidCachePath/ls719=== RUN TestIsValidCachePath/log720=== RUN TestIsValidUploadKey/build_log_plus_in_name721=== RUN TestParseSingleRange/suffix722=== PAUSE TestIsValidCachePath/log723=== RUN TestIsValidCachePath/realisation724=== PAUSE TestIsValidUploadKey/build_log_plus_in_name725=== PAUSE TestParseSingleRange/suffix726=== PAUSE TestIsValidCachePath/realisation727=== RUN TestIsValidUploadKey/build_log_question_mark728=== RUN TestParseSingleRange/suffix_exceeds_size729=== RUN TestIsValidCachePath/nix-cache-info730=== PAUSE TestIsValidCachePath/nix-cache-info731=== PAUSE TestIsValidUploadKey/build_log_question_mark732=== RUN TestIsValidUploadKey/build_log_equals733=== PAUSE TestParseSingleRange/suffix_exceeds_size734=== RUN TestParseSingleRange/single_byte735=== RUN TestIsValidCachePath/index.html736=== PAUSE TestIsValidCachePath/index.html737=== RUN TestIsValidCachePath/traversal_parent738=== PAUSE TestIsValidUploadKey/build_log_equals739=== PAUSE TestParseSingleRange/single_byte740=== PAUSE TestIsValidCachePath/traversal_parent741=== RUN TestIsValidUploadKey/realisation742=== RUN TestParseSingleRange/start_past_EOF743=== RUN TestIsValidCachePath/traversal_in_middle744=== PAUSE TestIsValidUploadKey/realisation745=== PAUSE TestParseSingleRange/start_past_EOF746=== PAUSE TestIsValidCachePath/traversal_in_middle747=== RUN TestParseSingleRange/start_far_past_EOF748=== RUN TestIsValidUploadKey/realisation_plus_in_output749=== RUN TestIsValidCachePath/invalid_char_e750=== PAUSE TestParseSingleRange/start_far_past_EOF751=== PAUSE TestIsValidUploadKey/realisation_plus_in_output752=== PAUSE TestIsValidCachePath/invalid_char_e753=== CONT TestParseSingleRange/start_far_past_EOF754=== CONT TestParseSingleRange/none755=== CONT TestParseSingleRange/open-ended756=== CONT TestParseSingleRange/closed757=== CONT TestParseSingleRange/suffix758=== CONT TestParseSingleRange/malformed_end_before_start759=== CONT TestParseSingleRange/end_clamped_to_size760=== CONT TestParseSingleRange/malformed_both_empty761=== CONT TestParseSingleRange/suffix_exceeds_size762=== CONT TestParseSingleRange/malformed_no_dash763=== CONT TestParseSingleRange/start_past_EOF764=== CONT TestParseSingleRange/single_byte765=== CONT TestParseSingleRange/multi-range_ignored766=== CONT TestParseSingleRange/unknown_unit767=== RUN TestIsValidUploadKey/nix-cache-info768=== RUN TestIsValidCachePath/invalid_char_u769--- PASS: TestParseSingleRange (0.12s)770 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)771 --- PASS: TestParseSingleRange/none (0.00s)772 --- PASS: TestParseSingleRange/open-ended (0.00s)773 --- PASS: TestParseSingleRange/closed (0.00s)774 --- PASS: TestParseSingleRange/suffix (0.00s)775 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)776 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)777 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)778 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)779 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)780 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)781 --- PASS: TestParseSingleRange/single_byte (0.00s)782 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)783 --- PASS: TestParseSingleRange/unknown_unit (0.00s)784=== PAUSE TestIsValidUploadKey/nix-cache-info785=== RUN TestIsValidUploadKey/index.html786=== PAUSE TestIsValidCachePath/invalid_char_u787=== PAUSE TestIsValidUploadKey/index.html788=== RUN TestIsValidUploadKey/narinfo_key,_nar_type789=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type790=== RUN TestIsValidUploadKey/nar_key,_narinfo_type791=== RUN TestIsValidCachePath/random_path792=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type793=== PAUSE TestIsValidCachePath/random_path794=== RUN TestIsValidUploadKey/listing_key,_narinfo_type795=== RUN TestIsValidCachePath/empty796=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type797=== PAUSE TestIsValidCachePath/empty798=== RUN TestIsValidCachePath/leading_slash799=== RUN TestIsValidUploadKey/traversal800=== PAUSE TestIsValidUploadKey/traversal801=== RUN TestIsValidUploadKey/traversal_nar802=== PAUSE TestIsValidCachePath/leading_slash803=== PAUSE TestIsValidUploadKey/traversal_nar804=== RUN TestIsValidCachePath/wrong_extension805=== RUN TestIsValidUploadKey/absolute806=== PAUSE TestIsValidCachePath/wrong_extension807=== RUN TestIsValidCachePath/short_hash808=== PAUSE TestIsValidUploadKey/absolute809=== PAUSE TestIsValidCachePath/short_hash810=== RUN TestIsValidUploadKey/empty_key811=== CONT TestIsValidCachePath/invalid_char_u812=== CONT TestIsValidCachePath/index.html813=== CONT TestIsValidCachePath/wrong_extension814=== CONT TestIsValidCachePath/narinfo815=== CONT TestIsValidCachePath/leading_slash816=== CONT TestIsValidCachePath/realisation817=== CONT TestIsValidCachePath/log818=== CONT TestIsValidCachePath/random_path819=== CONT TestIsValidCachePath/ls820=== CONT TestIsValidCachePath/nar_uncompressed821=== CONT TestIsValidCachePath/nar_bz2822=== CONT TestIsValidCachePath/nar_xz823=== CONT TestIsValidCachePath/nar_zst824=== CONT TestIsValidCachePath/traversal_parent825=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars826=== CONT TestIsValidCachePath/invalid_char_e827=== PAUSE TestIsValidUploadKey/empty_key828=== RUN TestIsValidUploadKey/unknown_type829=== CONT TestIsValidCachePath/short_hash830=== CONT TestIsValidCachePath/traversal_in_middle831=== CONT TestIsValidCachePath/nix-cache-info832=== CONT TestIsValidCachePath/empty833--- PASS: TestIsValidCachePath (0.12s)834 --- PASS: TestIsValidCachePath/index.html (0.00s)835 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)836 --- PASS: TestIsValidCachePath/narinfo (0.00s)837 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)838 --- PASS: TestIsValidCachePath/leading_slash (0.00s)839 --- PASS: TestIsValidCachePath/realisation (0.00s)840 --- PASS: TestIsValidCachePath/log (0.00s)841 --- PASS: TestIsValidCachePath/random_path (0.00s)842 --- PASS: TestIsValidCachePath/ls (0.00s)843 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)844 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)845 --- PASS: TestIsValidCachePath/nar_xz (0.00s)846 --- PASS: TestIsValidCachePath/nar_zst (0.00s)847 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)848 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)849 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)850 --- PASS: TestIsValidCachePath/short_hash (0.00s)851 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)852 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)853 --- PASS: TestIsValidCachePath/empty (0.00s)854=== PAUSE TestIsValidUploadKey/unknown_type855=== CONT TestIsValidUploadKey/narinfo856=== CONT TestIsValidUploadKey/unknown_type857=== CONT TestIsValidUploadKey/empty_key858=== CONT TestIsValidUploadKey/traversal_nar859=== CONT TestIsValidUploadKey/nar_xz860=== CONT TestIsValidUploadKey/realisation861=== CONT TestIsValidUploadKey/nar_plain862=== CONT TestIsValidUploadKey/absolute863=== CONT TestIsValidUploadKey/narinfo_key,_nar_type864=== CONT TestIsValidUploadKey/traversal865=== CONT TestIsValidUploadKey/build_log_equals866=== CONT TestIsValidUploadKey/listing_key,_narinfo_type867=== CONT TestIsValidUploadKey/build_log_question_mark868=== CONT TestIsValidUploadKey/build_log_plus_in_name869=== CONT TestIsValidUploadKey/nar_key,_narinfo_type870=== CONT TestIsValidUploadKey/build_log_home-manager_file871=== CONT TestIsValidUploadKey/build_log872=== CONT TestIsValidUploadKey/listing873=== CONT TestIsValidUploadKey/nix-cache-info874=== CONT TestIsValidUploadKey/index.html875=== CONT TestIsValidUploadKey/nar_zst876=== CONT TestIsValidUploadKey/realisation_plus_in_output877--- PASS: TestIsValidUploadKey (0.12s)878 --- PASS: TestIsValidUploadKey/narinfo (0.00s)879 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)880 --- PASS: TestIsValidUploadKey/empty_key (0.00s)881 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)882 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)883 --- PASS: TestIsValidUploadKey/realisation (0.00s)884 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)885 --- PASS: TestIsValidUploadKey/absolute (0.00s)886 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)887 --- PASS: TestIsValidUploadKey/traversal (0.00s)888 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)889 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)890 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)891 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)892 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)893 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)894 --- PASS: TestIsValidUploadKey/build_log (0.00s)895 --- PASS: TestIsValidUploadKey/listing (0.00s)896 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)897 --- PASS: TestIsValidUploadKey/index.html (0.00s)898 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)899 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)900--- PASS: TestGenerateLandingPage (0.01s)9012026-07-19 09:49:05.755 UTC [718] ERROR: relation "goose_db_version" does not exist at character 369022026-07-19 09:49:05.755 UTC [718] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9032026-07-19 09:49:05.756 UTC [713] ERROR: relation "goose_db_version" does not exist at character 369042026-07-19 09:49:05.756 UTC [713] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9052026-07-19 09:49:05.756 UTC [712] ERROR: relation "goose_db_version" does not exist at character 369062026-07-19 09:49:05.756 UTC [712] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9072026-07-19 09:49:05.756 UTC [721] ERROR: relation "goose_db_version" does not exist at character 369082026-07-19 09:49:05.756 UTC [721] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9092026-07-19 09:49:05.756 UTC [714] ERROR: relation "goose_db_version" does not exist at character 369102026-07-19 09:49:05.756 UTC [714] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9112026-07-19 09:49:05.757 UTC [719] ERROR: relation "goose_db_version" does not exist at character 369122026-07-19 09:49:05.757 UTC [719] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9132026-07-19 09:49:05.766 UTC [737] ERROR: relation "goose_db_version" does not exist at character 369142026-07-19 09:49:05.766 UTC [737] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC915--- PASS: TestGracefulShutdownDrainsInflight (0.18s)9162026-07-19 09:49:05.825 UTC [744] ERROR: relation "goose_db_version" does not exist at character 369172026-07-19 09:49:05.825 UTC [744] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC918=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure919=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure920=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart921=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart922=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts923=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts924=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure925=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts926=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart9272026/07/19 09:49:05 INFO Received uploads request method=POST path=/9282026/07/19 09:49:05 INFO Received complete multipart upload request method=POST path=/9292026/07/19 09:49:05 INFO Received request for more parts method=POST path=/9302026-07-19 09:49:05.826 UTC [762] ERROR: relation "goose_db_version" does not exist at character 369312026-07-19 09:49:05.826 UTC [762] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9322026-07-19 09:49:05.834 UTC [791] ERROR: relation "goose_db_version" does not exist at character 369332026-07-19 09:49:05.834 UTC [791] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9342026-07-19 09:49:05.835 UTC [786] ERROR: relation "goose_db_version" does not exist at character 369352026-07-19 09:49:05.835 UTC [786] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9362026-07-19 09:49:05.836 UTC [794] ERROR: relation "goose_db_version" does not exist at character 369372026-07-19 09:49:05.836 UTC [794] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9382026-07-19 09:49:05.837 UTC [795] ERROR: relation "goose_db_version" does not exist at character 369392026-07-19 09:49:05.837 UTC [795] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9402026/07/19 09:49:05 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures9412026/07/19 09:49:05 OK 20241026095416_initial_model.sql (164.51ms)9422026/07/19 09:49:05 OK 20251210153512_drop_unused_gin_index.sql (16.41ms)9432026/07/19 09:49:05 OK 20241026095416_initial_model.sql (181.18ms)9442026/07/19 09:49:05 OK 20251210153512_drop_unused_gin_index.sql (5.88ms)9452026/07/19 09:49:05 OK 20251218171726_add_pins.sql (10.28ms)9462026/07/19 09:49:05 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=206.152354ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures9472026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (76.66ms)9482026/07/19 09:49:06 goose: successfully migrated database to version: 202606281200009492026/07/19 09:49:06 OK 20241026095416_initial_model.sql (268.92ms)9502026/07/19 09:49:06 OK 20251218171726_add_pins.sql (85.06ms)9512026/07/19 09:49:06 OK 1_commit_pending_closure.sql (6.6ms)9522026/07/19 09:49:06 OK 20241026095416_initial_model.sql (220.05ms)9532026/07/19 09:49:06 OK 20241026095416_initial_model.sql (221.14ms)9542026/07/19 09:49:06 OK 20241026095416_initial_model.sql (193.31ms)9552026/07/19 09:49:06 OK 20241026095416_initial_model.sql (223.83ms)9562026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (6.4ms)9572026/07/19 09:49:06 OK 2_object_stats_trigger.sql (13.57ms)9582026/07/19 09:49:06 goose: up to current file version: 29592026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (15.77ms)9602026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (15.31ms)9612026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (18ms)9622026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (15.28ms)9632026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (24.69ms)9642026/07/19 09:49:06 goose: successfully migrated database to version: 202606281200009652026/07/19 09:49:06 OK 20251218171726_add_pins.sql (21.42ms)9662026/07/19 09:49:06 OK 20241026095416_initial_model.sql (130.95ms)9672026/07/19 09:49:06 OK 20241026095416_initial_model.sql (135.97ms)9682026/07/19 09:49:06 OK 20251218171726_add_pins.sql (9.92ms)9692026/07/19 09:49:06 OK 20241026095416_initial_model.sql (123.73ms)9702026/07/19 09:49:06 OK 20241026095416_initial_model.sql (121.7ms)9712026/07/19 09:49:06 OK 1_commit_pending_closure.sql (6.91ms)9722026/07/19 09:49:06 OK 20251218171726_add_pins.sql (12.55ms)9732026/07/19 09:49:06 OK 20251218171726_add_pins.sql (12.5ms)9742026/07/19 09:49:06 OK 20251218171726_add_pins.sql (12.69ms)9752026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (6.92ms)9762026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (7.01ms)9772026/07/19 09:49:06 OK 20241026095416_initial_model.sql (122.58ms)9782026/07/19 09:49:06 OK 20241026095416_initial_model.sql (120.29ms)979{"timestamp":"2026-07-19T09:49:06.089662078Z","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(383)"}9802026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (13.92ms)9812026/07/19 09:49:06 OK 2_object_stats_trigger.sql (14.39ms)9822026/07/19 09:49:06 goose: up to current file version: 29832026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (20.92ms)9842026/07/19 09:49:06 goose: successfully migrated database to version: 202606281200009852026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (15.09ms)986--- PASS: TestReadProxyNarinfo (0.51s)9872026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (12.05ms)9882026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (14.32ms)9892026/07/19 09:49:06 OK 1_commit_pending_closure.sql (6.66ms)9902026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (26.93ms)9912026/07/19 09:49:06 goose: successfully migrated database to version: 202606281200009922026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.9ms)9932026/07/19 09:49:06 goose: up to current file version: 2994--- PASS: TestReadProxyNarStreaming (0.53s)9952026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (26.93ms)9962026/07/19 09:49:06 goose: successfully migrated database to version: 202606281200009972026/07/19 09:49:06 OK 1_commit_pending_closure.sql (5.54ms)9982026/07/19 09:49:06 OK 20251218171726_add_pins.sql (14.47ms)9992026/07/19 09:49:06 OK 20251218171726_add_pins.sql (27.74ms)10002026/07/19 09:49:06 OK 20251218171726_add_pins.sql (16.23ms)10012026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (27.95ms)10022026/07/19 09:49:06 INFO Received cleanup request method=DELETE path=/api/pending_closures10032026/07/19 09:49:06 OK 20251218171726_add_pins.sql (28.22ms)10042026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000010052026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (28.85ms)10062026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000010072026/07/19 09:49:06 OK 20251218171726_add_pins.sql (9.56ms)10082026/07/19 09:49:06 OK 20251218171726_add_pins.sql (11.72ms)10092026/07/19 09:49:06 INFO Aborted multipart uploads count=010102026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures10112026/07/19 09:49:06 OK 2_object_stats_trigger.sql (12.81ms)10122026/07/19 09:49:06 goose: up to current file version: 210132026/07/19 09:49:06 OK 1_commit_pending_closure.sql (14.47ms)10142026/07/19 09:49:06 OK 1_commit_pending_closure.sql (14.39ms)10152026/07/19 09:49:06 OK 1_commit_pending_closure.sql (16.91ms)10162026-07-19 09:49:06.125 UTC [836] ERROR: relation "goose_db_version" does not exist at character 3610172026-07-19 09:49:06.125 UTC [836] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10182026-07-19 09:49:06.126 UTC [837] ERROR: relation "goose_db_version" does not exist at character 3610192026-07-19 09:49:06.126 UTC [837] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10202026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (17.2ms)10212026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000010222026-07-19 09:49:06.126 UTC [838] ERROR: relation "goose_db_version" does not exist at character 3610232026-07-19 09:49:06.126 UTC [838] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10242026/07/19 09:49:06 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1025--- PASS: TestService_AuthMiddleware (0.55s)10262026-07-19 09:49:06.127 UTC [839] ERROR: relation "goose_db_version" does not exist at character 3610272026-07-19 09:49:06.127 UTC [839] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10282026-07-19 09:49:06.128 UTC [840] ERROR: relation "goose_db_version" does not exist at character 3610292026-07-19 09:49:06.128 UTC [840] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10302026-07-19 09:49:06.128 UTC [841] ERROR: relation "goose_db_version" does not exist at character 3610312026-07-19 09:49:06.128 UTC [841] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10322026-07-19 09:49:06.129 UTC [843] ERROR: relation "goose_db_version" does not exist at character 3610332026-07-19 09:49:06.129 UTC [843] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10342026/07/19 09:49:06 OK 2_object_stats_trigger.sql (5.16ms)10352026/07/19 09:49:06 goose: up to current file version: 210362026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (19.08ms)10372026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000010382026/07/19 09:49:06 OK 2_object_stats_trigger.sql (5.15ms)10392026/07/19 09:49:06 goose: up to current file version: 210402026-07-19 09:49:06.129 UTC [845] ERROR: relation "goose_db_version" does not exist at character 3610412026-07-19 09:49:06.129 UTC [845] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10422026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (20.39ms)10432026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000010442026-07-19 09:49:06.129 UTC [842] ERROR: relation "goose_db_version" does not exist at character 3610452026-07-19 09:49:06.129 UTC [842] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10462026/07/19 09:49:06 OK 2_object_stats_trigger.sql (5.26ms)10472026/07/19 09:49:06 goose: up to current file version: 210482026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (20.65ms)10492026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000010502026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (19.02ms)10512026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000010522026-07-19 09:49:06.130 UTC [844] ERROR: relation "goose_db_version" does not exist at character 3610532026-07-19 09:49:06.130 UTC [844] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10542026-07-19 09:49:06.130 UTC [846] ERROR: relation "goose_db_version" does not exist at character 3610552026-07-19 09:49:06.130 UTC [846] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10562026-07-19 09:49:06.132 UTC [847] ERROR: relation "goose_db_version" does not exist at character 3610572026-07-19 09:49:06.132 UTC [847] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10582026-07-19 09:49:06.133 UTC [848] ERROR: relation "goose_db_version" does not exist at character 3610592026-07-19 09:49:06.133 UTC [848] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10602026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (24.6ms)10612026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000010622026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures10632026/07/19 09:49:06 OK 1_commit_pending_closure.sql (6.98ms)10642026/07/19 09:49:06 OK 1_commit_pending_closure.sql (9.89ms)10652026/07/19 09:49:06 INFO Created nix-cache-info in bucket bucket=bucket710662026/07/19 09:49:06 OK 1_commit_pending_closure.sql (8.5ms)10672026/07/19 09:49:06 OK 1_commit_pending_closure.sql (8.16ms)10682026/07/19 09:49:06 OK 1_commit_pending_closure.sql (7.79ms)10692026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.22ms)10702026/07/19 09:49:06 goose: up to current file version: 210712026/07/19 09:49:06 OK 1_commit_pending_closure.sql (6.25ms)1072--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.56s)10732026/07/19 09:49:06 OK 2_object_stats_trigger.sql (4.31ms)10742026/07/19 09:49:06 goose: up to current file version: 210752026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.89ms)10762026/07/19 09:49:06 goose: up to current file version: 210772026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.8ms)10782026/07/19 09:49:06 goose: up to current file version: 210792026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.74ms)10802026/07/19 09:49:06 goose: up to current file version: 210812026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.38ms)10822026/07/19 09:49:06 goose: up to current file version: 210832026/07/19 09:49:06 INFO Received cleanup request method=DELETE path=/api/pending_closures10842026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures10852026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures10862026/07/19 09:49:06 INFO Aborted multipart uploads count=11087--- PASS: TestReadProxyInvalidPath (0.57s)1088--- PASS: TestReadProxy404 (0.57s)10892026/07/19 09:49:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10902026-07-19 09:49:06.151 UTC [851] ERROR: relation "goose_db_version" does not exist at character 3610912026-07-19 09:49:06.151 UTC [851] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10922026-07-19 09:49:06.151 UTC [853] ERROR: relation "goose_db_version" does not exist at character 3610932026-07-19 09:49:06.151 UTC [853] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10942026-07-19 09:49:06.151 UTC [850] ERROR: relation "goose_db_version" does not exist at character 3610952026-07-19 09:49:06.151 UTC [850] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10962026-07-19 09:49:06.152 UTC [718] ERROR: Closure does not exist: id=110972026-07-19 09:49:06.152 UTC [718] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10982026-07-19 09:49:06.152 UTC [718] STATEMENT: -- name: CommitPendingClosure :exec1099 SELECT commit_pending_closure($1::bigint)1100 1101--- PASS: TestService_cleanupPendingClosuresHandler (0.57s)11022026-07-19 09:49:06.153 UTC [857] ERROR: relation "goose_db_version" does not exist at character 3611032026-07-19 09:49:06.153 UTC [857] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11042026-07-19 09:49:06.154 UTC [854] ERROR: relation "goose_db_version" does not exist at character 3611052026-07-19 09:49:06.154 UTC [854] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11062026-07-19 09:49:06.154 UTC [855] ERROR: relation "goose_db_version" does not exist at character 3611072026-07-19 09:49:06.154 UTC [855] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11082026-07-19 09:49:06.155 UTC [856] ERROR: relation "goose_db_version" does not exist at character 3611092026-07-19 09:49:06.155 UTC [856] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11102026-07-19 09:49:06.156 UTC [858] ERROR: relation "goose_db_version" does not exist at character 3611112026-07-19 09:49:06.156 UTC [858] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11122026/07/19 09:49:06 OK 20241026095416_initial_model.sql (14.5ms)11132026/07/19 09:49:06 INFO Aborted multipart uploads count=011142026/07/19 09:49:06 OK 20241026095416_initial_model.sql (18.55ms)11152026/07/19 09:49:06 OK 20241026095416_initial_model.sql (18.46ms)11162026/07/19 09:49:06 OK 20241026095416_initial_model.sql (14.12ms)11172026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (4.09ms)11182026/07/19 09:49:06 WARN Force mode enabled - objects will be deleted immediately without grace period11192026/07/19 09:49:06 OK 20241026095416_initial_model.sql (17.89ms)11202026/07/19 09:49:06 OK 20241026095416_initial_model.sql (19.21ms)11212026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (4.33ms)11222026/07/19 09:49:06 OK 20241026095416_initial_model.sql (19.55ms)11232026/07/19 09:49:06 OK 20241026095416_initial_model.sql (17.88ms)11242026/07/19 09:49:06 OK 20241026095416_initial_model.sql (19.79ms)11252026/07/19 09:49:06 OK 20241026095416_initial_model.sql (20.32ms)11262026/07/19 09:49:06 OK 20241026095416_initial_model.sql (18.47ms)11272026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (4.34ms)11282026/07/19 09:49:06 OK 20241026095416_initial_model.sql (19.04ms)11292026/07/19 09:49:06 OK 20241026095416_initial_model.sql (19.57ms)11302026-07-19 09:49:06.165 UTC [863] ERROR: relation "goose_db_version" does not exist at character 3611312026-07-19 09:49:06.165 UTC [863] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11322026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (4.38ms)11332026/07/19 09:49:06 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011342026-07-19 09:49:06.166 UTC [862] ERROR: relation "goose_db_version" does not exist at character 3611352026-07-19 09:49:06.166 UTC [862] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11362026-07-19 09:49:06.166 UTC [865] ERROR: relation "goose_db_version" does not exist at character 3611372026-07-19 09:49:06.166 UTC [865] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11382026-07-19 09:49:06.166 UTC [864] ERROR: relation "goose_db_version" does not exist at character 3611392026-07-19 09:49:06.166 UTC [864] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11402026/07/19 09:49:06 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11412026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures11422026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (4.16ms)11432026/07/19 09:49:06 INFO Vacuumed table table=pending_closures11442026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (3.62ms)11452026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (4ms)11462026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (3.75ms)11472026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (3.82ms)11482026-07-19 09:49:06.168 UTC [866] ERROR: relation "goose_db_version" does not exist at character 3611492026-07-19 09:49:06.168 UTC [866] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11502026/07/19 09:49:06 OK 20251218171726_add_pins.sql (6.52ms)11512026/07/19 09:49:06 INFO Vacuumed table table=pending_objects11522026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (3.81ms)11532026-07-19 09:49:06.169 UTC [867] ERROR: relation "goose_db_version" does not exist at character 3611542026-07-19 09:49:06.169 UTC [867] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11552026-07-19 09:49:06.169 UTC [869] ERROR: relation "goose_db_version" does not exist at character 3611562026-07-19 09:49:06.169 UTC [869] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11572026/07/19 09:49:06 INFO Vacuumed table table=multipart_uploads11582026/07/19 09:49:06 OK 20251218171726_add_pins.sql (6.25ms)11592026-07-19 09:49:06.169 UTC [868] ERROR: relation "goose_db_version" does not exist at character 3611602026-07-19 09:49:06.169 UTC [868] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11612026/07/19 09:49:06 INFO Vacuumed table table=closures11622026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (5.59ms)11632026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (5.8ms)11642026/07/19 09:49:06 INFO Vacuumed table table=objects11652026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (5.94ms)11662026-07-19 09:49:06.171 UTC [870] ERROR: relation "goose_db_version" does not exist at character 3611672026-07-19 09:49:06.171 UTC [870] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1168--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.59s)11692026/07/19 09:49:06 OK 20251218171726_add_pins.sql (6.37ms)11702026/07/19 09:49:06 OK 20251218171726_add_pins.sql (6.14ms)11712026-07-19 09:49:06.173 UTC [871] ERROR: relation "goose_db_version" does not exist at character 3611722026-07-19 09:49:06.173 UTC [871] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11732026/07/19 09:49:06 OK 20251218171726_add_pins.sql (7.58ms)11742026/07/19 09:49:06 OK 20251218171726_add_pins.sql (6.28ms)11752026/07/19 09:49:06 OK 20251218171726_add_pins.sql (9.1ms)11762026/07/19 09:49:06 OK 20251218171726_add_pins.sql (6.21ms)11772026/07/19 09:49:06 OK 20251218171726_add_pins.sql (7.49ms)11782026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (6.84ms)11792026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000011802026/07/19 09:49:06 OK 20251218171726_add_pins.sql (6.68ms)11812026-07-19 09:49:06.175 UTC [872] ERROR: relation "goose_db_version" does not exist at character 3611822026-07-19 09:49:06.175 UTC [872] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1183--- PASS: TestGCMetrics (0.59s)11842026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (7.15ms)11852026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000011862026/07/19 09:49:06 OK 20251218171726_add_pins.sql (7.11ms)11872026/07/19 09:49:06 OK 20251218171726_add_pins.sql (7.29ms)11882026/07/19 09:49:06 OK 20241026095416_initial_model.sql (13.58ms)11892026/07/19 09:49:06 OK 1_commit_pending_closure.sql (3.52ms)11902026/07/19 09:49:06 OK 20251218171726_add_pins.sql (8.38ms)11912026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (6.63ms)11922026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000011932026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (6.53ms)11942026/07/19 09:49:06 goose: successfully migrated database to version: 202606281200001195=== NAME TestNARDeduplicationMetadataUploadBug1196 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2720869609/001/store/808grppi8mrsml3815fafspl8p90sv60-file1.txt11972026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (13.58ms)11982026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000011992026/07/19 09:49:06 OK 1_commit_pending_closure.sql (10.39ms)12002026/07/19 09:49:06 OK 20241026095416_initial_model.sql (20.48ms)12012026/07/19 09:49:06 OK 2_object_stats_trigger.sql (8.53ms)12022026/07/19 09:49:06 goose: up to current file version: 212032026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (13.42ms)12042026/07/19 09:49:06 OK 20241026095416_initial_model.sql (22.57ms)12052026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000012062026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (13.36ms)12072026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000012082026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (10.1ms)12092026/07/19 09:49:06 OK 20241026095416_initial_model.sql (23.33ms)12102026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (12.2ms)12112026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000012122026/07/19 09:49:06 OK 20241026095416_initial_model.sql (19.81ms)12132026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (12.46ms)12142026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000012152026/07/19 09:49:06 OK 20241026095416_initial_model.sql (20.77ms)12162026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (13.56ms)12172026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000012182026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (11.17ms)12192026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000012202026/07/19 09:49:06 OK 20241026095416_initial_model.sql (18.5ms)12212026/07/19 09:49:06 OK 1_commit_pending_closure.sql (8.48ms)12222026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (11.31ms)12232026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000012242026/07/19 09:49:06 OK 1_commit_pending_closure.sql (8.73ms)12252026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (10.07ms)12262026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000012272026/07/19 09:49:06 OK 20241026095416_initial_model.sql (20.83ms)12282026/07/19 09:49:06 OK 20241026095416_initial_model.sql (12.21ms)12292026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.73ms)12302026/07/19 09:49:06 goose: up to current file version: 212312026/07/19 09:49:06 OK 1_commit_pending_closure.sql (3.84ms)12322026/07/19 09:49:06 OK 20241026095416_initial_model.sql (11.74ms)12332026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (3.3ms)12342026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (4.05ms)12352026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (3.76ms)12362026/07/19 09:49:06 OK 1_commit_pending_closure.sql (4ms)12372026/07/19 09:49:06 OK 20241026095416_initial_model.sql (15.65ms)12382026/07/19 09:49:06 OK 20241026095416_initial_model.sql (12.62ms)12392026/07/19 09:49:06 OK 20241026095416_initial_model.sql (12.03ms)12402026/07/19 09:49:06 OK 1_commit_pending_closure.sql (4.5ms)12412026/07/19 09:49:06 OK 1_commit_pending_closure.sql (4.15ms)12422026/07/19 09:49:06 OK 1_commit_pending_closure.sql (4.08ms)12432026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (4.38ms)12442026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (4.13ms)12452026/07/19 09:49:06 OK 1_commit_pending_closure.sql (4.56ms)12462026/07/19 09:49:06 OK 1_commit_pending_closure.sql (3.98ms)12472026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.87ms)12482026/07/19 09:49:06 goose: up to current file version: 212492026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (3.02ms)12502026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (3.87ms)12512026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (4.23ms)12522026/07/19 09:49:06 OK 1_commit_pending_closure.sql (4.95ms)12532026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.02ms)12542026/07/19 09:49:06 goose: up to current file version: 212552026/07/19 09:49:06 OK 1_commit_pending_closure.sql (5.12ms)12562026/07/19 09:49:06 OK 20251218171726_add_pins.sql (6.26ms)12572026/07/19 09:49:06 OK 2_object_stats_trigger.sql (6.33ms)12582026/07/19 09:49:06 goose: up to current file version: 212592026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.05ms)12602026/07/19 09:49:06 goose: up to current file version: 212612026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.17ms)12622026/07/19 09:49:06 goose: up to current file version: 212632026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (4.56ms)12642026/07/19 09:49:06 OK 2_object_stats_trigger.sql (2.98ms)12652026/07/19 09:49:06 goose: up to current file version: 212662026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.49ms)12672026/07/19 09:49:06 goose: up to current file version: 212682026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (3.97ms)12692026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.08ms)12702026/07/19 09:49:06 goose: up to current file version: 212712026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (3.88ms)12722026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (3.97ms)1273--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.61s)12742026/07/19 09:49:06 OK 2_object_stats_trigger.sql (2.73ms)12752026/07/19 09:49:06 goose: up to current file version: 212762026/07/19 09:49:06 OK 20241026095416_initial_model.sql (15.58ms)12772026/07/19 09:49:06 OK 20251218171726_add_pins.sql (5.5ms)12782026/07/19 09:49:06 OK 2_object_stats_trigger.sql (4.06ms)12792026/07/19 09:49:06 goose: up to current file version: 212802026/07/19 09:49:06 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=435.153798ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures12812026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.95ms)12822026/07/19 09:49:06 goose: up to current file version: 212832026/07/19 09:49:06 OK 20241026095416_initial_model.sql (17.49ms)12842026/07/19 09:49:06 OK 20251218171726_add_pins.sql (6.93ms)12852026/07/19 09:49:06 OK 20251218171726_add_pins.sql (5.36ms)12862026/07/19 09:49:06 OK 20251218171726_add_pins.sql (5.98ms)12872026/07/19 09:49:06 OK 20251218171726_add_pins.sql (7.01ms)12882026/07/19 09:49:06 OK 20251218171726_add_pins.sql (6.57ms)12892026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures12902026/07/19 09:49:06 OK 20251218171726_add_pins.sql (7.38ms)12912026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures12922026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures12932026/07/19 09:49:06 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1294--- PASS: TestService_ReadAuthMiddleware (0.61s)12952026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (6.99ms)12962026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000012972026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (4.29ms)12982026/07/19 09:49:06 OK 20251218171726_add_pins.sql (8.17ms)12992026/07/19 09:49:06 OK 20251218171726_add_pins.sql (5.71ms)13002026/07/19 09:49:06 OK 20241026095416_initial_model.sql (13.5ms)13012026/07/19 09:49:06 OK 20251218171726_add_pins.sql (6.45ms)13022026/07/19 09:49:06 OK 20251218171726_add_pins.sql (6.46ms)13032026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (4.25ms)13042026/07/19 09:49:06 OK 20251218171726_add_pins.sql (6.46ms)13052026/07/19 09:49:06 INFO Created nix-cache-info in bucket bucket=bucket2413062026/07/19 09:49:06 INFO Created nix-cache-info in bucket bucket=bucket2713072026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (7ms)13082026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000013092026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (7.02ms)13102026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000013112026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (7.09ms)13122026/07/19 09:49:06 goose: successfully migrated database to version: 202606281200001313--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.62s)13142026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (5.78ms)13152026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000013162026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (8.26ms)13172026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000013182026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (7.01ms)13192026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000013202026/07/19 09:49:06 OK 1_commit_pending_closure.sql (5.37ms)13212026/07/19 09:49:06 OK 20241026095416_initial_model.sql (16.04ms)13222026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (7.05ms)13232026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000013242026/07/19 09:49:06 OK 20251218171726_add_pins.sql (5.47ms)13252026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (4.58ms)13262026/07/19 09:49:06 OK 20241026095416_initial_model.sql (18.51ms)13272026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (6.46ms)13282026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000013292026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (6.5ms)13302026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000013312026/07/19 09:49:06 OK 20241026095416_initial_model.sql (16.99ms)13322026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (5.48ms)13332026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000013342026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (5.77ms)13352026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000013362026/07/19 09:49:06 OK 20251218171726_add_pins.sql (5.8ms)13372026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (6.03ms)13382026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000013392026/07/19 09:49:06 OK 1_commit_pending_closure.sql (2.78ms)13402026/07/19 09:49:06 OK 1_commit_pending_closure.sql (3.09ms)13412026/07/19 09:49:06 OK 2_object_stats_trigger.sql (1.72ms)13422026/07/19 09:49:06 goose: up to current file version: 213432026/07/19 09:49:06 OK 1_commit_pending_closure.sql (3.12ms)13442026/07/19 09:49:06 OK 1_commit_pending_closure.sql (3.03ms)13452026/07/19 09:49:06 OK 1_commit_pending_closure.sql (2.92ms)13462026/07/19 09:49:06 OK 1_commit_pending_closure.sql (2.89ms)13472026/07/19 09:49:06 OK 1_commit_pending_closure.sql (2.24ms)13482026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)13492026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)13502026/07/19 09:49:06 OK 1_commit_pending_closure.sql (2.5ms)13512026/07/19 09:49:06 OK 2_object_stats_trigger.sql (1.77ms)13522026/07/19 09:49:06 goose: up to current file version: 213532026/07/19 09:49:06 OK 2_object_stats_trigger.sql (1.86ms)13542026/07/19 09:49:06 goose: up to current file version: 213552026/07/19 09:49:06 OK 20251210153512_drop_unused_gin_index.sql (2.72ms)13562026/07/19 09:49:06 OK 1_commit_pending_closure.sql (2.74ms)13572026/07/19 09:49:06 OK 2_object_stats_trigger.sql (2.33ms)13582026/07/19 09:49:06 goose: up to current file version: 213592026/07/19 09:49:06 OK 1_commit_pending_closure.sql (5.25ms)13602026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (6.19ms)13612026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000013622026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.83ms)13632026/07/19 09:49:06 goose: up to current file version: 213642026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.71ms)13652026/07/19 09:49:06 goose: up to current file version: 213662026/07/19 09:49:06 OK 1_commit_pending_closure.sql (4.81ms)13672026/07/19 09:49:06 OK 2_object_stats_trigger.sql (3.62ms)13682026/07/19 09:49:06 goose: up to current file version: 213692026/07/19 09:49:06 OK 1_commit_pending_closure.sql (4.5ms)1370--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.62s)13712026/07/19 09:49:06 OK 20251218171726_add_pins.sql (6.19ms)13722026/07/19 09:49:06 OK 2_object_stats_trigger.sql (4.08ms)13732026/07/19 09:49:06 OK 20251218171726_add_pins.sql (4.48ms)1374--- PASS: TestCacheStatsHandler (0.62s)13752026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures13762026/07/19 09:49:06 goose: up to current file version: 213772026/07/19 09:49:06 OK 2_object_stats_trigger.sql (1.39ms)13782026/07/19 09:49:06 goose: up to current file version: 213792026/07/19 09:49:06 OK 2_object_stats_trigger.sql (2.47ms)13802026/07/19 09:49:06 goose: up to current file version: 213812026/07/19 09:49:06 OK 20251218171726_add_pins.sql (3.7ms)13822026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (5.39ms)13832026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000013842026/07/19 09:49:06 OK 20251218171726_add_pins.sql (4.35ms)13852026/07/19 09:49:06 OK 2_object_stats_trigger.sql (2.87ms)13862026/07/19 09:49:06 goose: up to current file version: 213872026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures13882026/07/19 09:49:06 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13892026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures13902026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures13912026/07/19 09:49:06 WARN mTLS auth: bound subjects configured but subject DN unavailable13922026/07/19 09:49:06 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"13932026/07/19 09:49:06 OK 2_object_stats_trigger.sql (1.49ms)1394--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.63s)13952026/07/19 09:49:06 goose: up to current file version: 213962026/07/19 09:49:06 OK 2_object_stats_trigger.sql (1.54ms)13972026/07/19 09:49:06 goose: up to current file version: 213982026/07/19 09:49:06 OK 1_commit_pending_closure.sql (4.02ms)13992026/07/19 09:49:06 OK 1_commit_pending_closure.sql (2.82ms)1400--- PASS: TestService_healthCheckHandler (0.63s)14012026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)14022026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000014032026/07/19 09:49:06 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14042026/07/19 09:49:06 WARN mTLS auth: subject not in bound subjects subject="CN=writer"14052026/07/19 09:49:06 INFO Created nix-cache-info in bucket bucket=bucket281406--- PASS: TestService_NativeMTLS (0.63s)14072026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)14082026/07/19 09:49:06 goose: successfully migrated database to version: 202606281200001409--- PASS: TestMetricsInventory (0.63s)14102026/07/19 09:49:06 OK 2_object_stats_trigger.sql (2.18ms)14112026/07/19 09:49:06 goose: up to current file version: 214122026/07/19 09:49:06 OK 2_object_stats_trigger.sql (1.69ms)14132026/07/19 09:49:06 goose: up to current file version: 214142026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (6.73ms)14152026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000014162026/07/19 09:49:06 OK 20260628120000_add_object_size_and_stats.sql (5.65ms)14172026/07/19 09:49:06 goose: successfully migrated database to version: 2026062812000014182026/07/19 09:49:06 OK 1_commit_pending_closure.sql (3.65ms)1419--- PASS: TestReadProxyDisabled (0.64s)14202026/07/19 09:49:06 OK 1_commit_pending_closure.sql (6.85ms)14212026/07/19 09:49:06 OK 2_object_stats_trigger.sql (1.59ms)14222026/07/19 09:49:06 goose: up to current file version: 214232026/07/19 09:49:06 OK 2_object_stats_trigger.sql (1.59ms)14242026/07/19 09:49:06 goose: up to current file version: 21425=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token14262026/07/19 09:49:06 OK 1_commit_pending_closure.sql (2.91ms)1427=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1428=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1429=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1430=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1431=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected14322026/07/19 09:49:06 OK 1_commit_pending_closure.sql (3.09ms)1433=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured14342026/07/19 09:49:06 INFO Created nix-cache-info in bucket bucket=bucket391435=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1436=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1437=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1438=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected14392026/07/19 09:49:06 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]1440=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured14412026/07/19 09:49:06 OK 2_object_stats_trigger.sql (2.24ms)14422026/07/19 09:49:06 goose: up to current file version: 21443--- PASS: TestService_Rustfstest (0.65s)14442026/07/19 09:49:06 INFO Created nix-cache-info in bucket bucket=bucket4114452026/07/19 09:49:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14462026/07/19 09:49:06 OK 2_object_stats_trigger.sql (1.93ms)14472026/07/19 09:49:06 goose: up to current file version: 214482026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures1449--- PASS: TestObjectStatsTrigger (0.65s)1450{"timestamp":"2026-07-19T09:49:06.236613656Z","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(279)"}1451{"timestamp":"2026-07-19T09:49:06.236675676Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket20, 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(279)"}1452--- PASS: TestReadProxyRangeRequest (0.65s)14532026/07/19 09:49:06 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=MWJiMmY2YjItMWVhZC00ZGU0LWFhNjUtNGU3NjZhNjMzY2EwLjc5NWFmNDQzLTE1ZGMtNDExMC04N2RiLWNlOGZiNjA4NTg5YngxNzg0NDU0NTQ2MjA5MzkwMjA214542026/07/19 09:49:06 WARN Authentication failed token_preview=eyJhbGciOi...WlvVHlVT7A 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]14552026/07/19 09:49:06 INFO OIDC auth successful provider=test14562026/07/19 09:49:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1457--- PASS: TestService_AuthMiddleware_OIDC (0.64s)1458 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1459 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1460 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)1461 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)1462--- PASS: TestResurrectedObjectNotDeleted (0.65s)14632026/07/19 09:49:06 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst14642026/07/19 09:49:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1465--- PASS: TestCompleteMultipartUnregistered (0.54s)14662026/07/19 09:49:06 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWJiMmY2YjItMWVhZC00ZGU0LWFhNjUtNGU3NjZhNjMzY2EwLjc5NWFmNDQzLTE1ZGMtNDExMC04N2RiLWNlOGZiNjA4NTg5YngxNzg0NDU0NTQ2MjA5MzkwMjA2 parts=11467--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.66s)14682026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures1469=== NAME TestClientMultipleUploads1470 client_integration_test.go:338: Created store path 0: /build/TestClientMultipleUploads1859825038/001/store/jncnk6l52pag2kbhv5wzxjljhb04izcn-test-file-0.txt1471=== NAME TestClientIntegration1472 client_integration_test.go:276: Created store path: /build/TestClientIntegration2593742128/002/store/df0wv8g3x1rr6d9pjwzjjlqrnv4fyy10-test-file.txt1473=== NAME TestPinProtectsFromGC1474 client_integration_test.go:646: Pinned store path: /build/TestPinProtectsFromGC534380471/001/store/n5b2s2xmxankmmji7vqywxn8483fvm2h-pinned-file.txt1475 client_integration_test.go:647: Unpinned store path: /build/TestPinProtectsFromGC534380471/001/store/sbm98jy2q3p1qzz43w18065k3iljycdl-unpinned-file.txt1476=== NAME TestClientWithDependencies1477 client_integration_test.go:593: Built derivation: /build/TestClientWithDependencies2640420386/001/store/c78k43l6r3az02qdcrkxzs1napyaf68i-test-script14782026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures1479=== NAME TestClientMultipleUploads1480 client_integration_test.go:338: Created store path 1: /build/TestClientMultipleUploads1859825038/001/store/whvh25swnwpwpmayz22389p49wnd5d9r-test-file-1.txt14812026/07/19 09:49:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14822026/07/19 09:49:06 INFO Uploading 808grppi8mrsml3815fafspl8p90sv60-file1.txt (160B)14832026/07/19 09:49:06 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14842026/07/19 09:49:06 WARN Failed to register uploaded object key=808grppi8mrsml3815fafspl8p90sv60.ls error="server returned 404: 404 page not found\n"14852026/07/19 09:49:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1486=== NAME TestClientWithDependencies1487 client_integration_test.go:595: Found 1 dependencies (including self)14882026/07/19 09:49:06 INFO Signed narinfos id=1 count=11489=== NAME TestClientCADerivations1490 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations796636047/001/store/0y0s0b1zgihxkgyyfk1xa57vfgyrr38p-ca-test14912026/07/19 09:49:06 INFO Uploading 1 narinfos14922026/07/19 09:49:06 WARN Failed to register uploaded object key=808grppi8mrsml3815fafspl8p90sv60.narinfo error="server returned 404: 404 page not found\n"14932026/07/19 09:49:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1494--- PASS: TestReadProxyHead (0.74s)14952026/07/19 09:49:06 INFO Completed upload id=114962026/07/19 09:49:06 INFO Upload complete. (105ms)1497--- PASS: TestReadProxyConditionalGet (0.74s)1498=== NAME TestNARDeduplicationMetadataUploadBug1499 metadata_upload_test.go:54: Retrieved narinfo from S3:1500 StorePath: /build/TestNARDeduplicationMetadataUploadBug2720869609/001/store/808grppi8mrsml3815fafspl8p90sv60-file1.txt1501 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1502 Compression: zstd1503 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1504 NarSize: 1601505 References: 1506 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf15072026/07/19 09:49:06 INFO Received cleanup request method=DELETE path=/api/pending_closures1508=== NAME TestClientMultipleUploads1509 client_integration_test.go:338: Created store path 2: /build/TestClientMultipleUploads1859825038/001/store/pnfilqy5fnrpvi5mc3ifrfhh5kx48fj1-test-file-2.txt1510=== NAME TestNARDeduplicationMetadataUploadBug1511 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1512 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):15132026/07/19 09:49:06 INFO Aborted multipart uploads count=11514 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1515--- PASS: TestMultipartCleanup (0.75s)1516=== NAME TestClientCADerivations1517 client_ca_test.go:139: Found 1 dependencies (including self)1518=== NAME TestNARDeduplicationMetadataUploadBug1519 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2720869609/001/store/il6yd1fspq1wspxf7bfrvd8gzf1wxs50-file2.txt15202026/07/19 09:49:06 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"15212026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures15222026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures15232026/07/19 09:49:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15242026/07/19 09:49:06 INFO Uploading n5b2s2xmxankmmji7vqywxn8483fvm2h-pinned-file.txt (128B)15252026/07/19 09:49:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15262026/07/19 09:49:06 INFO Uploading c78k43l6r3az02qdcrkxzs1napyaf68i-test-script (136B)1527--- PASS: TestGCBugBareHashReferences (0.81s)15282026/07/19 09:49:06 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15292026/07/19 09:49:06 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15302026/07/19 09:49:06 WARN Failed to register uploaded object key=log/mlyx9m838f5v9g8v85x4ffq9nvlpyrvz-test-script.drv error="server returned 404: 404 page not found\n"15312026/07/19 09:49:06 WARN Failed to register uploaded object key=n5b2s2xmxankmmji7vqywxn8483fvm2h.ls error="server returned 404: 404 page not found\n"15322026/07/19 09:49:06 WARN Failed to register uploaded object key=c78k43l6r3az02qdcrkxzs1napyaf68i.ls error="server returned 404: 404 page not found\n"15332026/07/19 09:49:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15342026/07/19 09:49:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15352026/07/19 09:49:06 INFO Signed narinfos id=1 count=115362026/07/19 09:49:06 INFO Signed narinfos id=1 count=115372026/07/19 09:49:06 INFO Uploading 1 narinfos15382026/07/19 09:49:06 INFO Uploading 1 narinfos15392026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures15402026/07/19 09:49:06 WARN Failed to register uploaded object key=c78k43l6r3az02qdcrkxzs1napyaf68i.narinfo error="server returned 404: 404 page not found\n"15412026/07/19 09:49:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15422026/07/19 09:49:06 WARN Failed to register uploaded object key=n5b2s2xmxankmmji7vqywxn8483fvm2h.narinfo error="server returned 404: 404 page not found\n"15432026/07/19 09:49:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15442026/07/19 09:49:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15452026/07/19 09:49:06 INFO Uploading df0wv8g3x1rr6d9pjwzjjlqrnv4fyy10-test-file.txt (152B)15462026/07/19 09:49:06 INFO Completed upload id=115472026/07/19 09:49:06 INFO Completed upload id=115482026/07/19 09:49:06 INFO Upload complete. (105ms)15492026/07/19 09:49:06 INFO Upload complete. (67ms)15502026/07/19 09:49:06 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15512026/07/19 09:49:06 WARN Failed to register uploaded object key=df0wv8g3x1rr6d9pjwzjjlqrnv4fyy10.ls error="server returned 404: 404 page not found\n"15522026/07/19 09:49:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1553=== NAME TestClientWithDependencies1554 client_integration_test.go:597: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2640420386/001/store) requires matching store prefix15552026/07/19 09:49:06 INFO Signed narinfos id=1 count=115562026/07/19 09:49:06 INFO Uploading 1 narinfos15572026/07/19 09:49:06 WARN Failed to register uploaded object key=df0wv8g3x1rr6d9pjwzjjlqrnv4fyy10.narinfo error="server returned 404: 404 page not found\n"15582026/07/19 09:49:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1559--- PASS: TestClientWithDependencies (0.84s)15602026/07/19 09:49:06 INFO Completed upload id=115612026/07/19 09:49:06 INFO Upload complete. (123ms)1562=== NAME TestClientIntegration1563 client_integration_test.go:292: Retrieved narinfo from S3:1564 StorePath: /build/TestClientIntegration2593742128/002/store/df0wv8g3x1rr6d9pjwzjjlqrnv4fyy10-test-file.txt1565 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1566 Compression: zstd1567 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11568 NarSize: 1521569 References: 1570 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11571 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1572 client_integration_test.go:293: Decompressed .ls content (64 bytes):15732026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures1574 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1575 client_integration_test.go:296: Testing garbage collection...15762026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures15772026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures15782026/07/19 09:49:06 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15792026/07/19 09:49:06 INFO Uploading jncnk6l52pag2kbhv5wzxjljhb04izcn-test-file-0.txt (160B)15802026/07/19 09:49:06 INFO Uploading pnfilqy5fnrpvi5mc3ifrfhh5kx48fj1-test-file-2.txt (160B)15812026/07/19 09:49:06 INFO Uploading whvh25swnwpwpmayz22389p49wnd5d9r-test-file-1.txt (160B)15822026/07/19 09:49:06 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15832026/07/19 09:49:06 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15842026/07/19 09:49:06 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15852026/07/19 09:49:06 WARN Failed to register uploaded object key=jncnk6l52pag2kbhv5wzxjljhb04izcn.ls error="server returned 404: 404 page not found\n"15862026/07/19 09:49:06 WARN Failed to register uploaded object key=whvh25swnwpwpmayz22389p49wnd5d9r.ls error="server returned 404: 404 page not found\n"15872026/07/19 09:49:06 WARN Failed to register uploaded object key=pnfilqy5fnrpvi5mc3ifrfhh5kx48fj1.ls error="server returned 404: 404 page not found\n"15882026/07/19 09:49:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15892026/07/19 09:49:06 INFO Signed narinfos id=1 count=115902026/07/19 09:49:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15912026/07/19 09:49:06 INFO Signed narinfos id=2 count=115922026/07/19 09:49:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15932026/07/19 09:49:06 INFO Signed narinfos id=3 count=115942026/07/19 09:49:06 INFO Uploading 3 narinfos15952026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures15962026/07/19 09:49:06 WARN Failed to register uploaded object key=pnfilqy5fnrpvi5mc3ifrfhh5kx48fj1.narinfo error="server returned 404: 404 page not found\n"15972026/07/19 09:49:06 WARN Failed to register uploaded object key=jncnk6l52pag2kbhv5wzxjljhb04izcn.narinfo error="server returned 404: 404 page not found\n"15982026/07/19 09:49:06 WARN Failed to register uploaded object key=whvh25swnwpwpmayz22389p49wnd5d9r.narinfo error="server returned 404: 404 page not found\n"15992026/07/19 09:49:06 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16002026/07/19 09:49:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures16012026/07/19 09:49:06 INFO Garbage collection started16022026/07/19 09:49:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16032026/07/19 09:49:06 INFO Uploading 0y0s0b1zgihxkgyyfk1xa57vfgyrr38p-ca-test (144B)16042026/07/19 09:49:06 INFO Completed upload id=216052026/07/19 09:49:06 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16062026/07/19 09:49:06 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16072026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures16082026/07/19 09:49:06 INFO Completed upload id=316092026/07/19 09:49:06 WARN Failed to register uploaded object key=log/6ah5i05sq04n6pddaw31dfh9rz93rpx9-ca-test.drv error="server returned 404: 404 page not found\n"16102026/07/19 09:49:06 INFO Aborted multipart uploads count=016112026/07/19 09:49:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16122026/07/19 09:49:06 WARN Failed to register uploaded object key=0y0s0b1zgihxkgyyfk1xa57vfgyrr38p.ls error="server returned 404: 404 page not found\n"16132026/07/19 09:49:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16142026/07/19 09:49:06 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16152026/07/19 09:49:06 INFO Completed upload id=116162026/07/19 09:49:06 INFO Upload complete. (115ms)1617=== NAME TestClientMultipleUploads1618 client_integration_test.go:349: Uploaded 3 paths in 146.502333ms16192026/07/19 09:49:06 INFO Signed narinfos id=1 count=116202026/07/19 09:49:06 WARN Force mode enabled - objects will be deleted immediately without grace period16212026/07/19 09:49:06 INFO Uploading 1 narinfos16222026/07/19 09:49:06 WARN Failed to register uploaded object key=il6yd1fspq1wspxf7bfrvd8gzf1wxs50.ls error="server returned 404: 404 page not found\n"16232026/07/19 09:49:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16242026/07/19 09:49:06 INFO Signed narinfos id=2 count=116252026/07/19 09:49:06 INFO Uploading 1 narinfos16262026/07/19 09:49:06 WARN Failed to register uploaded object key=0y0s0b1zgihxkgyyfk1xa57vfgyrr38p.narinfo error="server returned 404: 404 page not found\n"16272026/07/19 09:49:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16282026/07/19 09:49:06 WARN Failed to register uploaded object key=il6yd1fspq1wspxf7bfrvd8gzf1wxs50.narinfo error="server returned 404: 404 page not found\n"16292026/07/19 09:49:06 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16302026/07/19 09:49:06 INFO Completed upload id=216312026/07/19 09:49:06 INFO Upload complete. (82ms)16322026/07/19 09:49:06 INFO Completed upload id=116332026/07/19 09:49:06 INFO Upload complete. (116ms)1634=== NAME TestNARDeduplicationMetadataUploadBug1635 metadata_upload_test.go:76: Retrieved narinfo from S3:1636 StorePath: /build/TestNARDeduplicationMetadataUploadBug2720869609/001/store/il6yd1fspq1wspxf7bfrvd8gzf1wxs50-file2.txt1637 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1638 Compression: zstd1639 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1640 NarSize: 1601641 References: 1642 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1643=== NAME TestOrphanedObjectsGC1644 orphaned_objects_gc_test.go:290: GC Test Summary:1645 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1646 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1647 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1648 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1649 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1650--- PASS: TestOrphanedObjectsGC (0.91s)1651--- PASS: TestClientMultipleUploads (0.91s)1652=== NAME TestClientCADerivations1653 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations796636047/001/store/0y0s0b1zgihxkgyyfk1xa57vfgyrr38p-ca-test1654 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1655 Compression: zstd1656 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1657 NarSize: 1441658 References: 1659 Deriver: /build/TestClientCADerivations796636047/001/store/6ah5i05sq04n6pddaw31dfh9rz93rpx9-ca-test.drv1660 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1661 client_ca_test.go:185: Checking for realisation files in S3...1662=== NAME TestNARDeduplicationMetadataUploadBug1663 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1664 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1665 {"version":1,"root":{"type":"regular","size":44}}1666=== NAME TestClientCADerivations1667 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1668 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1669--- PASS: TestNARDeduplicationMetadataUploadBug (0.92s)16702026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures16712026/07/19 09:49:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16722026/07/19 09:49:06 INFO Uploading sbm98jy2q3p1qzz43w18065k3iljycdl-unpinned-file.txt (128B)16732026/07/19 09:49:06 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16742026/07/19 09:49:06 WARN Failed to register uploaded object key=sbm98jy2q3p1qzz43w18065k3iljycdl.ls error="server returned 404: 404 page not found\n"16752026/07/19 09:49:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16762026/07/19 09:49:06 INFO Signed narinfos id=2 count=116772026/07/19 09:49:06 INFO Uploading 1 narinfos16782026/07/19 09:49:06 WARN Failed to register uploaded object key=sbm98jy2q3p1qzz43w18065k3iljycdl.narinfo error="server returned 404: 404 page not found\n"16792026/07/19 09:49:06 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16802026/07/19 09:49:06 INFO Completed upload id=216812026/07/19 09:49:06 INFO Upload complete. (87ms)16822026/07/19 09:49:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16832026/07/19 09:49:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16842026/07/19 09:49:06 INFO Received create pin request method=POST path=/api/pins/myapp16852026/07/19 09:49:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16862026/07/19 09:49:06 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC534380471/001/store/n5b2s2xmxankmmji7vqywxn8483fvm2h-pinned-file.txt narinfo_key=n5b2s2xmxankmmji7vqywxn8483fvm2h.narinfo16872026/07/19 09:49:06 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MWJiMmY2YjItMWVhZC00ZGU0LWFhNjUtNGU3NjZhNjMzY2EwLjU5MGYyOTMxLTkxYTAtNGMxZS1hZTg5LWIxNTQyODEzYmU2NngxNzg0NDU0NTQ2MjA5NjIyNTQ4 parts=1016882026/07/19 09:49:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16892026/07/19 09:49:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures16902026/07/19 09:49:06 INFO Garbage collection started16912026/07/19 09:49:06 INFO Completed upload id=116922026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures16932026/07/19 09:49:06 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MWJiMmY2YjItMWVhZC00ZGU0LWFhNjUtNGU3NjZhNjMzY2EwLjRlNmQ2YzE3LTg5N2MtNDIyNC1hM2QwLTM0ZmQyMDBiMjA3YXgxNzg0NDU0NTQ2MTQ1NjIwNDI5 parts=1216942026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures16952026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures1696--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.99s)16972026/07/19 09:49:06 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16982026/07/19 09:49:06 WARN Found objects in DB but missing from S3, will re-upload count=11699--- PASS: TestService_verifyS3Integrity (0.99s)17002026/07/19 09:49:06 INFO Aborted multipart uploads count=017012026/07/19 09:49:06 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MWJiMmY2YjItMWVhZC00ZGU0LWFhNjUtNGU3NjZhNjMzY2EwLmM3NmUxNjVmLTM1YjAtNGRkMy04YjA4LTc4ZDRiYmY0MGU0OXgxNzg0NDU0NTQ2MjI4NjYyODY5 parts=1017022026/07/19 09:49:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17032026/07/19 09:49:06 WARN Force mode enabled - objects will be deleted immediately without grace period17042026/07/19 09:49:06 INFO Completed upload id=117052026/07/19 09:49:06 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000017062026/07/19 09:49:06 INFO Received uploads request method=POST path=/api/pending_closures17072026/07/19 09:49:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures17082026/07/19 09:49:06 INFO Aborted multipart uploads count=01709=== NAME TestClientCADerivations1710 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1711 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1712 error: binary cache 's3://bucket41?endpoint=http://localhost:36925&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations796636047/001/store'1713 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117142026/07/19 09:49:06 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=01715--- PASS: TestClientCADerivations (1.02s)17162026/07/19 09:49:06 INFO Vacuumed table table=pending_closures17172026/07/19 09:49:06 INFO Vacuumed table table=pending_objects17182026/07/19 09:49:06 INFO Vacuumed table table=multipart_uploads17192026/07/19 09:49:06 INFO Vacuumed table table=closures17202026/07/19 09:49:06 INFO Vacuumed table table=objects17212026/07/19 09:49:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17222026/07/19 09:49:06 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=844.589082ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17232026/07/19 09:49:06 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001724--- PASS: TestService_createPendingClosureHandler (1.05s)17252026/07/19 09:49:06 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MWJiMmY2YjItMWVhZC00ZGU0LWFhNjUtNGU3NjZhNjMzY2EwLmNiMWNhMDY3LTk5ZDEtNGFlNi04NzdmLWE2M2IxNjRmZjA0M3gxNzg0NDU0NTQ2MjQzNDg3NTcz parts=121726--- PASS: TestRedundantMultipartUpload (1.06s)1727--- PASS: TestUploadHandlersRejectOversizedBody (0.24s)1728 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1729 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1730 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.11s)1731=== NAME TestOrphanedObjectsGCStressTest1732 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1733 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion17342026/07/19 09:49:07 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=017352026/07/19 09:49:07 INFO Vacuumed table table=pending_closures17362026/07/19 09:49:07 INFO Vacuumed table table=pending_objects17372026/07/19 09:49:07 INFO Vacuumed table table=multipart_uploads17382026/07/19 09:49:07 INFO Vacuumed table table=closures17392026/07/19 09:49:07 INFO Vacuumed table table=objects1740 orphaned_objects_gc_test.go:509: Stress test completed successfully:1741 orphaned_objects_gc_test.go:510: - Active objects preserved: 201742 orphaned_objects_gc_test.go:511: - Objects deleted: 2101743 orphaned_objects_gc_test.go:512: - Total GC'd: 2101744--- PASS: TestOrphanedObjectsGCStressTest (1.70s)17452026/07/19 09:49:07 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=017462026/07/19 09:49:07 INFO Vacuumed table table=pending_closures17472026/07/19 09:49:07 INFO Vacuumed table table=pending_objects17482026/07/19 09:49:07 INFO Vacuumed table table=multipart_uploads17492026/07/19 09:49:07 INFO Vacuumed table table=closures17502026/07/19 09:49:07 INFO Vacuumed table table=objects17512026/07/19 09:49:07 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.588983896s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17522026/07/19 09:49:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01753=== NAME TestClientIntegration1754 client_integration_test.go:303: Objects in database after GC:1755 client_integration_test.go:303: Successfully deleted all objects with GC --force1756--- PASS: TestClientIntegration (2.89s)17572026/07/19 09:49:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01758=== NAME TestPinProtectsFromGC1759 client_integration_test.go:709: Pin successfully protected closure from garbage collection1760--- PASS: TestPinProtectsFromGC (2.99s)1761--- PASS: TestClientErrorHandling (0.11s)1762 --- PASS: TestClientErrorHandling/InvalidStorePath (0.56s)1763 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.68s)1764 --- PASS: TestClientErrorHandling/ServerNotAvailable (3.37s)17652026/07/19 09:49:11 WARN Rate limiter enabled after throttle name=s3-test rate=517662026/07/19 09:49:11 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1767=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1768 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101769 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001770--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.90s)1771PASS17722026-07-19 09:49:12.130 UTC [205] LOG: received smart shutdown request17732026-07-19 09:49:12.135 UTC [205] LOG: background worker "logical replication launcher" (PID 215) exited with exit code 117742026-07-19 09:49:12.144 UTC [210] LOG: shutting down17752026-07-19 09:49:12.145 UTC [210] LOG: checkpoint starting: shutdown immediate17762026-07-19 09:49:13.075 UTC [210] LOG: checkpoint complete: wrote 8095 buffers (49.4%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 13 recycled; write=0.177 s, sync=0.745 s, total=0.931 s; sync files=15167, longest=0.019 s, average=0.001 s; distance=208460 kB, estimate=208460 kB; lsn=0/E2F22E0, redo lsn=0/E2F22E017772026-07-19 09:49:13.189 UTC [205] LOG: database system is shut down1778Running OIDC tests...1779=== RUN TestGlobMatch1780=== PAUSE TestGlobMatch1781=== RUN TestAudienceForIssuer1782=== PAUSE TestAudienceForIssuer1783=== RUN TestValidateToken_ValidToken1784=== PAUSE TestValidateToken_ValidToken1785=== RUN TestValidateToken_WrongAudience1786=== PAUSE TestValidateToken_WrongAudience1787=== RUN TestValidateToken_Expired1788=== PAUSE TestValidateToken_Expired1789=== RUN TestValidateToken_BoundClaimsMismatch1790=== PAUSE TestValidateToken_BoundClaimsMismatch1791=== RUN TestValidateToken_BoundSubjectMismatch1792=== PAUSE TestValidateToken_BoundSubjectMismatch1793=== RUN TestValidateToken_MultipleProviders1794=== PAUSE TestValidateToken_MultipleProviders1795=== RUN TestValidateToken_NoMatchingProvider1796=== PAUSE TestValidateToken_NoMatchingProvider1797=== CONT TestGlobMatch1798=== RUN TestGlobMatch/foo_foo1799=== PAUSE TestGlobMatch/foo_foo1800=== RUN TestGlobMatch/foo_bar1801=== PAUSE TestGlobMatch/foo_bar1802=== CONT TestValidateToken_NoMatchingProvider1803=== CONT TestValidateToken_BoundClaimsMismatch1804=== CONT TestValidateToken_WrongAudience1805=== RUN TestGlobMatch/*_1806=== PAUSE TestGlobMatch/*_1807=== RUN TestGlobMatch/*_anything1808=== PAUSE TestGlobMatch/*_anything1809=== RUN TestGlobMatch/foo*_foo1810=== PAUSE TestGlobMatch/foo*_foo1811=== RUN TestGlobMatch/foo*_foobar1812=== PAUSE TestGlobMatch/foo*_foobar1813=== RUN TestGlobMatch/foo*_bar1814=== PAUSE TestGlobMatch/foo*_bar1815=== RUN TestGlobMatch/*bar_bar1816=== PAUSE TestGlobMatch/*bar_bar1817=== CONT TestValidateToken_ValidToken1818=== CONT TestAudienceForIssuer1819=== CONT TestValidateToken_MultipleProviders1820=== CONT TestValidateToken_BoundSubjectMismatch1821--- PASS: TestAudienceForIssuer (0.00s)1822=== CONT TestValidateToken_Expired1823=== RUN TestGlobMatch/*bar_foobar1824=== PAUSE TestGlobMatch/*bar_foobar1825=== RUN TestGlobMatch/*bar_foo1826=== PAUSE TestGlobMatch/*bar_foo1827=== RUN TestGlobMatch/foo*bar_foobar1828=== PAUSE TestGlobMatch/foo*bar_foobar1829=== RUN TestGlobMatch/foo*bar_foo123bar1830=== PAUSE TestGlobMatch/foo*bar_foo123bar1831=== RUN TestGlobMatch/foo*bar_foobarbaz1832=== PAUSE TestGlobMatch/foo*bar_foobarbaz1833=== RUN TestGlobMatch/*/*_foo/bar1834=== PAUSE TestGlobMatch/*/*_foo/bar1835=== RUN TestGlobMatch/*/*_foo1836=== PAUSE TestGlobMatch/*/*_foo1837=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1838=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1839=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01840=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01841=== RUN TestGlobMatch/refs/*/main_refs/heads/main1842=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1843=== RUN TestGlobMatch/fo?_foo1844=== PAUSE TestGlobMatch/fo?_foo1845=== RUN TestGlobMatch/fo?_fo1846=== PAUSE TestGlobMatch/fo?_fo1847=== RUN TestGlobMatch/fo?_fooo1848=== PAUSE TestGlobMatch/fo?_fooo1849=== RUN TestGlobMatch/?oo_foo1850=== PAUSE TestGlobMatch/?oo_foo1851=== RUN TestGlobMatch/?oo_boo1852=== PAUSE TestGlobMatch/?oo_boo1853=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1854=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1855=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1856=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1857=== CONT TestGlobMatch/foo_foo1858=== CONT TestGlobMatch/fo?_fo1859=== CONT TestGlobMatch/?oo_foo1860=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1861=== CONT TestGlobMatch/foo*_foo1862=== CONT TestGlobMatch/*_anything1863=== CONT TestGlobMatch/*_1864=== CONT TestGlobMatch/foo_bar1865=== CONT TestGlobMatch/foo*_bar1866=== CONT TestGlobMatch/*bar_bar1867=== CONT TestGlobMatch/*/*_foo/bar1868=== CONT TestGlobMatch/*/*_foo1869=== CONT TestGlobMatch/fo?_fooo1870=== CONT TestGlobMatch/foo*bar_foobarbaz1871=== CONT TestGlobMatch/refs/*/main_refs/heads/main1872=== CONT TestGlobMatch/fo?_foo1873=== CONT TestGlobMatch/foo*_foobar1874=== CONT TestGlobMatch/foo*bar_foo123bar1875=== CONT TestGlobMatch/foo*bar_foobar1876=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1877=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01878=== CONT TestGlobMatch/*bar_foo1879=== CONT TestGlobMatch/?oo_boo1880=== CONT TestGlobMatch/*bar_foobar1881=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1882--- PASS: TestGlobMatch (0.01s)1883 --- PASS: TestGlobMatch/foo_foo (0.00s)1884 --- PASS: TestGlobMatch/fo?_fo (0.00s)1885 --- PASS: TestGlobMatch/?oo_foo (0.00s)1886 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1887 --- PASS: TestGlobMatch/foo*_foo (0.00s)1888 --- PASS: TestGlobMatch/*_anything (0.00s)1889 --- PASS: TestGlobMatch/*_ (0.00s)1890 --- PASS: TestGlobMatch/foo_bar (0.00s)1891 --- PASS: TestGlobMatch/foo*_bar (0.00s)1892 --- PASS: TestGlobMatch/*bar_bar (0.00s)1893 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1894 --- PASS: TestGlobMatch/*/*_foo (0.00s)1895 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1896 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1897 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1898 --- PASS: TestGlobMatch/fo?_foo (0.00s)1899 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1900 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1901 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1902 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1903 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1904 --- PASS: TestGlobMatch/*bar_foo (0.00s)1905 --- PASS: TestGlobMatch/?oo_boo (0.00s)1906 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1907 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)19082026/07/19 09:49:14 INFO OIDC provider initialized name=provider119092026/07/19 09:49:14 INFO OIDC provider initialized name=test19102026/07/19 09:49:14 INFO OIDC provider initialized name=test19112026/07/19 09:49:14 INFO OIDC provider initialized name=test19122026/07/19 09:49:14 INFO OIDC provider initialized name=provider119132026/07/19 09:49:14 INFO OIDC provider initialized name=test19142026/07/19 09:49:14 INFO OIDC provider initialized name=test19152026/07/19 09:49:14 INFO OIDC provider initialized name=provider21916--- PASS: TestValidateToken_ValidToken (0.01s)1917--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1918--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)1919--- PASS: TestValidateToken_Expired (0.01s)1920--- PASS: TestValidateToken_WrongAudience (0.02s)1921--- PASS: TestValidateToken_NoMatchingProvider (0.02s)1922--- PASS: TestValidateToken_MultipleProviders (0.02s)1923PASS1924Running hook tests...1925=== RUN TestSendPathsEmpty1926=== PAUSE TestSendPathsEmpty1927=== RUN TestQueueEnqueueAndFetch1928=== PAUSE TestQueueEnqueueAndFetch1929=== RUN TestQueueDeduplication1930=== PAUSE TestQueueDeduplication1931=== RUN TestQueueRemove1932=== PAUSE TestQueueRemove1933=== RUN TestQueueFetchBatchLimit1934=== PAUSE TestQueueFetchBatchLimit1935=== RUN TestQueueFetchRemoveLifecycle1936=== PAUSE TestQueueFetchRemoveLifecycle1937=== RUN TestQueueConcurrentWriters1938=== PAUSE TestQueueConcurrentWriters1939=== RUN TestServerClientIntegration1940=== PAUSE TestServerClientIntegration1941=== RUN TestServerQueueError1942=== PAUSE TestServerQueueError1943=== RUN TestGetListenerSocketActivation1944 server_test.go:210: === RUN TestGetListenerSocketActivation1945 --- PASS: TestGetListenerSocketActivation (0.00s)1946 PASS1947 1948--- PASS: TestGetListenerSocketActivation (0.01s)1949=== RUN TestWorkerUploadsAndRemoves1950=== PAUSE TestWorkerUploadsAndRemoves1951=== RUN TestWorkerSkipsGCdPaths1952=== PAUSE TestWorkerSkipsGCdPaths1953=== RUN TestWorkerPrunesClosureDeps1954=== PAUSE TestWorkerPrunesClosureDeps1955=== CONT TestSendPathsEmpty1956=== CONT TestWorkerPrunesClosureDeps1957=== CONT TestQueueEnqueueAndFetch1958=== CONT TestQueueRemove1959=== CONT TestQueueFetchRemoveLifecycle1960=== CONT TestQueueFetchBatchLimit1961=== CONT TestWorkerUploadsAndRemoves1962=== CONT TestWorkerSkipsGCdPaths1963=== CONT TestServerQueueError1964=== CONT TestServerClientIntegration1965=== CONT TestQueueDeduplication1966--- PASS: TestSendPathsEmpty (0.00s)1967=== CONT TestQueueConcurrentWriters19682026/07/19 09:49:14 ERROR Failed to queue paths error="permission denied" count=11969--- PASS: TestServerClientIntegration (0.00s)1970--- PASS: TestServerQueueError (0.00s)19712026/07/19 09:49:14 INFO Upload queue status pending=219722026/07/19 09:49:14 INFO Uploading batch count=11973--- PASS: TestQueueDeduplication (0.01s)1974--- PASS: TestQueueEnqueueAndFetch (0.02s)1975--- PASS: TestQueueFetchBatchLimit (0.01s)19762026/07/19 09:49:14 INFO Upload queue status pending=219772026/07/19 09:49:14 INFO Upload queue status pending=219782026/07/19 09:49:14 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths311120633/002/nonexistent19792026/07/19 09:49:14 INFO Uploading batch count=21980--- PASS: TestQueueFetchRemoveLifecycle (0.02s)19812026/07/19 09:49:14 INFO Uploading batch count=11982--- PASS: TestQueueRemove (0.02s)1983--- PASS: TestWorkerUploadsAndRemoves (0.06s)1984--- PASS: TestWorkerPrunesClosureDeps (0.07s)1985--- PASS: TestWorkerSkipsGCdPaths (0.06s)1986--- PASS: TestQueueConcurrentWriters (0.21s)1987PASS

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

succeeded `niks3-go-unit-tests` `aarch64-linux.go-unit-tests` · build #103 · raw