niks3-go-unit-tests
aarch64-linux.go-unit-tests
· build #100
· 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 TestResolveStorePath73=== CONT TestFileTokenMissing74=== CONT TestSetClientTLSDoesNotMutateDefaultTransport75=== CONT TestSetClientTLS76=== CONT TestScriptTokenNoExpiryRerunsEveryCall77=== CONT TestFileTokenReadsAndCaches78=== CONT TestFileTokenEmpty79--- PASS: TestFileTokenMissing (0.01s)80=== CONT TestScriptTokenEmptyToken81=== CONT TestScriptTokenCachesUntilRefresh82=== CONT TestConvertHashToNix3283=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess84=== CONT TestRateLimiterFeedback85=== CONT TestScriptTokenBadJSON86=== CONT TestScriptTokenScriptFails87=== CONT TestParsePathInfoJSONMultiplePaths88=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths89--- PASS: TestResolveStorePath (0.01s)90=== CONT TestParsePathInfoJSON91=== CONT TestDumpPathSingleFile92=== CONT TestPathInfoHashCompatibility93=== CONT TestEncodeNixBase32WithRealHash94=== CONT TestGetStorePathHash95=== CONT TestEncodeNixBase3296=== CONT TestDumpPathWriterError97=== CONT TestUploadMultipart_SupersededByPeer98=== CONT TestDumpPathMatchesNix99=== CONT TestShellSplit100=== CONT TestSetClientTLSErrors101=== CONT TestShellSplitErrors102=== CONT TestDoWithRetry_BodyReplayedViaGetBody103=== CONT TestPartSizeForNAR104=== CONT TestCaseHackSuffix105=== CONT TestScriptTokenEmptyCommand106=== CONT TestStaticToken107=== RUN TestRateLimiterFeedback/429_enables_limiter108=== PAUSE TestRateLimiterFeedback/429_enables_limiter109=== CONT TestPathInfoCACompatibility1102026/07/18 13:54:38 WARN Rate limiter enabled after throttle name=server-test rate=5111=== RUN TestPartSizeForNAR/zero_stays_at_minimum112=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum113=== RUN TestPartSizeForNAR/small_stays_at_minimum114=== PAUSE TestPartSizeForNAR/small_stays_at_minimum115=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum116=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum117=== RUN TestPathInfoCACompatibility/null_ca_field118=== PAUSE TestPathInfoCACompatibility/null_ca_field119=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths120=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)121=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)122--- PASS: TestEncodeNixBase32WithRealHash (0.00s)123--- PASS: TestStaticToken (0.00s)124--- PASS: TestShellSplit (0.00s)125--- PASS: TestScriptTokenEmptyCommand (0.00s)126--- PASS: TestShellSplitErrors (0.00s)127=== RUN TestParsePathInfoJSON/Nix_format128=== PAUSE TestParsePathInfoJSON/Nix_format129=== RUN TestGetStorePathHash/valid_store_path130=== PAUSE TestGetStorePathHash/valid_store_path131=== RUN TestUploadMultipart_SupersededByPeer/exists132=== PAUSE TestUploadMultipart_SupersededByPeer/exists133=== RUN TestEncodeNixBase32/test_string_hash134=== PAUSE TestEncodeNixBase32/test_string_hash135=== RUN TestConvertHashToNix32/SRI_format_to_Nix32136=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32137--- PASS: TestFileTokenReadsAndCaches (0.00s)138--- PASS: TestFileTokenEmpty (0.00s)139=== RUN TestRateLimiterFeedback/503_enables_limiter140--- PASS: TestScriptTokenScriptFails (0.01s)141=== RUN TestParsePathInfoJSON/Lix_format142=== PAUSE TestParsePathInfoJSON/Lix_format143=== RUN TestUploadMultipart_SupersededByPeer/missing144=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts145=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts146=== PAUSE TestUploadMultipart_SupersededByPeer/missing147=== CONT TestUploadMultipart_SupersededByPeer/exists148=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths149=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths150=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths151=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon152=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon153=== PAUSE TestRateLimiterFeedback/503_enables_limiter154=== RUN TestGetStorePathHash/basename_without_hyphen_should_error155=== RUN TestParsePathInfoJSON/empty_input156=== RUN TestEncodeNixBase32/empty_input157=== RUN TestConvertHashToNix32/already_Nix32_format158=== RUN TestPathInfoCACompatibility/old_string_format_-_text159=== RUN TestPartSizeForNAR/1_TiB160=== CONT TestUploadMultipart_SupersededByPeer/missing161--- PASS: TestScriptTokenBadJSON (0.01s)162--- PASS: TestScriptTokenEmptyToken (0.02s)163=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths164=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error165=== PAUSE TestParsePathInfoJSON/empty_input166=== PAUSE TestEncodeNixBase32/empty_input167=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter168=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI169=== RUN TestSetClientTLSErrors/missing_cert_file170=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text171=== PAUSE TestSetClientTLSErrors/missing_cert_file172=== PAUSE TestConvertHashToNix32/already_Nix32_format173=== PAUSE TestPartSizeForNAR/1_TiB174=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error175--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.03s)176--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)177=== RUN TestParsePathInfoJSON/whitespace_only178=== CONT TestEncodeNixBase32/test_string_hash179=== CONT TestEncodeNixBase32/empty_input180=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter181=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI182=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive183=== RUN TestSetClientTLSErrors/missing_key_file184=== RUN TestConvertHashToNix32/invalid_format185=== RUN TestSetClientTLS/rejects_connection_without_client_cert186=== RUN TestPartSizeForNAR/5_TiB_S3_max_object187=== PAUSE TestSetClientTLSErrors/missing_key_file1882026/07/18 13:54:38 WARN Rate limiter enabled after throttle name=server-test rate=5189=== RUN TestSetClientTLSErrors/missing_ca_file190--- PASS: TestDoServerRequestAttachesToken (0.04s)191=== PAUSE TestParsePathInfoJSON/whitespace_only1922026/07/18 13:54:38 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43053193=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter194=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive195=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512196=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error197=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert198=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA199=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA200=== RUN TestSetClientTLS/preserves_debug_logging_transport201=== PAUSE TestConvertHashToNix32/invalid_format202=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object203=== RUN TestPartSizeForNAR/capped_at_5_GiB2042026/07/18 13:54:38 WARN Rate limiter backed off name=server-test rate=5205=== PAUSE TestSetClientTLSErrors/missing_ca_file2062026/07/18 13:54:38 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43053207--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)208 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.01s)209 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)210=== RUN TestParsePathInfoJSON/invalid_JSON211=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter212=== RUN TestPathInfoCACompatibility/new_structured_format_-_text213=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512214=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error215=== PAUSE TestSetClientTLS/preserves_debug_logging_transport216=== CONT TestConvertHashToNix32/SRI_format_to_Nix32217=== CONT TestConvertHashToNix32/invalid_format218=== CONT TestConvertHashToNix32/already_Nix32_format219=== PAUSE TestPartSizeForNAR/capped_at_5_GiB220=== CONT TestPartSizeForNAR/zero_stays_at_minimum221=== CONT TestPartSizeForNAR/5_TiB_S3_max_object222=== CONT TestPartSizeForNAR/1_TiB223=== CONT TestPartSizeForNAR/small_stays_at_minimum224--- PASS: TestEncodeNixBase32 (0.02s)225 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)226 --- PASS: TestEncodeNixBase32/empty_input (0.00s)227--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)228=== PAUSE TestParsePathInfoJSON/invalid_JSON229--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)230=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter231=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter232=== CONT TestRateLimiterFeedback/503_enables_limiter233=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text234=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)235=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512236=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI237=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon238=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error239=== CONT TestGetStorePathHash/valid_store_path240=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error241=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error242=== CONT TestSetClientTLS/preserves_debug_logging_transport243=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA2442026/07/18 13:54:38 WARN Rate limiter enabled after throttle name=server-test rate=5245=== RUN TestSetClientTLSErrors/invalid_ca_file2462026/07/18 13:54:38 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:35797247=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum248=== CONT TestPartSizeForNAR/capped_at_5_GiB249=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts250=== CONT TestParsePathInfoJSON/Nix_format251=== CONT TestParsePathInfoJSON/empty_input252=== CONT TestParsePathInfoJSON/Lix_format253=== CONT TestRateLimiterFeedback/429_enables_limiter2542026/07/18 13:54:38 WARN Rate limiter backed off name=server-test rate=5255=== CONT TestParsePathInfoJSON/whitespace_only256=== CONT TestParsePathInfoJSON/invalid_JSON257--- PASS: TestConvertHashToNix32 (0.03s)258 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)259 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)260 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)261=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method262=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method263=== CONT TestGetStorePathHash/basename_without_hyphen_should_error264=== CONT TestSetClientTLS/rejects_connection_without_client_cert2652026/07/18 13:54:38 WARN Rate limiter enabled after throttle name=server-test rate=5266=== PAUSE TestSetClientTLSErrors/invalid_ca_file2672026/07/18 13:54:38 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:39491268--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)269 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)270 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.02s)271=== CONT TestPathInfoCACompatibility/null_ca_field272--- PASS: TestPathInfoHashCompatibility (0.03s)273 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)274 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)275 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)276 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)277=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method278--- PASS: TestPartSizeForNAR (0.03s)279 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)280 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)281 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)282 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)283 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)284 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)285 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)286--- PASS: TestParsePathInfoJSON (0.03s)287 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)288 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)289 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)290 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)291 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)292=== CONT TestPathInfoCACompatibility/new_structured_format_-_text293=== CONT TestPathInfoCACompatibility/old_string_format_-_text2942026/07/18 13:54:38 WARN Rate limiter backed off name=server-test rate=5295=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive296=== CONT TestSetClientTLSErrors/missing_cert_file297=== CONT TestSetClientTLSErrors/invalid_ca_file298=== CONT TestSetClientTLSErrors/missing_ca_file299=== CONT TestSetClientTLSErrors/missing_key_file300--- PASS: TestGetStorePathHash (0.03s)301 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)302 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)303 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)304 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)305--- PASS: TestPathInfoCACompatibility (0.03s)306 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)307 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)308 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)309 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)310 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)311--- PASS: TestRateLimiterFeedback (0.03s)312 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)313 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)314 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)315 --- PASS: TestRateLimiterFeedback/429_enables_limiter (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/missing_ca_file (0.00s)320 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)3212026/07/18 13:54:38 http: TLS handshake error from 127.0.0.1:60712: remote error: tls: bad certificate322--- PASS: TestSetClientTLS (0.04s)323 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.00s)324 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)325 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)326--- PASS: TestDumpPathWriterError (0.09s)327--- PASS: TestDumpPathSingleFile (0.10s)328--- PASS: TestCaseHackSuffix (0.10s)329--- PASS: TestDumpPathMatchesNix (0.13s)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/postgres851983721/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/postgres851983721/data -l logfile start359360/build/postgres851983721:5432 - no response3612026-07-18 13:54:39.890 UTC [248] LOG: starting PostgreSQL 18.4 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit3622026-07-18 13:54:39.891 UTC [248] LOG: listening on Unix socket "/build/postgres851983721/.s.PGSQL.5432"3632026-07-18 13:54:39.895 UTC [255] LOG: database system was shut down at 2026-07-18 13:54:39 UTC3642026-07-18 13:54:39.899 UTC [248] LOG: database system is ready to accept connections365/build/postgres851983721:5432 - accepting connections366{"timestamp":"2026-07-18T13:54:40.243320085Z","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(377)"}367368thread 'rustfs-worker' (641) panicked at /build/rustfs-1.0.0-beta.7-vendor/source-registry-0/reqwest-0.13.4/src/async_impl/client.rs:2507:38:369Client::new(): reqwest::Error { kind: Builder, source: General("No CA certificates were loaded from the system") }370note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace371=== RUN TestService_AuthMiddleware372=== PAUSE TestService_AuthMiddleware373=== RUN TestService_AuthMiddleware_MTLSProxyHeader374=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader375=== RUN TestService_AuthMiddleware_MTLSBoundSubjects376=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects377=== RUN TestService_ReadAuthMiddleware378=== PAUSE TestService_ReadAuthMiddleware379=== RUN TestService_AuthMiddleware_OIDC380=== PAUSE TestService_AuthMiddleware_OIDC381=== RUN TestCacheConfigHandler382=== PAUSE TestCacheConfigHandler383=== RUN TestCacheStatsHandler384=== PAUSE TestCacheStatsHandler385=== RUN TestClientCADerivations386=== PAUSE TestClientCADerivations387=== RUN TestClientErrorHandling388=== PAUSE TestClientErrorHandling389=== RUN TestClientIntegration390=== PAUSE TestClientIntegration391=== RUN TestClientMultipleUploads392=== PAUSE TestClientMultipleUploads393=== RUN TestClientWithDependencies394=== PAUSE TestClientWithDependencies395=== RUN TestPinProtectsFromGC396=== PAUSE TestPinProtectsFromGC397=== RUN TestGCAdvisoryLockBlocksConcurrentRun3982026-07-18 13:54:40.418 UTC [668] ERROR: relation "goose_db_version" does not exist at character 363992026-07-18 13:54:40.418 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4002026/07/18 13:54:40 OK 20241026095416_initial_model.sql (11.14ms)4012026/07/18 13:54:40 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)4022026/07/18 13:54:40 OK 20251218171726_add_pins.sql (3.75ms)4032026/07/18 13:54:40 OK 20260628120000_add_object_size_and_stats.sql (3.38ms)4042026/07/18 13:54:40 goose: successfully migrated database to version: 202606281200004052026/07/18 13:54:40 OK 1_commit_pending_closure.sql (2.36ms)4062026/07/18 13:54:40 OK 2_object_stats_trigger.sql (1.04ms)4072026/07/18 13:54:40 goose: up to current file version: 2408--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.19s)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 TestService_Rustfstest484=== PAUSE TestService_Rustfstest485=== RUN TestSystemdListenerNotActivated486--- PASS: TestSystemdListenerNotActivated (0.00s)487=== RUN TestWatchdogBeatsWhenHealthy488--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)489=== RUN TestWatchdogSkipsWhenUnhealthy4902026/07/18 13:54:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4912026/07/18 13:54:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4922026/07/18 13:54:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4932026/07/18 13:54:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4942026/07/18 13:54:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4952026/07/18 13:54:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4962026/07/18 13:54:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4972026/07/18 13:54:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4982026/07/18 13:54:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4992026/07/18 13:54:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"500--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)501=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle502=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle503=== RUN TestProxyWriteTimeout504=== PAUSE TestProxyWriteTimeout505=== RUN TestIsValidUploadKey506=== PAUSE TestIsValidUploadKey507=== RUN TestUploadHandlersRejectInvalidKeys508=== PAUSE TestUploadHandlersRejectInvalidKeys509=== RUN TestUploadHandlersRejectOversizedBody510=== PAUSE TestUploadHandlersRejectOversizedBody511=== RUN TestService_cleanupPendingClosuresHandler512=== PAUSE TestService_cleanupPendingClosuresHandler513=== RUN TestService_createPendingClosureHandler514=== PAUSE TestService_createPendingClosureHandler515=== RUN TestService_verifyS3Integrity516=== PAUSE TestService_verifyS3Integrity517=== RUN TestCompleteMultipartUnregistered518=== PAUSE TestCompleteMultipartUnregistered519=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT520=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT521=== CONT TestReadProxyNarStreaming522=== CONT TestReadProxyRangeRequest523=== CONT TestService_AuthMiddleware524=== CONT TestReadProxyNarinfoAlreadyDecompressed525=== CONT TestReadProxyNarinfo526=== CONT TestIsValidCachePath527=== CONT TestParseSingleRange528=== CONT TestResurrectedObjectNotDeleted529=== CONT TestGCTaskStore_DeduplicateSameParams530--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)531=== CONT TestGCTaskStore_StartNew532--- PASS: TestGCTaskStore_StartNew (0.00s)533=== CONT TestGCMetrics534=== CONT TestGCBugBareHashReferences535=== CONT TestPinProtectsFromGC536=== CONT TestClientWithDependencies537=== CONT TestGCTaskStore_ConflictDifferentParams538=== CONT TestOrphanedObjectsGCStressTest539=== CONT TestClientMultipleUploads540=== CONT TestOrphanedObjectsGC541=== CONT TestClientIntegration542=== CONT TestObjectStatsTrigger543=== CONT TestClientErrorHandling544=== CONT TestMultipartCleanup545=== CONT TestServerTLSConfig546=== CONT TestClientCADerivations547=== CONT TestService_NativeMTLS548=== CONT TestCacheStatsHandler549=== CONT TestMetricsInventory550=== CONT TestCacheConfigHandler551=== CONT TestNARDeduplicationMetadataUploadBug552=== CONT TestService_AuthMiddleware_OIDC553=== CONT TestGenerateLandingPage554=== CONT TestService_ReadAuthMiddleware555=== CONT TestService_Rustfstest556=== CONT TestService_healthCheckHandler557=== CONT TestService_AuthMiddleware_MTLSBoundSubjects558=== CONT TestGracefulShutdownDrainsInflight559=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT560=== CONT TestService_AuthMiddleware_MTLSProxyHeader561=== CONT TestGCTaskStore_Fail562=== CONT TestCompleteMultipartUnregistered563=== CONT TestGCTaskStore_PhaseUpdates564=== CONT TestService_verifyS3Integrity565=== CONT TestGCTaskStore_GetReturnsLatest566=== CONT TestService_createPendingClosureHandler567=== CONT TestGCTaskStore_CompletedAllowsNewTask568=== CONT TestUploadHandlersRejectInvalidKeys569=== CONT TestIsValidUploadKey570=== CONT TestService_cleanupPendingClosuresHandler571=== CONT TestProxyWriteTimeout572=== CONT TestUploadHandlersRejectOversizedBody573=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle574=== CONT TestReadProxyDisabled575=== CONT TestRedundantMultipartUpload576=== CONT TestCompleteMultipartUpload_ErrorButObjectExists577=== CONT TestCompletedNarNotReofferedAcrossClosures578=== CONT TestGCTaskStore_GetEmpty579=== CONT TestReadProxyHead580=== CONT TestReadProxyRootRedirectsToIndexHTML581=== CONT TestReadProxyInvalidPath582=== CONT TestReadProxyConditionalGet583=== CONT TestReadProxy404584=== RUN TestIsValidCachePath/narinfo585=== RUN TestParseSingleRange/none586=== PAUSE TestParseSingleRange/none587=== RUN TestParseSingleRange/unknown_unit588=== PAUSE TestParseSingleRange/unknown_unit589=== RUN TestParseSingleRange/multi-range_ignored590=== PAUSE TestParseSingleRange/multi-range_ignored591=== RUN TestParseSingleRange/malformed_no_dash592=== PAUSE TestParseSingleRange/malformed_no_dash593=== RUN TestParseSingleRange/malformed_both_empty594=== PAUSE TestParseSingleRange/malformed_both_empty595=== RUN TestParseSingleRange/malformed_end_before_start596=== PAUSE TestParseSingleRange/malformed_end_before_start597=== RUN TestParseSingleRange/closed598=== PAUSE TestParseSingleRange/closed599=== RUN TestParseSingleRange/open-ended600=== PAUSE TestParseSingleRange/open-ended601=== RUN TestParseSingleRange/end_clamped_to_size602=== PAUSE TestParseSingleRange/end_clamped_to_size603=== RUN TestParseSingleRange/suffix604=== PAUSE TestParseSingleRange/suffix605=== RUN TestParseSingleRange/suffix_exceeds_size606=== PAUSE TestParseSingleRange/suffix_exceeds_size607=== RUN TestParseSingleRange/single_byte608=== PAUSE TestParseSingleRange/single_byte609=== RUN TestParseSingleRange/start_past_EOF610=== PAUSE TestParseSingleRange/start_past_EOF611=== RUN TestParseSingleRange/start_far_past_EOF612=== PAUSE TestParseSingleRange/start_far_past_EOF613=== CONT TestParseSingleRange/none614=== PAUSE TestIsValidCachePath/narinfo615=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars616=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars617=== RUN TestIsValidCachePath/nar_zst618=== PAUSE TestIsValidCachePath/nar_zst619=== RUN TestIsValidCachePath/nar_xz620=== PAUSE TestIsValidCachePath/nar_xz621=== RUN TestIsValidCachePath/nar_bz2622=== PAUSE TestIsValidCachePath/nar_bz2623=== RUN TestIsValidCachePath/nar_uncompressed624=== PAUSE TestIsValidCachePath/nar_uncompressed625=== RUN TestIsValidCachePath/ls626=== PAUSE TestIsValidCachePath/ls627=== RUN TestIsValidCachePath/log628=== PAUSE TestIsValidCachePath/log629=== RUN TestIsValidCachePath/realisation630=== PAUSE TestIsValidCachePath/realisation631=== RUN TestIsValidCachePath/nix-cache-info632=== PAUSE TestIsValidCachePath/nix-cache-info633=== RUN TestIsValidCachePath/index.html634=== PAUSE TestIsValidCachePath/index.html635=== RUN TestIsValidCachePath/traversal_parent636=== PAUSE TestIsValidCachePath/traversal_parent637=== RUN TestIsValidCachePath/traversal_in_middle638=== PAUSE TestIsValidCachePath/traversal_in_middle639=== RUN TestIsValidCachePath/invalid_char_e640=== PAUSE TestIsValidCachePath/invalid_char_e641=== RUN TestIsValidCachePath/invalid_char_u642=== PAUSE TestIsValidCachePath/invalid_char_u643=== RUN TestIsValidCachePath/random_path644=== PAUSE TestIsValidCachePath/random_path645=== RUN TestIsValidCachePath/empty646=== PAUSE TestIsValidCachePath/empty6472026/07/18 13:54:40 INFO Starting HTTP server address=127.0.0.1:43557648=== RUN TestIsValidCachePath/leading_slash649=== PAUSE TestIsValidCachePath/leading_slash650=== RUN TestIsValidCachePath/wrong_extension651=== PAUSE TestIsValidCachePath/wrong_extension652=== RUN TestIsValidCachePath/short_hash653=== PAUSE TestIsValidCachePath/short_hash654=== CONT TestIsValidCachePath/narinfo655=== CONT TestParseSingleRange/start_far_past_EOF656=== CONT TestParseSingleRange/start_past_EOF657=== CONT TestParseSingleRange/single_byte658=== CONT TestParseSingleRange/suffix_exceeds_size659=== CONT TestParseSingleRange/suffix660=== CONT TestParseSingleRange/end_clamped_to_size661=== CONT TestParseSingleRange/open-ended662=== CONT TestParseSingleRange/closed663=== CONT TestParseSingleRange/malformed_end_before_start664=== CONT TestParseSingleRange/malformed_both_empty665=== CONT TestParseSingleRange/malformed_no_dash666=== CONT TestParseSingleRange/multi-range_ignored667=== CONT TestParseSingleRange/unknown_unit668--- PASS: TestParseSingleRange (0.00s)669 --- PASS: TestParseSingleRange/none (0.00s)670 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)671 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)672 --- PASS: TestParseSingleRange/single_byte (0.00s)673 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)674 --- PASS: TestParseSingleRange/suffix (0.00s)675 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)676 --- PASS: TestParseSingleRange/open-ended (0.00s)677 --- PASS: TestParseSingleRange/closed (0.00s)678 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)679 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)680 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)681 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)682 --- PASS: TestParseSingleRange/unknown_unit (0.00s)683=== CONT TestIsValidCachePath/short_hash684=== CONT TestIsValidCachePath/wrong_extension685=== CONT TestIsValidCachePath/leading_slash686=== CONT TestIsValidCachePath/empty687=== CONT TestIsValidCachePath/random_path688=== CONT TestIsValidCachePath/invalid_char_u689=== CONT TestIsValidCachePath/invalid_char_e690=== CONT TestIsValidCachePath/traversal_in_middle691=== CONT TestIsValidCachePath/traversal_parent692=== CONT TestIsValidCachePath/index.html693=== CONT TestIsValidCachePath/nix-cache-info694=== CONT TestIsValidCachePath/realisation695=== CONT TestIsValidCachePath/log696=== CONT TestIsValidCachePath/ls697=== CONT TestIsValidCachePath/nar_uncompressed698=== CONT TestIsValidCachePath/nar_bz2699=== CONT TestIsValidCachePath/nar_xz700=== CONT TestIsValidCachePath/nar_zst701=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars702--- PASS: TestIsValidCachePath (0.01s)703 --- PASS: TestIsValidCachePath/narinfo (0.00s)704 --- PASS: TestIsValidCachePath/short_hash (0.00s)705 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)706 --- PASS: TestIsValidCachePath/leading_slash (0.00s)707 --- PASS: TestIsValidCachePath/empty (0.00s)708 --- PASS: TestIsValidCachePath/random_path (0.00s)709 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)710 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)711 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)712 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)713 --- PASS: TestIsValidCachePath/index.html (0.00s)714 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)715 --- PASS: TestIsValidCachePath/realisation (0.00s)716 --- PASS: TestIsValidCachePath/log (0.00s)717 --- PASS: TestIsValidCachePath/ls (0.00s)718 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)719 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)720 --- PASS: TestIsValidCachePath/nar_xz (0.00s)721 --- PASS: TestIsValidCachePath/nar_zst (0.00s)722 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)723=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info724=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info725=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal726=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal727=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key728=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key729=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key730=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key731=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info732=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key733=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key734=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal735--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)7362026/07/18 13:54:40 INFO Received uploads request method=POST path=/7372026/07/18 13:54:40 INFO Shutdown signal received, draining in-flight requests timeout=10s738--- PASS: TestGCTaskStore_GetEmpty (0.00s)739=== RUN TestProxyWriteTimeout/narinfo740=== PAUSE TestProxyWriteTimeout/narinfo741=== RUN TestProxyWriteTimeout/1_GiB_nar742=== PAUSE TestProxyWriteTimeout/1_GiB_nar743=== RUN TestProxyWriteTimeout/10_GiB_nar744=== PAUSE TestProxyWriteTimeout/10_GiB_nar745=== RUN TestProxyWriteTimeout/unknown_size746=== PAUSE TestProxyWriteTimeout/unknown_size7472026/07/18 13:54:40 INFO Received request for more parts method=POST path=/748=== CONT TestProxyWriteTimeout/narinfo749=== CONT TestProxyWriteTimeout/unknown_size750=== CONT TestProxyWriteTimeout/10_GiB_nar7512026/07/18 13:54:40 INFO Received complete multipart upload request method=POST path=/752=== CONT TestProxyWriteTimeout/1_GiB_nar753--- PASS: TestProxyWriteTimeout (0.00s)754 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)755 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)756 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)757 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)7582026/07/18 13:54:40 INFO Received uploads request method=POST path=/759--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)760--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)761 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)762 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.01s)763 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.01s)764 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.01s)765=== RUN TestServerTLSConfig/no_client_CA766=== PAUSE TestServerTLSConfig/no_client_CA767=== RUN TestServerTLSConfig/missing_CA_file768=== PAUSE TestServerTLSConfig/missing_CA_file769=== RUN TestServerTLSConfig/not_a_PEM_file770=== PAUSE TestServerTLSConfig/not_a_PEM_file771=== CONT TestServerTLSConfig/no_client_CA772=== CONT TestServerTLSConfig/not_a_PEM_file773=== CONT TestServerTLSConfig/missing_CA_file774--- PASS: TestServerTLSConfig (0.00s)775 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)776 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)777 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)778--- PASS: TestGCTaskStore_Fail (0.00s)779=== RUN TestIsValidUploadKey/narinfo780=== RUN TestCacheConfigHandler/full_config,_no_issuer781=== PAUSE TestCacheConfigHandler/full_config,_no_issuer782=== RUN TestCacheConfigHandler/no_cache_url_configured783=== PAUSE TestCacheConfigHandler/no_cache_url_configured784--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)785=== PAUSE TestIsValidUploadKey/narinfo786=== RUN TestIsValidUploadKey/nar_zst787=== PAUSE TestIsValidUploadKey/nar_zst788=== RUN TestCacheConfigHandler/no_signing_keys789=== RUN TestIsValidUploadKey/nar_xz790=== RUN TestClientErrorHandling/InvalidStorePath791--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)792=== PAUSE TestCacheConfigHandler/no_signing_keys793=== PAUSE TestIsValidUploadKey/nar_xz794=== PAUSE TestClientErrorHandling/InvalidStorePath795=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator796=== RUN TestIsValidUploadKey/nar_plain797=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator798=== RUN TestClientErrorHandling/InvalidAuthToken799=== PAUSE TestClientErrorHandling/InvalidAuthToken800=== CONT TestCacheConfigHandler/full_config,_no_issuer801=== CONT TestCacheConfigHandler/no_cache_url_configured802=== CONT TestCacheConfigHandler/no_signing_keys803=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator804=== PAUSE TestIsValidUploadKey/nar_plain805=== RUN TestClientErrorHandling/ServerNotAvailable806=== PAUSE TestClientErrorHandling/ServerNotAvailable807=== CONT TestClientErrorHandling/InvalidStorePath808=== CONT TestClientErrorHandling/ServerNotAvailable809=== CONT TestClientErrorHandling/InvalidAuthToken8102026/07/18 13:54:40 INFO OIDC provider initialized name=test811--- PASS: TestGenerateLandingPage (0.02s)812=== RUN TestIsValidUploadKey/listing813--- PASS: TestCacheConfigHandler (0.00s)814 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)815 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)816 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)817 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)818=== PAUSE TestIsValidUploadKey/listing819=== RUN TestIsValidUploadKey/build_log820=== PAUSE TestIsValidUploadKey/build_log821=== RUN TestIsValidUploadKey/build_log_home-manager_file822=== PAUSE TestIsValidUploadKey/build_log_home-manager_file823=== RUN TestIsValidUploadKey/build_log_plus_in_name824=== PAUSE TestIsValidUploadKey/build_log_plus_in_name825=== RUN TestIsValidUploadKey/build_log_question_mark826=== PAUSE TestIsValidUploadKey/build_log_question_mark827=== RUN TestIsValidUploadKey/build_log_equals828=== PAUSE TestIsValidUploadKey/build_log_equals829=== RUN TestIsValidUploadKey/realisation830=== PAUSE TestIsValidUploadKey/realisation831=== RUN TestIsValidUploadKey/realisation_plus_in_output832=== PAUSE TestIsValidUploadKey/realisation_plus_in_output833=== RUN TestIsValidUploadKey/nix-cache-info834=== PAUSE TestIsValidUploadKey/nix-cache-info835=== RUN TestIsValidUploadKey/index.html836=== PAUSE TestIsValidUploadKey/index.html837=== RUN TestIsValidUploadKey/narinfo_key,_nar_type838=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type839=== RUN TestIsValidUploadKey/nar_key,_narinfo_type840=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type841=== RUN TestIsValidUploadKey/listing_key,_narinfo_type842=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type843=== RUN TestIsValidUploadKey/traversal844=== PAUSE TestIsValidUploadKey/traversal845=== RUN TestIsValidUploadKey/traversal_nar846=== PAUSE TestIsValidUploadKey/traversal_nar847=== RUN TestIsValidUploadKey/absolute848=== PAUSE TestIsValidUploadKey/absolute849=== RUN TestIsValidUploadKey/empty_key850=== PAUSE TestIsValidUploadKey/empty_key851=== RUN TestIsValidUploadKey/unknown_type852=== PAUSE TestIsValidUploadKey/unknown_type853=== CONT TestIsValidUploadKey/narinfo854=== CONT TestIsValidUploadKey/traversal855=== CONT TestIsValidUploadKey/nar_key,_narinfo_type856=== CONT TestIsValidUploadKey/build_log_plus_in_name857=== CONT TestIsValidUploadKey/build_log_home-manager_file858=== CONT TestIsValidUploadKey/unknown_type859=== CONT TestIsValidUploadKey/empty_key860=== CONT TestIsValidUploadKey/absolute861=== CONT TestIsValidUploadKey/traversal_nar862=== CONT TestIsValidUploadKey/nix-cache-info863=== CONT TestIsValidUploadKey/realisation_plus_in_output864=== CONT TestIsValidUploadKey/realisation865=== CONT TestIsValidUploadKey/build_log_equals866=== CONT TestIsValidUploadKey/build_log_question_mark867=== CONT TestIsValidUploadKey/build_log868=== CONT TestIsValidUploadKey/narinfo_key,_nar_type869=== CONT TestIsValidUploadKey/listing870=== CONT TestIsValidUploadKey/nar_zst871=== CONT TestIsValidUploadKey/listing_key,_narinfo_type872=== CONT TestIsValidUploadKey/index.html873=== CONT TestIsValidUploadKey/nar_plain874=== CONT TestIsValidUploadKey/nar_xz875--- PASS: TestIsValidUploadKey (0.01s)876 --- PASS: TestIsValidUploadKey/narinfo (0.00s)877 --- PASS: TestIsValidUploadKey/traversal (0.00s)878 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)879 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)880 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)881 --- PASS: TestIsValidUploadKey/empty_key (0.00s)882 --- PASS: TestIsValidUploadKey/absolute (0.00s)883 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)884 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)885 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)886 --- PASS: TestIsValidUploadKey/realisation (0.00s)887 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)888 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)889 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)890 --- PASS: TestIsValidUploadKey/listing (0.00s)891 --- PASS: TestIsValidUploadKey/build_log (0.00s)892 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)893 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)894 --- PASS: TestIsValidUploadKey/index.html (0.00s)895 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)896 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)897 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)898--- PASS: TestGracefulShutdownDrainsInflight (0.08s)8992026-07-18 13:54:40.839 UTC [814] ERROR: relation "goose_db_version" does not exist at character 369002026-07-18 13:54:40.839 UTC [814] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC901=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure902=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure903=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart904=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart905=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts906=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts907=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure9082026/07/18 13:54:40 INFO Received uploads request method=POST path=/909=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts910=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart9112026/07/18 13:54:40 INFO Received request for more parts method=POST path=/9122026/07/18 13:54:40 INFO Received complete multipart upload request method=POST path=/9132026-07-18 13:54:40.968 UTC [833] ERROR: relation "goose_db_version" does not exist at character 369142026-07-18 13:54:40.968 UTC [833] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9152026-07-18 13:54:40.970 UTC [816] ERROR: relation "goose_db_version" does not exist at character 369162026-07-18 13:54:40.970 UTC [816] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9172026-07-18 13:54:40.999 UTC [851] ERROR: relation "goose_db_version" does not exist at character 369182026-07-18 13:54:40.999 UTC [851] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9192026-07-18 13:54:41.003 UTC [853] ERROR: relation "goose_db_version" does not exist at character 369202026-07-18 13:54:41.003 UTC [853] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9212026-07-18 13:54:41.004 UTC [858] ERROR: relation "goose_db_version" does not exist at character 369222026-07-18 13:54:41.004 UTC [858] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9232026-07-18 13:54:41.005 UTC [854] ERROR: relation "goose_db_version" does not exist at character 369242026-07-18 13:54:41.005 UTC [854] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9252026-07-18 13:54:41.006 UTC [855] ERROR: relation "goose_db_version" does not exist at character 369262026-07-18 13:54:41.006 UTC [855] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9272026-07-18 13:54:41.009 UTC [857] ERROR: relation "goose_db_version" does not exist at character 369282026-07-18 13:54:41.009 UTC [857] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9292026-07-18 13:54:41.010 UTC [856] ERROR: relation "goose_db_version" does not exist at character 369302026-07-18 13:54:41.010 UTC [856] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9312026-07-18 13:54:41.011 UTC [876] ERROR: relation "goose_db_version" does not exist at character 369322026-07-18 13:54:41.011 UTC [876] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9332026-07-18 13:54:41.011 UTC [877] ERROR: relation "goose_db_version" does not exist at character 369342026-07-18 13:54:41.011 UTC [877] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9352026-07-18 13:54:41.044 UTC [888] ERROR: relation "goose_db_version" does not exist at character 369362026-07-18 13:54:41.044 UTC [888] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9372026-07-18 13:54:41.048 UTC [880] ERROR: relation "goose_db_version" does not exist at character 369382026-07-18 13:54:41.048 UTC [880] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9392026/07/18 13:54:41 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_closures9402026/07/18 13:54:41 OK 20241026095416_initial_model.sql (100.91ms)9412026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (11.03ms)9422026-07-18 13:54:41.094 UTC [898] ERROR: relation "goose_db_version" does not exist at character 369432026-07-18 13:54:41.094 UTC [898] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9442026-07-18 13:54:41.097 UTC [899] ERROR: relation "goose_db_version" does not exist at character 369452026-07-18 13:54:41.097 UTC [899] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9462026/07/18 13:54:41 OK 20251218171726_add_pins.sql (39.97ms)9472026/07/18 13:54:41 OK 20241026095416_initial_model.sql (104.16ms)9482026/07/18 13:54:41 OK 20241026095416_initial_model.sql (111.39ms)9492026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (7.74ms)9502026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (5.03ms)9512026/07/18 13:54:41 OK 20241026095416_initial_model.sql (59.07ms)9522026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (17.51ms)9532026/07/18 13:54:41 goose: successfully migrated database to version: 202606281200009542026/07/18 13:54:41 OK 20241026095416_initial_model.sql (72.39ms)9552026/07/18 13:54:41 OK 20241026095416_initial_model.sql (68.74ms)9562026/07/18 13:54:41 OK 20241026095416_initial_model.sql (80.05ms)9572026/07/18 13:54:41 OK 20241026095416_initial_model.sql (68.17ms)9582026/07/18 13:54:41 OK 20251218171726_add_pins.sql (8.24ms)9592026/07/18 13:54:41 OK 20241026095416_initial_model.sql (67.84ms)9602026/07/18 13:54:41 OK 20241026095416_initial_model.sql (70.88ms)9612026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (4.96ms)9622026-07-18 13:54:41.151 UTC [900] ERROR: relation "goose_db_version" does not exist at character 369632026-07-18 13:54:41.151 UTC [900] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9642026/07/18 13:54:41 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.538199ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures9652026-07-18 13:54:41.152 UTC [902] ERROR: relation "goose_db_version" does not exist at character 369662026-07-18 13:54:41.152 UTC [902] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9672026-07-18 13:54:41.153 UTC [903] ERROR: relation "goose_db_version" does not exist at character 369682026-07-18 13:54:41.153 UTC [903] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9692026-07-18 13:54:41.154 UTC [901] ERROR: relation "goose_db_version" does not exist at character 369702026-07-18 13:54:41.154 UTC [901] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9712026/07/18 13:54:41 OK 20241026095416_initial_model.sql (76.63ms)9722026-07-18 13:54:41.155 UTC [904] ERROR: relation "goose_db_version" does not exist at character 369732026-07-18 13:54:41.155 UTC [904] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9742026/07/18 13:54:41 OK 20241026095416_initial_model.sql (89.75ms)9752026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (17.01ms)9762026/07/18 13:54:41 OK 1_commit_pending_closure.sql (21.56ms)9772026/07/18 13:54:41 OK 20251218171726_add_pins.sql (26.37ms)9782026/07/18 13:54:41 OK 20241026095416_initial_model.sql (99.65ms)9792026/07/18 13:54:41 OK 20241026095416_initial_model.sql (89ms)9802026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (21.56ms)9812026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (20.03ms)9822026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (21.1ms)9832026/07/18 13:54:41 OK 2_object_stats_trigger.sql (4.21ms)9842026/07/18 13:54:41 goose: up to current file version: 29852026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (4.52ms)9862026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (9.14ms)9872026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (24.65ms)9882026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (8.33ms)9892026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (24.4ms)9902026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (4.69ms)9912026/07/18 13:54:41 OK 20251218171726_add_pins.sql (25.04ms)9922026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (28.25ms)9932026/07/18 13:54:41 goose: successfully migrated database to version: 202606281200009942026/07/18 13:54:41 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"995--- PASS: TestService_AuthMiddleware (0.45s)9962026/07/18 13:54:41 OK 20251218171726_add_pins.sql (16.96ms)9972026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (12.66ms)9982026/07/18 13:54:41 goose: successfully migrated database to version: 202606281200009992026/07/18 13:54:41 OK 1_commit_pending_closure.sql (7.12ms)10002026/07/18 13:54:41 OK 1_commit_pending_closure.sql (6.63ms)10012026/07/18 13:54:41 OK 20251218171726_add_pins.sql (19.46ms)10022026/07/18 13:54:41 OK 20251218171726_add_pins.sql (29.71ms)10032026/07/18 13:54:41 OK 2_object_stats_trigger.sql (16.85ms)10042026/07/18 13:54:41 goose: up to current file version: 210052026/07/18 13:54:41 OK 20251218171726_add_pins.sql (31.87ms)10062026/07/18 13:54:41 OK 2_object_stats_trigger.sql (14.9ms)10072026/07/18 13:54:41 goose: up to current file version: 210082026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (30.08ms)10092026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000010102026/07/18 13:54:41 OK 20251218171726_add_pins.sql (36.81ms)10112026/07/18 13:54:41 OK 20251218171726_add_pins.sql (36.33ms)10122026/07/18 13:54:41 OK 20251218171726_add_pins.sql (36.41ms)10132026/07/18 13:54:41 OK 20251218171726_add_pins.sql (36.59ms)10142026/07/18 13:54:41 OK 20251218171726_add_pins.sql (38.64ms)10152026/07/18 13:54:41 OK 20241026095416_initial_model.sql (70.38ms)10162026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (31.11ms)10172026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000010182026/07/18 13:54:41 OK 20251218171726_add_pins.sql (38.97ms)10192026/07/18 13:54:41 OK 1_commit_pending_closure.sql (6.41ms)1020{"timestamp":"2026-07-18T13:54:41.210786102Z","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(373)"}10212026/07/18 13:54:41 OK 2_object_stats_trigger.sql (6.09ms)10222026/07/18 13:54:41 goose: up to current file version: 210232026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (19.51ms)10242026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000010252026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (7.27ms)10262026/07/18 13:54:41 OK 1_commit_pending_closure.sql (8.52ms)10272026/07/18 13:54:41 OK 20241026095416_initial_model.sql (83.37ms)10282026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (35.46ms)10292026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000010302026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (22.98ms)10312026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000010322026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (16.37ms)10332026/07/18 13:54:41 goose: successfully migrated database to version: 202606281200001034--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.49s)1035--- PASS: TestReadProxyNarStreaming (0.51s)10362026/07/18 13:54:41 OK 2_object_stats_trigger.sql (16.73ms)10372026/07/18 13:54:41 goose: up to current file version: 210382026/07/18 13:54:41 OK 1_commit_pending_closure.sql (19.91ms)10392026/07/18 13:54:41 OK 1_commit_pending_closure.sql (18.4ms)10402026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (32.65ms)10412026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000010422026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (30.32ms)10432026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000010442026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (32.78ms)10452026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000010462026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (18.44ms)10472026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (32.6ms)10482026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000010492026/07/18 13:54:41 OK 1_commit_pending_closure.sql (17.07ms)10502026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (34.35ms)10512026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000010522026/07/18 13:54:41 OK 1_commit_pending_closure.sql (22.04ms)10532026/07/18 13:54:41 OK 2_object_stats_trigger.sql (6.29ms)10542026/07/18 13:54:41 goose: up to current file version: 210552026/07/18 13:54:41 OK 2_object_stats_trigger.sql (5.05ms)10562026/07/18 13:54:41 goose: up to current file version: 210572026/07/18 13:54:41 OK 2_object_stats_trigger.sql (9.1ms)10582026/07/18 13:54:41 goose: up to current file version: 210592026/07/18 13:54:41 OK 1_commit_pending_closure.sql (9.11ms)10602026/07/18 13:54:41 OK 1_commit_pending_closure.sql (9.15ms)10612026/07/18 13:54:41 OK 1_commit_pending_closure.sql (9.01ms)10622026/07/18 13:54:41 OK 1_commit_pending_closure.sql (8.84ms)10632026/07/18 13:54:41 OK 20251218171726_add_pins.sql (32.08ms)10642026/07/18 13:54:41 OK 20251218171726_add_pins.sql (11.44ms)10652026/07/18 13:54:41 OK 20241026095416_initial_model.sql (65.78ms)10662026/07/18 13:54:41 OK 20241026095416_initial_model.sql (70.9ms)10672026/07/18 13:54:41 OK 2_object_stats_trigger.sql (5.41ms)10682026/07/18 13:54:41 goose: up to current file version: 210692026/07/18 13:54:41 OK 1_commit_pending_closure.sql (7.89ms)10702026/07/18 13:54:41 OK 20241026095416_initial_model.sql (65.19ms)10712026/07/18 13:54:41 INFO Created nix-cache-info in bucket bucket=bucket910722026/07/18 13:54:41 OK 2_object_stats_trigger.sql (6.2ms)10732026/07/18 13:54:41 goose: up to current file version: 210742026/07/18 13:54:41 OK 20241026095416_initial_model.sql (73.55ms)10752026/07/18 13:54:41 OK 2_object_stats_trigger.sql (6.35ms)10762026/07/18 13:54:41 goose: up to current file version: 210772026/07/18 13:54:41 OK 2_object_stats_trigger.sql (6.49ms)10782026/07/18 13:54:41 goose: up to current file version: 210792026/07/18 13:54:41 OK 2_object_stats_trigger.sql (6.41ms)10802026/07/18 13:54:41 goose: up to current file version: 210812026/07/18 13:54:41 OK 20241026095416_initial_model.sql (69.91ms)10822026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (7.97ms)10832026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (8.07ms)10842026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures1085--- PASS: TestReadProxyRangeRequest (0.54s)10862026/07/18 13:54:41 OK 2_object_stats_trigger.sql (10.05ms)10872026/07/18 13:54:41 goose: up to current file version: 21088--- PASS: TestService_Rustfstest (0.52s)10892026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (8.92ms)10902026/07/18 13:54:41 INFO Aborted multipart uploads count=010912026/07/18 13:54:41 WARN Force mode enabled - objects will be deleted immediately without grace period10922026/07/18 13:54:41 INFO Created nix-cache-info in bucket bucket=bucket1510932026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (24.24ms)10942026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (28.59ms)1095--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.56s)10962026/07/18 13:54:41 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=010972026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (35.6ms)10982026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000010992026/07/18 13:54:41 INFO Vacuumed table table=pending_closures11002026/07/18 13:54:41 INFO Vacuumed table table=pending_objects11012026/07/18 13:54:41 INFO Vacuumed table table=multipart_uploads11022026/07/18 13:54:41 INFO Vacuumed table table=closures11032026/07/18 13:54:41 INFO Vacuumed table table=objects11042026/07/18 13:54:41 OK 20251218171726_add_pins.sql (28.9ms)11052026/07/18 13:54:41 OK 20251218171726_add_pins.sql (33.72ms)11062026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (42.12ms)11072026/07/18 13:54:41 goose: successfully migrated database to version: 202606281200001108--- PASS: TestGCMetrics (0.57s)11092026/07/18 13:54:41 OK 1_commit_pending_closure.sql (9.97ms)11102026/07/18 13:54:41 OK 20251218171726_add_pins.sql (15.17ms)11112026/07/18 13:54:41 OK 20251218171726_add_pins.sql (31.32ms)11122026/07/18 13:54:41 OK 20251218171726_add_pins.sql (15.39ms)11132026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (9.44ms)11142026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000011152026/07/18 13:54:41 OK 2_object_stats_trigger.sql (3.84ms)11162026/07/18 13:54:41 goose: up to current file version: 211172026/07/18 13:54:41 OK 1_commit_pending_closure.sql (6.48ms)1118--- PASS: TestReadProxyNarinfo (0.58s)1119--- PASS: TestReadProxyConditionalGet (0.57s)1120--- PASS: TestResurrectedObjectNotDeleted (0.58s)11212026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (9.12ms)11222026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000011232026/07/18 13:54:41 OK 2_object_stats_trigger.sql (3.68ms)11242026/07/18 13:54:41 goose: up to current file version: 211252026/07/18 13:54:41 OK 1_commit_pending_closure.sql (6.5ms)11262026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (8.73ms)11272026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000011282026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (9.79ms)11292026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000011302026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (10.26ms)11312026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000011322026/07/18 13:54:41 OK 1_commit_pending_closure.sql (4.39ms)11332026/07/18 13:54:41 OK 2_object_stats_trigger.sql (2.35ms)11342026/07/18 13:54:41 goose: up to current file version: 211352026/07/18 13:54:41 OK 1_commit_pending_closure.sql (3.71ms)11362026/07/18 13:54:41 OK 2_object_stats_trigger.sql (2.41ms)11372026/07/18 13:54:41 goose: up to current file version: 211382026/07/18 13:54:41 OK 1_commit_pending_closure.sql (3.67ms)11392026/07/18 13:54:41 OK 1_commit_pending_closure.sql (4.16ms)11402026-07-18 13:54:41.317 UTC [926] ERROR: relation "goose_db_version" does not exist at character 3611412026-07-18 13:54:41.317 UTC [926] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11422026/07/18 13:54:41 OK 2_object_stats_trigger.sql (4.94ms)11432026/07/18 13:54:41 goose: up to current file version: 21144--- PASS: TestReadProxy404 (0.60s)11452026/07/18 13:54:41 OK 2_object_stats_trigger.sql (2.21ms)11462026/07/18 13:54:41 goose: up to current file version: 211472026/07/18 13:54:41 OK 2_object_stats_trigger.sql (2.51ms)11482026/07/18 13:54:41 goose: up to current file version: 211492026-07-18 13:54:41.320 UTC [944] ERROR: relation "goose_db_version" does not exist at character 3611502026-07-18 13:54:41.320 UTC [944] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11512026-07-18 13:54:41.321 UTC [946] ERROR: relation "goose_db_version" does not exist at character 3611522026-07-18 13:54:41.321 UTC [946] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11532026-07-18 13:54:41.322 UTC [931] ERROR: relation "goose_db_version" does not exist at character 3611542026-07-18 13:54:41.322 UTC [931] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11552026/07/18 13:54:41 INFO Created nix-cache-info in bucket bucket=bucket1811562026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures11572026-07-18 13:54:41.322 UTC [945] ERROR: relation "goose_db_version" does not exist at character 3611582026-07-18 13:54:41.322 UTC [945] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11592026-07-18 13:54:41.323 UTC [948] ERROR: relation "goose_db_version" does not exist at character 3611602026-07-18 13:54:41.323 UTC [948] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11612026-07-18 13:54:41.323 UTC [947] ERROR: relation "goose_db_version" does not exist at character 3611622026-07-18 13:54:41.323 UTC [947] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11632026/07/18 13:54:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1164--- PASS: TestReadProxyDisabled (0.59s)11652026-07-18 13:54:41.325 UTC [949] ERROR: relation "goose_db_version" does not exist at character 3611662026-07-18 13:54:41.325 UTC [949] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11672026-07-18 13:54:41.328 UTC [953] ERROR: relation "goose_db_version" does not exist at character 3611682026-07-18 13:54:41.328 UTC [953] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11692026-07-18 13:54:41.328 UTC [956] ERROR: relation "goose_db_version" does not exist at character 3611702026-07-18 13:54:41.328 UTC [956] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11712026-07-18 13:54:41.328 UTC [952] ERROR: relation "goose_db_version" does not exist at character 3611722026-07-18 13:54:41.328 UTC [952] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11732026/07/18 13:54:41 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst11742026-07-18 13:54:41.328 UTC [950] ERROR: relation "goose_db_version" does not exist at character 3611752026-07-18 13:54:41.328 UTC [950] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1176--- PASS: TestCompleteMultipartUnregistered (0.57s)11772026-07-18 13:54:41.329 UTC [951] ERROR: relation "goose_db_version" does not exist at character 3611782026-07-18 13:54:41.329 UTC [951] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11792026-07-18 13:54:41.329 UTC [955] ERROR: relation "goose_db_version" does not exist at character 3611802026-07-18 13:54:41.329 UTC [955] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11812026-07-18 13:54:41.332 UTC [963] ERROR: relation "goose_db_version" does not exist at character 3611822026-07-18 13:54:41.332 UTC [963] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11832026-07-18 13:54:41.332 UTC [959] ERROR: relation "goose_db_version" does not exist at character 3611842026-07-18 13:54:41.332 UTC [959] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11852026-07-18 13:54:41.333 UTC [964] ERROR: relation "goose_db_version" does not exist at character 3611862026-07-18 13:54:41.333 UTC [964] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11872026-07-18 13:54:41.333 UTC [957] ERROR: relation "goose_db_version" does not exist at character 3611882026-07-18 13:54:41.333 UTC [957] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11892026-07-18 13:54:41.334 UTC [958] ERROR: relation "goose_db_version" does not exist at character 3611902026-07-18 13:54:41.334 UTC [958] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11912026-07-18 13:54:41.334 UTC [960] ERROR: relation "goose_db_version" does not exist at character 3611922026-07-18 13:54:41.334 UTC [960] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11932026-07-18 13:54:41.338 UTC [967] ERROR: relation "goose_db_version" does not exist at character 3611942026-07-18 13:54:41.338 UTC [967] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11952026-07-18 13:54:41.338 UTC [965] ERROR: relation "goose_db_version" does not exist at character 3611962026-07-18 13:54:41.338 UTC [965] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11972026-07-18 13:54:41.339 UTC [966] ERROR: relation "goose_db_version" does not exist at character 3611982026-07-18 13:54:41.339 UTC [966] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11992026/07/18 13:54:41 OK 20241026095416_initial_model.sql (13.87ms)1200--- PASS: TestReadProxyHead (0.62s)12012026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures12022026/07/18 13:54:41 OK 20241026095416_initial_model.sql (15.25ms)12032026/07/18 13:54:41 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=376.57248ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1204=== NAME TestPinProtectsFromGC1205 client_integration_test.go:646: Pinned store path: /build/TestPinProtectsFromGC2334114004/001/store/xdhf1p882im3xz3ahnaf34qjcscnswhc-pinned-file.txt1206 client_integration_test.go:647: Unpinned store path: /build/TestPinProtectsFromGC2334114004/001/store/fdhradi5kxsfah5cg91zkw78jj4mhiwf-unpinned-file.txt12072026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (4.12ms)12082026/07/18 13:54:41 OK 20241026095416_initial_model.sql (16.77ms)12092026/07/18 13:54:41 OK 20241026095416_initial_model.sql (19.05ms)12102026/07/18 13:54:41 OK 20241026095416_initial_model.sql (19.28ms)12112026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (7.39ms)12122026/07/18 13:54:41 OK 20241026095416_initial_model.sql (15.1ms)12132026/07/18 13:54:41 OK 20241026095416_initial_model.sql (15ms)12142026/07/18 13:54:41 OK 20241026095416_initial_model.sql (20.51ms)12152026/07/18 13:54:41 OK 20251218171726_add_pins.sql (6.59ms)12162026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (5.61ms)12172026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (3.96ms)12182026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (5.69ms)12192026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (4.27ms)12202026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (4.17ms)12212026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (5.51ms)12222026/07/18 13:54:41 OK 20241026095416_initial_model.sql (21.74ms)12232026/07/18 13:54:41 OK 20241026095416_initial_model.sql (20.41ms)12242026/07/18 13:54:41 OK 20251218171726_add_pins.sql (8.8ms)12252026/07/18 13:54:41 OK 20241026095416_initial_model.sql (15.46ms)12262026/07/18 13:54:41 OK 20241026095416_initial_model.sql (14.19ms)12272026/07/18 13:54:41 OK 20241026095416_initial_model.sql (17.76ms)12282026/07/18 13:54:41 OK 20241026095416_initial_model.sql (15.54ms)12292026/07/18 13:54:41 OK 20241026095416_initial_model.sql (19.85ms)12302026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (4.09ms)12312026/07/18 13:54:41 OK 20251218171726_add_pins.sql (6.4ms)12322026/07/18 13:54:41 OK 20251218171726_add_pins.sql (6.52ms)12332026/07/18 13:54:41 OK 20251218171726_add_pins.sql (6.33ms)12342026/07/18 13:54:41 OK 20241026095416_initial_model.sql (16.76ms)12352026/07/18 13:54:41 OK 20241026095416_initial_model.sql (15.52ms)12362026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (3.49ms)12372026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (3.59ms)12382026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (5.72ms)12392026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (8.85ms)12402026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000012412026/07/18 13:54:41 OK 20241026095416_initial_model.sql (19.03ms)12422026/07/18 13:54:41 OK 20251218171726_add_pins.sql (8.47ms)12432026/07/18 13:54:41 OK 20251218171726_add_pins.sql (8.64ms)12442026/07/18 13:54:41 OK 20251218171726_add_pins.sql (8.76ms)12452026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (5.42ms)12462026/07/18 13:54:41 OK 20241026095416_initial_model.sql (15.73ms)12472026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (3.65ms)12482026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (5.19ms)12492026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (5.01ms)12502026/07/18 13:54:41 OK 20241026095416_initial_model.sql (20.04ms)12512026/07/18 13:54:41 OK 20241026095416_initial_model.sql (23.06ms)12522026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (10.04ms)12532026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000012542026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (6.75ms)12552026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (8.27ms)12562026/07/18 13:54:41 goose: successfully migrated database to version: 202606281200001257=== NAME TestClientMultipleUploads12582026/07/18 13:54:41 OK 1_commit_pending_closure.sql (6.14ms)1259 client_integration_test.go:338: Created store path 0: /build/TestClientMultipleUploads2208915041/001/store/rxny9kkis9igr7w9x2chhn74ym4fl5cd-test-file-0.txt12602026/07/18 13:54:41 OK 20251218171726_add_pins.sql (7.79ms)12612026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (8.42ms)12622026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000012632026/07/18 13:54:41 OK 20251218171726_add_pins.sql (9.3ms)12642026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (4.94ms)12652026/07/18 13:54:41 OK 20251218171726_add_pins.sql (7.88ms)12662026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (8.45ms)12672026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000012682026/07/18 13:54:41 OK 20241026095416_initial_model.sql (31.03ms)12692026/07/18 13:54:41 OK 20251218171726_add_pins.sql (7.93ms)12702026/07/18 13:54:41 OK 20241026095416_initial_model.sql (20.01ms)12712026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (6.45ms)12722026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (8.84ms)12732026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000012742026/07/18 13:54:41 OK 20251218171726_add_pins.sql (7.43ms)12752026/07/18 13:54:41 OK 20251218171726_add_pins.sql (7.32ms)12762026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (8.94ms)12772026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000012782026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (4.83ms)12792026/07/18 13:54:41 OK 1_commit_pending_closure.sql (3.6ms)12802026/07/18 13:54:41 OK 2_object_stats_trigger.sql (4.35ms)12812026/07/18 13:54:41 goose: up to current file version: 212822026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (10.4ms)12832026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000012842026/07/18 13:54:41 OK 1_commit_pending_closure.sql (4.37ms)12852026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (6.35ms)12862026/07/18 13:54:41 OK 20251218171726_add_pins.sql (8.88ms)12872026/07/18 13:54:41 OK 20251218171726_add_pins.sql (10.27ms)12882026/07/18 13:54:41 OK 1_commit_pending_closure.sql (5.81ms)12892026/07/18 13:54:41 OK 20251218171726_add_pins.sql (6.78ms)12902026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (6.78ms)12912026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000012922026/07/18 13:54:41 OK 1_commit_pending_closure.sql (3.99ms)12932026/07/18 13:54:41 OK 2_object_stats_trigger.sql (2.55ms)12942026/07/18 13:54:41 goose: up to current file version: 212952026/07/18 13:54:41 OK 1_commit_pending_closure.sql (4.16ms)12962026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (6.73ms)12972026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000012982026/07/18 13:54:41 OK 2_object_stats_trigger.sql (3.14ms)12992026/07/18 13:54:41 goose: up to current file version: 213002026/07/18 13:54:41 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13012026/07/18 13:54:41 WARN mTLS auth: bound subjects configured but subject DN unavailable13022026/07/18 13:54:41 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1303--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.62s)13042026/07/18 13:54:41 OK 1_commit_pending_closure.sql (6.92ms)13052026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (7.17ms)13062026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (9.18ms)13072026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000013082026/07/18 13:54:41 OK 20251218171726_add_pins.sql (8.87ms)13092026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (5.39ms)13102026/07/18 13:54:41 OK 20251210153512_drop_unused_gin_index.sql (5.98ms)13112026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (9.65ms)13122026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000013132026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (7.23ms)13142026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000013152026/07/18 13:54:41 OK 1_commit_pending_closure.sql (5.56ms)13162026/07/18 13:54:41 OK 2_object_stats_trigger.sql (5.05ms)13172026/07/18 13:54:41 goose: up to current file version: 213182026/07/18 13:54:41 OK 20251218171726_add_pins.sql (6.96ms)13192026/07/18 13:54:41 goose: successfully migrated database to version: 202606281200001320=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1321=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1322=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1323=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1324=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1325=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1326=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1327=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1328=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token13292026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures1330=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1331=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected13322026/07/18 13:54:41 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]1333=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured13342026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (7.2ms)13352026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000013362026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (7.12ms)13372026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000013382026/07/18 13:54:41 OK 2_object_stats_trigger.sql (4.9ms)13392026/07/18 13:54:41 goose: up to current file version: 213402026/07/18 13:54:41 OK 1_commit_pending_closure.sql (4.84ms)13412026/07/18 13:54:41 OK 2_object_stats_trigger.sql (5.98ms)13422026/07/18 13:54:41 goose: up to current file version: 213432026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (7.62ms)13442026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000013452026/07/18 13:54:41 OK 1_commit_pending_closure.sql (6.12ms)13462026/07/18 13:54:41 OK 2_object_stats_trigger.sql (2.89ms)13472026/07/18 13:54:41 goose: up to current file version: 213482026/07/18 13:54:41 OK 20251218171726_add_pins.sql (8.32ms)13492026/07/18 13:54:41 OK 20251218171726_add_pins.sql (7.46ms)13502026/07/18 13:54:41 OK 1_commit_pending_closure.sql (4.28ms)13512026/07/18 13:54:41 OK 2_object_stats_trigger.sql (3.82ms)13522026/07/18 13:54:41 goose: up to current file version: 213532026/07/18 13:54:41 OK 1_commit_pending_closure.sql (3.92ms)13542026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures13552026/07/18 13:54:41 INFO OIDC auth successful provider=test13562026/07/18 13:54:41 OK 1_commit_pending_closure.sql (5.79ms)13572026/07/18 13:54:41 OK 20251218171726_add_pins.sql (5.96ms)13582026/07/18 13:54:41 OK 2_object_stats_trigger.sql (4.34ms)13592026/07/18 13:54:41 goose: up to current file version: 213602026/07/18 13:54:41 OK 2_object_stats_trigger.sql (5.12ms)13612026/07/18 13:54:41 goose: up to current file version: 213622026/07/18 13:54:41 OK 1_commit_pending_closure.sql (5.44ms)13632026/07/18 13:54:41 OK 1_commit_pending_closure.sql (5.38ms)13642026/07/18 13:54:41 OK 2_object_stats_trigger.sql (2.77ms)13652026/07/18 13:54:41 goose: up to current file version: 213662026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (7.32ms)13672026/07/18 13:54:41 OK 2_object_stats_trigger.sql (2.98ms)13682026/07/18 13:54:41 goose: up to current file version: 213692026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (7ms)13702026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000013712026/07/18 13:54:41 OK 20251218171726_add_pins.sql (7.63ms)13722026/07/18 13:54:41 OK 1_commit_pending_closure.sql (6.46ms)13732026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000013742026/07/18 13:54:41 OK 1_commit_pending_closure.sql (4.45ms)13752026/07/18 13:54:41 OK 2_object_stats_trigger.sql (1.98ms)13762026/07/18 13:54:41 goose: up to current file version: 213772026/07/18 13:54:41 WARN Authentication failed token_preview=eyJhbGciOi...SCzB5fKVWA 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]13782026/07/18 13:54:41 OK 2_object_stats_trigger.sql (1.77ms)1379--- PASS: TestService_AuthMiddleware_OIDC (0.63s)1380 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1381 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1382 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1383 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)13842026/07/18 13:54:41 goose: up to current file version: 213852026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (6.17ms)13862026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000013872026/07/18 13:54:41 OK 2_object_stats_trigger.sql (2.25ms)13882026/07/18 13:54:41 goose: up to current file version: 213892026/07/18 13:54:41 OK 2_object_stats_trigger.sql (1.88ms)13902026/07/18 13:54:41 goose: up to current file version: 213912026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)13922026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000013932026/07/18 13:54:41 OK 2_object_stats_trigger.sql (2.33ms)13942026/07/18 13:54:41 goose: up to current file version: 213952026/07/18 13:54:41 OK 1_commit_pending_closure.sql (3.24ms)13962026/07/18 13:54:41 OK 1_commit_pending_closure.sql (4.04ms)13972026/07/18 13:54:41 OK 2_object_stats_trigger.sql (1.2ms)13982026/07/18 13:54:41 goose: up to current file version: 213992026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (4.83ms)14002026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000014012026/07/18 13:54:41 OK 2_object_stats_trigger.sql (1.11ms)14022026/07/18 13:54:41 goose: up to current file version: 214032026/07/18 13:54:41 OK 20260628120000_add_object_size_and_stats.sql (4.93ms)14042026/07/18 13:54:41 goose: successfully migrated database to version: 2026062812000014052026/07/18 13:54:41 OK 1_commit_pending_closure.sql (4.22ms)14062026/07/18 13:54:41 OK 1_commit_pending_closure.sql (2.04ms)14072026/07/18 13:54:41 OK 2_object_stats_trigger.sql (1.11ms)14082026/07/18 13:54:41 goose: up to current file version: 214092026/07/18 13:54:41 OK 1_commit_pending_closure.sql (2.09ms)14102026/07/18 13:54:41 INFO Received cleanup request method=DELETE path=/api/pending_closures14112026/07/18 13:54:41 INFO Aborted multipart uploads count=014122026/07/18 13:54:41 OK 1_commit_pending_closure.sql (7.38ms)14132026/07/18 13:54:41 OK 2_object_stats_trigger.sql (4.45ms)14142026/07/18 13:54:41 goose: up to current file version: 214152026/07/18 13:54:41 OK 2_object_stats_trigger.sql (3.96ms)14162026/07/18 13:54:41 goose: up to current file version: 214172026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures14182026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures14192026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures14202026/07/18 13:54:41 OK 2_object_stats_trigger.sql (1.18ms)14212026/07/18 13:54:41 goose: up to current file version: 21422--- PASS: TestService_healthCheckHandler (0.64s)14232026/07/18 13:54:41 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14242026/07/18 13:54:41 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1425--- PASS: TestService_NativeMTLS (0.65s)1426--- PASS: TestReadProxyInvalidPath (0.68s)14272026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures14282026/07/18 13:54:41 INFO Created nix-cache-info in bucket bucket=bucket291429=== NAME TestClientWithDependencies1430 client_integration_test.go:593: Built derivation: /build/TestClientWithDependencies1853759673/001/store/hpchlmwlnbd9a5y8ycnakpdsr89fgjp7-test-script1431--- PASS: TestMetricsInventory (0.65s)14322026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures14332026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures14342026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures14352026/07/18 13:54:41 INFO Created nix-cache-info in bucket bucket=bucket331436--- PASS: TestCacheStatsHandler (0.64s)1437--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.68s)14382026/07/18 13:54:41 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1439--- PASS: TestService_ReadAuthMiddleware (0.66s)14402026/07/18 13:54:41 INFO Created nix-cache-info in bucket bucket=bucket411441--- PASS: TestObjectStatsTrigger (0.68s)14422026/07/18 13:54:41 INFO Received cleanup request method=DELETE path=/api/pending_closures14432026/07/18 13:54:41 INFO Aborted multipart uploads count=11444--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.65s)1445=== NAME TestClientMultipleUploads1446 client_integration_test.go:338: Created store path 1: /build/TestClientMultipleUploads2208915041/001/store/mvpfrzzad6vg7bb65520bscpp4xfvnqq-test-file-1.txt14472026/07/18 13:54:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14482026-07-18 13:54:41.419 UTC [956] ERROR: Closure does not exist: id=114492026-07-18 13:54:41.419 UTC [956] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE14502026-07-18 13:54:41.419 UTC [956] STATEMENT: -- name: CommitPendingClosure :exec1451 SELECT commit_pending_closure($1::bigint)1452 1453--- PASS: TestService_cleanupPendingClosuresHandler (0.65s)14542026/07/18 13:54:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1455{"timestamp":"2026-07-18T13:54:41.440195197Z","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(381)"}1456{"timestamp":"2026-07-18T13:54:41.440317738Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket37, 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(381)"}14572026/07/18 13:54:41 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=NjVkYmE5NTUtMWVjNy00MzYzLThhM2MtYzlmYWYzNWM4N2Q2LjA1ZDYyNjZkLWQwYWEtNGU4YS05ZWY4LTM5Zjk2YzkxZjFkMHgxNzg0MzgyODgxNDE0NDY5MTYw1458=== NAME TestClientWithDependencies1459 client_integration_test.go:595: Found 1 dependencies (including self)14602026/07/18 13:54:41 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjVkYmE5NTUtMWVjNy00MzYzLThhM2MtYzlmYWYzNWM4N2Q2LjA1ZDYyNjZkLWQwYWEtNGU4YS05ZWY4LTM5Zjk2YzkxZjFkMHgxNzg0MzgyODgxNDE0NDY5MTYw parts=11461--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.69s)1462=== NAME TestClientIntegration1463 client_integration_test.go:276: Created store path: /build/TestClientIntegration1470376219/002/store/yp4fx7hbv4lj0rpg9vnwjqbmihssc208-test-file.txt1464=== NAME TestNARDeduplicationMetadataUploadBug1465 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1304170794/001/store/km2ws58g446ww71my30h2y1ylgd019bc-file1.txt1466=== NAME TestClientMultipleUploads1467 client_integration_test.go:338: Created store path 2: /build/TestClientMultipleUploads2208915041/001/store/kxwna3mh95b49gmnybl68hys8fqznpln-test-file-2.txt14682026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures14692026/07/18 13:54:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14702026/07/18 13:54:41 INFO Uploading xdhf1p882im3xz3ahnaf34qjcscnswhc-pinned-file.txt (128B)14712026/07/18 13:54:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14722026/07/18 13:54:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14732026/07/18 13:54:41 INFO Signed narinfos id=1 count=114742026/07/18 13:54:41 INFO Uploading 1 narinfos14752026/07/18 13:54:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14762026/07/18 13:54:41 INFO Completed upload id=114772026/07/18 13:54:41 INFO Upload complete. (110ms)1478=== NAME TestClientCADerivations1479 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4138404098/001/store/hjlzkk2da7anywc95j8vdzq507ikh3kj-ca-test14802026/07/18 13:54:41 INFO Received cleanup request method=DELETE path=/api/pending_closures14812026/07/18 13:54:41 INFO Aborted multipart uploads count=114822026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures1483--- PASS: TestMultipartCleanup (0.77s)14842026/07/18 13:54:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14852026/07/18 13:54:41 INFO Uploading hpchlmwlnbd9a5y8ycnakpdsr89fgjp7-test-script (136B)14862026/07/18 13:54:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14872026/07/18 13:54:41 INFO Signed narinfos id=1 count=114882026/07/18 13:54:41 INFO Uploading 1 narinfos14892026/07/18 13:54:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1490=== NAME TestClientCADerivations1491 client_ca_test.go:139: Found 1 dependencies (including self)14922026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures14932026/07/18 13:54:41 INFO Completed upload id=114942026/07/18 13:54:41 INFO Upload complete. (66ms)14952026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures1496=== NAME TestClientWithDependencies1497 client_integration_test.go:597: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1853759673/001/store) requires matching store prefix14982026/07/18 13:54:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14992026/07/18 13:54:41 INFO Uploading km2ws58g446ww71my30h2y1ylgd019bc-file1.txt (160B)15002026/07/18 13:54:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15012026/07/18 13:54:41 INFO Uploading yp4fx7hbv4lj0rpg9vnwjqbmihssc208-test-file.txt (152B)1502--- PASS: TestClientWithDependencies (0.84s)15032026/07/18 13:54:41 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"15042026/07/18 13:54:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15052026/07/18 13:54:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15062026/07/18 13:54:41 INFO Signed narinfos id=1 count=115072026/07/18 13:54:41 INFO Uploading 1 narinfos15082026/07/18 13:54:41 INFO Signed narinfos id=1 count=115092026/07/18 13:54:41 INFO Uploading 1 narinfos1510--- PASS: TestGCBugBareHashReferences (0.85s)15112026/07/18 13:54:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15122026/07/18 13:54:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15132026/07/18 13:54:41 INFO Completed upload id=115142026/07/18 13:54:41 INFO Upload complete. (96ms)15152026/07/18 13:54:41 INFO Completed upload id=115162026/07/18 13:54:41 INFO Upload complete. (98ms)1517=== NAME TestNARDeduplicationMetadataUploadBug1518 metadata_upload_test.go:54: Retrieved narinfo from S3:1519 StorePath: /build/TestNARDeduplicationMetadataUploadBug1304170794/001/store/km2ws58g446ww71my30h2y1ylgd019bc-file1.txt1520 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1521 Compression: zstd1522 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1523 NarSize: 1601524 References: 1525 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1526=== NAME TestClientIntegration1527 client_integration_test.go:292: Retrieved narinfo from S3:1528 StorePath: /build/TestClientIntegration1470376219/002/store/yp4fx7hbv4lj0rpg9vnwjqbmihssc208-test-file.txt1529 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1530 Compression: zstd1531 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11532 NarSize: 1521533 References: 1534 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11535=== NAME TestNARDeduplicationMetadataUploadBug1536 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1537 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):15382026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures1539 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1540=== NAME TestClientIntegration1541 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1542 client_integration_test.go:293: Decompressed .ls content (64 bytes):1543 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1544 client_integration_test.go:296: Testing garbage collection...15452026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures15462026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures15472026/07/18 13:54:41 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15482026/07/18 13:54:41 INFO Uploading kxwna3mh95b49gmnybl68hys8fqznpln-test-file-2.txt (160B)15492026/07/18 13:54:41 INFO Uploading rxny9kkis9igr7w9x2chhn74ym4fl5cd-test-file-0.txt (160B)15502026/07/18 13:54:41 INFO Uploading mvpfrzzad6vg7bb65520bscpp4xfvnqq-test-file-1.txt (160B)15512026/07/18 13:54:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15522026/07/18 13:54:41 INFO Signed narinfos id=3 count=115532026/07/18 13:54:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15542026/07/18 13:54:41 INFO Signed narinfos id=1 count=115552026/07/18 13:54:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15562026/07/18 13:54:41 INFO Signed narinfos id=2 count=115572026/07/18 13:54:41 INFO Uploading 3 narinfos15582026/07/18 13:54:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15592026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures15602026/07/18 13:54:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15612026/07/18 13:54:41 INFO Uploading fdhradi5kxsfah5cg91zkw78jj4mhiwf-unpinned-file.txt (128B)15622026/07/18 13:54:41 INFO Completed upload id=115632026/07/18 13:54:41 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15642026/07/18 13:54:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15652026/07/18 13:54:41 INFO Signed narinfos id=2 count=115662026/07/18 13:54:41 INFO Uploading 1 narinfos15672026/07/18 13:54:41 INFO Completed upload id=215682026/07/18 13:54:41 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete1569=== NAME TestNARDeduplicationMetadataUploadBug1570 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1304170794/001/store/0d9vanxib1r3lpjlhsarf5znq16qpd31-file2.txt15712026/07/18 13:54:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures15722026/07/18 13:54:41 INFO Completed upload id=315732026/07/18 13:54:41 INFO Upload complete. (146ms)1574=== NAME TestClientMultipleUploads1575 client_integration_test.go:349: Uploaded 3 paths in 176.022604ms15762026/07/18 13:54:41 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15772026/07/18 13:54:41 INFO Completed upload id=215782026/07/18 13:54:41 INFO Upload complete. (86ms)15792026/07/18 13:54:41 INFO Garbage collection started15802026/07/18 13:54:41 INFO Aborted multipart uploads count=01581--- PASS: TestClientMultipleUploads (0.89s)15822026/07/18 13:54:41 WARN Force mode enabled - objects will be deleted immediately without grace period15832026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures15842026/07/18 13:54:41 INFO Received create pin request method=POST path=/api/pins/myapp15852026/07/18 13:54:41 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2334114004/001/store/xdhf1p882im3xz3ahnaf34qjcscnswhc-pinned-file.txt narinfo_key=xdhf1p882im3xz3ahnaf34qjcscnswhc.narinfo15862026/07/18 13:54:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15872026/07/18 13:54:41 INFO Uploading hjlzkk2da7anywc95j8vdzq507ikh3kj-ca-test (144B)15882026/07/18 13:54:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures15892026/07/18 13:54:41 INFO Garbage collection started15902026/07/18 13:54:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15912026/07/18 13:54:41 INFO Signed narinfos id=1 count=115922026/07/18 13:54:41 INFO Uploading 1 narinfos15932026/07/18 13:54:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15942026/07/18 13:54:41 INFO Aborted multipart uploads count=015952026/07/18 13:54:41 WARN Force mode enabled - objects will be deleted immediately without grace period15962026/07/18 13:54:41 INFO Completed upload id=115972026/07/18 13:54:41 INFO Upload complete. (118ms)1598=== NAME TestClientCADerivations1599 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4138404098/001/store/hjlzkk2da7anywc95j8vdzq507ikh3kj-ca-test1600 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1601 Compression: zstd1602 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1603 NarSize: 1441604 References: 1605 Deriver: /build/TestClientCADerivations4138404098/001/store/abmgz0l70ffsn0dfnz9vig00ac84bh3i-ca-test.drv1606 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1607 client_ca_test.go:185: Checking for realisation files in S3...1608 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1609 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1610=== NAME TestOrphanedObjectsGC1611 orphaned_objects_gc_test.go:290: GC Test Summary:1612 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1613 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1614 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1615 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1616 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1617--- PASS: TestOrphanedObjectsGC (0.98s)16182026/07/18 13:54:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16192026/07/18 13:54:41 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=875.064236ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16202026/07/18 13:54:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16212026/07/18 13:54:41 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NjVkYmE5NTUtMWVjNy00MzYzLThhM2MtYzlmYWYzNWM4N2Q2LjZkNzQ0MWY5LWExMWQtNGVhMi04ZGNhLWFkOTc1MmYwNGNhNHgxNzg0MzgyODgxMjkwNDMxMDM0 parts=1216222026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures1623--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.02s)16242026/07/18 13:54:41 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NjVkYmE5NTUtMWVjNy00MzYzLThhM2MtYzlmYWYzNWM4N2Q2LmYwNTJkODAyLWQ0NWMtNGJiMS1hNDQyLWIwMTY5ODFiYzUyNHgxNzg0MzgyODgxNDE2ODg0NzYw parts=1016252026/07/18 13:54:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16262026/07/18 13:54:41 INFO Completed upload id=116272026/07/18 13:54:41 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016282026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures16292026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures16302026/07/18 13:54:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16312026/07/18 13:54:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures16322026/07/18 13:54:41 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16332026/07/18 13:54:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16342026/07/18 13:54:41 INFO Signed narinfos id=2 count=116352026/07/18 13:54:41 INFO Uploading 1 narinfos16362026/07/18 13:54:41 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16372026/07/18 13:54:41 INFO Completed upload id=216382026/07/18 13:54:41 INFO Upload complete. (92ms)16392026/07/18 13:54:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1640=== NAME TestNARDeduplicationMetadataUploadBug1641 metadata_upload_test.go:76: Retrieved narinfo from S3:1642 StorePath: /build/TestNARDeduplicationMetadataUploadBug1304170794/001/store/0d9vanxib1r3lpjlhsarf5znq16qpd31-file2.txt1643 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1644 Compression: zstd1645 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1646 NarSize: 1601647 References: 1648 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf16492026/07/18 13:54:41 INFO Aborted multipart uploads count=01650 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1651 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1652 {"version":1,"root":{"type":"regular","size":44}}16532026/07/18 13:54:41 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NjVkYmE5NTUtMWVjNy00MzYzLThhM2MtYzlmYWYzNWM4N2Q2LjUzMmFiZThiLTJkMmEtNDBiZS1iYjVhLTU1NTM4YjlhZTRhOXgxNzg0MzgyODgxMzM3MTUzNzg4 parts=121654--- PASS: TestRedundantMultipartUpload (1.04s)1655--- PASS: TestNARDeduplicationMetadataUploadBug (1.00s)16562026/07/18 13:54:41 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NjVkYmE5NTUtMWVjNy00MzYzLThhM2MtYzlmYWYzNWM4N2Q2LjJjODUzMTIyLWY2OGYtNGUzMS1hMThiLWE1N2FkODdmOGQ1NXgxNzg0MzgyODgxNDA4NDI5NTA5 parts=1016572026/07/18 13:54:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16582026/07/18 13:54:41 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=016592026/07/18 13:54:41 INFO Vacuumed table table=pending_closures16602026/07/18 13:54:41 INFO Vacuumed table table=pending_objects16612026/07/18 13:54:41 INFO Completed upload id=116622026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures16632026/07/18 13:54:41 INFO Vacuumed table table=multipart_uploads16642026/07/18 13:54:41 INFO Received uploads request method=POST path=/api/pending_closures16652026/07/18 13:54:41 INFO Vacuumed table table=closures16662026/07/18 13:54:41 INFO Vacuumed table table=objects16672026/07/18 13:54:41 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16682026/07/18 13:54:41 WARN Found objects in DB but missing from S3, will re-upload count=11669--- PASS: TestService_verifyS3Integrity (1.02s)16702026/07/18 13:54:41 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001671--- PASS: TestService_createPendingClosureHandler (1.05s)1672=== NAME TestClientCADerivations1673 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1674 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1675 error: binary cache 's3://bucket29?endpoint=http://localhost:33229®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4138404098/001/store'1676 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11677--- PASS: TestClientCADerivations (1.06s)1678=== NAME TestOrphanedObjectsGCStressTest1679 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1680--- PASS: TestUploadHandlersRejectOversizedBody (0.21s)1681 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.09s)1682 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.09s)1683 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.27s)1684=== NAME TestOrphanedObjectsGCStressTest1685 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion16862026/07/18 13:54:42 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=016872026/07/18 13:54:42 INFO Vacuumed table table=pending_closures16882026/07/18 13:54:42 INFO Vacuumed table table=pending_objects16892026/07/18 13:54:42 INFO Vacuumed table table=multipart_uploads16902026/07/18 13:54:42 INFO Vacuumed table table=closures16912026/07/18 13:54:42 INFO Vacuumed table table=objects16922026/07/18 13:54:42 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=016932026/07/18 13:54:42 INFO Vacuumed table table=pending_closures16942026/07/18 13:54:42 INFO Vacuumed table table=pending_objects16952026/07/18 13:54:42 INFO Vacuumed table table=multipart_uploads16962026/07/18 13:54:42 INFO Vacuumed table table=closures16972026/07/18 13:54:42 INFO Vacuumed table table=objects1698 orphaned_objects_gc_test.go:509: Stress test completed successfully:1699 orphaned_objects_gc_test.go:510: - Active objects preserved: 201700 orphaned_objects_gc_test.go:511: - Objects deleted: 2101701 orphaned_objects_gc_test.go:512: - Total GC'd: 2101702--- PASS: TestOrphanedObjectsGCStressTest (1.68s)17032026/07/18 13:54:42 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.715382144s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17042026/07/18 13:54:43 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01705=== NAME TestClientIntegration1706 client_integration_test.go:303: Objects in database after GC:1707 client_integration_test.go:303: Successfully deleted all objects with GC --force1708--- PASS: TestClientIntegration (2.89s)17092026/07/18 13:54:43 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01710=== NAME TestPinProtectsFromGC1711 client_integration_test.go:709: Pin successfully protected closure from garbage collection1712--- PASS: TestPinProtectsFromGC (2.97s)1713--- PASS: TestClientErrorHandling (0.00s)1714 --- PASS: TestClientErrorHandling/InvalidStorePath (0.66s)1715 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.80s)1716 --- PASS: TestClientErrorHandling/ServerNotAvailable (3.55s)17172026/07/18 13:54:47 WARN Rate limiter enabled after throttle name=s3-test rate=517182026/07/18 13:54:47 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1719=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1720 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101721 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001722--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.49s)1723PASS1724{"timestamp":"2026-07-18T13:54:47.710311763Z","level":"ERROR","fields":{"message":"Unknown connection IO error:Cancelled","peer_addr":"127.0.0.1:58414"},"target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":973,"threadName":"rustfs-worker","threadId":"ThreadId(374)"}17252026-07-18 13:54:47.865 UTC [248] LOG: received smart shutdown request17262026-07-18 13:54:47.870 UTC [248] LOG: background worker "logical replication launcher" (PID 258) exited with exit code 117272026-07-18 13:54:47.880 UTC [253] LOG: shutting down17282026-07-18 13:54:47.880 UTC [253] LOG: checkpoint starting: shutdown immediate17292026-07-18 13:54:48.820 UTC [253] LOG: checkpoint complete: wrote 9028 buffers (55.1%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 12 recycled; write=0.188 s, sync=0.744 s, total=0.941 s; sync files=14838, longest=0.001 s, average=0.001 s; distance=203941 kB, estimate=203941 kB; lsn=0/DE886E0, redo lsn=0/DE886E017302026-07-18 13:54:48.923 UTC [248] LOG: database system is shut down1731Running OIDC tests...1732=== RUN TestGlobMatch1733=== PAUSE TestGlobMatch1734=== RUN TestAudienceForIssuer1735=== PAUSE TestAudienceForIssuer1736=== RUN TestValidateToken_ValidToken1737=== PAUSE TestValidateToken_ValidToken1738=== RUN TestValidateToken_WrongAudience1739=== PAUSE TestValidateToken_WrongAudience1740=== RUN TestValidateToken_Expired1741=== PAUSE TestValidateToken_Expired1742=== RUN TestValidateToken_BoundClaimsMismatch1743=== PAUSE TestValidateToken_BoundClaimsMismatch1744=== RUN TestValidateToken_BoundSubjectMismatch1745=== PAUSE TestValidateToken_BoundSubjectMismatch1746=== RUN TestValidateToken_MultipleProviders1747=== PAUSE TestValidateToken_MultipleProviders1748=== RUN TestValidateToken_NoMatchingProvider1749=== PAUSE TestValidateToken_NoMatchingProvider1750=== CONT TestGlobMatch1751=== CONT TestValidateToken_NoMatchingProvider1752=== CONT TestValidateToken_Expired1753=== CONT TestValidateToken_ValidToken1754=== RUN TestGlobMatch/foo_foo1755=== PAUSE TestGlobMatch/foo_foo1756=== RUN TestGlobMatch/foo_bar1757=== PAUSE TestGlobMatch/foo_bar1758=== RUN TestGlobMatch/*_1759=== CONT TestAudienceForIssuer1760=== CONT TestValidateToken_WrongAudience1761=== CONT TestValidateToken_BoundSubjectMismatch1762=== CONT TestValidateToken_MultipleProviders1763=== CONT TestValidateToken_BoundClaimsMismatch1764=== PAUSE TestGlobMatch/*_1765=== RUN TestGlobMatch/*_anything1766=== PAUSE TestGlobMatch/*_anything1767--- PASS: TestAudienceForIssuer (0.00s)1768=== RUN TestGlobMatch/foo*_foo1769=== PAUSE TestGlobMatch/foo*_foo1770=== RUN TestGlobMatch/foo*_foobar1771=== PAUSE TestGlobMatch/foo*_foobar1772=== RUN TestGlobMatch/foo*_bar1773=== PAUSE TestGlobMatch/foo*_bar1774=== RUN TestGlobMatch/*bar_bar1775=== PAUSE TestGlobMatch/*bar_bar1776=== RUN TestGlobMatch/*bar_foobar1777=== PAUSE TestGlobMatch/*bar_foobar1778=== RUN TestGlobMatch/*bar_foo1779=== PAUSE TestGlobMatch/*bar_foo1780=== RUN TestGlobMatch/foo*bar_foobar1781=== PAUSE TestGlobMatch/foo*bar_foobar1782=== RUN TestGlobMatch/foo*bar_foo123bar1783=== PAUSE TestGlobMatch/foo*bar_foo123bar1784=== RUN TestGlobMatch/foo*bar_foobarbaz1785=== PAUSE TestGlobMatch/foo*bar_foobarbaz1786=== RUN TestGlobMatch/*/*_foo/bar1787=== PAUSE TestGlobMatch/*/*_foo/bar1788=== RUN TestGlobMatch/*/*_foo1789=== PAUSE TestGlobMatch/*/*_foo1790=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1791=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1792=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01793=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01794=== RUN TestGlobMatch/refs/*/main_refs/heads/main1795=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1796=== RUN TestGlobMatch/fo?_foo1797=== PAUSE TestGlobMatch/fo?_foo1798=== RUN TestGlobMatch/fo?_fo1799=== PAUSE TestGlobMatch/fo?_fo1800=== RUN TestGlobMatch/fo?_fooo1801=== PAUSE TestGlobMatch/fo?_fooo1802=== RUN TestGlobMatch/?oo_foo1803=== PAUSE TestGlobMatch/?oo_foo1804=== RUN TestGlobMatch/?oo_boo1805=== PAUSE TestGlobMatch/?oo_boo1806=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1807=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1808=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1809=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1810=== CONT TestGlobMatch/foo_foo1811=== CONT TestGlobMatch/foo*bar_foobarbaz1812=== CONT TestGlobMatch/*/*_foo/bar1813=== CONT TestGlobMatch/foo*bar_foo123bar1814=== CONT TestGlobMatch/foo*bar_foobar1815=== CONT TestGlobMatch/*bar_foo1816=== CONT TestGlobMatch/*bar_foobar1817=== CONT TestGlobMatch/*bar_bar1818=== CONT TestGlobMatch/foo*_bar1819=== CONT TestGlobMatch/foo*_foobar1820=== CONT TestGlobMatch/foo*_foo1821=== CONT TestGlobMatch/*_anything1822=== CONT TestGlobMatch/*_1823=== CONT TestGlobMatch/foo_bar1824=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01825=== CONT TestGlobMatch/fo?_foo1826=== CONT TestGlobMatch/refs/*/main_refs/heads/main1827=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1828=== CONT TestGlobMatch/*/*_foo1829=== CONT TestGlobMatch/?oo_boo1830=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1831=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1832=== CONT TestGlobMatch/?oo_foo1833=== CONT TestGlobMatch/fo?_fo1834=== CONT TestGlobMatch/fo?_fooo1835--- PASS: TestGlobMatch (0.01s)1836 --- PASS: TestGlobMatch/foo_foo (0.00s)1837 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1838 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1839 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1840 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1841 --- PASS: TestGlobMatch/*bar_foo (0.00s)1842 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1843 --- PASS: TestGlobMatch/*bar_bar (0.00s)1844 --- PASS: TestGlobMatch/foo*_bar (0.00s)1845 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1846 --- PASS: TestGlobMatch/foo*_foo (0.00s)1847 --- PASS: TestGlobMatch/*_anything (0.00s)1848 --- PASS: TestGlobMatch/*_ (0.00s)1849 --- PASS: TestGlobMatch/foo_bar (0.00s)1850 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1851 --- PASS: TestGlobMatch/fo?_foo (0.00s)1852 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1853 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1854 --- PASS: TestGlobMatch/*/*_foo (0.00s)1855 --- PASS: TestGlobMatch/?oo_boo (0.00s)1856 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1857 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1858 --- PASS: TestGlobMatch/?oo_foo (0.00s)1859 --- PASS: TestGlobMatch/fo?_fo (0.00s)1860 --- PASS: TestGlobMatch/fo?_fooo (0.00s)18612026/07/18 13:54:49 INFO OIDC provider initialized name=test18622026/07/18 13:54:49 INFO OIDC provider initialized name=provider118632026/07/18 13:54:49 INFO OIDC provider initialized name=test18642026/07/18 13:54:49 INFO OIDC provider initialized name=provider118652026/07/18 13:54:49 INFO OIDC provider initialized name=test18662026/07/18 13:54:49 INFO OIDC provider initialized name=test18672026/07/18 13:54:49 INFO OIDC provider initialized name=test18682026/07/18 13:54:49 INFO OIDC provider initialized name=provider21869--- PASS: TestValidateToken_NoMatchingProvider (0.02s)1870--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)1871--- PASS: TestValidateToken_WrongAudience (0.02s)1872--- PASS: TestValidateToken_MultipleProviders (0.02s)1873--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)1874--- PASS: TestValidateToken_ValidToken (0.02s)1875--- PASS: TestValidateToken_Expired (0.02s)1876PASS1877Running hook tests...1878=== RUN TestSendPathsEmpty1879=== PAUSE TestSendPathsEmpty1880=== RUN TestQueueEnqueueAndFetch1881=== PAUSE TestQueueEnqueueAndFetch1882=== RUN TestQueueDeduplication1883=== PAUSE TestQueueDeduplication1884=== RUN TestQueueRemove1885=== PAUSE TestQueueRemove1886=== RUN TestQueueFetchBatchLimit1887=== PAUSE TestQueueFetchBatchLimit1888=== RUN TestQueueFetchRemoveLifecycle1889=== PAUSE TestQueueFetchRemoveLifecycle1890=== RUN TestQueueConcurrentWriters1891=== PAUSE TestQueueConcurrentWriters1892=== RUN TestServerClientIntegration1893=== PAUSE TestServerClientIntegration1894=== RUN TestServerQueueError1895=== PAUSE TestServerQueueError1896=== RUN TestGetListenerSocketActivation1897 server_test.go:210: === RUN TestGetListenerSocketActivation1898 --- PASS: TestGetListenerSocketActivation (0.00s)1899 PASS1900 1901--- PASS: TestGetListenerSocketActivation (0.01s)1902=== RUN TestWorkerUploadsAndRemoves1903=== PAUSE TestWorkerUploadsAndRemoves1904=== RUN TestWorkerSkipsGCdPaths1905=== PAUSE TestWorkerSkipsGCdPaths1906=== RUN TestWorkerPrunesClosureDeps1907=== PAUSE TestWorkerPrunesClosureDeps1908=== CONT TestSendPathsEmpty1909=== CONT TestServerClientIntegration1910=== CONT TestWorkerUploadsAndRemoves1911=== CONT TestServerQueueError1912=== CONT TestWorkerPrunesClosureDeps1913=== CONT TestWorkerSkipsGCdPaths1914=== CONT TestQueueRemove1915=== CONT TestQueueFetchRemoveLifecycle1916=== CONT TestQueueFetchBatchLimit1917--- PASS: TestSendPathsEmpty (0.00s)1918=== CONT TestQueueConcurrentWriters1919=== CONT TestQueueDeduplication19202026/07/18 13:54:49 ERROR Failed to queue paths error="permission denied" count=11921=== CONT TestQueueEnqueueAndFetch1922--- PASS: TestServerClientIntegration (0.01s)1923--- PASS: TestServerQueueError (0.01s)19242026/07/18 13:54:49 INFO Upload queue status pending=219252026/07/18 13:54:49 INFO Uploading batch count=119262026/07/18 13:54:49 INFO Upload queue status pending=219272026/07/18 13:54:49 INFO Uploading batch count=21928--- PASS: TestQueueEnqueueAndFetch (0.01s)1929--- PASS: TestQueueFetchBatchLimit (0.01s)19302026/07/18 13:54:49 INFO Upload queue status pending=219312026/07/18 13:54:49 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1760967827/002/nonexistent1932--- PASS: TestQueueRemove (0.01s)1933--- PASS: TestQueueDeduplication (0.01s)1934--- PASS: TestQueueFetchRemoveLifecycle (0.01s)19352026/07/18 13:54:49 INFO Uploading batch count=11936--- PASS: TestWorkerPrunesClosureDeps (0.06s)1937--- PASS: TestWorkerUploadsAndRemoves (0.07s)1938--- PASS: TestWorkerSkipsGCdPaths (0.06s)1939--- PASS: TestQueueConcurrentWriters (0.16s)1940PASS