niks3-go-unit-tests
x86_64-linux.go-unit-tests
· build #95
· 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 TestFileTokenMissing73=== CONT TestSetClientTLSErrors74=== CONT TestScriptTokenEmptyCommand75=== CONT TestScriptTokenBadJSON76--- PASS: TestScriptTokenEmptyCommand (0.00s)77=== CONT TestShellSplit78--- PASS: TestShellSplit (0.00s)79=== CONT TestSetClientTLSDoesNotMutateDefaultTransport80--- PASS: TestFileTokenMissing (0.00s)81=== CONT TestResolveStorePath82=== CONT TestSetClientTLS83=== CONT TestFileTokenReadsAndCaches84=== CONT TestShellSplitErrors85--- PASS: TestShellSplitErrors (0.00s)86=== CONT TestStaticToken87--- PASS: TestStaticToken (0.00s)88=== CONT TestDoWithRetry_BodyReplayedViaGetBody89=== CONT TestParsePathInfoJSONMultiplePaths90=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths91=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths92=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths93=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess94=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths95=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths96=== CONT TestPathInfoCACompatibility97=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths98=== CONT TestPathInfoHashCompatibility99=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)100=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)101=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon102=== CONT TestParsePathInfoJSON103=== RUN TestParsePathInfoJSON/Nix_format104=== CONT TestGetStorePathHash105=== CONT TestScriptTokenNoExpiryRerunsEveryCall106=== CONT TestScriptTokenCachesUntilRefresh107=== CONT TestFileTokenEmpty108=== CONT TestDumpPathSingleFile109=== CONT TestEncodeNixBase32WithRealHash110=== CONT TestEncodeNixBase32111=== CONT TestDumpPathWriterError112=== CONT TestScriptTokenEmptyToken113=== CONT TestPartSizeForNAR114=== CONT TestDumpPathMatchesNix115=== CONT TestCaseHackSuffix116=== CONT TestScriptTokenScriptFails117=== CONT TestConvertHashToNix32118=== CONT TestUploadMultipart_SupersededByPeer119=== CONT TestRateLimiterFeedback120--- PASS: TestFileTokenReadsAndCaches (0.00s)121--- PASS: TestResolveStorePath (0.00s)122--- PASS: TestEncodeNixBase32WithRealHash (0.00s)123=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon124=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1252026/07/09 07:42:53 WARN Rate limiter enabled after throttle name=server-test rate=5126=== RUN TestPartSizeForNAR/zero_stays_at_minimum127--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)128 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)129 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)130=== RUN TestConvertHashToNix32/SRI_format_to_Nix32131=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum132=== RUN TestEncodeNixBase32/test_string_hash133=== RUN TestGetStorePathHash/valid_store_path134=== PAUSE TestEncodeNixBase32/test_string_hash135=== RUN TestUploadMultipart_SupersededByPeer/exists136=== PAUSE TestUploadMultipart_SupersededByPeer/exists137=== RUN TestEncodeNixBase32/empty_input138=== PAUSE TestEncodeNixBase32/empty_input139=== PAUSE TestParsePathInfoJSON/Nix_format140=== RUN TestRateLimiterFeedback/429_enables_limiter141--- PASS: TestFileTokenEmpty (0.00s)142=== PAUSE TestRateLimiterFeedback/429_enables_limiter1432026/07/09 07:42:53 WARN Rate limiter enabled after throttle name=server-test rate=51442026/07/09 07:42:53 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37191145=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI146=== RUN TestSetClientTLSErrors/missing_cert_file147=== PAUSE TestSetClientTLSErrors/missing_cert_file148=== RUN TestSetClientTLSErrors/missing_key_file149=== RUN TestParsePathInfoJSON/Lix_format150=== PAUSE TestParsePathInfoJSON/Lix_format151=== PAUSE TestGetStorePathHash/valid_store_path152=== RUN TestPartSizeForNAR/small_stays_at_minimum153=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32154=== RUN TestPathInfoCACompatibility/null_ca_field155=== RUN TestUploadMultipart_SupersededByPeer/missing156=== CONT TestEncodeNixBase32/test_string_hash157=== CONT TestEncodeNixBase32/empty_input158=== RUN TestRateLimiterFeedback/503_enables_limiter159--- PASS: TestScriptTokenEmptyToken (0.01s)160=== PAUSE TestSetClientTLSErrors/missing_key_file161=== PAUSE TestRateLimiterFeedback/503_enables_limiter162=== PAUSE TestUploadMultipart_SupersededByPeer/missing163=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter164=== PAUSE TestPathInfoCACompatibility/null_ca_field165=== PAUSE TestPartSizeForNAR/small_stays_at_minimum166=== RUN TestConvertHashToNix32/already_Nix32_format167=== RUN TestPathInfoCACompatibility/old_string_format_-_text168=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum169=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum170=== RUN TestParsePathInfoJSON/empty_input171=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512172=== RUN TestGetStorePathHash/basename_without_hyphen_should_error173=== RUN TestSetClientTLSErrors/missing_ca_file174=== PAUSE TestSetClientTLSErrors/missing_ca_file175=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter176=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter177=== PAUSE TestParsePathInfoJSON/empty_input178=== RUN TestParsePathInfoJSON/whitespace_only179=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text1802026/07/09 07:42:53 WARN Rate limiter backed off name=server-test rate=5181=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1822026/07/09 07:42:53 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37191183=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive184=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter185=== RUN TestSetClientTLSErrors/invalid_ca_file186=== PAUSE TestSetClientTLSErrors/invalid_ca_file187=== CONT TestUploadMultipart_SupersededByPeer/missing188=== PAUSE TestConvertHashToNix32/already_Nix32_format189=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts190=== CONT TestUploadMultipart_SupersededByPeer/exists191=== RUN TestConvertHashToNix32/invalid_format192--- PASS: TestEncodeNixBase32 (0.00s)193 --- PASS: TestEncodeNixBase32/empty_input (0.00s)194 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)195--- PASS: TestScriptTokenBadJSON (0.01s)196--- PASS: TestDoServerRequestAttachesToken (0.00s)197=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512198=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon199=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512200=== PAUSE TestParsePathInfoJSON/whitespace_only201=== RUN TestPathInfoCACompatibility/new_structured_format_-_text202=== CONT TestRateLimiterFeedback/429_enables_limiter203=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter204=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter205=== CONT TestRateLimiterFeedback/503_enables_limiter206=== CONT TestSetClientTLSErrors/missing_cert_file207=== CONT TestSetClientTLSErrors/invalid_ca_file208=== CONT TestSetClientTLSErrors/missing_ca_file209=== CONT TestSetClientTLSErrors/missing_key_file210=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts211=== PAUSE TestConvertHashToNix32/invalid_format212=== RUN TestSetClientTLS/rejects_connection_without_client_cert213=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert214--- PASS: TestScriptTokenScriptFails (0.01s)215=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error216=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI217=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error218=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error219=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error220=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error221=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)222=== RUN TestParsePathInfoJSON/invalid_JSON223=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text224=== CONT TestConvertHashToNix32/SRI_format_to_Nix32225=== CONT TestConvertHashToNix32/invalid_format226=== CONT TestConvertHashToNix32/already_Nix32_format227=== RUN TestPartSizeForNAR/1_TiB2282026/07/09 07:42:53 WARN Rate limiter enabled after throttle name=server-test rate=5229=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA2302026/07/09 07:42:53 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:41691231=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA232=== RUN TestSetClientTLS/preserves_debug_logging_transport233--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)2342026/07/09 07:42:53 WARN Rate limiter enabled after throttle name=server-test rate=5235=== CONT TestGetStorePathHash/valid_store_path2362026/07/09 07:42:53 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:33095237=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error238=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error239=== CONT TestGetStorePathHash/basename_without_hyphen_should_error240=== PAUSE TestParsePathInfoJSON/invalid_JSON241=== CONT TestParsePathInfoJSON/Nix_format242=== CONT TestParsePathInfoJSON/empty_input243=== CONT TestParsePathInfoJSON/Lix_format244=== CONT TestParsePathInfoJSON/whitespace_only2452026/07/09 07:42:53 WARN Rate limiter backed off name=server-test rate=5246=== PAUSE TestPartSizeForNAR/1_TiB247=== PAUSE TestSetClientTLS/preserves_debug_logging_transport248=== RUN TestPartSizeForNAR/5_TiB_S3_max_object249=== CONT TestSetClientTLS/rejects_connection_without_client_cert2502026/07/09 07:42:53 WARN Rate limiter backed off name=server-test rate=5251=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method252=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method253=== CONT TestParsePathInfoJSON/invalid_JSON254--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)255=== CONT TestSetClientTLS/preserves_debug_logging_transport256=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA257=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object258=== CONT TestPathInfoCACompatibility/null_ca_field259=== CONT TestPathInfoCACompatibility/new_structured_format_-_text260=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method261=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive262=== CONT TestPathInfoCACompatibility/old_string_format_-_text263--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)264=== RUN TestPartSizeForNAR/capped_at_5_GiB265=== PAUSE TestPartSizeForNAR/capped_at_5_GiB266=== CONT TestPartSizeForNAR/zero_stays_at_minimum267=== CONT TestPartSizeForNAR/5_TiB_S3_max_object268=== CONT TestPartSizeForNAR/1_TiB269=== CONT TestPartSizeForNAR/capped_at_5_GiB270--- PASS: TestPathInfoHashCompatibility (0.01s)271 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)272 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)273 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)274 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)275=== CONT TestPartSizeForNAR/small_stays_at_minimum276=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts277=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum278--- PASS: TestConvertHashToNix32 (0.02s)279 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)280 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)281 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)282--- PASS: TestParsePathInfoJSON (0.02s)283 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)284 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)285 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)286 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)287 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)288--- PASS: TestRateLimiterFeedback (0.01s)289 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)290 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)291 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)292 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)293--- PASS: TestGetStorePathHash (0.02s)294 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)295 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)296 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)297 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)298--- PASS: TestSetClientTLSErrors (0.01s)299 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)300 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)301 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)302 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)303--- PASS: TestPartSizeForNAR (0.02s)304 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)305 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)306 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)307 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)308 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)309 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)310 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)311--- PASS: TestPathInfoCACompatibility (0.02s)312 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)313 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)314 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)315 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)316 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)317--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)318 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)319 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)3202026/07/09 07:42:53 http: TLS handshake error from 127.0.0.1:56476: remote error: tls: bad certificate321--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)322--- 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: TestCaseHackSuffix (0.04s)327--- PASS: TestDumpPathSingleFile (0.05s)328--- PASS: TestDumpPathWriterError (0.07s)329--- PASS: TestDumpPathMatchesNix (0.13s)330--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)331PASS332Running server tests...333The files belonging to this database system will be owned by user "nixbld".334This user must also own the server process.335336The database cluster will be initialized with locale "C".337The default database encoding has accordingly been set to "SQL_ASCII".338The default text search configuration will be set to "english".339340Data page checksums are disabled.341342creating directory /build/postgres1731862845/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/postgres1731862845/data -l logfile start359360/build/postgres1731862845:5432 - no response3612026-07-09 07:42:55.077 UTC [330] LOG: starting PostgreSQL 17.10 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit3622026-07-09 07:42:55.077 UTC [330] LOG: listening on Unix socket "/build/postgres1731862845/.s.PGSQL.5432"3632026-07-09 07:42:55.082 UTC [334] LOG: database system was shut down at 2026-07-09 07:42:54 UTC3642026-07-09 07:42:55.086 UTC [330] LOG: database system is ready to accept connections365/build/postgres1731862845:5432 - accepting connections366{"timestamp":"2026-07-09T07:42:55.457863222Z","level":"ERROR","fields":{"message":"list_path_raw: revjob err VolumeNotFound"},"target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":486,"threadName":"rustfs-worker","threadId":"ThreadId(766)"}367368thread 'rustfs-worker' (1109) panicked at /build/rustfs-1.0.0-beta.7-vendor/source-registry-0/reqwest-0.13.4/src/async_impl/client.rs:2507:38:369Client::new(): reqwest::Error { kind: Builder, source: General("No CA certificates were loaded from the system") }370note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace371=== RUN TestService_AuthMiddleware372=== PAUSE TestService_AuthMiddleware373=== RUN TestService_AuthMiddleware_MTLSProxyHeader374=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader375=== RUN TestService_AuthMiddleware_MTLSBoundSubjects376=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects377=== RUN TestService_ReadAuthMiddleware378=== PAUSE TestService_ReadAuthMiddleware379=== RUN TestService_AuthMiddleware_OIDC380=== PAUSE TestService_AuthMiddleware_OIDC381=== RUN TestCacheConfigHandler382=== PAUSE TestCacheConfigHandler383=== RUN TestCacheStatsHandler384=== PAUSE TestCacheStatsHandler385=== RUN TestClientCADerivations386=== PAUSE TestClientCADerivations387=== RUN TestClientErrorHandling388=== PAUSE TestClientErrorHandling389=== RUN TestClientIntegration390=== PAUSE TestClientIntegration391=== RUN TestClientMultipleUploads392=== PAUSE TestClientMultipleUploads393=== RUN TestClientWithDependencies394=== PAUSE TestClientWithDependencies395=== RUN TestPinProtectsFromGC396=== PAUSE TestPinProtectsFromGC397=== RUN TestGCAdvisoryLockBlocksConcurrentRun3982026-07-09 07:42:55.539 UTC [1129] ERROR: relation "goose_db_version" does not exist at character 363992026-07-09 07:42:55.539 UTC [1129] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4002026/07/09 07:42:55 OK 20241026095416_initial_model.sql (5.35ms)4012026/07/09 07:42:55 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)4022026/07/09 07:42:55 OK 20251218171726_add_pins.sql (2.14ms)4032026/07/09 07:42:55 OK 20260628120000_add_object_size_and_stats.sql (1.7ms)4042026/07/09 07:42:55 goose: successfully migrated database to version: 202606281200004052026/07/09 07:42:55 OK 1_commit_pending_closure.sql (1.31ms)4062026/07/09 07:42:55 OK 2_object_stats_trigger.sql (657.44µs)4072026/07/09 07:42:55 goose: up to current file version: 2408--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.09s)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 TestService_Rustfstest482=== PAUSE TestService_Rustfstest483=== RUN TestSystemdListenerNotActivated484--- PASS: TestSystemdListenerNotActivated (0.00s)485=== RUN TestWatchdogBeatsWhenHealthy486--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)487=== RUN TestWatchdogSkipsWhenUnhealthy4882026/07/09 07:42:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4892026/07/09 07:42:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4902026/07/09 07:42:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4912026/07/09 07:42:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4922026/07/09 07:42:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4932026/07/09 07:42:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4942026/07/09 07:42:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4952026/07/09 07:42:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4962026/07/09 07:42:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4972026/07/09 07:42:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"498--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)499=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle500=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle501=== RUN TestProxyWriteTimeout502=== PAUSE TestProxyWriteTimeout503=== RUN TestIsValidUploadKey504=== PAUSE TestIsValidUploadKey505=== RUN TestUploadHandlersRejectInvalidKeys506=== PAUSE TestUploadHandlersRejectInvalidKeys507=== RUN TestUploadHandlersRejectOversizedBody508=== PAUSE TestUploadHandlersRejectOversizedBody509=== RUN TestService_cleanupPendingClosuresHandler510=== PAUSE TestService_cleanupPendingClosuresHandler511=== RUN TestService_createPendingClosureHandler512=== PAUSE TestService_createPendingClosureHandler513=== RUN TestService_verifyS3Integrity514=== PAUSE TestService_verifyS3Integrity515=== RUN TestCompleteMultipartUnregistered516=== PAUSE TestCompleteMultipartUnregistered517=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT518=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT519=== CONT TestService_AuthMiddleware520=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT521=== CONT TestServerTLSConfig522=== CONT TestGCTaskStore_StartNew523=== CONT TestService_ReadAuthMiddleware524=== CONT TestCompleteMultipartUnregistered525=== RUN TestServerTLSConfig/no_client_CA526=== PAUSE TestServerTLSConfig/no_client_CA527=== CONT TestService_AuthMiddleware_MTLSProxyHeader528=== CONT TestService_verifyS3Integrity529=== CONT TestService_createPendingClosureHandler530=== CONT TestService_cleanupPendingClosuresHandler531=== CONT TestUploadHandlersRejectOversizedBody532=== CONT TestUploadHandlersRejectInvalidKeys533=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info534=== CONT TestIsValidUploadKey535=== CONT TestProxyWriteTimeout536=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle537=== CONT TestService_Rustfstest538=== CONT TestCompleteMultipartUpload_ErrorButObjectExists539=== CONT TestRedundantMultipartUpload540=== CONT TestReadProxyRangeRequest541=== CONT TestReadProxyDisabled542=== CONT TestReadProxyRootRedirectsToIndexHTML543=== CONT TestReadProxyConditionalGet544=== CONT TestReadProxyHead545=== CONT TestReadProxyInvalidPath546=== CONT TestReadProxy404547=== CONT TestReadProxyNarStreaming548=== CONT TestReadProxyNarinfoAlreadyDecompressed549=== CONT TestReadProxyNarinfo550=== CONT TestIsValidCachePath551=== CONT TestParseSingleRange552=== CONT TestResurrectedObjectNotDeleted553=== CONT TestOrphanedObjectsGCStressTest554=== CONT TestOrphanedObjectsGC555=== CONT TestObjectStatsTrigger556=== CONT TestMultipartCleanup557=== CONT TestPinProtectsFromGC558=== CONT TestGCMetrics559=== CONT TestGCBugBareHashReferences560=== CONT TestClientMultipleUploads561=== CONT TestClientErrorHandling562=== CONT TestClientWithDependencies563=== CONT TestClientIntegration564=== CONT TestGCTaskStore_Fail565=== CONT TestService_NativeMTLS566=== CONT TestService_AuthMiddleware_OIDC567=== CONT TestMetricsInventory568=== CONT TestClientCADerivations569=== CONT TestNARDeduplicationMetadataUploadBug570=== CONT TestCacheStatsHandler571=== CONT TestGenerateLandingPage572=== CONT TestService_healthCheckHandler573=== CONT TestCacheConfigHandler574=== CONT TestGCTaskStore_GetReturnsLatest575=== CONT TestGCTaskStore_PhaseUpdates576=== CONT TestGracefulShutdownDrainsInflight577=== CONT TestService_AuthMiddleware_MTLSBoundSubjects578=== CONT TestGCTaskStore_CompletedAllowsNewTask579=== CONT TestGCTaskStore_ConflictDifferentParams580=== CONT TestGCTaskStore_GetEmpty581=== CONT TestGCTaskStore_DeduplicateSameParams582--- PASS: TestGCTaskStore_StartNew (0.00s)583=== RUN TestServerTLSConfig/missing_CA_file584=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info585--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)586=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal587=== RUN TestIsValidUploadKey/narinfo588=== RUN TestProxyWriteTimeout/narinfo589=== RUN TestIsValidCachePath/narinfo590=== RUN TestClientErrorHandling/InvalidStorePath591--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)592--- PASS: TestGCTaskStore_Fail (0.00s)593=== PAUSE TestIsValidCachePath/narinfo594=== RUN TestParseSingleRange/none595=== PAUSE TestClientErrorHandling/InvalidStorePath596=== RUN TestCacheConfigHandler/full_config,_no_issuer597=== RUN TestClientErrorHandling/InvalidAuthToken598=== PAUSE TestClientErrorHandling/InvalidAuthToken599=== PAUSE TestCacheConfigHandler/full_config,_no_issuer600=== PAUSE TestIsValidUploadKey/narinfo6012026/07/09 07:42:55 INFO Starting HTTP server address=127.0.0.1:40535602=== PAUSE TestProxyWriteTimeout/narinfo603--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)604=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars605=== PAUSE TestParseSingleRange/none606=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal607=== PAUSE TestServerTLSConfig/missing_CA_file608=== RUN TestClientErrorHandling/ServerNotAvailable609=== PAUSE TestClientErrorHandling/ServerNotAvailable610=== RUN TestCacheConfigHandler/no_cache_url_configured611=== CONT TestClientErrorHandling/InvalidStorePath6122026/07/09 07:42:55 INFO Shutdown signal received, draining in-flight requests timeout=10s613=== RUN TestProxyWriteTimeout/1_GiB_nar614=== PAUSE TestProxyWriteTimeout/1_GiB_nar615=== RUN TestProxyWriteTimeout/10_GiB_nar616=== PAUSE TestProxyWriteTimeout/10_GiB_nar617--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)618=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars619=== RUN TestParseSingleRange/unknown_unit620=== RUN TestIsValidCachePath/nar_zst621=== PAUSE TestIsValidCachePath/nar_zst622=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key623=== PAUSE TestParseSingleRange/unknown_unit624=== RUN TestServerTLSConfig/not_a_PEM_file625=== PAUSE TestServerTLSConfig/not_a_PEM_file626=== CONT TestServerTLSConfig/no_client_CA627=== CONT TestServerTLSConfig/not_a_PEM_file628=== CONT TestServerTLSConfig/missing_CA_file629=== CONT TestClientErrorHandling/InvalidAuthToken630=== CONT TestClientErrorHandling/ServerNotAvailable631=== RUN TestIsValidUploadKey/nar_zst632=== PAUSE TestIsValidUploadKey/nar_zst633=== RUN TestIsValidUploadKey/nar_xz634=== PAUSE TestCacheConfigHandler/no_cache_url_configured635=== RUN TestProxyWriteTimeout/unknown_size636--- PASS: TestGCTaskStore_GetEmpty (0.00s)637--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)638=== RUN TestIsValidCachePath/nar_xz639=== PAUSE TestIsValidCachePath/nar_xz640=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key641=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key642=== RUN TestParseSingleRange/multi-range_ignored643=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key644=== PAUSE TestProxyWriteTimeout/unknown_size645=== RUN TestCacheConfigHandler/no_signing_keys646=== CONT TestProxyWriteTimeout/10_GiB_nar647=== PAUSE TestCacheConfigHandler/no_signing_keys648--- PASS: TestServerTLSConfig (0.01s)649 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)650 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)651 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)652=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator653=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator654=== CONT TestCacheConfigHandler/full_config,_no_issuer655=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator656=== PAUSE TestParseSingleRange/multi-range_ignored657=== RUN TestParseSingleRange/malformed_no_dash658=== PAUSE TestParseSingleRange/malformed_no_dash659=== RUN TestParseSingleRange/malformed_both_empty660=== PAUSE TestIsValidUploadKey/nar_xz661=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info662=== RUN TestIsValidUploadKey/nar_plain663=== PAUSE TestIsValidUploadKey/nar_plain664=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key665=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key6662026/07/09 07:42:55 INFO Received request for more parts method=POST path=/667=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal6682026/07/09 07:42:55 INFO Received uploads request method=POST path=/669=== CONT TestProxyWriteTimeout/narinfo6702026/07/09 07:42:55 INFO Received uploads request method=POST path=/671=== CONT TestProxyWriteTimeout/1_GiB_nar6722026/07/09 07:42:55 INFO Received complete multipart upload request method=POST path=/673=== CONT TestProxyWriteTimeout/unknown_size674=== RUN TestIsValidCachePath/nar_bz2675=== PAUSE TestIsValidCachePath/nar_bz2676=== RUN TestIsValidCachePath/nar_uncompressed677=== CONT TestCacheConfigHandler/no_signing_keys678=== CONT TestCacheConfigHandler/no_cache_url_configured679=== PAUSE TestParseSingleRange/malformed_both_empty680=== RUN TestParseSingleRange/malformed_end_before_start681=== RUN TestIsValidUploadKey/listing682--- PASS: TestProxyWriteTimeout (0.00s)683 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)684 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)685 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)686 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)687=== PAUSE TestIsValidCachePath/nar_uncompressed688--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)689 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)690 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)691 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)692 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)6932026/07/09 07:42:55 INFO OIDC provider initialized name=test694=== RUN TestIsValidCachePath/ls695=== PAUSE TestIsValidCachePath/ls696=== RUN TestIsValidCachePath/log697=== PAUSE TestIsValidUploadKey/listing698=== PAUSE TestParseSingleRange/malformed_end_before_start699=== RUN TestParseSingleRange/closed700--- PASS: TestCacheConfigHandler (0.00s)701 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)702 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)703 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)704 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)705=== PAUSE TestIsValidCachePath/log706=== RUN TestIsValidUploadKey/build_log707=== PAUSE TestIsValidUploadKey/build_log708=== PAUSE TestParseSingleRange/closed709=== RUN TestIsValidCachePath/realisation710=== RUN TestIsValidUploadKey/build_log_home-manager_file711--- PASS: TestGenerateLandingPage (0.01s)712=== RUN TestParseSingleRange/open-ended713=== PAUSE TestIsValidCachePath/realisation714=== PAUSE TestParseSingleRange/open-ended715=== PAUSE TestIsValidUploadKey/build_log_home-manager_file716=== RUN TestIsValidUploadKey/build_log_plus_in_name717=== PAUSE TestIsValidUploadKey/build_log_plus_in_name718=== RUN TestIsValidUploadKey/build_log_question_mark719=== PAUSE TestIsValidUploadKey/build_log_question_mark720=== RUN TestIsValidUploadKey/build_log_equals721=== RUN TestParseSingleRange/end_clamped_to_size722=== RUN TestIsValidCachePath/nix-cache-info723=== PAUSE TestIsValidCachePath/nix-cache-info724=== PAUSE TestIsValidUploadKey/build_log_equals725=== PAUSE TestParseSingleRange/end_clamped_to_size726=== RUN TestIsValidCachePath/index.html727=== PAUSE TestIsValidCachePath/index.html728=== RUN TestIsValidUploadKey/realisation729=== PAUSE TestIsValidUploadKey/realisation730=== RUN TestParseSingleRange/suffix731=== PAUSE TestParseSingleRange/suffix732=== RUN TestIsValidCachePath/traversal_parent733=== PAUSE TestIsValidCachePath/traversal_parent734=== RUN TestIsValidUploadKey/realisation_plus_in_output735=== PAUSE TestIsValidUploadKey/realisation_plus_in_output736=== RUN TestParseSingleRange/suffix_exceeds_size737=== PAUSE TestParseSingleRange/suffix_exceeds_size738=== RUN TestIsValidCachePath/traversal_in_middle739=== RUN TestIsValidUploadKey/nix-cache-info740=== RUN TestParseSingleRange/single_byte741=== PAUSE TestParseSingleRange/single_byte742=== PAUSE TestIsValidCachePath/traversal_in_middle743=== RUN TestIsValidCachePath/invalid_char_e744=== PAUSE TestIsValidUploadKey/nix-cache-info745=== RUN TestParseSingleRange/start_past_EOF746=== PAUSE TestParseSingleRange/start_past_EOF747=== RUN TestParseSingleRange/start_far_past_EOF748=== PAUSE TestIsValidCachePath/invalid_char_e749=== RUN TestIsValidCachePath/invalid_char_u750=== PAUSE TestIsValidCachePath/invalid_char_u751=== RUN TestIsValidCachePath/random_path752=== RUN TestIsValidUploadKey/index.html753=== PAUSE TestParseSingleRange/start_far_past_EOF754=== PAUSE TestIsValidCachePath/random_path755=== PAUSE TestIsValidUploadKey/index.html756=== CONT TestParseSingleRange/none757=== CONT TestParseSingleRange/start_far_past_EOF758=== CONT TestParseSingleRange/closed759=== CONT TestParseSingleRange/malformed_end_before_start760=== CONT TestParseSingleRange/open-ended761=== CONT TestParseSingleRange/malformed_both_empty762=== CONT TestParseSingleRange/start_past_EOF763=== CONT TestParseSingleRange/malformed_no_dash764=== CONT TestParseSingleRange/single_byte765=== CONT TestParseSingleRange/unknown_unit766=== CONT TestParseSingleRange/suffix_exceeds_size767=== CONT TestParseSingleRange/multi-range_ignored768=== CONT TestParseSingleRange/suffix769=== CONT TestParseSingleRange/end_clamped_to_size770--- PASS: TestParseSingleRange (0.01s)771 --- PASS: TestParseSingleRange/none (0.00s)772 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)773 --- PASS: TestParseSingleRange/closed (0.00s)774 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)775 --- PASS: TestParseSingleRange/open-ended (0.00s)776 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)777 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)778 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)779 --- PASS: TestParseSingleRange/single_byte (0.00s)780 --- PASS: TestParseSingleRange/unknown_unit (0.00s)781 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)782 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)783 --- PASS: TestParseSingleRange/suffix (0.00s)784 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)785=== RUN TestIsValidCachePath/empty786=== PAUSE TestIsValidCachePath/empty787=== RUN TestIsValidCachePath/leading_slash788=== PAUSE TestIsValidCachePath/leading_slash789=== RUN TestIsValidUploadKey/narinfo_key,_nar_type790=== RUN TestIsValidCachePath/wrong_extension791=== PAUSE TestIsValidCachePath/wrong_extension792=== RUN TestIsValidCachePath/short_hash793=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type794=== PAUSE TestIsValidCachePath/short_hash795=== RUN TestIsValidUploadKey/nar_key,_narinfo_type796=== CONT TestIsValidCachePath/narinfo797=== CONT TestIsValidCachePath/traversal_in_middle798=== CONT TestIsValidCachePath/nar_xz799=== CONT TestIsValidCachePath/realisation800=== CONT TestIsValidCachePath/index.html801=== CONT TestIsValidCachePath/invalid_char_u802=== CONT TestIsValidCachePath/nar_zst803=== CONT TestIsValidCachePath/short_hash804=== CONT TestIsValidCachePath/wrong_extension805=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type806=== CONT TestIsValidCachePath/leading_slash807=== CONT TestIsValidCachePath/empty808=== CONT TestIsValidCachePath/invalid_char_e809=== CONT TestIsValidCachePath/random_path810=== CONT TestIsValidCachePath/traversal_parent811=== CONT TestIsValidCachePath/nar_uncompressed812=== CONT TestIsValidCachePath/nix-cache-info813=== CONT TestIsValidCachePath/ls814=== CONT TestIsValidCachePath/nar_bz2815=== CONT TestIsValidCachePath/log816=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars817--- PASS: TestIsValidCachePath (0.01s)818 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)819 --- PASS: TestIsValidCachePath/nar_xz (0.00s)820 --- PASS: TestIsValidCachePath/narinfo (0.00s)821 --- PASS: TestIsValidCachePath/index.html (0.00s)822 --- PASS: TestIsValidCachePath/realisation (0.00s)823 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)824 --- PASS: TestIsValidCachePath/nar_zst (0.00s)825 --- PASS: TestIsValidCachePath/short_hash (0.00s)826 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)827 --- PASS: TestIsValidCachePath/leading_slash (0.00s)828 --- PASS: TestIsValidCachePath/empty (0.00s)829 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)830 --- PASS: TestIsValidCachePath/random_path (0.00s)831 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)832 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)833 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)834 --- PASS: TestIsValidCachePath/ls (0.00s)835 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)836 --- PASS: TestIsValidCachePath/log (0.00s)837 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)838=== RUN TestIsValidUploadKey/listing_key,_narinfo_type839=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type840=== RUN TestIsValidUploadKey/traversal841=== PAUSE TestIsValidUploadKey/traversal842=== RUN TestIsValidUploadKey/traversal_nar843=== PAUSE TestIsValidUploadKey/traversal_nar844=== RUN TestIsValidUploadKey/absolute845=== PAUSE TestIsValidUploadKey/absolute846=== RUN TestIsValidUploadKey/empty_key847=== PAUSE TestIsValidUploadKey/empty_key848=== RUN TestIsValidUploadKey/unknown_type849=== PAUSE TestIsValidUploadKey/unknown_type850=== CONT TestIsValidUploadKey/narinfo851=== CONT TestIsValidUploadKey/realisation_plus_in_output852=== CONT TestIsValidUploadKey/realisation853=== CONT TestIsValidUploadKey/build_log_equals854=== CONT TestIsValidUploadKey/build_log_question_mark855=== CONT TestIsValidUploadKey/build_log_plus_in_name856=== CONT TestIsValidUploadKey/build_log_home-manager_file857=== CONT TestIsValidUploadKey/build_log858=== CONT TestIsValidUploadKey/listing859=== CONT TestIsValidUploadKey/nar_plain860=== CONT TestIsValidUploadKey/nar_xz861=== CONT TestIsValidUploadKey/nar_zst862=== CONT TestIsValidUploadKey/traversal863=== CONT TestIsValidUploadKey/empty_key864=== CONT TestIsValidUploadKey/absolute865=== CONT TestIsValidUploadKey/unknown_type866=== CONT TestIsValidUploadKey/narinfo_key,_nar_type867=== CONT TestIsValidUploadKey/traversal_nar868=== CONT TestIsValidUploadKey/nar_key,_narinfo_type869=== CONT TestIsValidUploadKey/listing_key,_narinfo_type870=== CONT TestIsValidUploadKey/nix-cache-info871=== CONT TestIsValidUploadKey/index.html872--- PASS: TestIsValidUploadKey (0.01s)873 --- PASS: TestIsValidUploadKey/narinfo (0.00s)874 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)875 --- PASS: TestIsValidUploadKey/realisation (0.00s)876 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)877 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)878 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)879 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)880 --- PASS: TestIsValidUploadKey/build_log (0.00s)881 --- PASS: TestIsValidUploadKey/listing (0.00s)882 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)883 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)884 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)885 --- PASS: TestIsValidUploadKey/traversal (0.00s)886 --- PASS: TestIsValidUploadKey/empty_key (0.00s)887 --- PASS: TestIsValidUploadKey/absolute (0.00s)888 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)889 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)890 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)891 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)892 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)893 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)894 --- PASS: TestIsValidUploadKey/index.html (0.00s)895--- PASS: TestGracefulShutdownDrainsInflight (0.09s)8962026/07/09 07:42:55 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_closures8972026-07-09 07:42:55.978 UTC [1291] ERROR: relation "goose_db_version" does not exist at character 368982026-07-09 07:42:55.978 UTC [1291] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8992026-07-09 07:42:55.978 UTC [1288] ERROR: relation "goose_db_version" does not exist at character 369002026-07-09 07:42:55.978 UTC [1288] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9012026-07-09 07:42:55.978 UTC [1305] ERROR: relation "goose_db_version" does not exist at character 369022026-07-09 07:42:55.978 UTC [1305] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC903=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure904=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure905=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart906=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart907=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts908=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts909=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure910=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts9112026/07/09 07:42:55 INFO Received uploads request method=POST path=/9122026/07/09 07:42:55 INFO Received request for more parts method=POST path=/913=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart9142026/07/09 07:42:55 INFO Received complete multipart upload request method=POST path=/9152026-07-09 07:42:56.011 UTC [1308] ERROR: relation "goose_db_version" does not exist at character 369162026-07-09 07:42:56.011 UTC [1308] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9172026-07-09 07:42:56.012 UTC [1286] ERROR: relation "goose_db_version" does not exist at character 369182026-07-09 07:42:56.012 UTC [1286] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9192026-07-09 07:42:56.013 UTC [1285] ERROR: relation "goose_db_version" does not exist at character 369202026-07-09 07:42:56.013 UTC [1285] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9212026-07-09 07:42:56.015 UTC [1266] ERROR: relation "goose_db_version" does not exist at character 369222026-07-09 07:42:56.015 UTC [1266] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9232026-07-09 07:42:56.016 UTC [1307] ERROR: relation "goose_db_version" does not exist at character 369242026-07-09 07:42:56.016 UTC [1307] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9252026-07-09 07:42:56.022 UTC [1335] ERROR: relation "goose_db_version" does not exist at character 369262026-07-09 07:42:56.022 UTC [1335] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9272026-07-09 07:42:56.026 UTC [1336] ERROR: relation "goose_db_version" does not exist at character 369282026-07-09 07:42:56.026 UTC [1336] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9292026/07/09 07:42:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.585948ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures9302026/07/09 07:42:56 OK 20241026095416_initial_model.sql (127.41ms)9312026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (8.19ms)9322026/07/09 07:42:56 OK 20241026095416_initial_model.sql (139.97ms)9332026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (6.48ms)9342026/07/09 07:42:56 OK 20241026095416_initial_model.sql (149.97ms)9352026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (7.16ms)9362026/07/09 07:42:56 OK 20251218171726_add_pins.sql (42.67ms)9372026/07/09 07:42:56 OK 20251218171726_add_pins.sql (28.41ms)9382026/07/09 07:42:56 OK 20251218171726_add_pins.sql (45.52ms)9392026-07-09 07:42:56.195 UTC [1341] ERROR: relation "goose_db_version" does not exist at character 369402026-07-09 07:42:56.195 UTC [1341] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9412026-07-09 07:42:56.197 UTC [1342] ERROR: relation "goose_db_version" does not exist at character 369422026-07-09 07:42:56.197 UTC [1342] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9432026/07/09 07:42:56 OK 20241026095416_initial_model.sql (146.61ms)9442026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (18.76ms)9452026/07/09 07:42:56 goose: successfully migrated database to version: 202606281200009462026/07/09 07:42:56 OK 20241026095416_initial_model.sql (133.53ms)9472026/07/09 07:42:56 OK 20241026095416_initial_model.sql (142.91ms)9482026/07/09 07:42:56 OK 20241026095416_initial_model.sql (148.34ms)9492026/07/09 07:42:56 OK 20241026095416_initial_model.sql (138ms)9502026/07/09 07:42:56 OK 20241026095416_initial_model.sql (133.98ms)9512026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (13.37ms)9522026/07/09 07:42:56 OK 20241026095416_initial_model.sql (131.89ms)9532026/07/09 07:42:56 goose: successfully migrated database to version: 202606281200009542026-07-09 07:42:56.203 UTC [1343] ERROR: relation "goose_db_version" does not exist at character 369552026-07-09 07:42:56.203 UTC [1343] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9562026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (8.85ms)9572026/07/09 07:42:56 goose: successfully migrated database to version: 202606281200009582026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (5.2ms)9592026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (3.65ms)9602026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (4.32ms)9612026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (3.91ms)9622026/07/09 07:42:56 OK 1_commit_pending_closure.sql (6.62ms)9632026/07/09 07:42:56 OK 1_commit_pending_closure.sql (5.1ms)9642026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (5.26ms)9652026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (5.39ms)9662026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (5.47ms)9672026/07/09 07:42:56 OK 1_commit_pending_closure.sql (6.81ms)9682026-07-09 07:42:56.212 UTC [1344] ERROR: relation "goose_db_version" does not exist at character 369692026-07-09 07:42:56.212 UTC [1344] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9702026/07/09 07:42:56 OK 2_object_stats_trigger.sql (4.96ms)9712026/07/09 07:42:56 goose: up to current file version: 29722026/07/09 07:42:56 OK 2_object_stats_trigger.sql (4.31ms)9732026/07/09 07:42:56 goose: up to current file version: 29742026-07-09 07:42:56.213 UTC [1345] ERROR: relation "goose_db_version" does not exist at character 369752026-07-09 07:42:56.213 UTC [1345] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9762026/07/09 07:42:56 OK 20251218171726_add_pins.sql (9.17ms)9772026-07-09 07:42:56.216 UTC [1346] ERROR: relation "goose_db_version" does not exist at character 369782026-07-09 07:42:56.216 UTC [1346] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9792026/07/09 07:42:56 OK 2_object_stats_trigger.sql (5.43ms)9802026/07/09 07:42:56 goose: up to current file version: 29812026/07/09 07:42:56 OK 20251218171726_add_pins.sql (11.5ms)982--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.41s)9832026/07/09 07:42:56 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"984--- PASS: TestService_AuthMiddleware (0.41s)9852026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures9862026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures9872026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures9882026/07/09 07:42:56 OK 20251218171726_add_pins.sql (21.83ms)9892026-07-09 07:42:56.228 UTC [1347] ERROR: relation "goose_db_version" does not exist at character 369902026-07-09 07:42:56.228 UTC [1347] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9912026/07/09 07:42:56 OK 20251218171726_add_pins.sql (23.05ms)9922026/07/09 07:42:56 OK 20251218171726_add_pins.sql (21.75ms)9932026/07/09 07:42:56 OK 20251218171726_add_pins.sql (21.62ms)9942026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (17.2ms)9952026/07/09 07:42:56 goose: successfully migrated database to version: 202606281200009962026-07-09 07:42:56.233 UTC [1348] ERROR: relation "goose_db_version" does not exist at character 369972026-07-09 07:42:56.233 UTC [1348] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9982026/07/09 07:42:56 OK 20251218171726_add_pins.sql (26.68ms)9992026/07/09 07:42:56 OK 1_commit_pending_closure.sql (4.3ms)10002026/07/09 07:42:56 OK 2_object_stats_trigger.sql (3.29ms)10012026/07/09 07:42:56 goose: up to current file version: 210022026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (24.96ms)10032026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000010042026/07/09 07:42:56 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1005--- PASS: TestService_ReadAuthMiddleware (0.44s)10062026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (16.58ms)10072026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000010082026/07/09 07:42:56 OK 1_commit_pending_closure.sql (5.91ms)10092026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (18.41ms)10102026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000010112026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (18.32ms)10122026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000010132026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (23.88ms)10142026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000010152026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (15.39ms)10162026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000010172026/07/09 07:42:56 OK 1_commit_pending_closure.sql (14.56ms)10182026/07/09 07:42:56 OK 1_commit_pending_closure.sql (16.19ms)10192026/07/09 07:42:56 OK 2_object_stats_trigger.sql (14.65ms)10202026/07/09 07:42:56 goose: up to current file version: 210212026/07/09 07:42:56 OK 1_commit_pending_closure.sql (14.53ms)10222026/07/09 07:42:56 OK 1_commit_pending_closure.sql (15.4ms)10232026/07/09 07:42:56 OK 1_commit_pending_closure.sql (15.32ms)10242026/07/09 07:42:56 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=425.218277ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures10252026/07/09 07:42:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10262026/07/09 07:42:56 OK 2_object_stats_trigger.sql (6.52ms)10272026/07/09 07:42:56 goose: up to current file version: 210282026/07/09 07:42:56 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1029--- PASS: TestCompleteMultipartUnregistered (0.46s)10302026/07/09 07:42:56 OK 2_object_stats_trigger.sql (5.11ms)10312026/07/09 07:42:56 OK 2_object_stats_trigger.sql (5.19ms)10322026/07/09 07:42:56 goose: up to current file version: 210332026/07/09 07:42:56 OK 2_object_stats_trigger.sql (7.89ms)10342026/07/09 07:42:56 goose: up to current file version: 210352026/07/09 07:42:56 goose: up to current file version: 210362026/07/09 07:42:56 OK 2_object_stats_trigger.sql (10.08ms)10372026/07/09 07:42:56 goose: up to current file version: 210382026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures10392026/07/09 07:42:56 INFO Received cleanup request method=DELETE path=/api/pending_closures10402026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures1041--- PASS: TestReadProxyInvalidPath (0.46s)10422026/07/09 07:42:56 INFO Aborted multipart uploads count=010432026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures10442026/07/09 07:42:56 OK 20241026095416_initial_model.sql (48.44ms)10452026/07/09 07:42:56 OK 20241026095416_initial_model.sql (75.8ms)10462026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (3.34ms)10472026/07/09 07:42:56 OK 20241026095416_initial_model.sql (78.97ms)10482026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (6.35ms)10492026-07-09 07:42:56.294 UTC [1354] ERROR: relation "goose_db_version" does not exist at character 3610502026-07-09 07:42:56.294 UTC [1354] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10512026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (7.05ms)10522026-07-09 07:42:56.296 UTC [1355] ERROR: relation "goose_db_version" does not exist at character 3610532026-07-09 07:42:56.296 UTC [1355] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10542026-07-09 07:42:56.297 UTC [1356] ERROR: relation "goose_db_version" does not exist at character 3610552026-07-09 07:42:56.297 UTC [1356] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10562026-07-09 07:42:56.298 UTC [1357] ERROR: relation "goose_db_version" does not exist at character 3610572026-07-09 07:42:56.298 UTC [1357] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10582026-07-09 07:42:56.298 UTC [1359] ERROR: relation "goose_db_version" does not exist at character 3610592026-07-09 07:42:56.298 UTC [1359] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10602026-07-09 07:42:56.300 UTC [1360] ERROR: relation "goose_db_version" does not exist at character 3610612026-07-09 07:42:56.300 UTC [1360] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10622026-07-09 07:42:56.301 UTC [1361] ERROR: relation "goose_db_version" does not exist at character 3610632026-07-09 07:42:56.301 UTC [1361] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10642026/07/09 07:42:56 OK 20251218171726_add_pins.sql (20.52ms)10652026/07/09 07:42:56 OK 20241026095416_initial_model.sql (53.03ms)10662026/07/09 07:42:56 OK 20241026095416_initial_model.sql (69.54ms)10672026/07/09 07:42:56 OK 20241026095416_initial_model.sql (68.7ms)1068--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.50s)10692026/07/09 07:42:56 OK 20241026095416_initial_model.sql (78.99ms)10702026/07/09 07:42:56 INFO Received cleanup request method=DELETE path=/api/pending_closures1071--- PASS: TestCacheStatsHandler (0.49s)10722026/07/09 07:42:56 INFO Aborted multipart uploads count=110732026/07/09 07:42:56 OK 20251218171726_add_pins.sql (17.51ms)10742026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (7.57ms)10752026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (7.66ms)10762026/07/09 07:42:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10772026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (10.27ms)10782026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (10.73ms)10792026-07-09 07:42:56.318 UTC [1307] ERROR: Closure does not exist: id=110802026-07-09 07:42:56.318 UTC [1307] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10812026-07-09 07:42:56.318 UTC [1307] STATEMENT: -- name: CommitPendingClosure :exec1082 SELECT commit_pending_closure($1::bigint)1083 1084--- PASS: TestService_cleanupPendingClosuresHandler (0.51s)10852026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (10.07ms)10862026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000010872026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (13.34ms)10882026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000010892026/07/09 07:42:56 OK 20251218171726_add_pins.sql (25.02ms)10902026/07/09 07:42:56 OK 20241026095416_initial_model.sql (68.93ms)10912026/07/09 07:42:56 OK 20251218171726_add_pins.sql (9.46ms)10922026/07/09 07:42:56 OK 20251218171726_add_pins.sql (9.57ms)10932026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (3.88ms)10942026/07/09 07:42:56 OK 20251218171726_add_pins.sql (8.35ms)10952026/07/09 07:42:56 OK 1_commit_pending_closure.sql (5.65ms)10962026/07/09 07:42:56 OK 1_commit_pending_closure.sql (5.67ms)10972026/07/09 07:42:56 OK 20251218171726_add_pins.sql (10.13ms)10982026/07/09 07:42:56 OK 2_object_stats_trigger.sql (4.21ms)10992026/07/09 07:42:56 goose: up to current file version: 211002026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (9.83ms)11012026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000011022026/07/09 07:42:56 OK 2_object_stats_trigger.sql (4.13ms)11032026/07/09 07:42:56 goose: up to current file version: 211042026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (6.9ms)11052026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000011062026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (8.04ms)11072026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000011082026/07/09 07:42:56 OK 1_commit_pending_closure.sql (2.92ms)11092026/07/09 07:42:56 OK 20251218171726_add_pins.sql (8.91ms)11102026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (7.6ms)11112026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000011122026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (5.61ms)11132026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000011142026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures11152026/07/09 07:42:56 OK 2_object_stats_trigger.sql (2.76ms)11162026/07/09 07:42:56 goose: up to current file version: 211172026/07/09 07:42:56 OK 1_commit_pending_closure.sql (4.85ms)11182026/07/09 07:42:56 OK 1_commit_pending_closure.sql (4.63ms)1119{"timestamp":"2026-07-09T07:42:56.338233187Z","level":"ERROR","fields":{"message":"system path read failed","path_kind":"data_usage","operation":"read_primary","reason":"config_not_found","object":"buckets/.usage.json","error":"Config not found"},"target":"rustfs_ecstore::data_usage","filename":"crates/ecstore/src/data_usage.rs","line_number":126,"threadName":"rustfs-worker","threadId":"ThreadId(766)"}11202026/07/09 07:42:56 OK 1_commit_pending_closure.sql (4.61ms)11212026/07/09 07:42:56 OK 20241026095416_initial_model.sql (13.21ms)11222026/07/09 07:42:56 OK 20241026095416_initial_model.sql (15.02ms)11232026/07/09 07:42:56 OK 20241026095416_initial_model.sql (13.46ms)11242026-07-09 07:42:56.339 UTC [1362] ERROR: relation "goose_db_version" does not exist at character 3611252026-07-09 07:42:56.339 UTC [1362] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11262026/07/09 07:42:56 OK 1_commit_pending_closure.sql (4.87ms)11272026/07/09 07:42:56 OK 2_object_stats_trigger.sql (2.6ms)11282026/07/09 07:42:56 goose: up to current file version: 211292026/07/09 07:42:56 OK 2_object_stats_trigger.sql (3.71ms)11302026/07/09 07:42:56 goose: up to current file version: 211312026/07/09 07:42:56 OK 20241026095416_initial_model.sql (18.67ms)11322026/07/09 07:42:56 OK 20241026095416_initial_model.sql (18.77ms)11332026/07/09 07:42:56 OK 20241026095416_initial_model.sql (18.29ms)1134--- PASS: TestService_Rustfstest (0.53s)11352026/07/09 07:42:56 OK 2_object_stats_trigger.sql (2.48ms)11362026/07/09 07:42:56 goose: up to current file version: 211372026-07-09 07:42:56.342 UTC [1363] ERROR: relation "goose_db_version" does not exist at character 3611382026-07-09 07:42:56.342 UTC [1363] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11392026/07/09 07:42:56 OK 20241026095416_initial_model.sql (17.14ms)11402026/07/09 07:42:56 OK 2_object_stats_trigger.sql (3.25ms)11412026/07/09 07:42:56 goose: up to current file version: 211422026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (3.59ms)11432026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (3.54ms)11442026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (3.52ms)11452026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (8.82ms)11462026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000011472026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (3.41ms)11482026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (3.4ms)11492026-07-09 07:42:56.344 UTC [1364] ERROR: relation "goose_db_version" does not exist at character 3611502026-07-09 07:42:56.344 UTC [1364] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11512026-07-09 07:42:56.344 UTC [1365] ERROR: relation "goose_db_version" does not exist at character 3611522026-07-09 07:42:56.344 UTC [1365] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11532026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (2.99ms)11542026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (4.24ms)11552026-07-09 07:42:56.345 UTC [1368] ERROR: relation "goose_db_version" does not exist at character 3611562026-07-09 07:42:56.345 UTC [1368] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11572026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures11582026-07-09 07:42:56.346 UTC [1367] ERROR: relation "goose_db_version" does not exist at character 3611592026-07-09 07:42:56.346 UTC [1367] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11602026-07-09 07:42:56.346 UTC [1369] ERROR: relation "goose_db_version" does not exist at character 3611612026-07-09 07:42:56.346 UTC [1369] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11622026/07/09 07:42:56 OK 20251218171726_add_pins.sql (3.32ms)11632026/07/09 07:42:56 OK 1_commit_pending_closure.sql (4.38ms)11642026/07/09 07:42:56 OK 20251218171726_add_pins.sql (4.55ms)11652026/07/09 07:42:56 INFO Created nix-cache-info in bucket bucket=bucket1611662026/07/09 07:42:56 OK 20251218171726_add_pins.sql (4.61ms)11672026-07-09 07:42:56.348 UTC [1370] ERROR: relation "goose_db_version" does not exist at character 3611682026-07-09 07:42:56.348 UTC [1370] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11692026-07-09 07:42:56.348 UTC [1366] ERROR: relation "goose_db_version" does not exist at character 3611702026-07-09 07:42:56.348 UTC [1366] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11712026/07/09 07:42:56 OK 20251218171726_add_pins.sql (4.35ms)11722026/07/09 07:42:56 OK 20251218171726_add_pins.sql (4.28ms)1173--- PASS: TestReadProxyRangeRequest (0.54s)11742026/07/09 07:42:56 OK 20251218171726_add_pins.sql (4.13ms)11752026/07/09 07:42:56 OK 20251218171726_add_pins.sql (4.43ms)11762026/07/09 07:42:56 OK 2_object_stats_trigger.sql (1.98ms)11772026/07/09 07:42:56 goose: up to current file version: 21178--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.54s)11792026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (4.21ms)11802026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000011812026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)11822026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000011832026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (4.77ms)11842026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000011852026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (7.17ms)11862026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000011872026-07-09 07:42:56.356 UTC [1373] ERROR: relation "goose_db_version" does not exist at character 3611882026-07-09 07:42:56.356 UTC [1373] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11892026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (6.8ms)11902026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000011912026-07-09 07:42:56.356 UTC [1375] ERROR: relation "goose_db_version" does not exist at character 3611922026-07-09 07:42:56.356 UTC [1375] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11932026-07-09 07:42:56.357 UTC [1374] ERROR: relation "goose_db_version" does not exist at character 3611942026-07-09 07:42:56.357 UTC [1374] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11952026-07-09 07:42:56.357 UTC [1377] ERROR: relation "goose_db_version" does not exist at character 3611962026-07-09 07:42:56.357 UTC [1377] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11972026/07/09 07:42:56 OK 1_commit_pending_closure.sql (6.09ms)11982026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (7.99ms)11992026/07/09 07:42:56 OK 1_commit_pending_closure.sql (6.9ms)12002026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000012012026/07/09 07:42:56 OK 1_commit_pending_closure.sql (4.06ms)12022026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (11.79ms)12032026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000012042026-07-09 07:42:56.361 UTC [1379] ERROR: relation "goose_db_version" does not exist at character 3612052026-07-09 07:42:56.361 UTC [1379] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12062026-07-09 07:42:56.361 UTC [1380] ERROR: relation "goose_db_version" does not exist at character 3612072026-07-09 07:42:56.361 UTC [1380] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12082026-07-09 07:42:56.361 UTC [1378] ERROR: relation "goose_db_version" does not exist at character 3612092026-07-09 07:42:56.361 UTC [1378] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1210--- PASS: TestReadProxy404 (0.55s)12112026/07/09 07:42:56 OK 1_commit_pending_closure.sql (5.55ms)12122026/07/09 07:42:56 OK 1_commit_pending_closure.sql (6.08ms)12132026/07/09 07:42:56 OK 2_object_stats_trigger.sql (5ms)12142026/07/09 07:42:56 goose: up to current file version: 212152026/07/09 07:42:56 OK 2_object_stats_trigger.sql (2.56ms)12162026/07/09 07:42:56 goose: up to current file version: 212172026/07/09 07:42:56 OK 2_object_stats_trigger.sql (4.46ms)12182026/07/09 07:42:56 goose: up to current file version: 212192026/07/09 07:42:56 OK 20241026095416_initial_model.sql (12.66ms)12202026/07/09 07:42:56 OK 20241026095416_initial_model.sql (13.17ms)12212026/07/09 07:42:56 OK 1_commit_pending_closure.sql (2.57ms)12222026-07-09 07:42:56.364 UTC [1381] ERROR: relation "goose_db_version" does not exist at character 3612232026-07-09 07:42:56.364 UTC [1381] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12242026/07/09 07:42:56 OK 20241026095416_initial_model.sql (8.08ms)12252026/07/09 07:42:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12262026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures12272026/07/09 07:42:56 OK 2_object_stats_trigger.sql (2.49ms)12282026/07/09 07:42:56 OK 2_object_stats_trigger.sql (1.62ms)12292026/07/09 07:42:56 goose: up to current file version: 212302026-07-09 07:42:56.365 UTC [1382] ERROR: relation "goose_db_version" does not exist at character 3612312026-07-09 07:42:56.365 UTC [1382] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12322026/07/09 07:42:56 goose: up to current file version: 212332026/07/09 07:42:56 OK 1_commit_pending_closure.sql (3.57ms)12342026/07/09 07:42:56 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12352026/07/09 07:42:56 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1236--- PASS: TestService_NativeMTLS (0.55s)1237{"timestamp":"2026-07-09T07:42:56.367413764Z","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(762)"}1238{"timestamp":"2026-07-09T07:42:56.367458714Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket12, 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(762)"}12392026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures12402026/07/09 07:42:56 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=M2YyYzA3OTEtM2I1NC00MTQ4LWEwNTQtYjNmNDEwMzVlYmQ3LmFkOTgxOTgzLTU0ODktNDYyMy1iNTQ0LWZkOGE5Njg3NGY3M3gxNzgzNTgyOTc2MzQ0ODMwMzg112412026/07/09 07:42:56 INFO Created nix-cache-info in bucket bucket=bucket2112422026/07/09 07:42:56 OK 2_object_stats_trigger.sql (6.72ms)12432026/07/09 07:42:56 goose: up to current file version: 212442026/07/09 07:42:56 OK 2_object_stats_trigger.sql (6.81ms)12452026/07/09 07:42:56 goose: up to current file version: 212462026/07/09 07:42:56 OK 20241026095416_initial_model.sql (13.37ms)12472026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (8.41ms)12482026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (7.98ms)12492026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (8.28ms)12502026/07/09 07:42:56 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2YyYzA3OTEtM2I1NC00MTQ4LWEwNTQtYjNmNDEwMzVlYmQ3LmFkOTgxOTgzLTU0ODktNDYyMy1iNTQ0LWZkOGE5Njg3NGY3M3gxNzgzNTgyOTc2MzQ0ODMwMzg1 parts=11251--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.56s)12522026/07/09 07:42:56 OK 20241026095416_initial_model.sql (10.61ms)12532026/07/09 07:42:56 OK 20241026095416_initial_model.sql (10.91ms)12542026/07/09 07:42:56 OK 20241026095416_initial_model.sql (14.38ms)12552026/07/09 07:42:56 OK 20241026095416_initial_model.sql (11.71ms)12562026/07/09 07:42:56 OK 20241026095416_initial_model.sql (11.2ms)12572026/07/09 07:42:56 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"12582026/07/09 07:42:56 WARN mTLS auth: bound subjects configured but subject DN unavailable12592026/07/09 07:42:56 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1260--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.56s)12612026/07/09 07:42:56 OK 20241026095416_initial_model.sql (9.39ms)12622026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)12632026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)12642026/07/09 07:42:56 OK 20241026095416_initial_model.sql (9.91ms)12652026/07/09 07:42:56 INFO Created nix-cache-info in bucket bucket=bucket2512662026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (2.75ms)12672026/07/09 07:42:56 OK 20241026095416_initial_model.sql (11.07ms)12682026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)12692026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (2.46ms)12702026/07/09 07:42:56 OK 20241026095416_initial_model.sql (10.89ms)12712026/07/09 07:42:56 OK 20251218171726_add_pins.sql (4.48ms)12722026/07/09 07:42:56 OK 20251218171726_add_pins.sql (4.42ms)12732026/07/09 07:42:56 OK 20251218171726_add_pins.sql (4.46ms)12742026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (2.01ms)12752026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)12762026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)12772026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)12782026/07/09 07:42:56 OK 20251218171726_add_pins.sql (4.39ms)12792026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (3ms)12802026/07/09 07:42:56 OK 20251218171726_add_pins.sql (4.43ms)12812026/07/09 07:42:56 OK 20251218171726_add_pins.sql (3.85ms)12822026/07/09 07:42:56 OK 20251218171726_add_pins.sql (3.95ms)12832026/07/09 07:42:56 OK 20251218171726_add_pins.sql (4.57ms)12842026/07/09 07:42:56 OK 20251218171726_add_pins.sql (5.15ms)12852026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (5.28ms)12862026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000012872026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (5.29ms)12882026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000012892026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (6.02ms)12902026/07/09 07:42:56 OK 20251218171726_add_pins.sql (3.42ms)12912026/07/09 07:42:56 OK 20251218171726_add_pins.sql (4.48ms)12922026/07/09 07:42:56 OK 20241026095416_initial_model.sql (9.68ms)12932026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000012942026/07/09 07:42:56 OK 20251218171726_add_pins.sql (4.41ms)12952026/07/09 07:42:56 OK 20251218171726_add_pins.sql (5.21ms)12962026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (3.22ms)12972026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000012982026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (4.12ms)12992026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000013002026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)13012026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000013022026/07/09 07:42:56 OK 20241026095416_initial_model.sql (9.61ms)13032026/07/09 07:42:56 OK 20241026095416_initial_model.sql (10.03ms)13042026/07/09 07:42:56 OK 20241026095416_initial_model.sql (10.86ms)13052026/07/09 07:42:56 OK 20241026095416_initial_model.sql (11.17ms)13062026/07/09 07:42:56 OK 1_commit_pending_closure.sql (2.76ms)13072026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (4.59ms)13082026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000013092026/07/09 07:42:56 OK 1_commit_pending_closure.sql (2.73ms)13102026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)13112026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000013122026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (3.63ms)13132026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000013142026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)13152026/07/09 07:42:56 OK 1_commit_pending_closure.sql (2.97ms)13162026/07/09 07:42:56 OK 1_commit_pending_closure.sql (2.45ms)13172026/07/09 07:42:56 OK 1_commit_pending_closure.sql (2.43ms)13182026/07/09 07:42:56 OK 2_object_stats_trigger.sql (1.14ms)13192026/07/09 07:42:56 goose: up to current file version: 213202026/07/09 07:42:56 OK 2_object_stats_trigger.sql (1.21ms)13212026/07/09 07:42:56 goose: up to current file version: 213222026/07/09 07:42:56 OK 1_commit_pending_closure.sql (2.57ms)13232026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)13242026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)13252026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)13262026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (3.83ms)13272026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (3.6ms)13282026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000013292026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000013302026/07/09 07:42:56 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)13312026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (3.49ms)13322026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000013332026/07/09 07:42:56 OK 1_commit_pending_closure.sql (2.02ms)1334--- PASS: TestMetricsInventory (0.57s)13352026/07/09 07:42:56 OK 1_commit_pending_closure.sql (1.97ms)13362026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (4.08ms)13372026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000013382026/07/09 07:42:56 OK 2_object_stats_trigger.sql (1.01ms)13392026/07/09 07:42:56 goose: up to current file version: 213402026/07/09 07:42:56 OK 2_object_stats_trigger.sql (1.27ms)13412026/07/09 07:42:56 goose: up to current file version: 213422026/07/09 07:42:56 OK 2_object_stats_trigger.sql (1.13ms)13432026/07/09 07:42:56 goose: up to current file version: 213442026/07/09 07:42:56 OK 2_object_stats_trigger.sql (1.32ms)13452026/07/09 07:42:56 goose: up to current file version: 213462026/07/09 07:42:56 OK 2_object_stats_trigger.sql (817.56µs)13472026/07/09 07:42:56 goose: up to current file version: 213482026/07/09 07:42:56 OK 2_object_stats_trigger.sql (1.12ms)13492026/07/09 07:42:56 goose: up to current file version: 213502026/07/09 07:42:56 OK 20251218171726_add_pins.sql (2.73ms)13512026/07/09 07:42:56 OK 1_commit_pending_closure.sql (2.73ms)13522026/07/09 07:42:56 OK 1_commit_pending_closure.sql (1.97ms)13532026/07/09 07:42:56 OK 1_commit_pending_closure.sql (2.06ms)13542026/07/09 07:42:56 OK 1_commit_pending_closure.sql (2.04ms)1355--- PASS: TestService_healthCheckHandler (0.58s)13562026/07/09 07:42:56 OK 20251218171726_add_pins.sql (2.63ms)13572026/07/09 07:42:56 OK 1_commit_pending_closure.sql (2.03ms)13582026/07/09 07:42:56 OK 20251218171726_add_pins.sql (2.5ms)13592026/07/09 07:42:56 OK 20251218171726_add_pins.sql (2.9ms)13602026/07/09 07:42:56 OK 20251218171726_add_pins.sql (2.82ms)13612026/07/09 07:42:56 OK 2_object_stats_trigger.sql (920.07µs)13622026/07/09 07:42:56 goose: up to current file version: 213632026/07/09 07:42:56 OK 2_object_stats_trigger.sql (1.02ms)13642026/07/09 07:42:56 goose: up to current file version: 213652026/07/09 07:42:56 OK 2_object_stats_trigger.sql (1.19ms)13662026/07/09 07:42:56 goose: up to current file version: 213672026/07/09 07:42:56 OK 2_object_stats_trigger.sql (927.39µs)13682026/07/09 07:42:56 goose: up to current file version: 213692026/07/09 07:42:56 OK 2_object_stats_trigger.sql (1.35ms)13702026/07/09 07:42:56 goose: up to current file version: 213712026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures1372--- PASS: TestResurrectedObjectNotDeleted (0.58s)13732026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (2.74ms)13742026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000013752026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (2.83ms)13762026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000013772026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)13782026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000013792026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (3.12ms)13802026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000013812026/07/09 07:42:56 OK 20260628120000_add_object_size_and_stats.sql (3.33ms)13822026/07/09 07:42:56 goose: successfully migrated database to version: 2026062812000013832026/07/09 07:42:56 INFO Created nix-cache-info in bucket bucket=bucket2913842026/07/09 07:42:56 OK 1_commit_pending_closure.sql (1.79ms)1385--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.58s)13862026/07/09 07:42:56 OK 1_commit_pending_closure.sql (1.68ms)13872026/07/09 07:42:56 OK 2_object_stats_trigger.sql (903.01µs)13882026/07/09 07:42:56 goose: up to current file version: 213892026/07/09 07:42:56 OK 1_commit_pending_closure.sql (1.48ms)13902026/07/09 07:42:56 OK 1_commit_pending_closure.sql (1.65ms)13912026/07/09 07:42:56 OK 1_commit_pending_closure.sql (1.61ms)13922026/07/09 07:42:56 INFO Created nix-cache-info in bucket bucket=bucket3613932026/07/09 07:42:56 OK 2_object_stats_trigger.sql (728.61µs)13942026/07/09 07:42:56 goose: up to current file version: 213952026/07/09 07:42:56 OK 2_object_stats_trigger.sql (711.24µs)13962026/07/09 07:42:56 goose: up to current file version: 213972026/07/09 07:42:56 OK 2_object_stats_trigger.sql (900.64µs)13982026/07/09 07:42:56 goose: up to current file version: 213992026/07/09 07:42:56 INFO Created nix-cache-info in bucket bucket=bucket3914002026/07/09 07:42:56 OK 2_object_stats_trigger.sql (1.01ms)14012026/07/09 07:42:56 goose: up to current file version: 21402--- PASS: TestReadProxyNarStreaming (0.58s)14032026/07/09 07:42:56 INFO Aborted multipart uploads count=01404=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1405=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1406=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1407=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1408=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1409=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1410=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1411=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1412=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1413=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1414=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1415=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected14162026/07/09 07:42:56 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]1417--- PASS: TestReadProxyDisabled (0.59s)14182026/07/09 07:42:56 WARN Force mode enabled - objects will be deleted immediately without grace period14192026/07/09 07:42:56 INFO OIDC auth successful provider=test14202026/07/09 07:42:56 WARN Authentication failed token_preview=eyJhbGciOi...AsGIt-w8Xg 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]14212026/07/09 07:42:56 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=014222026/07/09 07:42:56 INFO Vacuumed table table=pending_closures1423--- PASS: TestService_AuthMiddleware_OIDC (0.59s)1424 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1425 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1426 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1427 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)14282026/07/09 07:42:56 INFO Vacuumed table table=pending_objects14292026/07/09 07:42:56 INFO Vacuumed table table=multipart_uploads14302026/07/09 07:42:56 INFO Vacuumed table table=closures14312026/07/09 07:42:56 INFO Vacuumed table table=objects1432--- PASS: TestObjectStatsTrigger (0.59s)1433=== NAME TestClientMultipleUploads1434 client_integration_test.go:338: Created store path 0: /build/TestClientMultipleUploads3592308589/001/store/0g88bw24csa7lvy0b5vrlm38ljqicrzl-test-file-0.txt1435--- PASS: TestGCMetrics (0.60s)1436=== NAME TestNARDeduplicationMetadataUploadBug1437 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1019669248/001/store/py0a8rzflg24n09323qjw06cm38wzmk3-file1.txt1438=== NAME TestClientIntegration1439 client_integration_test.go:276: Created store path: /build/TestClientIntegration87108969/002/store/w8aml4hdqln5m3g6fs71bbkfzniyc2ld-test-file.txt1440=== NAME TestClientWithDependencies1441 client_integration_test.go:593: Built derivation: /build/TestClientWithDependencies840556054/001/store/rsh4bg3aklzn4h8cvi4r1sadiqf5vj23-test-script14422026/07/09 07:42:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1443=== NAME TestClientMultipleUploads1444 client_integration_test.go:338: Created store path 1: /build/TestClientMultipleUploads3592308589/001/store/2jd3ss3w16zfmb468w7x34lxk3gwjpcj-test-file-1.txt1445=== NAME TestClientCADerivations1446 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3599309625/001/store/0bzyw4nsn4bvmrljy4shcqkyzlin6h7s-ca-test1447=== NAME TestClientWithDependencies1448 client_integration_test.go:595: Found 1 dependencies (including self)1449=== NAME TestPinProtectsFromGC1450 client_integration_test.go:646: Pinned store path: /build/TestPinProtectsFromGC3168964912/001/store/mdp43vx7q01s60f1rdq1hcc1gakdz2m0-pinned-file.txt1451 client_integration_test.go:647: Unpinned store path: /build/TestPinProtectsFromGC3168964912/001/store/fk0jccnbibci5gh7hi3mh98rmrjq0hv5-unpinned-file.txt1452=== NAME TestClientMultipleUploads1453 client_integration_test.go:338: Created store path 2: /build/TestClientMultipleUploads3592308589/001/store/wyhqsxsj1hcy652xixhmypq85kdk8gly-test-file-2.txt1454=== NAME TestClientCADerivations1455 client_ca_test.go:139: Found 1 dependencies (including self)14562026/07/09 07:42:56 INFO Received cleanup request method=DELETE path=/api/pending_closures14572026/07/09 07:42:56 INFO Aborted multipart uploads count=11458--- PASS: TestMultipartCleanup (0.69s)14592026/07/09 07:42:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14602026/07/09 07:42:56 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=M2YyYzA3OTEtM2I1NC00MTQ4LWEwNTQtYjNmNDEwMzVlYmQ3LmEyN2RlOTA5LTNhYzktNDE2Ni1iNmNhLTYwMTA1ZjkzOTgyY3gxNzgzNTgyOTc2MjM3MDM1MDc4 parts=1014612026/07/09 07:42:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1462--- PASS: TestReadProxyConditionalGet (0.71s)14632026/07/09 07:42:56 INFO Completed upload id=114642026/07/09 07:42:56 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014652026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures14662026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures14672026/07/09 07:42:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures1468--- PASS: TestReadProxyHead (0.71s)14692026/07/09 07:42:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14702026/07/09 07:42:56 INFO Uploading py0a8rzflg24n09323qjw06cm38wzmk3-file1.txt (160B)14712026/07/09 07:42:56 INFO Aborted multipart uploads count=014722026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures14732026/07/09 07:42:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14742026/07/09 07:42:56 INFO Signed narinfos id=1 count=114752026/07/09 07:42:56 INFO Uploading 1 narinfos14762026/07/09 07:42:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14772026/07/09 07:42:56 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"14782026/07/09 07:42:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14792026/07/09 07:42:56 INFO Uploading w8aml4hdqln5m3g6fs71bbkfzniyc2ld-test-file.txt (152B)14802026/07/09 07:42:56 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=014812026/07/09 07:42:56 INFO Vacuumed table table=pending_closures14822026/07/09 07:42:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14832026/07/09 07:42:56 INFO Completed upload id=114842026/07/09 07:42:56 INFO Signed narinfos id=1 count=114852026/07/09 07:42:56 INFO Upload complete. (79ms)14862026/07/09 07:42:56 INFO Uploading 1 narinfos14872026/07/09 07:42:56 INFO Vacuumed table table=pending_objects1488=== NAME TestNARDeduplicationMetadataUploadBug1489 metadata_upload_test.go:54: Retrieved narinfo from S3:1490 StorePath: /build/TestNARDeduplicationMetadataUploadBug1019669248/001/store/py0a8rzflg24n09323qjw06cm38wzmk3-file1.txt1491 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1492 Compression: zstd1493 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1494 NarSize: 1601495 References: 1496 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf14972026/07/09 07:42:56 INFO Vacuumed table table=multipart_uploads14982026/07/09 07:42:56 INFO Vacuumed table table=closures14992026/07/09 07:42:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1500 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1501 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1502 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}15032026/07/09 07:42:56 INFO Vacuumed table table=objects15042026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures15052026/07/09 07:42:56 INFO Completed upload id=115062026/07/09 07:42:56 INFO Upload complete. (79ms)1507=== NAME TestClientIntegration1508 client_integration_test.go:292: Retrieved narinfo from S3:1509 StorePath: /build/TestClientIntegration87108969/002/store/w8aml4hdqln5m3g6fs71bbkfzniyc2ld-test-file.txt1510 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1511 Compression: zstd1512 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11513 NarSize: 1521514 References: 1515 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk115162026/07/09 07:42:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1517 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1518 client_integration_test.go:293: Decompressed .ls content (64 bytes):1519 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1520 client_integration_test.go:296: Testing garbage collection...15212026/07/09 07:42:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15222026/07/09 07:42:56 INFO Uploading rsh4bg3aklzn4h8cvi4r1sadiqf5vj23-test-script (136B)15232026/07/09 07:42:56 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=M2YyYzA3OTEtM2I1NC00MTQ4LWEwNTQtYjNmNDEwMzVlYmQ3LjFkNjc1NzAyLTIzMDItNDQwMC1iMTZiLTZhZjdlYjI5NTQzNXgxNzgzNTgyOTc2Mjg2NTc2MzUx parts=1015242026/07/09 07:42:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15252026/07/09 07:42:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15262026/07/09 07:42:56 INFO Signed narinfos id=1 count=115272026/07/09 07:42:56 INFO Uploading 1 narinfos15282026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures15292026/07/09 07:42:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15302026/07/09 07:42:56 INFO Completed upload id=115312026/07/09 07:42:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15322026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures15332026/07/09 07:42:56 INFO Uploading mdp43vx7q01s60f1rdq1hcc1gakdz2m0-pinned-file.txt (128B)15342026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures15352026/07/09 07:42:56 INFO Completed upload id=115362026/07/09 07:42:56 INFO Upload complete. (59ms)15372026/07/09 07:42:56 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo15382026/07/09 07:42:56 WARN Found objects in DB but missing from S3, will re-upload count=115392026/07/09 07:42:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1540--- PASS: TestService_verifyS3Integrity (0.76s)15412026/07/09 07:42:56 INFO Signed narinfos id=1 count=115422026/07/09 07:42:56 INFO Uploading 1 narinfos1543=== NAME TestClientWithDependencies1544 client_integration_test.go:597: Skipping nix copy test - isolated store (/build/TestClientWithDependencies840556054/001/store) requires matching store prefix15452026/07/09 07:42:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1546--- PASS: TestClientWithDependencies (0.75s)1547--- PASS: TestReadProxyNarinfo (0.75s)15482026/07/09 07:42:56 INFO Completed upload id=115492026/07/09 07:42:56 INFO Upload complete. (70ms)15502026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures15512026/07/09 07:42:56 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001552--- PASS: TestService_createPendingClosureHandler (0.77s)15532026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures1554=== NAME TestNARDeduplicationMetadataUploadBug1555 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1019669248/001/store/fy9x38z6lncxd83swsjawbi46bcp91jr-file2.txt15562026/07/09 07:42:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15572026/07/09 07:42:56 INFO Uploading 0bzyw4nsn4bvmrljy4shcqkyzlin6h7s-ca-test (144B)15582026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures15592026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures15602026/07/09 07:42:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures15612026/07/09 07:42:56 INFO Garbage collection started15622026/07/09 07:42:56 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15632026/07/09 07:42:56 INFO Uploading wyhqsxsj1hcy652xixhmypq85kdk8gly-test-file-2.txt (160B)15642026/07/09 07:42:56 INFO Uploading 0g88bw24csa7lvy0b5vrlm38ljqicrzl-test-file-0.txt (160B)15652026/07/09 07:42:56 INFO Uploading 2jd3ss3w16zfmb468w7x34lxk3gwjpcj-test-file-1.txt (160B)15662026/07/09 07:42:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15672026/07/09 07:42:56 INFO Signed narinfos id=1 count=115682026/07/09 07:42:56 INFO Uploading 1 narinfos15692026/07/09 07:42:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15702026/07/09 07:42:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15712026/07/09 07:42:56 INFO Signed narinfos id=2 count=115722026/07/09 07:42:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15732026/07/09 07:42:56 INFO Aborted multipart uploads count=015742026/07/09 07:42:56 INFO Signed narinfos id=3 count=115752026/07/09 07:42:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15762026/07/09 07:42:56 INFO Signed narinfos id=1 count=115772026/07/09 07:42:56 INFO Uploading 3 narinfos15782026/07/09 07:42:56 INFO Completed upload id=115792026/07/09 07:42:56 INFO Upload complete. (77ms)15802026/07/09 07:42:56 WARN Force mode enabled - objects will be deleted immediately without grace period15812026/07/09 07:42:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1582=== NAME TestClientCADerivations1583 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3599309625/001/store/0bzyw4nsn4bvmrljy4shcqkyzlin6h7s-ca-test1584 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1585 Compression: zstd1586 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1587 NarSize: 1441588 References: 1589 Deriver: /build/TestClientCADerivations3599309625/001/store/bgqbg92xyj9blj5slzaihps7sjw0f2ky-ca-test.drv1590 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1591 client_ca_test.go:185: Checking for realisation files in S3...15922026/07/09 07:42:56 INFO Completed upload id=11593 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1594 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15952026/07/09 07:42:56 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15962026/07/09 07:42:56 INFO Completed upload id=215972026/07/09 07:42:56 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete15982026/07/09 07:42:56 INFO Completed upload id=315992026/07/09 07:42:56 INFO Upload complete. (90ms)1600=== NAME TestClientMultipleUploads1601 client_integration_test.go:349: Uploaded 3 paths in 122.873487ms1602--- PASS: TestGCBugBareHashReferences (0.79s)1603--- PASS: TestClientMultipleUploads (0.79s)16042026/07/09 07:42:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1605=== NAME TestOrphanedObjectsGC1606 orphaned_objects_gc_test.go:290: GC Test Summary:1607 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1608 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1609 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1610 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1611 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1612--- PASS: TestOrphanedObjectsGC (0.81s)16132026/07/09 07:42:56 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=M2YyYzA3OTEtM2I1NC00MTQ4LWEwNTQtYjNmNDEwMzVlYmQ3LjlhODkwMWNlLTNkYzMtNDE2Mi1hYjcxLTk5ZDQwNGQxN2FhZngxNzgzNTgyOTc2MzU2MzQ2ODUw parts=121614--- PASS: TestRedundantMultipartUpload (0.81s)16152026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures16162026/07/09 07:42:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16172026/07/09 07:42:56 INFO Uploading fk0jccnbibci5gh7hi3mh98rmrjq0hv5-unpinned-file.txt (128B)16182026/07/09 07:42:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16192026/07/09 07:42:56 INFO Signed narinfos id=2 count=116202026/07/09 07:42:56 INFO Uploading 1 narinfos16212026/07/09 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures16222026/07/09 07:42:56 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16232026/07/09 07:42:56 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16242026/07/09 07:42:56 INFO Completed upload id=216252026/07/09 07:42:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16262026/07/09 07:42:56 INFO Upload complete. (66ms)16272026/07/09 07:42:56 INFO Signed narinfos id=2 count=116282026/07/09 07:42:56 INFO Uploading 1 narinfos16292026/07/09 07:42:56 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16302026/07/09 07:42:56 INFO Completed upload id=216312026/07/09 07:42:56 INFO Upload complete. (61ms)1632=== NAME TestNARDeduplicationMetadataUploadBug1633 metadata_upload_test.go:76: Retrieved narinfo from S3:1634 StorePath: /build/TestNARDeduplicationMetadataUploadBug1019669248/001/store/fy9x38z6lncxd83swsjawbi46bcp91jr-file2.txt1635 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1636 Compression: zstd1637 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1638 NarSize: 1601639 References: 1640 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1641 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1642 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1643 {"version":1,"root":{"type":"regular","size":44}}1644--- PASS: TestNARDeduplicationMetadataUploadBug (0.86s)16452026/07/09 07:42:56 INFO Received create pin request method=POST path=/api/pins/myapp16462026/07/09 07:42:56 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=847.451908ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16472026/07/09 07:42:56 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3168964912/001/store/mdp43vx7q01s60f1rdq1hcc1gakdz2m0-pinned-file.txt narinfo_key=mdp43vx7q01s60f1rdq1hcc1gakdz2m0.narinfo16482026/07/09 07:42:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures16492026/07/09 07:42:56 INFO Garbage collection started16502026/07/09 07:42:56 INFO Aborted multipart uploads count=016512026/07/09 07:42:56 WARN Force mode enabled - objects will be deleted immediately without grace period1652--- PASS: TestUploadHandlersRejectOversizedBody (0.18s)1653 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)1654 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)1655 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.72s)1656=== NAME TestClientCADerivations1657 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1658 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1659 error: binary cache 's3://bucket25?endpoint=http://localhost:42221®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3599309625/001/store'1660 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11661--- PASS: TestClientCADerivations (0.91s)1662=== NAME TestOrphanedObjectsGCStressTest1663 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1664 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion16652026/07/09 07:42:57 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=016662026/07/09 07:42:57 INFO Vacuumed table table=pending_closures16672026/07/09 07:42:57 INFO Vacuumed table table=pending_objects16682026/07/09 07:42:57 INFO Vacuumed table table=multipart_uploads16692026/07/09 07:42:57 INFO Vacuumed table table=closures16702026/07/09 07:42:57 INFO Vacuumed table table=objects1671 orphaned_objects_gc_test.go:509: Stress test completed successfully:1672 orphaned_objects_gc_test.go:510: - Active objects preserved: 201673 orphaned_objects_gc_test.go:511: - Objects deleted: 2101674 orphaned_objects_gc_test.go:512: - Total GC'd: 2101675--- PASS: TestOrphanedObjectsGCStressTest (1.31s)16762026/07/09 07:42:57 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=016772026/07/09 07:42:57 INFO Vacuumed table table=pending_closures16782026/07/09 07:42:57 INFO Vacuumed table table=pending_objects16792026/07/09 07:42:57 INFO Vacuumed table table=multipart_uploads16802026/07/09 07:42:57 INFO Vacuumed table table=closures16812026/07/09 07:42:57 INFO Vacuumed table table=objects16822026/07/09 07:42:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.606497972s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16832026/07/09 07:42:58 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01684=== NAME TestClientIntegration1685 client_integration_test.go:303: Objects in database after GC:1686 client_integration_test.go:303: Successfully deleted all objects with GC --force1687--- PASS: TestClientIntegration (2.78s)16882026/07/09 07:42:58 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01689=== NAME TestPinProtectsFromGC1690 client_integration_test.go:709: Pin successfully protected closure from garbage collection1691--- PASS: TestPinProtectsFromGC (2.89s)1692--- PASS: TestClientErrorHandling (0.00s)1693 --- PASS: TestClientErrorHandling/InvalidStorePath (0.62s)1694 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.72s)1695 --- PASS: TestClientErrorHandling/ServerNotAvailable (3.34s)16962026/07/09 07:43:01 WARN Rate limiter enabled after throttle name=s3-test rate=516972026/07/09 07:43:01 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1698=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1699 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101700 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001701--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.13s)1702PASS17032026-07-09 07:43:02.586 UTC [330] LOG: received smart shutdown request17042026-07-09 07:43:02.589 UTC [330] LOG: background worker "logical replication launcher" (PID 337) exited with exit code 117052026-07-09 07:43:02.596 UTC [332] LOG: shutting down17062026-07-09 07:43:02.597 UTC [332] LOG: checkpoint starting: shutdown immediate17072026-07-09 07:43:03.880 UTC [332] LOG: checkpoint complete: wrote 8597 buffers (52.5%); 0 WAL file(s) added, 0 removed, 12 recycled; write=0.132 s, sync=1.142 s, total=1.284 s; sync files=14421, longest=0.001 s, average=0.001 s; distance=194058 kB, estimate=194058 kB; lsn=0/D26F500, redo lsn=0/D26F50017082026-07-09 07:43:03.957 UTC [330] LOG: database system is shut down1709Running OIDC tests...1710=== RUN TestGlobMatch1711=== PAUSE TestGlobMatch1712=== RUN TestAudienceForIssuer1713=== PAUSE TestAudienceForIssuer1714=== RUN TestValidateToken_ValidToken1715=== PAUSE TestValidateToken_ValidToken1716=== RUN TestValidateToken_WrongAudience1717=== PAUSE TestValidateToken_WrongAudience1718=== RUN TestValidateToken_Expired1719=== PAUSE TestValidateToken_Expired1720=== RUN TestValidateToken_BoundClaimsMismatch1721=== PAUSE TestValidateToken_BoundClaimsMismatch1722=== RUN TestValidateToken_BoundSubjectMismatch1723=== PAUSE TestValidateToken_BoundSubjectMismatch1724=== RUN TestValidateToken_MultipleProviders1725=== PAUSE TestValidateToken_MultipleProviders1726=== RUN TestValidateToken_NoMatchingProvider1727=== PAUSE TestValidateToken_NoMatchingProvider1728=== CONT TestGlobMatch1729=== RUN TestGlobMatch/foo_foo1730=== PAUSE TestGlobMatch/foo_foo1731=== CONT TestValidateToken_MultipleProviders1732=== RUN TestGlobMatch/foo_bar1733=== PAUSE TestGlobMatch/foo_bar1734=== CONT TestValidateToken_Expired1735=== RUN TestGlobMatch/*_1736=== PAUSE TestGlobMatch/*_1737=== CONT TestValidateToken_WrongAudience1738=== CONT TestValidateToken_ValidToken1739=== CONT TestAudienceForIssuer1740--- PASS: TestAudienceForIssuer (0.00s)1741=== CONT TestValidateToken_BoundClaimsMismatch1742=== CONT TestValidateToken_BoundSubjectMismatch1743=== CONT TestValidateToken_NoMatchingProvider1744=== RUN TestGlobMatch/*_anything1745=== PAUSE TestGlobMatch/*_anything1746=== RUN TestGlobMatch/foo*_foo1747=== PAUSE TestGlobMatch/foo*_foo1748=== RUN TestGlobMatch/foo*_foobar1749=== PAUSE TestGlobMatch/foo*_foobar1750=== RUN TestGlobMatch/foo*_bar1751=== PAUSE TestGlobMatch/foo*_bar1752=== RUN TestGlobMatch/*bar_bar1753=== PAUSE TestGlobMatch/*bar_bar1754=== RUN TestGlobMatch/*bar_foobar1755=== PAUSE TestGlobMatch/*bar_foobar1756=== RUN TestGlobMatch/*bar_foo1757=== PAUSE TestGlobMatch/*bar_foo1758=== RUN TestGlobMatch/foo*bar_foobar1759=== PAUSE TestGlobMatch/foo*bar_foobar1760=== RUN TestGlobMatch/foo*bar_foo123bar1761=== PAUSE TestGlobMatch/foo*bar_foo123bar1762=== RUN TestGlobMatch/foo*bar_foobarbaz1763=== PAUSE TestGlobMatch/foo*bar_foobarbaz1764=== RUN TestGlobMatch/*/*_foo/bar1765=== PAUSE TestGlobMatch/*/*_foo/bar1766=== RUN TestGlobMatch/*/*_foo1767=== PAUSE TestGlobMatch/*/*_foo1768=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1769=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1770=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01771=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01772=== RUN TestGlobMatch/refs/*/main_refs/heads/main1773=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1774=== RUN TestGlobMatch/fo?_foo1775=== PAUSE TestGlobMatch/fo?_foo1776=== RUN TestGlobMatch/fo?_fo1777=== PAUSE TestGlobMatch/fo?_fo1778=== RUN TestGlobMatch/fo?_fooo1779=== PAUSE TestGlobMatch/fo?_fooo1780=== RUN TestGlobMatch/?oo_foo1781=== PAUSE TestGlobMatch/?oo_foo1782=== RUN TestGlobMatch/?oo_boo1783=== PAUSE TestGlobMatch/?oo_boo1784=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1785=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1786=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1787=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1788=== CONT TestGlobMatch/foo_foo1789=== CONT TestGlobMatch/foo*bar_foobarbaz1790=== CONT TestGlobMatch/foo*bar_foo123bar1791=== CONT TestGlobMatch/foo*bar_foobar1792=== CONT TestGlobMatch/?oo_foo1793=== CONT TestGlobMatch/foo*_foobar1794=== CONT TestGlobMatch/?oo_boo1795=== CONT TestGlobMatch/fo?_fo1796=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1797=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01798=== CONT TestGlobMatch/fo?_fooo1799=== CONT TestGlobMatch/fo?_foo1800=== CONT TestGlobMatch/foo*_foo1801=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1802=== CONT TestGlobMatch/*_anything1803=== CONT TestGlobMatch/refs/*/main_refs/heads/main1804=== CONT TestGlobMatch/*_1805=== CONT TestGlobMatch/*bar_foobar1806=== CONT TestGlobMatch/*bar_foo1807=== CONT TestGlobMatch/foo_bar1808=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1809=== CONT TestGlobMatch/*/*_foo1810=== CONT TestGlobMatch/*bar_bar1811=== CONT TestGlobMatch/foo*_bar1812=== CONT TestGlobMatch/*/*_foo/bar1813--- PASS: TestGlobMatch (0.00s)1814 --- PASS: TestGlobMatch/foo_foo (0.00s)1815 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1816 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1817 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1818 --- PASS: TestGlobMatch/?oo_foo (0.00s)1819 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1820 --- PASS: TestGlobMatch/?oo_boo (0.00s)1821 --- PASS: TestGlobMatch/fo?_fo (0.00s)1822 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1823 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1824 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1825 --- PASS: TestGlobMatch/fo?_foo (0.00s)1826 --- PASS: TestGlobMatch/foo*_foo (0.00s)1827 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1828 --- PASS: TestGlobMatch/*_anything (0.00s)1829 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1830 --- PASS: TestGlobMatch/*_ (0.00s)1831 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1832 --- PASS: TestGlobMatch/*bar_foo (0.00s)1833 --- PASS: TestGlobMatch/foo_bar (0.00s)1834 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1835 --- PASS: TestGlobMatch/*/*_foo (0.00s)1836 --- PASS: TestGlobMatch/*bar_bar (0.00s)1837 --- PASS: TestGlobMatch/foo*_bar (0.00s)1838 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)18392026/07/09 07:43:04 INFO OIDC provider initialized name=test18402026/07/09 07:43:04 INFO OIDC provider initialized name=test18412026/07/09 07:43:04 INFO OIDC provider initialized name=test18422026/07/09 07:43:04 INFO OIDC provider initialized name=test18432026/07/09 07:43:04 INFO OIDC provider initialized name=test18442026/07/09 07:43:04 INFO OIDC provider initialized name=provider118452026/07/09 07:43:04 INFO OIDC provider initialized name=provider118462026/07/09 07:43:04 INFO OIDC provider initialized name=provider21847--- PASS: TestValidateToken_ValidToken (0.01s)1848--- PASS: TestValidateToken_MultipleProviders (0.01s)1849--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1850--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1851--- PASS: TestValidateToken_Expired (0.01s)1852--- PASS: TestValidateToken_WrongAudience (0.01s)1853--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1854PASS1855Running hook tests...1856=== RUN TestSendPathsEmpty1857=== PAUSE TestSendPathsEmpty1858=== RUN TestQueueEnqueueAndFetch1859=== PAUSE TestQueueEnqueueAndFetch1860=== RUN TestQueueDeduplication1861=== PAUSE TestQueueDeduplication1862=== RUN TestQueueRemove1863=== PAUSE TestQueueRemove1864=== RUN TestQueueFetchBatchLimit1865=== PAUSE TestQueueFetchBatchLimit1866=== RUN TestQueueFetchRemoveLifecycle1867=== PAUSE TestQueueFetchRemoveLifecycle1868=== RUN TestQueueConcurrentWriters1869=== PAUSE TestQueueConcurrentWriters1870=== RUN TestServerClientIntegration1871=== PAUSE TestServerClientIntegration1872=== RUN TestServerQueueError1873=== PAUSE TestServerQueueError1874=== RUN TestGetListenerSocketActivation1875 server_test.go:210: === RUN TestGetListenerSocketActivation1876 --- PASS: TestGetListenerSocketActivation (0.00s)1877 PASS1878 1879--- PASS: TestGetListenerSocketActivation (0.02s)1880=== RUN TestWorkerUploadsAndRemoves1881=== PAUSE TestWorkerUploadsAndRemoves1882=== RUN TestWorkerSkipsGCdPaths1883=== PAUSE TestWorkerSkipsGCdPaths1884=== RUN TestWorkerPrunesClosureDeps1885=== PAUSE TestWorkerPrunesClosureDeps1886=== CONT TestSendPathsEmpty1887=== CONT TestQueueConcurrentWriters1888--- PASS: TestSendPathsEmpty (0.00s)1889=== CONT TestQueueFetchRemoveLifecycle1890=== CONT TestQueueFetchBatchLimit1891=== CONT TestQueueRemove1892=== CONT TestQueueDeduplication1893=== CONT TestQueueEnqueueAndFetch1894=== CONT TestWorkerUploadsAndRemoves1895=== CONT TestServerQueueError1896=== CONT TestWorkerSkipsGCdPaths1897=== CONT TestServerClientIntegration1898=== CONT TestWorkerPrunesClosureDeps18992026/07/09 07:43:04 ERROR Failed to queue paths error="permission denied" count=11900--- PASS: TestServerClientIntegration (0.00s)1901--- PASS: TestServerQueueError (0.00s)1902--- PASS: TestQueueRemove (0.01s)19032026/07/09 07:43:04 INFO Upload queue status pending=219042026/07/09 07:43:04 INFO Uploading batch count=11905--- PASS: TestQueueFetchRemoveLifecycle (0.02s)1906--- PASS: TestQueueDeduplication (0.01s)1907--- PASS: TestQueueEnqueueAndFetch (0.01s)19082026/07/09 07:43:04 INFO Upload queue status pending=219092026/07/09 07:43:04 INFO Uploading batch count=219102026/07/09 07:43:04 INFO Upload queue status pending=219112026/07/09 07:43:04 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3247119476/002/nonexistent1912--- PASS: TestQueueFetchBatchLimit (0.02s)19132026/07/09 07:43:04 INFO Uploading batch count=11914--- PASS: TestWorkerPrunesClosureDeps (0.06s)1915--- PASS: TestWorkerUploadsAndRemoves (0.07s)1916--- PASS: TestWorkerSkipsGCdPaths (0.07s)1917--- PASS: TestQueueConcurrentWriters (0.24s)1918PASS