niks3-go-unit-tests
x86_64-linux.go-unit-tests
· build #105
· raw
1tribuchet: building on jamie2Running 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 TestScriptTokenEmptyToken73=== CONT TestRateLimiterFeedback74=== CONT TestEncodeNixBase32WithRealHash75=== CONT TestPathInfoCACompatibility76--- PASS: TestEncodeNixBase32WithRealHash (0.00s)77=== CONT TestFileTokenMissing78=== RUN TestPathInfoCACompatibility/null_ca_field79=== PAUSE TestPathInfoCACompatibility/null_ca_field80=== CONT TestParsePathInfoJSONMultiplePaths81=== CONT TestParsePathInfoJSON82--- PASS: TestFileTokenMissing (0.00s)83=== CONT TestFileTokenReadsAndCaches84=== RUN TestParsePathInfoJSON/Nix_format85=== PAUSE TestParsePathInfoJSON/Nix_format86=== CONT TestPathInfoHashCompatibility87=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)88=== CONT TestGetStorePathHash89=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)90=== CONT TestConvertHashToNix3291=== CONT TestDumpPathMatchesNix92=== RUN TestConvertHashToNix32/SRI_format_to_Nix3293=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix3294=== RUN TestConvertHashToNix32/already_Nix32_format95=== PAUSE TestConvertHashToNix32/already_Nix32_format96=== CONT TestEncodeNixBase3297=== CONT TestDumpPathWriterError98=== CONT TestDumpPathSingleFile99=== CONT TestScriptTokenScriptFails100=== CONT TestScriptTokenEmptyCommand101=== CONT TestPartSizeForNAR102=== CONT TestUploadMultipart_SupersededByPeer103=== CONT TestScriptTokenBadJSON104=== CONT TestCaseHackSuffix105=== CONT TestSetClientTLSErrors106=== CONT TestScriptTokenCachesUntilRefresh107=== CONT TestScriptTokenNoExpiryRerunsEveryCall108=== CONT TestFileTokenEmpty109=== RUN TestRateLimiterFeedback/429_enables_limiter110=== RUN TestPathInfoCACompatibility/old_string_format_-_text111=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths112=== RUN TestParsePathInfoJSON/Lix_format113=== PAUSE TestParsePathInfoJSON/Lix_format114=== RUN TestParsePathInfoJSON/empty_input115=== RUN TestEncodeNixBase32/test_string_hash116=== PAUSE TestEncodeNixBase32/test_string_hash117=== RUN TestEncodeNixBase32/empty_input118=== PAUSE TestEncodeNixBase32/empty_input119=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon120=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon121=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI122=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI123=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512124=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512125=== CONT TestShellSplit126=== CONT TestSetClientTLSDoesNotMutateDefaultTransport127=== CONT TestShellSplitErrors128=== CONT TestResolveStorePath129=== RUN TestUploadMultipart_SupersededByPeer/exists130=== PAUSE TestUploadMultipart_SupersededByPeer/exists131=== PAUSE TestRateLimiterFeedback/429_enables_limiter132=== RUN TestRateLimiterFeedback/503_enables_limiter133=== PAUSE TestRateLimiterFeedback/503_enables_limiter134=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter135=== CONT TestSetClientTLS136=== RUN TestUploadMultipart_SupersededByPeer/missing137=== RUN TestPartSizeForNAR/zero_stays_at_minimum138--- PASS: TestScriptTokenEmptyCommand (0.00s)139=== CONT TestStaticToken140=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)141=== PAUSE TestParsePathInfoJSON/empty_input142=== RUN TestConvertHashToNix32/invalid_format143=== CONT TestEncodeNixBase32/empty_input144=== RUN TestParsePathInfoJSON/whitespace_only145=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon146=== PAUSE TestConvertHashToNix32/invalid_format147=== CONT TestDoWithRetry_BodyReplayedViaGetBody148=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter149=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter150=== CONT TestEncodeNixBase32/test_string_hash151=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess152=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths153=== PAUSE TestUploadMultipart_SupersededByPeer/missing154--- PASS: TestFileTokenReadsAndCaches (0.00s)155=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum156=== RUN TestSetClientTLSErrors/missing_cert_file157=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI158=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512159=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text160=== RUN TestGetStorePathHash/valid_store_path161=== PAUSE TestParsePathInfoJSON/whitespace_only162=== CONT TestConvertHashToNix32/invalid_format163=== CONT TestConvertHashToNix32/already_Nix32_format164=== RUN TestParsePathInfoJSON/invalid_JSON165=== CONT TestConvertHashToNix32/SRI_format_to_Nix32166=== PAUSE TestParsePathInfoJSON/invalid_JSON167=== CONT TestParsePathInfoJSON/Nix_format168=== CONT TestParsePathInfoJSON/invalid_JSON169=== CONT TestParsePathInfoJSON/empty_input170=== CONT TestParsePathInfoJSON/whitespace_only171=== CONT TestUploadMultipart_SupersededByPeer/exists172=== CONT TestUploadMultipart_SupersededByPeer/missing1732026/07/19 09:59:21 WARN Rate limiter enabled after throttle name=server-test rate=51742026/07/19 09:59:21 WARN Rate limiter enabled after throttle name=server-test rate=5175--- PASS: TestShellSplit (0.00s)1762026/07/19 09:59:21 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34497177--- PASS: TestShellSplitErrors (0.00s)178--- PASS: TestFileTokenEmpty (0.00s)179=== RUN TestPartSizeForNAR/small_stays_at_minimum180=== PAUSE TestGetStorePathHash/valid_store_path181=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive182=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter183=== CONT TestRateLimiterFeedback/429_enables_limiter184=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter185=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter1862026/07/19 09:59:21 WARN Rate limiter backed off name=server-test rate=51872026/07/19 09:59:21 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34497188=== CONT TestParsePathInfoJSON/Lix_format189--- PASS: TestResolveStorePath (0.00s)190--- PASS: TestScriptTokenEmptyToken (0.01s)191--- PASS: TestStaticToken (0.00s)192=== PAUSE TestSetClientTLSErrors/missing_cert_file193=== PAUSE TestPartSizeForNAR/small_stays_at_minimum194=== RUN TestGetStorePathHash/basename_without_hyphen_should_error195=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive196=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum197=== RUN TestPathInfoCACompatibility/new_structured_format_-_text198=== CONT TestRateLimiterFeedback/503_enables_limiter199=== RUN TestSetClientTLS/rejects_connection_without_client_cert2002026/07/19 09:59:21 WARN Rate limiter enabled after throttle name=server-test rate=5201--- PASS: TestScriptTokenScriptFails (0.01s)2022026/07/19 09:59:21 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:37225203=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths204=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths205=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths206=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths207=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error2082026/07/19 09:59:21 WARN Rate limiter backed off name=server-test rate=5209=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum210=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text211=== RUN TestSetClientTLSErrors/missing_key_file212=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method213=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method214=== PAUSE TestSetClientTLSErrors/missing_key_file215--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)216=== RUN TestSetClientTLSErrors/missing_ca_file217=== PAUSE TestSetClientTLSErrors/missing_ca_file218=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error2192026/07/19 09:59:21 WARN Rate limiter enabled after throttle name=server-test rate=5220=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error2212026/07/19 09:59:21 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:43275222=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts223=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts224=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert2252026/07/19 09:59:21 WARN Rate limiter backed off name=server-test rate=5226=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA227=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA228=== RUN TestSetClientTLS/preserves_debug_logging_transport229=== CONT TestPathInfoCACompatibility/null_ca_field230=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive231=== CONT TestPathInfoCACompatibility/new_structured_format_-_text232=== CONT TestPathInfoCACompatibility/old_string_format_-_text233=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method234--- PASS: TestScriptTokenBadJSON (0.01s)235--- PASS: TestDoServerRequestAttachesToken (0.01s)236=== RUN TestSetClientTLSErrors/invalid_ca_file237--- PASS: TestEncodeNixBase32 (0.00s)238 --- PASS: TestEncodeNixBase32/empty_input (0.00s)239 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)240--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)241=== PAUSE TestSetClientTLSErrors/invalid_ca_file242=== CONT TestSetClientTLSErrors/missing_cert_file243=== CONT TestSetClientTLSErrors/invalid_ca_file244=== CONT TestSetClientTLSErrors/missing_key_file245=== RUN TestPartSizeForNAR/1_TiB246=== PAUSE TestPartSizeForNAR/1_TiB247=== PAUSE TestSetClientTLS/preserves_debug_logging_transport248=== CONT TestSetClientTLS/rejects_connection_without_client_cert249=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error250=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error251=== CONT TestGetStorePathHash/valid_store_path252=== CONT TestGetStorePathHash/basename_without_hyphen_should_error253--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)254=== CONT TestSetClientTLSErrors/missing_ca_file255--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)256 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)257 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)258=== RUN TestPartSizeForNAR/5_TiB_S3_max_object259=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object260=== CONT TestSetClientTLS/preserves_debug_logging_transport261=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA262=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error263=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error264--- PASS: TestRateLimiterFeedback (0.02s)265 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)266 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)267 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)268 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)269=== RUN TestPartSizeForNAR/capped_at_5_GiB270=== PAUSE TestPartSizeForNAR/capped_at_5_GiB271=== CONT TestPartSizeForNAR/zero_stays_at_minimum272=== CONT TestPartSizeForNAR/1_TiB273--- PASS: TestPathInfoHashCompatibility (0.00s)274 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)275 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)276 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)277 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)278--- PASS: TestConvertHashToNix32 (0.01s)279 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)280 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)281 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)282--- PASS: TestParsePathInfoJSON (0.02s)283 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)284 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)285 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)286 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)287 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)288=== CONT TestPartSizeForNAR/small_stays_at_minimum289--- PASS: TestParsePathInfoJSONMultiplePaths (0.02s)290 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)291 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)292--- PASS: TestPathInfoCACompatibility (0.02s)293 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)294 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)295 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)296 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)297 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)298=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum299=== CONT TestPartSizeForNAR/capped_at_5_GiB300=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts301=== CONT TestPartSizeForNAR/5_TiB_S3_max_object302--- PASS: TestGetStorePathHash (0.02s)303 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)304 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)305 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)306 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)307--- PASS: TestPartSizeForNAR (0.02s)308 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)309 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)310 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)311 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)312 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)313 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)314 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)315--- PASS: TestSetClientTLSErrors (0.02s)316 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)317 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)318 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)319 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)320--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)3212026/07/19 09:59:21 http: TLS handshake error from 127.0.0.1:58822: remote error: tls: bad certificate322--- PASS: TestSetClientTLS (0.02s)323 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.00s)324 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)325 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)326--- PASS: TestDumpPathWriterError (0.04s)327--- PASS: TestDumpPathSingleFile (0.04s)328--- PASS: TestCaseHackSuffix (0.04s)329--- PASS: TestDumpPathMatchesNix (0.08s)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/postgres2361916105/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/postgres2361916105/data -l logfile start359360/build/postgres2361916105:5432 - no response3612026-07-19 09:59:23.763 UTC [112] LOG: starting PostgreSQL 18.4 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit3622026-07-19 09:59:23.763 UTC [112] LOG: listening on Unix socket "/build/postgres2361916105/.s.PGSQL.5432"3632026-07-19 09:59:23.769 UTC [119] LOG: database system was shut down at 2026-07-19 09:59:23 UTC3642026-07-19 09:59:23.773 UTC [112] LOG: database system is ready to accept connections365/build/postgres2361916105:5432 - accepting connections366=== RUN TestService_AuthMiddleware367=== PAUSE TestService_AuthMiddleware368=== RUN TestService_AuthMiddleware_MTLSProxyHeader369=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader370=== RUN TestService_AuthMiddleware_MTLSBoundSubjects371=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects372=== RUN TestService_ReadAuthMiddleware373=== PAUSE TestService_ReadAuthMiddleware374=== RUN TestService_AuthMiddleware_OIDC375=== PAUSE TestService_AuthMiddleware_OIDC376=== RUN TestCacheConfigHandler377=== PAUSE TestCacheConfigHandler378=== RUN TestCacheStatsHandler379=== PAUSE TestCacheStatsHandler380=== RUN TestClientCADerivations381=== PAUSE TestClientCADerivations382=== RUN TestClientErrorHandling383=== PAUSE TestClientErrorHandling384=== RUN TestClientIntegration385=== PAUSE TestClientIntegration386=== RUN TestClientMultipleUploads387=== PAUSE TestClientMultipleUploads388=== RUN TestClientWithDependencies389=== PAUSE TestClientWithDependencies390=== RUN TestPinProtectsFromGC391=== PAUSE TestPinProtectsFromGC392=== RUN TestGCAdvisoryLockBlocksConcurrentRun393{"timestamp":"2026-07-19T09:59:24.277911489Z","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(692)"}394395thread 'rustfs-worker' (897) panicked at /build/rustfs-1.0.0-beta.7-vendor/source-registry-0/reqwest-0.13.4/src/async_impl/client.rs:2507:38:396Client::new(): reqwest::Error { kind: Builder, source: General("No CA certificates were loaded from the system") }397note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace3982026-07-19 09:59:24.382 UTC [914] ERROR: relation "goose_db_version" does not exist at character 363992026-07-19 09:59:24.382 UTC [914] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4002026/07/19 09:59:24 OK 20241026095416_initial_model.sql (8.32ms)4012026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (1.62ms)4022026/07/19 09:59:24 OK 20251218171726_add_pins.sql (2.74ms)4032026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (2.43ms)4042026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200004052026/07/19 09:59:24 OK 1_commit_pending_closure.sql (1.79ms)4062026/07/19 09:59:24 OK 2_object_stats_trigger.sql (748.41µs)4072026/07/19 09:59:24 goose: up to current file version: 2408--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.15s)409=== RUN TestGCBugBareHashReferences410=== PAUSE TestGCBugBareHashReferences411=== RUN TestGCMetrics412=== PAUSE TestGCMetrics413=== RUN TestGCTaskStore_StartNew414=== PAUSE TestGCTaskStore_StartNew415=== RUN TestGCTaskStore_DeduplicateSameParams416=== PAUSE TestGCTaskStore_DeduplicateSameParams417=== RUN TestGCTaskStore_ConflictDifferentParams418=== PAUSE TestGCTaskStore_ConflictDifferentParams419=== RUN TestGCTaskStore_GetEmpty420=== PAUSE TestGCTaskStore_GetEmpty421=== RUN TestGCTaskStore_GetReturnsLatest422=== PAUSE TestGCTaskStore_GetReturnsLatest423=== RUN TestGCTaskStore_CompletedAllowsNewTask424=== PAUSE TestGCTaskStore_CompletedAllowsNewTask425=== RUN TestGCTaskStore_PhaseUpdates426=== PAUSE TestGCTaskStore_PhaseUpdates427=== RUN TestGCTaskStore_Fail428=== PAUSE TestGCTaskStore_Fail429=== RUN TestGracefulShutdownDrainsInflight430=== PAUSE TestGracefulShutdownDrainsInflight431=== RUN TestService_healthCheckHandler432=== PAUSE TestService_healthCheckHandler433=== RUN TestGenerateLandingPage434=== PAUSE TestGenerateLandingPage435=== RUN TestNARDeduplicationMetadataUploadBug436=== PAUSE TestNARDeduplicationMetadataUploadBug437=== RUN TestMetricsInventory438=== PAUSE TestMetricsInventory439=== RUN TestService_NativeMTLS440=== PAUSE TestService_NativeMTLS441=== RUN TestServerTLSConfig442=== PAUSE TestServerTLSConfig443=== RUN TestMultipartCleanup444=== PAUSE TestMultipartCleanup445=== RUN TestObjectStatsTrigger446=== PAUSE TestObjectStatsTrigger447=== RUN TestOrphanedObjectsGC448=== PAUSE TestOrphanedObjectsGC449=== RUN TestOrphanedObjectsGCStressTest450=== PAUSE TestOrphanedObjectsGCStressTest451=== RUN TestResurrectedObjectNotDeleted452=== PAUSE TestResurrectedObjectNotDeleted453=== RUN TestParseSingleRange454=== PAUSE TestParseSingleRange455=== RUN TestIsValidCachePath456=== PAUSE TestIsValidCachePath457=== RUN TestReadProxyNarinfo458=== PAUSE TestReadProxyNarinfo459=== RUN TestReadProxyNarinfoAlreadyDecompressed460=== PAUSE TestReadProxyNarinfoAlreadyDecompressed461=== RUN TestReadProxyNarStreaming462=== PAUSE TestReadProxyNarStreaming463=== RUN TestReadProxy404464=== PAUSE TestReadProxy404465=== RUN TestReadProxyInvalidPath466=== PAUSE TestReadProxyInvalidPath467=== RUN TestReadProxyHead468=== PAUSE TestReadProxyHead469=== RUN TestReadProxyConditionalGet470=== PAUSE TestReadProxyConditionalGet471=== RUN TestReadProxyRootRedirectsToIndexHTML472=== PAUSE TestReadProxyRootRedirectsToIndexHTML473=== RUN TestReadProxyDisabled474=== PAUSE TestReadProxyDisabled475=== RUN TestReadProxyRangeRequest476=== PAUSE TestReadProxyRangeRequest477=== RUN TestRedundantMultipartUpload478=== PAUSE TestRedundantMultipartUpload479=== RUN TestCompleteMultipartUpload_ErrorButObjectExists480=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists481=== RUN TestCompletedNarNotReofferedAcrossClosures482=== PAUSE TestCompletedNarNotReofferedAcrossClosures483=== RUN TestPresignedUploadRegisteredBeforeCommit484=== PAUSE TestPresignedUploadRegisteredBeforeCommit485=== RUN TestService_Rustfstest486=== PAUSE TestService_Rustfstest487=== RUN TestSystemdListenerNotActivated488--- PASS: TestSystemdListenerNotActivated (0.00s)489=== RUN TestWatchdogBeatsWhenHealthy490--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)491=== RUN TestWatchdogSkipsWhenUnhealthy4922026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4932026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4942026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4952026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4962026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4972026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4982026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4992026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5002026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5012026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"502--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)503=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle504=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle505=== RUN TestProxyWriteTimeout506=== PAUSE TestProxyWriteTimeout507=== RUN TestIsValidUploadKey508=== PAUSE TestIsValidUploadKey509=== RUN TestUploadHandlersRejectInvalidKeys510=== PAUSE TestUploadHandlersRejectInvalidKeys511=== RUN TestUploadHandlersRejectOversizedBody512=== PAUSE TestUploadHandlersRejectOversizedBody513=== RUN TestService_cleanupPendingClosuresHandler514=== PAUSE TestService_cleanupPendingClosuresHandler515=== RUN TestService_createPendingClosureHandler516=== PAUSE TestService_createPendingClosureHandler517=== RUN TestService_verifyS3Integrity518=== PAUSE TestService_verifyS3Integrity519=== RUN TestCompleteMultipartUnregistered520=== PAUSE TestCompleteMultipartUnregistered521=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT522=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT523=== CONT TestService_AuthMiddleware524=== CONT TestObjectStatsTrigger525=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT526=== CONT TestCompleteMultipartUnregistered527=== CONT TestService_verifyS3Integrity528=== CONT TestService_createPendingClosureHandler529=== CONT TestService_cleanupPendingClosuresHandler530=== CONT TestUploadHandlersRejectOversizedBody531=== CONT TestUploadHandlersRejectInvalidKeys532=== CONT TestIsValidUploadKey533=== RUN TestIsValidUploadKey/narinfo534=== PAUSE TestIsValidUploadKey/narinfo535=== RUN TestIsValidUploadKey/nar_zst536=== PAUSE TestIsValidUploadKey/nar_zst537=== CONT TestProxyWriteTimeout538=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle539=== CONT TestService_Rustfstest540=== CONT TestPresignedUploadRegisteredBeforeCommit541=== CONT TestCompletedNarNotReofferedAcrossClosures542=== CONT TestCompleteMultipartUpload_ErrorButObjectExists543=== CONT TestRedundantMultipartUpload544=== CONT TestReadProxyRangeRequest545=== CONT TestReadProxyDisabled546=== CONT TestReadProxyRootRedirectsToIndexHTML547=== CONT TestReadProxyConditionalGet548=== CONT TestReadProxyHead549=== CONT TestReadProxyInvalidPath550=== CONT TestReadProxy404551=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info552=== RUN TestIsValidUploadKey/nar_xz553=== RUN TestProxyWriteTimeout/narinfo554=== PAUSE TestIsValidUploadKey/nar_xz555=== RUN TestIsValidUploadKey/nar_plain556=== PAUSE TestIsValidUploadKey/nar_plain557=== RUN TestIsValidUploadKey/listing558=== PAUSE TestIsValidUploadKey/listing559=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info560=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal561=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal562=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key563=== PAUSE TestProxyWriteTimeout/narinfo564=== RUN TestIsValidUploadKey/build_log565=== PAUSE TestIsValidUploadKey/build_log566=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key567=== RUN TestProxyWriteTimeout/1_GiB_nar568=== PAUSE TestProxyWriteTimeout/1_GiB_nar569=== RUN TestIsValidUploadKey/build_log_home-manager_file570=== PAUSE TestIsValidUploadKey/build_log_home-manager_file571=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key572=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key573=== RUN TestProxyWriteTimeout/10_GiB_nar574=== PAUSE TestProxyWriteTimeout/10_GiB_nar575=== RUN TestIsValidUploadKey/build_log_plus_in_name576=== PAUSE TestIsValidUploadKey/build_log_plus_in_name577=== RUN TestIsValidUploadKey/build_log_question_mark578=== CONT TestReadProxyNarStreaming579=== RUN TestProxyWriteTimeout/unknown_size580=== PAUSE TestProxyWriteTimeout/unknown_size581=== PAUSE TestIsValidUploadKey/build_log_question_mark582=== RUN TestIsValidUploadKey/build_log_equals583=== PAUSE TestIsValidUploadKey/build_log_equals584=== RUN TestIsValidUploadKey/realisation585=== PAUSE TestIsValidUploadKey/realisation586=== RUN TestIsValidUploadKey/realisation_plus_in_output587=== PAUSE TestIsValidUploadKey/realisation_plus_in_output588=== CONT TestReadProxyNarinfoAlreadyDecompressed589=== RUN TestIsValidUploadKey/nix-cache-info590=== PAUSE TestIsValidUploadKey/nix-cache-info591=== RUN TestIsValidUploadKey/index.html592=== PAUSE TestIsValidUploadKey/index.html593=== RUN TestIsValidUploadKey/narinfo_key,_nar_type594=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type595=== RUN TestIsValidUploadKey/nar_key,_narinfo_type596=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type597=== RUN TestIsValidUploadKey/listing_key,_narinfo_type598=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type599=== RUN TestIsValidUploadKey/traversal600=== PAUSE TestIsValidUploadKey/traversal601=== RUN TestIsValidUploadKey/traversal_nar602=== PAUSE TestIsValidUploadKey/traversal_nar603=== RUN TestIsValidUploadKey/absolute604=== PAUSE TestIsValidUploadKey/absolute605=== RUN TestIsValidUploadKey/empty_key606=== PAUSE TestIsValidUploadKey/empty_key607=== RUN TestIsValidUploadKey/unknown_type608=== PAUSE TestIsValidUploadKey/unknown_type609=== CONT TestReadProxyNarinfo610=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart611=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart612=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts613=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts614=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure615=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure616=== CONT TestIsValidCachePath617=== RUN TestIsValidCachePath/narinfo618=== PAUSE TestIsValidCachePath/narinfo619=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars620=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars621=== RUN TestIsValidCachePath/nar_zst622=== PAUSE TestIsValidCachePath/nar_zst623=== RUN TestIsValidCachePath/nar_xz624=== PAUSE TestIsValidCachePath/nar_xz625=== RUN TestIsValidCachePath/nar_bz2626=== PAUSE TestIsValidCachePath/nar_bz2627=== RUN TestIsValidCachePath/nar_uncompressed628=== PAUSE TestIsValidCachePath/nar_uncompressed629=== RUN TestIsValidCachePath/ls630=== PAUSE TestIsValidCachePath/ls631=== RUN TestIsValidCachePath/log632=== PAUSE TestIsValidCachePath/log633=== RUN TestIsValidCachePath/realisation634=== PAUSE TestIsValidCachePath/realisation635=== RUN TestIsValidCachePath/nix-cache-info636=== PAUSE TestIsValidCachePath/nix-cache-info637=== RUN TestIsValidCachePath/index.html638=== PAUSE TestIsValidCachePath/index.html639=== RUN TestIsValidCachePath/traversal_parent640=== PAUSE TestIsValidCachePath/traversal_parent641=== RUN TestIsValidCachePath/traversal_in_middle642=== PAUSE TestIsValidCachePath/traversal_in_middle643=== RUN TestIsValidCachePath/invalid_char_e644=== PAUSE TestIsValidCachePath/invalid_char_e645=== RUN TestIsValidCachePath/invalid_char_u646=== PAUSE TestIsValidCachePath/invalid_char_u647=== RUN TestIsValidCachePath/random_path648=== PAUSE TestIsValidCachePath/random_path649=== RUN TestIsValidCachePath/empty650=== PAUSE TestIsValidCachePath/empty651=== RUN TestIsValidCachePath/leading_slash652=== PAUSE TestIsValidCachePath/leading_slash653=== RUN TestIsValidCachePath/wrong_extension654=== PAUSE TestIsValidCachePath/wrong_extension655=== RUN TestIsValidCachePath/short_hash656=== PAUSE TestIsValidCachePath/short_hash657=== CONT TestParseSingleRange658=== RUN TestParseSingleRange/none659=== PAUSE TestParseSingleRange/none660=== RUN TestParseSingleRange/unknown_unit661=== PAUSE TestParseSingleRange/unknown_unit662=== RUN TestParseSingleRange/multi-range_ignored663=== PAUSE TestParseSingleRange/multi-range_ignored664=== RUN TestParseSingleRange/malformed_no_dash665=== PAUSE TestParseSingleRange/malformed_no_dash666=== RUN TestParseSingleRange/malformed_both_empty667=== PAUSE TestParseSingleRange/malformed_both_empty668=== RUN TestParseSingleRange/malformed_end_before_start669=== PAUSE TestParseSingleRange/malformed_end_before_start670=== RUN TestParseSingleRange/closed671=== PAUSE TestParseSingleRange/closed672=== RUN TestParseSingleRange/open-ended673=== PAUSE TestParseSingleRange/open-ended674=== RUN TestParseSingleRange/end_clamped_to_size675=== PAUSE TestParseSingleRange/end_clamped_to_size676=== RUN TestParseSingleRange/suffix677=== PAUSE TestParseSingleRange/suffix678=== RUN TestParseSingleRange/suffix_exceeds_size679=== PAUSE TestParseSingleRange/suffix_exceeds_size680=== RUN TestParseSingleRange/single_byte681=== PAUSE TestParseSingleRange/single_byte682=== RUN TestParseSingleRange/start_past_EOF683=== PAUSE TestParseSingleRange/start_past_EOF684=== RUN TestParseSingleRange/start_far_past_EOF685=== PAUSE TestParseSingleRange/start_far_past_EOF686=== CONT TestResurrectedObjectNotDeleted6872026-07-19 09:59:24.963 UTC [987] ERROR: relation "goose_db_version" does not exist at character 366882026-07-19 09:59:24.963 UTC [987] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6892026-07-19 09:59:24.965 UTC [988] ERROR: relation "goose_db_version" does not exist at character 366902026-07-19 09:59:24.965 UTC [988] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6912026-07-19 09:59:25.007 UTC [989] ERROR: relation "goose_db_version" does not exist at character 366922026-07-19 09:59:25.007 UTC [989] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6932026-07-19 09:59:25.059 UTC [990] ERROR: relation "goose_db_version" does not exist at character 366942026-07-19 09:59:25.059 UTC [990] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6952026-07-19 09:59:25.065 UTC [991] ERROR: relation "goose_db_version" does not exist at character 366962026-07-19 09:59:25.065 UTC [991] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6972026-07-19 09:59:25.081 UTC [992] ERROR: relation "goose_db_version" does not exist at character 366982026-07-19 09:59:25.081 UTC [992] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6992026-07-19 09:59:25.100 UTC [993] ERROR: relation "goose_db_version" does not exist at character 367002026-07-19 09:59:25.100 UTC [993] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7012026/07/19 09:59:25 OK 20241026095416_initial_model.sql (203.8ms)7022026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (76.04ms)7032026/07/19 09:59:25 OK 20241026095416_initial_model.sql (291.36ms)7042026/07/19 09:59:25 OK 20241026095416_initial_model.sql (290.85ms)7052026/07/19 09:59:25 OK 20251218171726_add_pins.sql (79.33ms)7062026/07/19 09:59:25 OK 20241026095416_initial_model.sql (208.19ms)7072026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (108.52ms)7082026-07-19 09:59:25.451 UTC [994] ERROR: relation "goose_db_version" does not exist at character 367092026-07-19 09:59:25.451 UTC [994] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7102026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (137.5ms)7112026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200007122026/07/19 09:59:25 OK 20251218171726_add_pins.sql (72.97ms)7132026/07/19 09:59:25 OK 20241026095416_initial_model.sql (179.46ms)7142026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (83.6ms)7152026/07/19 09:59:25 OK 20241026095416_initial_model.sql (179.43ms)7162026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (176.61ms)7172026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (5.52ms)7182026/07/19 09:59:25 OK 1_commit_pending_closure.sql (10.51ms)7192026/07/19 09:59:25 OK 20241026095416_initial_model.sql (188.83ms)7202026/07/19 09:59:25 OK 20251218171726_add_pins.sql (8.53ms)7212026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (6.64ms)7222026-07-19 09:59:25.522 UTC [995] ERROR: relation "goose_db_version" does not exist at character 367232026-07-19 09:59:25.522 UTC [995] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7242026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (11.8ms)7252026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200007262026/07/19 09:59:25 OK 2_object_stats_trigger.sql (4.11ms)7272026/07/19 09:59:25 goose: up to current file version: 27282026/07/19 09:59:25 OK 20251218171726_add_pins.sql (10.73ms)7292026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (6.38ms)7302026/07/19 09:59:25 OK 1_commit_pending_closure.sql (5.3ms)7312026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures7322026/07/19 09:59:25 OK 20251218171726_add_pins.sql (10.47ms)7332026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures7342026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures7352026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (9.18ms)7362026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200007372026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.88ms)7382026/07/19 09:59:25 goose: up to current file version: 27392026/07/19 09:59:25 OK 20251218171726_add_pins.sql (12.31ms)7402026/07/19 09:59:25 OK 20241026095416_initial_model.sql (21.75ms)7412026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (9.2ms)7422026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200007432026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures7442026/07/19 09:59:25 OK 1_commit_pending_closure.sql (5.38ms)7452026/07/19 09:59:25 OK 20251218171726_add_pins.sql (8.49ms)7462026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (7.67ms)7472026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200007482026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (3.24ms)7492026/07/19 09:59:25 OK 2_object_stats_trigger.sql (3.19ms)7502026/07/19 09:59:25 goose: up to current file version: 27512026/07/19 09:59:25 OK 1_commit_pending_closure.sql (4.12ms)7522026/07/19 09:59:25 OK 1_commit_pending_closure.sql (4.31ms)7532026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures7542026/07/19 09:59:25 OK 2_object_stats_trigger.sql (3.37ms)7552026/07/19 09:59:25 goose: up to current file version: 27562026-07-19 09:59:25.543 UTC [996] ERROR: relation "goose_db_version" does not exist at character 367572026-07-19 09:59:25.543 UTC [996] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7582026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (7.03ms)7592026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200007602026/07/19 09:59:25 OK 20251218171726_add_pins.sql (5.29ms)7612026-07-19 09:59:25.544 UTC [997] ERROR: relation "goose_db_version" does not exist at character 367622026-07-19 09:59:25.544 UTC [997] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7632026/07/19 09:59:25 OK 2_object_stats_trigger.sql (3.11ms)7642026/07/19 09:59:25 goose: up to current file version: 27652026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (11.58ms)7662026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200007672026/07/19 09:59:25 INFO Received cleanup request method=DELETE path=/api/pending_closures7682026-07-19 09:59:25.546 UTC [998] ERROR: relation "goose_db_version" does not exist at character 367692026-07-19 09:59:25.546 UTC [998] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7702026/07/19 09:59:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7712026-07-19 09:59:25.547 UTC [999] ERROR: relation "goose_db_version" does not exist at character 367722026-07-19 09:59:25.547 UTC [999] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7732026/07/19 09:59:25 INFO Aborted multipart uploads count=07742026/07/19 09:59:25 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst7752026-07-19 09:59:25.550 UTC [1000] ERROR: relation "goose_db_version" does not exist at character 367762026-07-19 09:59:25.550 UTC [1000] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC777--- PASS: TestCompleteMultipartUnregistered (0.90s)778=== CONT TestOrphanedObjectsGCStressTest7792026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures7802026-07-19 09:59:25.554 UTC [1001] ERROR: relation "goose_db_version" does not exist at character 367812026-07-19 09:59:25.554 UTC [1001] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7822026-07-19 09:59:25.556 UTC [1002] ERROR: relation "goose_db_version" does not exist at character 367832026-07-19 09:59:25.556 UTC [1002] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7842026/07/19 09:59:25 OK 1_commit_pending_closure.sql (19.34ms)7852026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (22.35ms)7862026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200007872026/07/19 09:59:25 OK 20241026095416_initial_model.sql (28.15ms)7882026/07/19 09:59:25 OK 1_commit_pending_closure.sql (20.36ms)7892026/07/19 09:59:25 OK 2_object_stats_trigger.sql (4.14ms)7902026/07/19 09:59:25 goose: up to current file version: 27912026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.24ms)7922026/07/19 09:59:25 goose: up to current file version: 27932026/07/19 09:59:25 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"794--- PASS: TestService_AuthMiddleware (0.92s)7952026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (5.41ms)796=== CONT TestOrphanedObjectsGC7972026/07/19 09:59:25 INFO Received cleanup request method=DELETE path=/api/pending_closures7982026/07/19 09:59:25 OK 1_commit_pending_closure.sql (6.95ms)799--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.92s)800=== CONT TestGCTaskStore_DeduplicateSameParams801--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)802=== CONT TestMultipartCleanup8032026/07/19 09:59:25 INFO Aborted multipart uploads count=18042026/07/19 09:59:25 OK 2_object_stats_trigger.sql (4.71ms)8052026/07/19 09:59:25 goose: up to current file version: 28062026/07/19 09:59:25 OK 20251218171726_add_pins.sql (6.13ms)8072026/07/19 09:59:25 OK 20241026095416_initial_model.sql (11.07ms)8082026-07-19 09:59:25.578 UTC [1008] ERROR: relation "goose_db_version" does not exist at character 368092026-07-19 09:59:25.578 UTC [1008] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8102026-07-19 09:59:25.578 UTC [1006] ERROR: relation "goose_db_version" does not exist at character 368112026-07-19 09:59:25.578 UTC [1006] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8122026-07-19 09:59:25.578 UTC [1007] ERROR: relation "goose_db_version" does not exist at character 368132026-07-19 09:59:25.578 UTC [1007] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8142026/07/19 09:59:25 OK 20241026095416_initial_model.sql (12.05ms)8152026-07-19 09:59:25.578 UTC [1005] ERROR: relation "goose_db_version" does not exist at character 368162026-07-19 09:59:25.578 UTC [1005] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8172026/07/19 09:59:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8182026-07-19 09:59:25.579 UTC [1011] ERROR: relation "goose_db_version" does not exist at character 368192026-07-19 09:59:25.579 UTC [1011] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8202026/07/19 09:59:25 OK 20241026095416_initial_model.sql (11.89ms)8212026/07/19 09:59:25 OK 20241026095416_initial_model.sql (11.9ms)8222026/07/19 09:59:25 OK 20241026095416_initial_model.sql (13.1ms)8232026/07/19 09:59:25 OK 20241026095416_initial_model.sql (12.4ms)8242026/07/19 09:59:25 OK 20241026095416_initial_model.sql (11.93ms)8252026-07-19 09:59:25.580 UTC [1009] ERROR: relation "goose_db_version" does not exist at character 368262026-07-19 09:59:25.580 UTC [1009] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8272026-07-19 09:59:25.580 UTC [992] ERROR: Closure does not exist: id=18282026-07-19 09:59:25.580 UTC [992] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE8292026-07-19 09:59:25.580 UTC [992] STATEMENT: -- name: CommitPendingClosure :exec830 SELECT commit_pending_closure($1::bigint)831 832--- PASS: TestService_cleanupPendingClosuresHandler (0.93s)8332026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures834=== CONT TestServerTLSConfig8352026-07-19 09:59:25.581 UTC [1012] ERROR: relation "goose_db_version" does not exist at character 368362026-07-19 09:59:25.581 UTC [1012] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC837=== RUN TestServerTLSConfig/no_client_CA838=== PAUSE TestServerTLSConfig/no_client_CA839=== RUN TestServerTLSConfig/missing_CA_file840=== PAUSE TestServerTLSConfig/missing_CA_file841=== RUN TestServerTLSConfig/not_a_PEM_file842=== PAUSE TestServerTLSConfig/not_a_PEM_file843=== CONT TestService_NativeMTLS8442026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.8ms)8452026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (4.33ms)8462026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200008472026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (3.48ms)8482026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.99ms)8492026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.5ms)8502026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)8512026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.84ms)8522026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)8532026/07/19 09:59:25 OK 1_commit_pending_closure.sql (3.79ms)8542026/07/19 09:59:25 OK 20251218171726_add_pins.sql (4.57ms)8552026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.69ms)8562026/07/19 09:59:25 OK 20251218171726_add_pins.sql (4.32ms)8572026/07/19 09:59:25 OK 20251218171726_add_pins.sql (4.64ms)8582026/07/19 09:59:25 OK 20251218171726_add_pins.sql (4.76ms)8592026/07/19 09:59:25 OK 20251218171726_add_pins.sql (4.27ms)8602026/07/19 09:59:25 OK 20251218171726_add_pins.sql (4.56ms)8612026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.22ms)8622026/07/19 09:59:25 goose: up to current file version: 28632026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (6.52ms)8642026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200008652026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (5.57ms)8662026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200008672026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (6.54ms)8682026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200008692026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (6.47ms)8702026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (5.96ms)8712026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200008722026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200008732026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (6.43ms)8742026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200008752026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (6.7ms)8762026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200008772026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures8782026/07/19 09:59:25 OK 20241026095416_initial_model.sql (11.64ms)8792026/07/19 09:59:25 OK 20241026095416_initial_model.sql (11.48ms)8802026/07/19 09:59:25 OK 1_commit_pending_closure.sql (3.76ms)8812026/07/19 09:59:25 OK 20241026095416_initial_model.sql (11.65ms)8822026-07-19 09:59:25.598 UTC [1022] ERROR: relation "goose_db_version" does not exist at character 368832026-07-19 09:59:25.598 UTC [1022] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8842026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.86ms)885--- PASS: TestObjectStatsTrigger (0.95s)8862026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.76ms)887=== CONT TestMetricsInventory8882026/07/19 09:59:25 OK 20241026095416_initial_model.sql (11.56ms)8892026/07/19 09:59:25 OK 1_commit_pending_closure.sql (3.03ms)8902026/07/19 09:59:25 OK 1_commit_pending_closure.sql (4.33ms)8912026/07/19 09:59:25 OK 1_commit_pending_closure.sql (4.95ms)8922026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)8932026/07/19 09:59:25 OK 1_commit_pending_closure.sql (4.55ms)8942026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.14ms)8952026/07/19 09:59:25 goose: up to current file version: 28962026/07/19 09:59:25 OK 2_object_stats_trigger.sql (1.94ms)8972026/07/19 09:59:25 goose: up to current file version: 28982026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.51ms)8992026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)9002026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.24ms)9012026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.99ms)9022026/07/19 09:59:25 goose: up to current file version: 29032026/07/19 09:59:25 goose: up to current file version: 29042026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)9052026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.81ms)9062026/07/19 09:59:25 goose: up to current file version: 29072026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.71ms)9082026/07/19 09:59:25 goose: up to current file version: 29092026/07/19 09:59:25 OK 2_object_stats_trigger.sql (3.36ms)9102026/07/19 09:59:25 goose: up to current file version: 29112026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.54ms)9122026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures9132026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures9142026/07/19 09:59:25 OK 20251218171726_add_pins.sql (4.34ms)9152026/07/19 09:59:25 OK 20251218171726_add_pins.sql (4.35ms)916{"timestamp":"2026-07-19T09:59:25.606156775Z","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(386)"}9172026/07/19 09:59:25 OK 20241026095416_initial_model.sql (17.24ms)9182026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures9192026/07/19 09:59:25 OK 20251218171726_add_pins.sql (5.58ms)9202026/07/19 09:59:25 OK 20241026095416_initial_model.sql (12.99ms)9212026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (5.06ms)9222026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200009232026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (3.33ms)924--- PASS: TestReadProxyDisabled (0.94s)925=== CONT TestNARDeduplicationMetadataUploadBug9262026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (5.88ms)9272026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200009282026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (6.09ms)9292026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200009302026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (4.13ms)9312026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (5.47ms)932--- PASS: TestReadProxyInvalidPath (0.94s)9332026/07/19 09:59:25 goose: successfully migrated database to version: 20260628120000934=== CONT TestGenerateLandingPage9352026/07/19 09:59:25 OK 20241026095416_initial_model.sql (15.42ms)9362026/07/19 09:59:25 OK 1_commit_pending_closure.sql (5.43ms)937--- PASS: TestReadProxyRangeRequest (0.89s)938=== CONT TestService_healthCheckHandler9392026/07/19 09:59:25 OK 1_commit_pending_closure.sql (3.91ms)9402026/07/19 09:59:25 OK 20251218171726_add_pins.sql (6.73ms)9412026/07/19 09:59:25 OK 20251218171726_add_pins.sql (4.05ms)9422026/07/19 09:59:25 OK 1_commit_pending_closure.sql (4.36ms)9432026/07/19 09:59:25 OK 2_object_stats_trigger.sql (1.73ms)944--- PASS: TestReadProxyConditionalGet (0.89s)9452026/07/19 09:59:25 goose: up to current file version: 2946=== CONT TestGracefulShutdownDrainsInflight9472026/07/19 09:59:25 OK 1_commit_pending_closure.sql (3.24ms)9482026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures9492026/07/19 09:59:25 OK 20241026095416_initial_model.sql (10.72ms)9502026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (3.31ms)9512026/07/19 09:59:25 INFO Starting HTTP server address=127.0.0.1:397419522026/07/19 09:59:25 INFO Shutdown signal received, draining in-flight requests timeout=10s953--- PASS: TestGenerateLandingPage (0.01s)954=== CONT TestGCTaskStore_Fail955--- PASS: TestGCTaskStore_Fail (0.00s)956=== CONT TestGCTaskStore_PhaseUpdates9572026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.47ms)958--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)9592026/07/19 09:59:25 goose: up to current file version: 2960=== CONT TestGCTaskStore_CompletedAllowsNewTask961--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)9622026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.74ms)963=== CONT TestGCTaskStore_GetReturnsLatest9642026/07/19 09:59:25 goose: up to current file version: 2965--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)966=== CONT TestGCTaskStore_GetEmpty9672026/07/19 09:59:25 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst968--- PASS: TestGCTaskStore_GetEmpty (0.00s)969=== CONT TestGCTaskStore_ConflictDifferentParams9702026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures971--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)9722026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (3.01ms)973=== CONT TestClientErrorHandling974=== RUN TestClientErrorHandling/InvalidStorePath9752026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.99ms)976=== PAUSE TestClientErrorHandling/InvalidStorePath9772026/07/19 09:59:25 goose: up to current file version: 2978=== RUN TestClientErrorHandling/InvalidAuthToken979=== PAUSE TestClientErrorHandling/InvalidAuthToken980=== RUN TestClientErrorHandling/ServerNotAvailable981=== PAUSE TestClientErrorHandling/ServerNotAvailable982=== CONT TestGCTaskStore_StartNew983--- PASS: TestGCTaskStore_StartNew (0.00s)984=== CONT TestGCMetrics9852026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (5.35ms)9862026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200009872026/07/19 09:59:25 OK 20251218171726_add_pins.sql (5.06ms)9882026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (7.41ms)9892026/07/19 09:59:25 goose: successfully migrated database to version: 20260628120000990--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.96s)991=== CONT TestGCBugBareHashReferences9922026/07/19 09:59:25 OK 20251218171726_add_pins.sql (4.6ms)993--- PASS: TestReadProxy404 (0.90s)994=== CONT TestPinProtectsFromGC995--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.90s)996=== CONT TestClientWithDependencies9972026/07/19 09:59:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9982026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (5.78ms)9992026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000010002026/07/19 09:59:25 OK 1_commit_pending_closure.sql (5.81ms)10012026/07/19 09:59:25 OK 1_commit_pending_closure.sql (5.66ms)1002--- PASS: TestReadProxyHead (0.90s)1003=== CONT TestClientMultipleUploads1004{"timestamp":"2026-07-19T09:59:25.632596013Z","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(692)"}1005{"timestamp":"2026-07-19T09:59:25.632633123Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket17, 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(692)"}10062026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (6.55ms)10072026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000010082026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.59ms)10092026/07/19 09:59:25 goose: up to current file version: 210102026/07/19 09:59:25 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=NTMxOTRjYmUtYzBkOS00NGExLWI3MjEtMTJlMTI0YmRhNjQ3LmNlOTBhZDhmLTg0MDItNDFkOS04YmRkLTQ0Mjk0YTg4ZjdlZngxNzg0NDU1MTY1NjE2MjEwNjc010112026/07/19 09:59:25 OK 1_commit_pending_closure.sql (3.77ms)10122026/07/19 09:59:25 OK 2_object_stats_trigger.sql (3.6ms)10132026/07/19 09:59:25 goose: up to current file version: 210142026/07/19 09:59:25 OK 1_commit_pending_closure.sql (3.14ms)10152026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.34ms)10162026/07/19 09:59:25 goose: up to current file version: 210172026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2ms)10182026/07/19 09:59:25 goose: up to current file version: 21019--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.97s)1020=== CONT TestClientIntegration1021--- PASS: TestReadProxyNarinfo (0.91s)1022=== CONT TestService_AuthMiddleware_OIDC1023--- PASS: TestService_Rustfstest (0.99s)1024=== CONT TestClientCADerivations10252026/07/19 09:59:25 INFO OIDC provider initialized name=test1026--- PASS: TestReadProxyNarStreaming (0.91s)1027=== CONT TestCacheStatsHandler10282026/07/19 09:59:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10292026/07/19 09:59:25 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTMxOTRjYmUtYzBkOS00NGExLWI3MjEtMTJlMTI0YmRhNjQ3LmNlOTBhZDhmLTg0MDItNDFkOS04YmRkLTQ0Mjk0YTg4ZjdlZngxNzg0NDU1MTY1NjE2MjEwNjc0 parts=11030--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.00s)1031=== CONT TestCacheConfigHandler1032=== RUN TestCacheConfigHandler/full_config,_no_issuer1033=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1034=== RUN TestCacheConfigHandler/no_cache_url_configured1035=== PAUSE TestCacheConfigHandler/no_cache_url_configured1036=== RUN TestCacheConfigHandler/no_signing_keys1037=== PAUSE TestCacheConfigHandler/no_signing_keys1038=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1039=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1040=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1041--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1042=== CONT TestService_ReadAuthMiddleware1043--- PASS: TestResurrectedObjectNotDeleted (0.90s)1044=== CONT TestService_AuthMiddleware_MTLSProxyHeader10452026-07-19 09:59:25.718 UTC [1055] ERROR: relation "goose_db_version" does not exist at character 3610462026-07-19 09:59:25.718 UTC [1055] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10472026-07-19 09:59:25.721 UTC [1056] ERROR: relation "goose_db_version" does not exist at character 3610482026-07-19 09:59:25.721 UTC [1056] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10492026-07-19 09:59:25.723 UTC [1057] ERROR: relation "goose_db_version" does not exist at character 3610502026-07-19 09:59:25.723 UTC [1057] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10512026-07-19 09:59:25.729 UTC [1060] ERROR: relation "goose_db_version" does not exist at character 3610522026-07-19 09:59:25.729 UTC [1060] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10532026/07/19 09:59:25 OK 20241026095416_initial_model.sql (23.56ms)10542026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (3.82ms)10552026/07/19 09:59:25 OK 20241026095416_initial_model.sql (28.92ms)10562026/07/19 09:59:25 OK 20251218171726_add_pins.sql (7.76ms)10572026/07/19 09:59:25 OK 20241026095416_initial_model.sql (28.12ms)10582026/07/19 09:59:25 OK 20241026095416_initial_model.sql (27.87ms)10592026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (4.17ms)10602026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (5.36ms)10612026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (5.28ms)10622026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (9.85ms)10632026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000010642026/07/19 09:59:25 OK 20251218171726_add_pins.sql (12.08ms)10652026/07/19 09:59:25 OK 20251218171726_add_pins.sql (12.33ms)10662026-07-19 09:59:25.788 UTC [1061] ERROR: relation "goose_db_version" does not exist at character 3610672026-07-19 09:59:25.788 UTC [1061] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10682026/07/19 09:59:25 OK 1_commit_pending_closure.sql (10.66ms)10692026/07/19 09:59:25 OK 20251218171726_add_pins.sql (14.93ms)10702026-07-19 09:59:25.791 UTC [1062] ERROR: relation "goose_db_version" does not exist at character 3610712026-07-19 09:59:25.791 UTC [1062] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10722026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (7.94ms)10732026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000010742026/07/19 09:59:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10752026/07/19 09:59:25 OK 2_object_stats_trigger.sql (31.7ms)10762026/07/19 09:59:25 goose: up to current file version: 210772026/07/19 09:59:25 OK 1_commit_pending_closure.sql (33.29ms)10782026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (38.23ms)10792026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000010802026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (35.71ms)10812026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000010822026/07/19 09:59:25 OK 2_object_stats_trigger.sql (3.65ms)10832026/07/19 09:59:25 goose: up to current file version: 210842026/07/19 09:59:25 OK 1_commit_pending_closure.sql (5.66ms)10852026/07/19 09:59:25 OK 1_commit_pending_closure.sql (8.72ms)10862026-07-19 09:59:25.835 UTC [1063] ERROR: relation "goose_db_version" does not exist at character 3610872026-07-19 09:59:25.835 UTC [1063] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10882026/07/19 09:59:25 OK 2_object_stats_trigger.sql (5.41ms)10892026/07/19 09:59:25 goose: up to current file version: 210902026/07/19 09:59:25 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NTMxOTRjYmUtYzBkOS00NGExLWI3MjEtMTJlMTI0YmRhNjQ3LjVhZmMyNjZkLWQ4ZjItNDYyYi1iYTVhLTg3MGMxZjE2MjlmNXgxNzg0NDU1MTY1NTQwOTU2MzMy parts=1010912026/07/19 09:59:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10922026-07-19 09:59:25.838 UTC [1064] ERROR: relation "goose_db_version" does not exist at character 3610932026-07-19 09:59:25.838 UTC [1064] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10942026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures10952026/07/19 09:59:25 OK 2_object_stats_trigger.sql (8.97ms)10962026/07/19 09:59:25 goose: up to current file version: 210972026/07/19 09:59:25 INFO Completed upload id=110982026/07/19 09:59:25 OK 20241026095416_initial_model.sql (19.36ms)10992026/07/19 09:59:25 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11002026/07/19 09:59:25 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1101--- PASS: TestService_NativeMTLS (0.27s)11022026/07/19 09:59:25 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001103=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info11042026/07/19 09:59:25 INFO Received uploads request method=POST path=/1105=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key11062026/07/19 09:59:25 INFO Received request for more parts method=POST path=/1107=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key11082026/07/19 09:59:25 INFO Received complete multipart upload request method=POST path=/1109=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal11102026/07/19 09:59:25 INFO Received uploads request method=POST path=/1111--- PASS: TestUploadHandlersRejectInvalidKeys (0.08s)1112 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1113 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1114 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1115 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1116=== CONT TestProxyWriteTimeout/narinfo1117=== CONT TestProxyWriteTimeout/10_GiB_nar1118=== CONT TestProxyWriteTimeout/1_GiB_nar1119=== CONT TestProxyWriteTimeout/unknown_size11202026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures1121--- PASS: TestProxyWriteTimeout (0.08s)1122 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1123 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1124 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1125 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1126=== CONT TestIsValidUploadKey/narinfo1127=== CONT TestIsValidUploadKey/realisation_plus_in_output1128=== CONT TestIsValidUploadKey/unknown_type1129=== CONT TestIsValidUploadKey/empty_key1130=== CONT TestIsValidUploadKey/absolute11312026/07/19 09:59:25 OK 20241026095416_initial_model.sql (21.61ms)1132=== CONT TestIsValidUploadKey/traversal_nar1133=== CONT TestIsValidUploadKey/traversal1134=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1135=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1136=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1137=== CONT TestIsValidUploadKey/index.html1138=== CONT TestIsValidUploadKey/nix-cache-info1139=== CONT TestIsValidUploadKey/build_log_home-manager_file1140=== CONT TestIsValidUploadKey/realisation1141=== CONT TestIsValidUploadKey/build_log_equals1142=== CONT TestIsValidUploadKey/build_log_question_mark1143=== CONT TestIsValidUploadKey/build_log_plus_in_name1144=== CONT TestIsValidUploadKey/nar_xz1145=== CONT TestIsValidUploadKey/build_log1146=== CONT TestIsValidUploadKey/listing1147=== CONT TestIsValidUploadKey/nar_zst1148=== CONT TestIsValidUploadKey/nar_plain1149--- PASS: TestIsValidUploadKey (0.08s)1150 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1151 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1152 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1153 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1154 --- PASS: TestIsValidUploadKey/absolute (0.00s)1155 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1156 --- PASS: TestIsValidUploadKey/traversal (0.00s)1157 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1158 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1159 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1160 --- PASS: TestIsValidUploadKey/index.html (0.00s)1161 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1162 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1163 --- PASS: TestIsValidUploadKey/realisation (0.00s)1164 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1165 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1166 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1167 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1168 --- PASS: TestIsValidUploadKey/build_log (0.00s)1169 --- PASS: TestIsValidUploadKey/listing (0.00s)1170 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1171 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1172=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart11732026/07/19 09:59:25 INFO Received complete multipart upload request method=POST path=/11742026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (3.26ms)11752026/07/19 09:59:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures11762026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.75ms)11772026/07/19 09:59:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11782026-07-19 09:59:25.861 UTC [1066] ERROR: relation "goose_db_version" does not exist at character 3611792026-07-19 09:59:25.861 UTC [1066] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11802026/07/19 09:59:25 INFO Aborted multipart uploads count=011812026/07/19 09:59:25 OK 20251218171726_add_pins.sql (22.4ms)11822026/07/19 09:59:25 OK 20251218171726_add_pins.sql (21.4ms)11832026-07-19 09:59:25.877 UTC [1067] ERROR: relation "goose_db_version" does not exist at character 3611842026-07-19 09:59:25.877 UTC [1067] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11852026/07/19 09:59:25 OK 20241026095416_initial_model.sql (23.53ms)11862026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (9.79ms)11872026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000011882026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (9.63ms)11892026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000011902026/07/19 09:59:25 OK 20241026095416_initial_model.sql (29.32ms)11912026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (5.23ms)11922026/07/19 09:59:25 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=011932026/07/19 09:59:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NTMxOTRjYmUtYzBkOS00NGExLWI3MjEtMTJlMTI0YmRhNjQ3LmMxYzcxNmNlLWQxNDItNGUwZi04NjhhLWU5ZTMzYmIyNzAwMXgxNzg0NDU1MTY1NTQ3NDQ0NzEx parts=1011942026/07/19 09:59:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1195=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure11962026/07/19 09:59:25 INFO Received uploads request method=POST path=/11972026/07/19 09:59:25 OK 1_commit_pending_closure.sql (3.95ms)11982026-07-19 09:59:25.888 UTC [1068] ERROR: relation "goose_db_version" does not exist at character 3611992026-07-19 09:59:25.888 UTC [1068] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12002026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (5.08ms)12012026/07/19 09:59:25 OK 1_commit_pending_closure.sql (5.88ms)12022026/07/19 09:59:25 INFO Vacuumed table table=pending_closures12032026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.9ms)12042026/07/19 09:59:25 goose: up to current file version: 212052026/07/19 09:59:25 OK 20251218171726_add_pins.sql (6.69ms)12062026/07/19 09:59:25 INFO Completed upload id=112072026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.15ms)12082026/07/19 09:59:25 goose: up to current file version: 212092026-07-19 09:59:25.891 UTC [1069] ERROR: relation "goose_db_version" does not exist at character 3612102026-07-19 09:59:25.891 UTC [1069] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12112026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures12122026/07/19 09:59:25 INFO Vacuumed table table=pending_objects1213--- PASS: TestService_healthCheckHandler (0.28s)12142026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures1215=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts12162026/07/19 09:59:25 INFO Received request for more parts method=POST path=/12172026-07-19 09:59:25.894 UTC [1071] ERROR: relation "goose_db_version" does not exist at character 3612182026-07-19 09:59:25.894 UTC [1071] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12192026/07/19 09:59:25 OK 20251218171726_add_pins.sql (5.69ms)12202026-07-19 09:59:25.894 UTC [1070] ERROR: relation "goose_db_version" does not exist at character 3612212026-07-19 09:59:25.894 UTC [1070] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12222026/07/19 09:59:25 OK 20241026095416_initial_model.sql (10.96ms)12232026/07/19 09:59:25 INFO Created nix-cache-info in bucket bucket=bucket3112242026/07/19 09:59:25 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12252026/07/19 09:59:25 WARN Found objects in DB but missing from S3, will re-upload count=112262026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (6.57ms)12272026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000012282026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)12292026/07/19 09:59:25 OK 20241026095416_initial_model.sql (9.75ms)12302026/07/19 09:59:25 INFO Vacuumed table table=multipart_uploads1231--- PASS: TestService_verifyS3Integrity (1.24s)1232=== CONT TestIsValidCachePath/narinfo1233=== CONT TestIsValidCachePath/index.html1234=== CONT TestIsValidCachePath/short_hash1235=== CONT TestIsValidCachePath/wrong_extension1236=== CONT TestIsValidCachePath/nar_uncompressed1237=== CONT TestIsValidCachePath/leading_slash1238=== CONT TestIsValidCachePath/nix-cache-info1239=== CONT TestIsValidCachePath/empty1240=== CONT TestIsValidCachePath/realisation1241=== CONT TestIsValidCachePath/log1242=== CONT TestIsValidCachePath/random_path1243=== CONT TestIsValidCachePath/ls1244=== CONT TestIsValidCachePath/invalid_char_u1245=== CONT TestIsValidCachePath/traversal_in_middle1246=== CONT TestIsValidCachePath/traversal_parent1247=== CONT TestIsValidCachePath/invalid_char_e1248=== CONT TestIsValidCachePath/nar_xz1249=== CONT TestIsValidCachePath/nar_bz21250=== CONT TestIsValidCachePath/nar_zst1251=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1252--- PASS: TestIsValidCachePath (0.00s)1253 --- PASS: TestIsValidCachePath/narinfo (0.00s)1254 --- PASS: TestIsValidCachePath/index.html (0.00s)1255 --- PASS: TestIsValidCachePath/short_hash (0.00s)1256 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1257 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1258 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1259 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1260 --- PASS: TestIsValidCachePath/empty (0.00s)1261 --- PASS: TestIsValidCachePath/realisation (0.00s)1262 --- PASS: TestIsValidCachePath/log (0.00s)1263 --- PASS: TestIsValidCachePath/random_path (0.00s)1264 --- PASS: TestIsValidCachePath/ls (0.00s)1265 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1266 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1267 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1268 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1269 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1270 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1271 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1272 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)12732026-07-19 09:59:25.898 UTC [1074] ERROR: relation "goose_db_version" does not exist at character 3612742026-07-19 09:59:25.898 UTC [1074] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1275=== CONT TestParseSingleRange/none1276=== CONT TestParseSingleRange/open-ended1277=== CONT TestParseSingleRange/start_far_past_EOF12782026-07-19 09:59:25.898 UTC [1073] ERROR: relation "goose_db_version" does not exist at character 3612792026-07-19 09:59:25.898 UTC [1073] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1280=== CONT TestParseSingleRange/start_past_EOF1281=== CONT TestParseSingleRange/single_byte1282=== CONT TestParseSingleRange/suffix_exceeds_size1283=== CONT TestParseSingleRange/suffix1284=== CONT TestParseSingleRange/end_clamped_to_size12852026-07-19 09:59:25.899 UTC [1072] ERROR: relation "goose_db_version" does not exist at character 3612862026-07-19 09:59:25.899 UTC [1072] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1287=== CONT TestParseSingleRange/malformed_both_empty1288=== CONT TestParseSingleRange/closed1289=== CONT TestParseSingleRange/malformed_end_before_start1290=== CONT TestParseSingleRange/multi-range_ignored1291=== CONT TestParseSingleRange/malformed_no_dash1292=== CONT TestParseSingleRange/unknown_unit1293--- PASS: TestParseSingleRange (0.00s)1294 --- PASS: TestParseSingleRange/none (0.00s)1295 --- PASS: TestParseSingleRange/open-ended (0.00s)1296 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1297 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1298 --- PASS: TestParseSingleRange/single_byte (0.00s)1299 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1300 --- PASS: TestParseSingleRange/suffix (0.00s)1301 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1302 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1303 --- PASS: TestParseSingleRange/closed (0.00s)1304 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1305 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1306 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1307 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1308=== CONT TestServerTLSConfig/no_client_CA1309=== CONT TestServerTLSConfig/missing_CA_file1310=== CONT TestServerTLSConfig/not_a_PEM_file13112026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)13122026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.08ms)1313=== CONT TestClientErrorHandling/InvalidStorePath13142026/07/19 09:59:25 OK 1_commit_pending_closure.sql (3.17ms)1315--- PASS: TestServerTLSConfig (0.00s)1316 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1317 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1318 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)13192026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (5.61ms)13202026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000013212026/07/19 09:59:25 INFO Vacuumed table table=closures13222026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.13ms)13232026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.51ms)13242026/07/19 09:59:25 goose: up to current file version: 213252026/07/19 09:59:25 OK 1_commit_pending_closure.sql (3.16ms)13262026/07/19 09:59:25 INFO Vacuumed table table=objects13272026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)13282026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000013292026/07/19 09:59:25 OK 2_object_stats_trigger.sql (1.97ms)13302026/07/19 09:59:25 goose: up to current file version: 213312026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.71ms)13322026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (4.83ms)13332026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000013342026/07/19 09:59:25 OK 20241026095416_initial_model.sql (9.86ms)13352026/07/19 09:59:25 OK 2_object_stats_trigger.sql (1.91ms)13362026/07/19 09:59:25 goose: up to current file version: 213372026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (1.88ms)13382026/07/19 09:59:25 OK 20241026095416_initial_model.sql (10.44ms)13392026/07/19 09:59:25 OK 20241026095416_initial_model.sql (9.37ms)13402026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.39ms)13412026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)13422026/07/19 09:59:25 INFO Created nix-cache-info in bucket bucket=bucket3313432026/07/19 09:59:25 OK 20241026095416_initial_model.sql (10.16ms)13442026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.13ms)13452026/07/19 09:59:25 goose: up to current file version: 213462026-07-19 09:59:25.913 UTC [1078] ERROR: relation "goose_db_version" does not exist at character 3613472026-07-19 09:59:25.913 UTC [1078] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13482026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.58ms)13492026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.57ms)13502026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)13512026/07/19 09:59:25 OK 20241026095416_initial_model.sql (9.28ms)13522026/07/19 09:59:25 OK 20241026095416_initial_model.sql (9.03ms)13532026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.83ms)13542026-07-19 09:59:25.916 UTC [1079] ERROR: relation "goose_db_version" does not exist at character 3613552026-07-19 09:59:25.916 UTC [1079] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13562026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.32ms)13572026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)13582026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)13592026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.04ms)13602026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (4.48ms)13612026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000013622026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (4.34ms)13632026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000013642026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.19ms)13652026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (4.57ms)13662026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000013672026/07/19 09:59:25 OK 20241026095416_initial_model.sql (11.22ms)13682026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.71ms)13692026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.36ms)13702026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (3.12ms)13712026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200001372--- PASS: TestCacheStatsHandler (0.27s)13732026/07/19 09:59:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1374=== CONT TestClientErrorHandling/ServerNotAvailable13752026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.48ms)13762026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.26ms)13772026/07/19 09:59:25 goose: up to current file version: 213782026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.11ms)13792026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)13802026/07/19 09:59:25 OK 1_commit_pending_closure.sql (3.2ms)13812026/07/19 09:59:25 INFO Aborted multipart uploads count=013822026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (4.09ms)13832026/07/19 09:59:25 OK 2_object_stats_trigger.sql (1.72ms)13842026/07/19 09:59:25 goose: up to current file version: 213852026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.61ms)13862026/07/19 09:59:25 goose: up to current file version: 213872026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (4.46ms)13882026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000013892026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000013902026/07/19 09:59:25 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1391--- PASS: TestService_ReadAuthMiddleware (0.24s)1392=== CONT TestClientErrorHandling/InvalidAuthToken13932026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.04ms)13942026/07/19 09:59:25 goose: up to current file version: 213952026/07/19 09:59:25 WARN Force mode enabled - objects will be deleted immediately without grace period1396--- PASS: TestMetricsInventory (0.33s)13972026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.93ms)1398=== CONT TestCacheConfigHandler/full_config,_no_issuer1399=== CONT TestCacheConfigHandler/no_signing_keys1400=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1401=== CONT TestCacheConfigHandler/no_cache_url_configured1402--- PASS: TestCacheConfigHandler (0.00s)1403 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1404 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1405 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1406 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)14072026/07/19 09:59:25 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14082026/07/19 09:59:25 WARN mTLS auth: bound subjects configured but subject DN unavailable14092026/07/19 09:59:25 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1410--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.27s)14112026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.42ms)14122026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.31ms)14132026/07/19 09:59:25 OK 2_object_stats_trigger.sql (1.62ms)14142026/07/19 09:59:25 goose: up to current file version: 214152026/07/19 09:59:25 INFO Created nix-cache-info in bucket bucket=bucket3914162026/07/19 09:59:25 INFO Created nix-cache-info in bucket bucket=bucket3714172026/07/19 09:59:25 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=014182026/07/19 09:59:25 INFO Vacuumed table table=pending_closures14192026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.9ms)14202026/07/19 09:59:25 goose: up to current file version: 214212026/07/19 09:59:25 INFO Vacuumed table table=pending_objects14222026/07/19 09:59:25 OK 20241026095416_initial_model.sql (10.15ms)14232026/07/19 09:59:25 OK 20241026095416_initial_model.sql (9.78ms)14242026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (4.52ms)14252026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000014262026/07/19 09:59:25 INFO Vacuumed table table=multipart_uploads14272026/07/19 09:59:25 INFO Vacuumed table table=closures14282026/07/19 09:59:25 INFO Vacuumed table table=objects14292026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (1.32ms)14302026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)1431=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1432=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token14332026/07/19 09:59:25 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NTMxOTRjYmUtYzBkOS00NGExLWI3MjEtMTJlMTI0YmRhNjQ3LmY3ZGY4NmFkLTlkZTktNGYzYS1iNTJkLWNmMDZmMDNlMGM2ZXgxNzg0NDU1MTY1NjAzODA1MDM1 parts=121434=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1435=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected14362026/07/19 09:59:25 INFO Created nix-cache-info in bucket bucket=bucket401437=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1438=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1439=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1440=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1441=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1442=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1443=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected14442026/07/19 09:59:25 OK 1_commit_pending_closure.sql (3.02ms)14452026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures14462026/07/19 09:59:25 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]1447=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured14482026/07/19 09:59:25 OK 20251218171726_add_pins.sql (2.93ms)14492026/07/19 09:59:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14502026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.62ms)1451--- PASS: TestGCMetrics (0.32s)14522026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.92ms)14532026/07/19 09:59:25 goose: up to current file version: 214542026/07/19 09:59:25 INFO OIDC auth successful provider=test14552026/07/19 09:59:25 WARN Authentication failed token_preview=eyJhbGciOi...sv22ASNZOA 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]1456--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.28s)1457=== NAME TestNARDeduplicationMetadataUploadBug1458 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug540849321/001/store/pzi1qgjysazzb087nr2z4wp5grh95r07-file1.txt1459--- PASS: TestService_AuthMiddleware_OIDC (0.30s)1460 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1461 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1462 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1463 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)14642026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)14652026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000014662026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (3.74ms)14672026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000014682026/07/19 09:59:25 INFO Created nix-cache-info in bucket bucket=bucket4214692026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.08ms)14702026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.09ms)14712026/07/19 09:59:25 OK 2_object_stats_trigger.sql (1.02ms)14722026/07/19 09:59:25 goose: up to current file version: 214732026/07/19 09:59:25 OK 2_object_stats_trigger.sql (1.05ms)14742026/07/19 09:59:25 goose: up to current file version: 21475--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.23s)14762026/07/19 09:59:25 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001477--- PASS: TestService_createPendingClosureHandler (1.30s)14782026/07/19 09:59:25 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NTMxOTRjYmUtYzBkOS00NGExLWI3MjEtMTJlMTI0YmRhNjQ3LjNiNWRhZjhmLTU2OTctNDBiMy04YmE5LWZjZTVlYTUxZDJiNngxNzg0NDU1MTY1NjEyNzE1MjA0 parts=121479--- PASS: TestRedundantMultipartUpload (1.30s)14802026/07/19 09:59:25 INFO Received cleanup request method=DELETE path=/api/pending_closures1481=== NAME TestClientMultipleUploads1482 client_integration_test.go:338: Created store path 0: /build/TestClientMultipleUploads3874801332/001/store/c0m93myik1f4s7rr422dh2pq7ks5cpb8-test-file-0.txt14832026/07/19 09:59:25 INFO Aborted multipart uploads count=11484=== NAME TestClientIntegration1485 client_integration_test.go:276: Created store path: /build/TestClientIntegration4007548400/002/store/20i1qix4ccrg4bnivbxajqd66hh3mcfn-test-file.txt1486--- PASS: TestMultipartCleanup (0.40s)1487=== NAME TestPinProtectsFromGC1488 client_integration_test.go:646: Pinned store path: /build/TestPinProtectsFromGC2679133645/001/store/3mrnbqqvls9hliz09av6z15nji633maj-pinned-file.txt1489 client_integration_test.go:647: Unpinned store path: /build/TestPinProtectsFromGC2679133645/001/store/c6hwk5xnj58s27m7da4lhswfk2imxa1f-unpinned-file.txt1490=== NAME TestClientMultipleUploads1491 client_integration_test.go:338: Created store path 1: /build/TestClientMultipleUploads3874801332/001/store/rjaz4f5m9k90c89szzdxmm6078iwiavl-test-file-1.txt14922026-07-19 09:59:26.019 UTC [1352] ERROR: relation "goose_db_version" does not exist at character 3614932026-07-19 09:59:26.019 UTC [1352] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1494=== NAME TestClientCADerivations1495 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations722045148/001/store/caqjzqdyrv0q0h9i559qnvm7kaprlyjw-ca-test14962026-07-19 09:59:26.021 UTC [1365] ERROR: relation "goose_db_version" does not exist at character 3614972026-07-19 09:59:26.021 UTC [1365] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14982026/07/19 09:59:26 OK 20241026095416_initial_model.sql (6.81ms)1499=== NAME TestClientWithDependencies1500 client_integration_test.go:593: Built derivation: /build/TestClientWithDependencies2197382765/001/store/dl3q2hij5kbklr057kzvf4cwd30lbkzc-test-script15012026/07/19 09:59:26 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)15022026/07/19 09:59:26 OK 20241026095416_initial_model.sql (6.28ms)15032026/07/19 09:59:26 OK 20251210153512_drop_unused_gin_index.sql (962.61µs)1504=== NAME TestClientMultipleUploads1505 client_integration_test.go:338: Created store path 2: /build/TestClientMultipleUploads3874801332/001/store/wf752lk9w3w22qzfdnx77x3ar88m15rm-test-file-2.txt15062026/07/19 09:59:26 OK 20251218171726_add_pins.sql (1.79ms)15072026/07/19 09:59:26 OK 20251218171726_add_pins.sql (2.02ms)15082026/07/19 09:59:26 OK 20260628120000_add_object_size_and_stats.sql (1.99ms)15092026/07/19 09:59:26 goose: successfully migrated database to version: 2026062812000015102026/07/19 09:59:26 OK 1_commit_pending_closure.sql (2.04ms)15112026/07/19 09:59:26 OK 20260628120000_add_object_size_and_stats.sql (2.79ms)15122026/07/19 09:59:26 goose: successfully migrated database to version: 2026062812000015132026/07/19 09:59:26 OK 2_object_stats_trigger.sql (755µs)15142026/07/19 09:59:26 goose: up to current file version: 215152026/07/19 09:59:26 OK 1_commit_pending_closure.sql (1.19ms)15162026/07/19 09:59:26 OK 2_object_stats_trigger.sql (710.49µs)15172026/07/19 09:59:26 goose: up to current file version: 215182026/07/19 09:59:26 INFO Received uploads request method=POST path=/api/pending_closures15192026/07/19 09:59:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1520=== NAME TestClientCADerivations15212026/07/19 09:59:26 INFO Uploading pzi1qgjysazzb087nr2z4wp5grh95r07-file1.txt (160B)1522 client_ca_test.go:139: Found 1 dependencies (including self)15232026/07/19 09:59:26 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15242026/07/19 09:59:26 WARN Failed to register uploaded object key=pzi1qgjysazzb087nr2z4wp5grh95r07.ls error="server returned 404: 404 page not found\n"15252026/07/19 09:59:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15262026/07/19 09:59:26 INFO Signed narinfos id=1 count=115272026/07/19 09:59:26 INFO Uploading 1 narinfos1528=== NAME TestClientWithDependencies1529 client_integration_test.go:595: Found 1 dependencies (including self)15302026/07/19 09:59:26 WARN Failed to register uploaded object key=pzi1qgjysazzb087nr2z4wp5grh95r07.narinfo error="server returned 404: 404 page not found\n"15312026/07/19 09:59:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15322026/07/19 09:59:26 INFO Completed upload id=115332026/07/19 09:59:26 INFO Upload complete. (91ms)15342026/07/19 09:59:26 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_closures1535=== NAME TestNARDeduplicationMetadataUploadBug1536 metadata_upload_test.go:54: Retrieved narinfo from S3:1537 StorePath: /build/TestNARDeduplicationMetadataUploadBug540849321/001/store/pzi1qgjysazzb087nr2z4wp5grh95r07-file1.txt1538 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1539 Compression: zstd1540 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1541 NarSize: 1601542 References: 1543 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1544 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1545 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1546 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}15472026/07/19 09:59:26 INFO Received uploads request method=POST path=/api/pending_closures15482026/07/19 09:59:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15492026/07/19 09:59:26 INFO Uploading 20i1qix4ccrg4bnivbxajqd66hh3mcfn-test-file.txt (152B)15502026/07/19 09:59:26 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15512026/07/19 09:59:26 WARN Failed to register uploaded object key=20i1qix4ccrg4bnivbxajqd66hh3mcfn.ls error="server returned 404: 404 page not found\n"15522026/07/19 09:59:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15532026/07/19 09:59:26 INFO Signed narinfos id=1 count=115542026/07/19 09:59:26 INFO Uploading 1 narinfos15552026/07/19 09:59:26 INFO Received uploads request method=POST path=/api/pending_closures15562026/07/19 09:59:26 WARN Failed to register uploaded object key=20i1qix4ccrg4bnivbxajqd66hh3mcfn.narinfo error="server returned 404: 404 page not found\n"15572026/07/19 09:59:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15582026/07/19 09:59:26 INFO Completed upload id=115592026/07/19 09:59:26 INFO Upload complete. (83ms)1560=== NAME TestClientIntegration1561 client_integration_test.go:292: Retrieved narinfo from S3:1562 StorePath: /build/TestClientIntegration4007548400/002/store/20i1qix4ccrg4bnivbxajqd66hh3mcfn-test-file.txt1563 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1564 Compression: zstd1565 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11566 NarSize: 1521567 References: 1568 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11569 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1570 client_integration_test.go:293: Decompressed .ls content (64 bytes):1571 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1572 client_integration_test.go:296: Testing garbage collection...15732026/07/19 09:59:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15742026/07/19 09:59:26 INFO Uploading 3mrnbqqvls9hliz09av6z15nji633maj-pinned-file.txt (128B)15752026/07/19 09:59:26 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15762026/07/19 09:59:26 WARN Failed to register uploaded object key=3mrnbqqvls9hliz09av6z15nji633maj.ls error="server returned 404: 404 page not found\n"15772026/07/19 09:59:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15782026/07/19 09:59:26 INFO Signed narinfos id=1 count=115792026/07/19 09:59:26 INFO Uploading 1 narinfos15802026/07/19 09:59:26 WARN Failed to register uploaded object key=3mrnbqqvls9hliz09av6z15nji633maj.narinfo error="server returned 404: 404 page not found\n"15812026/07/19 09:59:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1582=== NAME TestNARDeduplicationMetadataUploadBug15832026/07/19 09:59:26 INFO Completed upload id=11584 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug540849321/001/store/5ff0fznnb15pa74sixzdwa4mpxrhrjc2-file2.txt15852026/07/19 09:59:26 INFO Upload complete. (88ms)1586=== NAME TestOrphanedObjectsGC1587 orphaned_objects_gc_test.go:290: GC Test Summary:1588 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1589 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1590 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1591 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1592 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1593--- PASS: TestOrphanedObjectsGC (0.54s)15942026/07/19 09:59:26 INFO Starting cleanup of old closures method=DELETE path=/api/closures15952026/07/19 09:59:26 INFO Received uploads request method=POST path=/api/pending_closures15962026/07/19 09:59:26 INFO Garbage collection started15972026/07/19 09:59:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15982026/07/19 09:59:26 INFO Uploading dl3q2hij5kbklr057kzvf4cwd30lbkzc-test-script (136B)15992026/07/19 09:59:26 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16002026/07/19 09:59:26 WARN Failed to register uploaded object key=log/7xac9lx9s2k9xv4dd4cjlgl1mksys3yd-test-script.drv error="server returned 404: 404 page not found\n"16012026/07/19 09:59:26 INFO Received uploads request method=POST path=/api/pending_closures16022026/07/19 09:59:26 INFO Aborted multipart uploads count=016032026/07/19 09:59:26 WARN Failed to register uploaded object key=dl3q2hij5kbklr057kzvf4cwd30lbkzc.ls error="server returned 404: 404 page not found\n"16042026/07/19 09:59:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16052026/07/19 09:59:26 INFO Signed narinfos id=1 count=116062026/07/19 09:59:26 INFO Uploading 1 narinfos16072026/07/19 09:59:26 WARN Force mode enabled - objects will be deleted immediately without grace period16082026/07/19 09:59:26 WARN Failed to register uploaded object key=dl3q2hij5kbklr057kzvf4cwd30lbkzc.narinfo error="server returned 404: 404 page not found\n"16092026/07/19 09:59:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16102026/07/19 09:59:26 INFO Received uploads request method=POST path=/api/pending_closures16112026/07/19 09:59:26 INFO Received uploads request method=POST path=/api/pending_closures16122026/07/19 09:59:26 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16132026/07/19 09:59:26 INFO Uploading c0m93myik1f4s7rr422dh2pq7ks5cpb8-test-file-0.txt (160B)16142026/07/19 09:59:26 INFO Uploading wf752lk9w3w22qzfdnx77x3ar88m15rm-test-file-2.txt (160B)16152026/07/19 09:59:26 INFO Uploading rjaz4f5m9k90c89szzdxmm6078iwiavl-test-file-1.txt (160B)16162026/07/19 09:59:26 INFO Completed upload id=116172026/07/19 09:59:26 INFO Upload complete. (48ms)16182026/07/19 09:59:26 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"1619=== NAME TestClientWithDependencies1620 client_integration_test.go:597: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2197382765/001/store) requires matching store prefix16212026/07/19 09:59:26 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16222026/07/19 09:59:26 WARN Failed to register uploaded object key=wf752lk9w3w22qzfdnx77x3ar88m15rm.ls error="server returned 404: 404 page not found\n"16232026/07/19 09:59:26 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16242026/07/19 09:59:26 WARN Failed to register uploaded object key=rjaz4f5m9k90c89szzdxmm6078iwiavl.ls error="server returned 404: 404 page not found\n"16252026/07/19 09:59:26 WARN Failed to register uploaded object key=c0m93myik1f4s7rr422dh2pq7ks5cpb8.ls error="server returned 404: 404 page not found\n"16262026/07/19 09:59:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16272026/07/19 09:59:26 INFO Signed narinfos id=1 count=11628--- PASS: TestClientWithDependencies (0.52s)16292026/07/19 09:59:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16302026/07/19 09:59:26 INFO Signed narinfos id=2 count=116312026/07/19 09:59:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16322026/07/19 09:59:26 INFO Signed narinfos id=3 count=116332026/07/19 09:59:26 INFO Uploading 3 narinfos16342026/07/19 09:59:26 WARN Failed to register uploaded object key=wf752lk9w3w22qzfdnx77x3ar88m15rm.narinfo error="server returned 404: 404 page not found\n"16352026/07/19 09:59:26 WARN Failed to register uploaded object key=c0m93myik1f4s7rr422dh2pq7ks5cpb8.narinfo error="server returned 404: 404 page not found\n"16362026/07/19 09:59:26 INFO Received uploads request method=POST path=/api/pending_closures16372026/07/19 09:59:26 WARN Failed to register uploaded object key=rjaz4f5m9k90c89szzdxmm6078iwiavl.narinfo error="server returned 404: 404 page not found\n"16382026/07/19 09:59:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16392026/07/19 09:59:26 INFO Completed upload id=216402026/07/19 09:59:26 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16412026/07/19 09:59:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16422026/07/19 09:59:26 INFO Uploading caqjzqdyrv0q0h9i559qnvm7kaprlyjw-ca-test (144B)16432026/07/19 09:59:26 INFO Completed upload id=316442026/07/19 09:59:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16452026/07/19 09:59:26 INFO Completed upload id=116462026/07/19 09:59:26 WARN Failed to register uploaded object key=log/wm6k56pix597sqkipixvr4f8h8kk0ydi-ca-test.drv error="server returned 404: 404 page not found\n"16472026/07/19 09:59:26 INFO Upload complete. (93ms)1648=== NAME TestClientMultipleUploads16492026/07/19 09:59:26 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"1650 client_integration_test.go:349: Uploaded 3 paths in 128.718277ms16512026/07/19 09:59:26 WARN Failed to register uploaded object key=caqjzqdyrv0q0h9i559qnvm7kaprlyjw.ls error="server returned 404: 404 page not found\n"16522026/07/19 09:59:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16532026/07/19 09:59:26 INFO Signed narinfos id=1 count=116542026/07/19 09:59:26 INFO Uploading 1 narinfos16552026/07/19 09:59:26 WARN Failed to register uploaded object key=caqjzqdyrv0q0h9i559qnvm7kaprlyjw.narinfo error="server returned 404: 404 page not found\n"16562026/07/19 09:59:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16572026/07/19 09:59:26 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.019585ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1658--- PASS: TestGCBugBareHashReferences (0.55s)1659--- PASS: TestClientMultipleUploads (0.54s)16602026/07/19 09:59:26 INFO Completed upload id=116612026/07/19 09:59:26 INFO Upload complete. (85ms)1662=== NAME TestClientCADerivations1663 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations722045148/001/store/caqjzqdyrv0q0h9i559qnvm7kaprlyjw-ca-test1664 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1665 Compression: zstd1666 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1667 NarSize: 1441668 References: 1669 Deriver: /build/TestClientCADerivations722045148/001/store/wm6k56pix597sqkipixvr4f8h8kk0ydi-ca-test.drv1670 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1671 client_ca_test.go:185: Checking for realisation files in S3...1672 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1673 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16742026/07/19 09:59:26 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"16752026/07/19 09:59:26 INFO Received uploads request method=POST path=/api/pending_closures16762026/07/19 09:59:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16772026/07/19 09:59:26 INFO Uploading c6hwk5xnj58s27m7da4lhswfk2imxa1f-unpinned-file.txt (128B)16782026/07/19 09:59:26 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16792026/07/19 09:59:26 WARN Failed to register uploaded object key=c6hwk5xnj58s27m7da4lhswfk2imxa1f.ls error="server returned 404: 404 page not found\n"16802026/07/19 09:59:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16812026/07/19 09:59:26 INFO Signed narinfos id=2 count=116822026/07/19 09:59:26 INFO Uploading 1 narinfos16832026/07/19 09:59:26 WARN Failed to register uploaded object key=c6hwk5xnj58s27m7da4lhswfk2imxa1f.narinfo error="server returned 404: 404 page not found\n"16842026/07/19 09:59:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16852026/07/19 09:59:26 INFO Received uploads request method=POST path=/api/pending_closures16862026/07/19 09:59:26 INFO Completed upload id=216872026/07/19 09:59:26 INFO Upload complete. (79ms)16882026/07/19 09:59:26 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16892026/07/19 09:59:26 WARN Failed to register uploaded object key=5ff0fznnb15pa74sixzdwa4mpxrhrjc2.ls error="server returned 404: 404 page not found\n"16902026/07/19 09:59:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16912026/07/19 09:59:26 INFO Signed narinfos id=2 count=116922026/07/19 09:59:26 INFO Uploading 1 narinfos16932026/07/19 09:59:26 WARN Failed to register uploaded object key=5ff0fznnb15pa74sixzdwa4mpxrhrjc2.narinfo error="server returned 404: 404 page not found\n"16942026/07/19 09:59:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16952026/07/19 09:59:26 INFO Completed upload id=216962026/07/19 09:59:26 INFO Upload complete. (85ms)1697=== NAME TestNARDeduplicationMetadataUploadBug1698 metadata_upload_test.go:76: Retrieved narinfo from S3:1699 StorePath: /build/TestNARDeduplicationMetadataUploadBug540849321/001/store/5ff0fznnb15pa74sixzdwa4mpxrhrjc2-file2.txt1700 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1701 Compression: zstd1702 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1703 NarSize: 1601704 References: 1705 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1706 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1707 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1708 {"version":1,"root":{"type":"regular","size":44}}1709--- PASS: TestNARDeduplicationMetadataUploadBug (0.62s)17102026/07/19 09:59:26 INFO Received create pin request method=POST path=/api/pins/myapp17112026/07/19 09:59:26 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2679133645/001/store/3mrnbqqvls9hliz09av6z15nji633maj-pinned-file.txt narinfo_key=3mrnbqqvls9hliz09av6z15nji633maj.narinfo17122026/07/19 09:59:26 INFO Starting cleanup of old closures method=DELETE path=/api/closures17132026/07/19 09:59:26 INFO Garbage collection started17142026/07/19 09:59:26 INFO Aborted multipart uploads count=017152026/07/19 09:59:26 WARN Force mode enabled - objects will be deleted immediately without grace period1716=== NAME TestClientCADerivations1717 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1718 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1719 error: binary cache 's3://bucket40?endpoint=http://localhost:42001®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations722045148/001/store'1720 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11721--- PASS: TestClientCADerivations (0.69s)17222026/07/19 09:59:26 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=434.323276ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1723=== NAME TestOrphanedObjectsGCStressTest1724 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1725 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1726--- PASS: TestUploadHandlersRejectOversizedBody (0.16s)1727 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)1728 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)1729 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.69s)17302026/07/19 09:59:26 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=017312026/07/19 09:59:26 INFO Vacuumed table table=pending_closures17322026/07/19 09:59:26 INFO Vacuumed table table=pending_objects17332026/07/19 09:59:26 INFO Vacuumed table table=multipart_uploads1734=== NAME TestOrphanedObjectsGCStressTest1735 orphaned_objects_gc_test.go:509: Stress test completed successfully:1736 orphaned_objects_gc_test.go:510: - Active objects preserved: 201737 orphaned_objects_gc_test.go:511: - Objects deleted: 2101738 orphaned_objects_gc_test.go:512: - Total GC'd: 2101739--- PASS: TestOrphanedObjectsGCStressTest (1.04s)17402026/07/19 09:59:26 INFO Vacuumed table table=closures17412026/07/19 09:59:26 INFO Vacuumed table table=objects17422026/07/19 09:59:26 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2043 objects-failed-to-delete=017432026/07/19 09:59:26 INFO Vacuumed table table=pending_closures17442026/07/19 09:59:26 INFO Vacuumed table table=pending_objects17452026/07/19 09:59:26 INFO Vacuumed table table=multipart_uploads17462026/07/19 09:59:26 INFO Vacuumed table table=closures17472026/07/19 09:59:26 INFO Vacuumed table table=objects17482026/07/19 09:59:26 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=876.73579ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17492026/07/19 09:59:27 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.5821675s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17502026/07/19 09:59:28 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01751=== NAME TestClientIntegration1752 client_integration_test.go:303: Objects in database after GC:1753 client_integration_test.go:303: Successfully deleted all objects with GC --force1754--- PASS: TestClientIntegration (2.50s)17552026/07/19 09:59:28 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2043 objects_failed=01756=== NAME TestPinProtectsFromGC1757 client_integration_test.go:709: Pin successfully protected closure from garbage collection1758--- PASS: TestPinProtectsFromGC (2.64s)1759--- PASS: TestClientErrorHandling (0.00s)1760 --- PASS: TestClientErrorHandling/InvalidStorePath (0.18s)1761 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.28s)1762 --- PASS: TestClientErrorHandling/ServerNotAvailable (3.35s)17632026/07/19 09:59:31 WARN Rate limiter enabled after throttle name=s3-test rate=517642026/07/19 09:59:31 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1765=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1766 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101767 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001768--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.68s)1769PASS17702026-07-19 09:59:31.976 UTC [112] LOG: received smart shutdown request17712026-07-19 09:59:31.980 UTC [112] LOG: background worker "logical replication launcher" (PID 122) exited with exit code 117722026-07-19 09:59:31.983 UTC [117] LOG: shutting down17732026-07-19 09:59:31.984 UTC [117] LOG: checkpoint starting: shutdown immediate17742026-07-19 09:59:33.241 UTC [117] LOG: checkpoint complete: wrote 10995 buffers (67.1%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 13 recycled; write=0.230 s, sync=1.019 s, total=1.258 s; sync files=15167, longest=0.002 s, average=0.001 s; distance=208458 kB, estimate=208458 kB; lsn=0/E2F1B88, redo lsn=0/E2F1B8817752026-07-19 09:59:33.308 UTC [112] LOG: database system is shut down1776Running OIDC tests...1777=== RUN TestGlobMatch1778=== PAUSE TestGlobMatch1779=== RUN TestAudienceForIssuer1780=== PAUSE TestAudienceForIssuer1781=== RUN TestValidateToken_ValidToken1782=== PAUSE TestValidateToken_ValidToken1783=== RUN TestValidateToken_WrongAudience1784=== PAUSE TestValidateToken_WrongAudience1785=== RUN TestValidateToken_Expired1786=== PAUSE TestValidateToken_Expired1787=== RUN TestValidateToken_BoundClaimsMismatch1788=== PAUSE TestValidateToken_BoundClaimsMismatch1789=== RUN TestValidateToken_BoundSubjectMismatch1790=== PAUSE TestValidateToken_BoundSubjectMismatch1791=== RUN TestValidateToken_MultipleProviders1792=== PAUSE TestValidateToken_MultipleProviders1793=== RUN TestValidateToken_NoMatchingProvider1794=== PAUSE TestValidateToken_NoMatchingProvider1795=== CONT TestGlobMatch1796=== RUN TestGlobMatch/foo_foo1797=== CONT TestValidateToken_BoundClaimsMismatch1798=== PAUSE TestGlobMatch/foo_foo1799=== RUN TestGlobMatch/foo_bar1800=== PAUSE TestGlobMatch/foo_bar1801=== CONT TestValidateToken_Expired1802=== CONT TestValidateToken_WrongAudience1803=== CONT TestValidateToken_NoMatchingProvider1804=== CONT TestValidateToken_ValidToken1805=== CONT TestValidateToken_MultipleProviders1806=== CONT TestValidateToken_BoundSubjectMismatch1807=== CONT TestAudienceForIssuer1808=== RUN TestGlobMatch/*_1809=== PAUSE TestGlobMatch/*_1810=== RUN TestGlobMatch/*_anything1811=== PAUSE TestGlobMatch/*_anything1812=== RUN TestGlobMatch/foo*_foo1813=== PAUSE TestGlobMatch/foo*_foo1814=== RUN TestGlobMatch/foo*_foobar1815=== PAUSE TestGlobMatch/foo*_foobar1816=== RUN TestGlobMatch/foo*_bar1817=== PAUSE TestGlobMatch/foo*_bar1818=== RUN TestGlobMatch/*bar_bar1819=== PAUSE TestGlobMatch/*bar_bar1820=== RUN TestGlobMatch/*bar_foobar1821=== PAUSE TestGlobMatch/*bar_foobar1822=== RUN TestGlobMatch/*bar_foo1823--- PASS: TestAudienceForIssuer (0.00s)1824=== PAUSE TestGlobMatch/*bar_foo1825=== RUN TestGlobMatch/foo*bar_foobar1826=== PAUSE TestGlobMatch/foo*bar_foobar1827=== RUN TestGlobMatch/foo*bar_foo123bar1828=== PAUSE TestGlobMatch/foo*bar_foo123bar1829=== RUN TestGlobMatch/foo*bar_foobarbaz1830=== PAUSE TestGlobMatch/foo*bar_foobarbaz1831=== RUN TestGlobMatch/*/*_foo/bar1832=== PAUSE TestGlobMatch/*/*_foo/bar1833=== RUN TestGlobMatch/*/*_foo1834=== PAUSE TestGlobMatch/*/*_foo1835=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1836=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1837=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01838=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01839=== RUN TestGlobMatch/refs/*/main_refs/heads/main1840=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1841=== RUN TestGlobMatch/fo?_foo1842=== PAUSE TestGlobMatch/fo?_foo1843=== RUN TestGlobMatch/fo?_fo1844=== PAUSE TestGlobMatch/fo?_fo1845=== RUN TestGlobMatch/fo?_fooo1846=== PAUSE TestGlobMatch/fo?_fooo1847=== RUN TestGlobMatch/?oo_foo1848=== PAUSE TestGlobMatch/?oo_foo1849=== RUN TestGlobMatch/?oo_boo1850=== PAUSE TestGlobMatch/?oo_boo1851=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1852=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1853=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main18542026/07/19 09:59:34 INFO OIDC provider initialized name=provider11855=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main18562026/07/19 09:59:34 INFO OIDC provider initialized name=test1857=== CONT TestGlobMatch/foo_foo1858=== CONT TestGlobMatch/?oo_boo1859=== CONT TestGlobMatch/foo*bar_foo123bar18602026/07/19 09:59:34 INFO OIDC provider initialized name=test1861=== CONT TestGlobMatch/*/*_foo/bar18622026/07/19 09:59:34 INFO OIDC provider initialized name=test1863=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main18642026/07/19 09:59:34 INFO OIDC provider initialized name=test1865=== CONT TestGlobMatch/fo?_foo18662026/07/19 09:59:34 INFO OIDC provider initialized name=provider11867=== CONT TestGlobMatch/foo*_bar18682026/07/19 09:59:34 INFO OIDC provider initialized name=test1869=== CONT TestGlobMatch/foo*_foobar1870=== CONT TestGlobMatch/refs/*/main_refs/heads/main1871=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01872=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1873=== CONT TestGlobMatch/fo?_fo1874=== CONT TestGlobMatch/*/*_foo1875=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1876=== CONT TestGlobMatch/?oo_foo1877=== CONT TestGlobMatch/fo?_fooo1878=== CONT TestGlobMatch/*bar_bar1879=== CONT TestGlobMatch/foo*bar_foobar1880=== CONT TestGlobMatch/*bar_foo1881=== CONT TestGlobMatch/foo*bar_foobarbaz1882=== CONT TestGlobMatch/*bar_foobar18832026/07/19 09:59:34 INFO OIDC provider initialized name=provider21884=== CONT TestGlobMatch/foo*_foo1885=== CONT TestGlobMatch/*_anything1886=== CONT TestGlobMatch/*_1887=== CONT TestGlobMatch/foo_bar1888--- PASS: TestGlobMatch (0.01s)1889 --- PASS: TestGlobMatch/foo_foo (0.00s)1890 --- PASS: TestGlobMatch/?oo_boo (0.00s)1891 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1892 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1893 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1894 --- PASS: TestGlobMatch/fo?_foo (0.00s)1895 --- PASS: TestGlobMatch/foo*_bar (0.00s)1896 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1897 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1898 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1899 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1900 --- PASS: TestGlobMatch/fo?_fo (0.00s)1901 --- PASS: TestGlobMatch/*/*_foo (0.00s)1902 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1903 --- PASS: TestGlobMatch/?oo_foo (0.00s)1904 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1905 --- PASS: TestGlobMatch/*bar_bar (0.00s)1906 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1907 --- PASS: TestGlobMatch/*bar_foo (0.00s)1908 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1909 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1910 --- PASS: TestGlobMatch/foo*_foo (0.00s)1911 --- PASS: TestGlobMatch/*_anything (0.00s)1912 --- PASS: TestGlobMatch/*_ (0.00s)1913 --- PASS: TestGlobMatch/foo_bar (0.00s)1914--- PASS: TestValidateToken_Expired (0.01s)1915--- PASS: TestValidateToken_WrongAudience (0.01s)1916--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1917--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1918--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1919--- PASS: TestValidateToken_ValidToken (0.01s)1920--- PASS: TestValidateToken_MultipleProviders (0.01s)1921PASS1922Running hook tests...1923=== RUN TestSendPathsEmpty1924=== PAUSE TestSendPathsEmpty1925=== RUN TestQueueEnqueueAndFetch1926=== PAUSE TestQueueEnqueueAndFetch1927=== RUN TestQueueDeduplication1928=== PAUSE TestQueueDeduplication1929=== RUN TestQueueRemove1930=== PAUSE TestQueueRemove1931=== RUN TestQueueFetchBatchLimit1932=== PAUSE TestQueueFetchBatchLimit1933=== RUN TestQueueFetchRemoveLifecycle1934=== PAUSE TestQueueFetchRemoveLifecycle1935=== RUN TestQueueConcurrentWriters1936=== PAUSE TestQueueConcurrentWriters1937=== RUN TestServerClientIntegration1938=== PAUSE TestServerClientIntegration1939=== RUN TestServerQueueError1940=== PAUSE TestServerQueueError1941=== RUN TestGetListenerSocketActivation1942 server_test.go:210: === RUN TestGetListenerSocketActivation1943 --- PASS: TestGetListenerSocketActivation (0.00s)1944 PASS1945 1946--- PASS: TestGetListenerSocketActivation (0.01s)1947=== RUN TestWorkerUploadsAndRemoves1948=== PAUSE TestWorkerUploadsAndRemoves1949=== RUN TestWorkerSkipsGCdPaths1950=== PAUSE TestWorkerSkipsGCdPaths1951=== RUN TestWorkerPrunesClosureDeps1952=== PAUSE TestWorkerPrunesClosureDeps1953=== CONT TestSendPathsEmpty1954=== CONT TestQueueConcurrentWriters1955=== CONT TestQueueDeduplication1956=== CONT TestWorkerUploadsAndRemoves1957=== CONT TestWorkerPrunesClosureDeps1958--- PASS: TestSendPathsEmpty (0.00s)1959=== CONT TestQueueFetchRemoveLifecycle1960=== CONT TestQueueFetchBatchLimit1961=== CONT TestWorkerSkipsGCdPaths1962=== CONT TestQueueRemove1963=== CONT TestQueueEnqueueAndFetch1964=== CONT TestServerQueueError1965=== CONT TestServerClientIntegration19662026/07/19 09:59:34 ERROR Failed to queue paths error="permission denied" count=11967--- PASS: TestServerClientIntegration (0.00s)1968--- PASS: TestServerQueueError (0.00s)1969--- PASS: TestQueueEnqueueAndFetch (0.01s)1970--- PASS: TestQueueDeduplication (0.02s)19712026/07/19 09:59:34 INFO Upload queue status pending=21972--- PASS: TestQueueFetchBatchLimit (0.02s)19732026/07/19 09:59:34 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1739176067/002/nonexistent19742026/07/19 09:59:34 INFO Upload queue status pending=219752026/07/19 09:59:34 INFO Upload queue status pending=219762026/07/19 09:59:34 INFO Uploading batch count=219772026/07/19 09:59:34 INFO Uploading batch count=11978--- PASS: TestQueueRemove (0.02s)19792026/07/19 09:59:34 INFO Uploading batch count=11980--- PASS: TestQueueFetchRemoveLifecycle (0.02s)1981--- PASS: TestWorkerUploadsAndRemoves (0.07s)1982--- PASS: TestWorkerSkipsGCdPaths (0.06s)1983--- PASS: TestWorkerPrunesClosureDeps (0.07s)1984--- PASS: TestQueueConcurrentWriters (0.28s)1985PASS