niks3-go-unit-tests
x86_64-linux.go-unit-tests
· build #91
· 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 TestShellSplitErrors73=== CONT TestFileTokenEmpty74=== CONT TestScriptTokenEmptyCommand75--- PASS: TestShellSplitErrors (0.00s)76--- PASS: TestScriptTokenEmptyCommand (0.00s)77=== CONT TestScriptTokenBadJSON78=== CONT TestScriptTokenEmptyToken79=== CONT TestScriptTokenCachesUntilRefresh80=== CONT TestScriptTokenNoExpiryRerunsEveryCall81=== CONT TestDumpPathSingleFile82=== CONT TestConvertHashToNix3283=== CONT TestEncodeNixBase32WithRealHash84=== CONT TestEncodeNixBase3285=== RUN TestEncodeNixBase32/test_string_hash86=== PAUSE TestEncodeNixBase32/test_string_hash87=== RUN TestEncodeNixBase32/empty_input88=== PAUSE TestEncodeNixBase32/empty_input89=== CONT TestEncodeNixBase32/test_string_hash90=== CONT TestGetStorePathHash91=== RUN TestGetStorePathHash/valid_store_path92=== PAUSE TestGetStorePathHash/valid_store_path93=== RUN TestGetStorePathHash/basename_without_hyphen_should_error94=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error95=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error96=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error97=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error98=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error99=== CONT TestGetStorePathHash/valid_store_path100=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error101=== CONT TestGetStorePathHash/basename_without_hyphen_should_error102=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error103=== CONT TestEncodeNixBase32/empty_input104=== CONT TestPathInfoCACompatibility105=== RUN TestPathInfoCACompatibility/null_ca_field106=== CONT TestStaticToken107=== PAUSE TestPathInfoCACompatibility/null_ca_field108=== CONT TestFileTokenMissing109=== CONT TestParsePathInfoJSONMultiplePaths110=== CONT TestParsePathInfoJSON111=== CONT TestFileTokenReadsAndCaches112=== CONT TestUploadMultipart_SupersededByPeer113=== CONT TestPathInfoHashCompatibility114=== CONT TestDumpPathMatchesNix115=== CONT TestSetClientTLSDoesNotMutateDefaultTransport116=== CONT TestPartSizeForNAR117=== CONT TestSetClientTLSErrors118=== CONT TestSetClientTLS119=== CONT TestResolveStorePath120=== CONT TestShellSplit121=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess122=== CONT TestCaseHackSuffix123=== CONT TestRateLimiterFeedback124=== CONT TestDoWithRetry_BodyReplayedViaGetBody125=== CONT TestScriptTokenScriptFails126--- PASS: TestFileTokenEmpty (0.00s)127=== RUN TestConvertHashToNix32/SRI_format_to_Nix32128=== CONT TestDumpPathWriterError129=== RUN TestPartSizeForNAR/zero_stays_at_minimum130=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum131=== RUN TestRateLimiterFeedback/429_enables_limiter132--- PASS: TestEncodeNixBase32WithRealHash (0.00s)133=== PAUSE TestRateLimiterFeedback/429_enables_limiter134--- PASS: TestStaticToken (0.00s)135--- PASS: TestGetStorePathHash (0.00s)136 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)137 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)138 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)139 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)140=== RUN TestPartSizeForNAR/small_stays_at_minimum141=== PAUSE TestPartSizeForNAR/small_stays_at_minimum142=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)143=== RUN TestParsePathInfoJSON/Nix_format144=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)145--- PASS: TestEncodeNixBase32 (0.00s)146 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)147 --- PASS: TestEncodeNixBase32/empty_input (0.00s)148--- PASS: TestShellSplit (0.00s)149=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum150=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32151=== RUN TestUploadMultipart_SupersededByPeer/exists152=== RUN TestConvertHashToNix32/already_Nix32_format153=== PAUSE TestConvertHashToNix32/already_Nix32_format154=== RUN TestRateLimiterFeedback/503_enables_limiter155=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths156=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths157=== RUN TestPathInfoCACompatibility/old_string_format_-_text158=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon159=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon160=== PAUSE TestParsePathInfoJSON/Nix_format161=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum162=== RUN TestConvertHashToNix32/invalid_format163=== PAUSE TestUploadMultipart_SupersededByPeer/exists164=== PAUSE TestRateLimiterFeedback/503_enables_limiter165=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text166--- PASS: TestFileTokenMissing (0.00s)167=== PAUSE TestConvertHashToNix32/invalid_format168=== CONT TestConvertHashToNix32/invalid_format169=== CONT TestConvertHashToNix32/already_Nix32_format170--- PASS: TestResolveStorePath (0.01s)171=== CONT TestConvertHashToNix32/SRI_format_to_Nix32172=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1732026/07/09 07:29:20 WARN Rate limiter enabled after throttle name=server-test rate=5174=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths175=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths176--- PASS: TestConvertHashToNix32 (0.01s)177 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)178 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)179 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.01s)180=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths181=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI182=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI183=== RUN TestParsePathInfoJSON/Lix_format184=== PAUSE TestParsePathInfoJSON/Lix_format185=== RUN TestParsePathInfoJSON/empty_input186=== PAUSE TestParsePathInfoJSON/empty_input187--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)188 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)189 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)190=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512191=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts192=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512193=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive194=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive195=== RUN TestUploadMultipart_SupersededByPeer/missing196=== PAUSE TestUploadMultipart_SupersededByPeer/missing197=== CONT TestUploadMultipart_SupersededByPeer/exists198=== CONT TestUploadMultipart_SupersededByPeer/missing1992026/07/09 07:29:20 WARN Rate limiter enabled after throttle name=server-test rate=52002026/07/09 07:29:20 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:39433201=== RUN TestParsePathInfoJSON/whitespace_only202=== PAUSE TestParsePathInfoJSON/whitespace_only203--- PASS: TestScriptTokenBadJSON (0.02s)204--- PASS: TestFileTokenReadsAndCaches (0.01s)205=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter206=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts207=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter208=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512209=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI210=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon211=== RUN TestPathInfoCACompatibility/new_structured_format_-_text212=== RUN TestParsePathInfoJSON/invalid_JSON2132026/07/09 07:29:20 WARN Rate limiter backed off name=server-test rate=5214--- PASS: TestDoServerRequestAttachesToken (0.02s)2152026/07/09 07:29:20 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:39433216=== PAUSE TestParsePathInfoJSON/invalid_JSON217=== RUN TestPartSizeForNAR/1_TiB218=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter219=== PAUSE TestPartSizeForNAR/1_TiB220=== RUN TestSetClientTLS/rejects_connection_without_client_cert221=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text222=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)223--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)224--- PASS: TestScriptTokenEmptyToken (0.02s)225--- PASS: TestScriptTokenScriptFails (0.02s)226--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.02s)227=== CONT TestParsePathInfoJSON/Nix_format228=== CONT TestParsePathInfoJSON/Lix_format229=== CONT TestParsePathInfoJSON/whitespace_only230=== CONT TestParsePathInfoJSON/invalid_JSON231=== CONT TestParsePathInfoJSON/empty_input232=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter233=== CONT TestRateLimiterFeedback/429_enables_limiter234=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter235=== RUN TestPartSizeForNAR/5_TiB_S3_max_object236=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method237=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert238=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method239=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA240=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive241--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)242--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)243=== RUN TestSetClientTLSErrors/missing_cert_file244=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter245=== CONT TestRateLimiterFeedback/503_enables_limiter246=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object247=== CONT TestPathInfoCACompatibility/null_ca_field248=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method249=== CONT TestPathInfoCACompatibility/new_structured_format_-_text2502026/07/09 07:29:20 WARN Rate limiter enabled after throttle name=server-test rate=52512026/07/09 07:29:20 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:43665252=== CONT TestPathInfoCACompatibility/old_string_format_-_text2532026/07/09 07:29:20 WARN Rate limiter enabled after throttle name=server-test rate=52542026/07/09 07:29:20 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:39713255=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA256--- PASS: TestPathInfoHashCompatibility (0.01s)257 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)258 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)259 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)260 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)261=== PAUSE TestSetClientTLSErrors/missing_cert_file2622026/07/09 07:29:20 WARN Rate limiter backed off name=server-test rate=5263=== RUN TestSetClientTLSErrors/missing_key_file2642026/07/09 07:29:20 WARN Rate limiter backed off name=server-test rate=5265=== PAUSE TestSetClientTLSErrors/missing_key_file266=== RUN TestSetClientTLSErrors/missing_ca_file267=== RUN TestPartSizeForNAR/capped_at_5_GiB268=== PAUSE TestPartSizeForNAR/capped_at_5_GiB269=== CONT TestPartSizeForNAR/5_TiB_S3_max_object270=== CONT TestPartSizeForNAR/capped_at_5_GiB271=== RUN TestSetClientTLS/preserves_debug_logging_transport272=== PAUSE TestSetClientTLS/preserves_debug_logging_transport273=== CONT TestSetClientTLS/rejects_connection_without_client_cert274=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA275=== CONT TestPartSizeForNAR/zero_stays_at_minimum276--- PASS: TestParsePathInfoJSON (0.02s)277 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)278 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)279 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)280 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)281 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)282=== PAUSE TestSetClientTLSErrors/missing_ca_file283=== RUN TestSetClientTLSErrors/invalid_ca_file284=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum285--- PASS: TestPathInfoCACompatibility (0.03s)286 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)287 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)288 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)289 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)290 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)291=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts292=== CONT TestPartSizeForNAR/small_stays_at_minimum293=== CONT TestPartSizeForNAR/1_TiB294=== CONT TestSetClientTLS/preserves_debug_logging_transport295=== PAUSE TestSetClientTLSErrors/invalid_ca_file296=== CONT TestSetClientTLSErrors/missing_cert_file297=== CONT TestSetClientTLSErrors/missing_ca_file298=== CONT TestSetClientTLSErrors/invalid_ca_file299=== CONT TestSetClientTLSErrors/missing_key_file300--- PASS: TestRateLimiterFeedback (0.03s)301 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)302 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)303 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)304 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)305--- PASS: TestPartSizeForNAR (0.03s)306 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)307 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)308 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)309 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)310 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)311 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)312 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)313--- PASS: TestSetClientTLSErrors (0.03s)314 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)315 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)316 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)317 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)318--- PASS: TestDumpPathSingleFile (0.03s)3192026/07/09 07:29:20 http: TLS handshake error from 127.0.0.1:53358: remote error: tls: bad certificate320--- PASS: TestSetClientTLS (0.03s)321 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.00s)322 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)323 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)324--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)325 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)326 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.03s)327--- PASS: TestCaseHackSuffix (0.05s)328--- PASS: TestDumpPathWriterError (0.06s)329--- PASS: TestDumpPathMatchesNix (0.08s)330--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)331PASS332Running server tests...333The files belonging to this database system will be owned by user "nixbld".334This user must also own the server process.335336The database cluster will be initialized with locale "C".337The default database encoding has accordingly been set to "SQL_ASCII".338The default text search configuration will be set to "english".339340Data page checksums are enabled.341342creating directory /build/postgres3356181463/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/postgres3356181463/data -l logfile start359360/build/postgres3356181463:5432 - no response3612026-07-09 07:29:21.944 UTC [298] LOG: starting PostgreSQL 18.4 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit3622026-07-09 07:29:21.945 UTC [298] LOG: listening on Unix socket "/build/postgres3356181463/.s.PGSQL.5432"3632026-07-09 07:29:21.950 UTC [305] LOG: database system was shut down at 2026-07-09 07:29:21 UTC3642026-07-09 07:29:21.953 UTC [298] LOG: database system is ready to accept connections365/build/postgres3356181463:5432 - accepting connections366{"timestamp":"2026-07-09T07:29:22.376998351Z","level":"ERROR","fields":{"message":"list_path_raw: revjob err VolumeNotFound"},"target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":486,"threadName":"rustfs-worker","threadId":"ThreadId(692)"}367368thread 'rustfs-worker' (1006) 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:29:22.535 UTC [1101] ERROR: relation "goose_db_version" does not exist at character 363992026-07-09 07:29:22.535 UTC [1101] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4002026/07/09 07:29:22 OK 20241026095416_initial_model.sql (7.8ms)4012026/07/09 07:29:22 OK 20251210153512_drop_unused_gin_index.sql (1.56ms)4022026/07/09 07:29:22 OK 20251218171726_add_pins.sql (2.11ms)4032026/07/09 07:29:22 OK 20260628120000_add_object_size_and_stats.sql (2.25ms)4042026/07/09 07:29:22 goose: successfully migrated database to version: 202606281200004052026/07/09 07:29:22 OK 1_commit_pending_closure.sql (1.66ms)4062026/07/09 07:29:22 OK 2_object_stats_trigger.sql (705.13µs)4072026/07/09 07:29:22 goose: up to current file version: 2408--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.13s)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:29:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4892026/07/09 07:29:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4902026/07/09 07:29:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4912026/07/09 07:29:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4922026/07/09 07:29:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4932026/07/09 07:29:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4942026/07/09 07:29:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4952026/07/09 07:29:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4962026/07/09 07:29:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4972026/07/09 07:29:22 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 TestService_NativeMTLS521=== CONT TestGCMetrics522=== CONT TestClientCADerivations523=== CONT TestService_AuthMiddleware_OIDC524=== CONT TestCacheStatsHandler525=== CONT TestService_AuthMiddleware_MTLSBoundSubjects526=== CONT TestClientWithDependencies527=== CONT TestService_ReadAuthMiddleware528=== CONT TestCacheConfigHandler529=== CONT TestReadProxyHead530=== CONT TestService_verifyS3Integrity531=== CONT TestGCTaskStore_PhaseUpdates532=== CONT TestCompleteMultipartUnregistered533=== CONT TestService_cleanupPendingClosuresHandler534=== CONT TestUploadHandlersRejectOversizedBody535=== CONT TestUploadHandlersRejectInvalidKeys536=== CONT TestIsValidUploadKey537=== CONT TestProxyWriteTimeout538=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle539=== CONT TestService_Rustfstest540=== CONT TestCompleteMultipartUpload_ErrorButObjectExists541=== CONT TestRedundantMultipartUpload542=== CONT TestReadProxyRangeRequest543=== CONT TestReadProxyDisabled544=== CONT TestReadProxyRootRedirectsToIndexHTML545=== CONT TestReadProxyConditionalGet546=== CONT TestGCTaskStore_GetEmpty547=== CONT TestGCTaskStore_CompletedAllowsNewTask548=== CONT TestGCTaskStore_GetReturnsLatest549=== CONT TestMetricsInventory550=== CONT TestNARDeduplicationMetadataUploadBug551=== CONT TestGenerateLandingPage552=== CONT TestService_healthCheckHandler553=== CONT TestGracefulShutdownDrainsInflight554=== CONT TestGCTaskStore_Fail555=== CONT TestGCTaskStore_DeduplicateSameParams556=== CONT TestParseSingleRange557=== CONT TestGCTaskStore_ConflictDifferentParams558=== CONT TestReadProxyInvalidPath559=== CONT TestReadProxyNarinfo560=== CONT TestReadProxyNarinfoAlreadyDecompressed561=== CONT TestReadProxy404562=== CONT TestIsValidCachePath563=== RUN TestIsValidCachePath/narinfo564=== CONT TestReadProxyNarStreaming5652026/07/09 07:29:22 INFO Starting HTTP server address=127.0.0.1:40369566=== CONT TestGCTaskStore_StartNew5672026/07/09 07:29:22 INFO OIDC provider initialized name=test568=== CONT TestService_AuthMiddleware_MTLSProxyHeader569=== CONT TestClientIntegration570=== CONT TestClientMultipleUploads571=== CONT TestOrphanedObjectsGC572=== CONT TestResurrectedObjectNotDeleted573=== CONT TestOrphanedObjectsGCStressTest574=== CONT TestPinProtectsFromGC575=== CONT TestClientErrorHandling576=== CONT TestMultipartCleanup577=== CONT TestObjectStatsTrigger578=== CONT TestServerTLSConfig579=== CONT TestService_createPendingClosureHandler580=== CONT TestGCBugBareHashReferences581=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT582=== RUN TestCacheConfigHandler/full_config,_no_issuer583--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)584=== RUN TestIsValidUploadKey/narinfo585=== RUN TestProxyWriteTimeout/narinfo586=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info587=== RUN TestParseSingleRange/none5882026/07/09 07:29:22 INFO Shutdown signal received, draining in-flight requests timeout=10s589=== PAUSE TestIsValidCachePath/narinfo590=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars591=== RUN TestClientErrorHandling/InvalidStorePath592--- PASS: TestGCTaskStore_GetEmpty (0.00s)593=== PAUSE TestClientErrorHandling/InvalidStorePath594=== PAUSE TestIsValidUploadKey/narinfo595=== PAUSE TestCacheConfigHandler/full_config,_no_issuer596=== RUN TestClientErrorHandling/InvalidAuthToken597=== PAUSE TestProxyWriteTimeout/narinfo598=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info599=== PAUSE TestParseSingleRange/none600=== RUN TestServerTLSConfig/no_client_CA601=== RUN TestParseSingleRange/unknown_unit602--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)603--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)604=== RUN TestIsValidUploadKey/nar_zst605=== RUN TestCacheConfigHandler/no_cache_url_configured606=== PAUSE TestCacheConfigHandler/no_cache_url_configured607=== PAUSE TestClientErrorHandling/InvalidAuthToken608=== RUN TestCacheConfigHandler/no_signing_keys609=== RUN TestProxyWriteTimeout/1_GiB_nar610=== PAUSE TestCacheConfigHandler/no_signing_keys611=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal612=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal613=== PAUSE TestServerTLSConfig/no_client_CA614=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars615=== RUN TestServerTLSConfig/missing_CA_file616=== RUN TestIsValidCachePath/nar_zst617=== PAUSE TestServerTLSConfig/missing_CA_file618=== PAUSE TestParseSingleRange/unknown_unit619--- PASS: TestGCTaskStore_Fail (0.00s)620--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)621=== PAUSE TestIsValidUploadKey/nar_zst622=== RUN TestClientErrorHandling/ServerNotAvailable623=== PAUSE TestClientErrorHandling/ServerNotAvailable624=== PAUSE TestProxyWriteTimeout/1_GiB_nar625=== RUN TestProxyWriteTimeout/10_GiB_nar626=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator627=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key628=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key629=== PAUSE TestIsValidCachePath/nar_zst630=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key631=== RUN TestIsValidCachePath/nar_xz632=== PAUSE TestIsValidCachePath/nar_xz633=== RUN TestIsValidCachePath/nar_bz2634=== PAUSE TestIsValidCachePath/nar_bz2635=== RUN TestServerTLSConfig/not_a_PEM_file636=== PAUSE TestServerTLSConfig/not_a_PEM_file637=== RUN TestParseSingleRange/multi-range_ignored638=== PAUSE TestParseSingleRange/multi-range_ignored639=== CONT TestServerTLSConfig/no_client_CA640--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)641--- PASS: TestGCTaskStore_StartNew (0.00s)642=== RUN TestIsValidUploadKey/nar_xz643=== PAUSE TestIsValidUploadKey/nar_xz644=== CONT TestClientErrorHandling/InvalidStorePath645=== CONT TestClientErrorHandling/InvalidAuthToken646=== CONT TestClientErrorHandling/ServerNotAvailable647=== PAUSE TestProxyWriteTimeout/10_GiB_nar648=== RUN TestProxyWriteTimeout/unknown_size649=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator650=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key651=== RUN TestIsValidCachePath/nar_uncompressed652=== RUN TestParseSingleRange/malformed_no_dash653=== PAUSE TestParseSingleRange/malformed_no_dash654=== CONT TestServerTLSConfig/missing_CA_file655=== CONT TestServerTLSConfig/not_a_PEM_file656=== RUN TestIsValidUploadKey/nar_plain657=== PAUSE TestProxyWriteTimeout/unknown_size658=== CONT TestCacheConfigHandler/full_config,_no_issuer659=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator660=== CONT TestCacheConfigHandler/no_signing_keys661--- PASS: TestGenerateLandingPage (0.01s)662=== CONT TestCacheConfigHandler/no_cache_url_configured663=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info664=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key665=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal6662026/07/09 07:29:22 INFO Received complete multipart upload request method=POST path=/667=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key6682026/07/09 07:29:22 INFO Received uploads request method=POST path=/6692026/07/09 07:29:22 INFO Received uploads request method=POST path=/670=== PAUSE TestIsValidCachePath/nar_uncompressed671=== RUN TestParseSingleRange/malformed_both_empty672=== RUN TestIsValidCachePath/ls6732026/07/09 07:29:22 INFO Received request for more parts method=POST path=/674=== PAUSE TestIsValidCachePath/ls675=== PAUSE TestIsValidUploadKey/nar_plain676=== CONT TestProxyWriteTimeout/10_GiB_nar677=== CONT TestProxyWriteTimeout/1_GiB_nar678=== CONT TestProxyWriteTimeout/unknown_size679=== CONT TestProxyWriteTimeout/narinfo680--- PASS: TestCacheConfigHandler (0.02s)681 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)682 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)683 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)684 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)685=== PAUSE TestParseSingleRange/malformed_both_empty686=== RUN TestIsValidCachePath/log687=== RUN TestParseSingleRange/malformed_end_before_start688=== PAUSE TestIsValidCachePath/log689=== RUN TestIsValidUploadKey/listing690=== PAUSE TestIsValidUploadKey/listing691=== RUN TestIsValidCachePath/realisation692=== RUN TestIsValidUploadKey/build_log693=== PAUSE TestIsValidUploadKey/build_log694--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)695 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)696 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)697 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)698 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)699=== PAUSE TestParseSingleRange/malformed_end_before_start700=== RUN TestParseSingleRange/closed701=== PAUSE TestIsValidCachePath/realisation702=== RUN TestIsValidCachePath/nix-cache-info703=== RUN TestIsValidUploadKey/build_log_home-manager_file704--- PASS: TestProxyWriteTimeout (0.01s)705 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)706 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)707 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)708 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)709--- PASS: TestServerTLSConfig (0.00s)710 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)711 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)712 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)713=== PAUSE TestParseSingleRange/closed714=== RUN TestParseSingleRange/open-ended715=== PAUSE TestIsValidCachePath/nix-cache-info716=== PAUSE TestParseSingleRange/open-ended717=== PAUSE TestIsValidUploadKey/build_log_home-manager_file718=== RUN TestIsValidUploadKey/build_log_plus_in_name719=== PAUSE TestIsValidUploadKey/build_log_plus_in_name720=== RUN TestIsValidCachePath/index.html721=== PAUSE TestIsValidCachePath/index.html722=== RUN TestParseSingleRange/end_clamped_to_size723=== RUN TestIsValidCachePath/traversal_parent724=== PAUSE TestIsValidCachePath/traversal_parent725=== RUN TestIsValidCachePath/traversal_in_middle726=== RUN TestIsValidUploadKey/build_log_question_mark727=== PAUSE TestParseSingleRange/end_clamped_to_size728=== RUN TestParseSingleRange/suffix729=== PAUSE TestParseSingleRange/suffix730=== RUN TestParseSingleRange/suffix_exceeds_size731=== PAUSE TestParseSingleRange/suffix_exceeds_size732=== PAUSE TestIsValidCachePath/traversal_in_middle733=== PAUSE TestIsValidUploadKey/build_log_question_mark734=== RUN TestParseSingleRange/single_byte735=== RUN TestIsValidCachePath/invalid_char_e736=== PAUSE TestParseSingleRange/single_byte737=== RUN TestIsValidUploadKey/build_log_equals738=== PAUSE TestIsValidUploadKey/build_log_equals739=== PAUSE TestIsValidCachePath/invalid_char_e740=== RUN TestParseSingleRange/start_past_EOF741=== RUN TestIsValidCachePath/invalid_char_u742=== PAUSE TestIsValidCachePath/invalid_char_u743=== RUN TestIsValidCachePath/random_path744=== PAUSE TestIsValidCachePath/random_path745=== PAUSE TestParseSingleRange/start_past_EOF746=== RUN TestIsValidUploadKey/realisation747=== RUN TestIsValidCachePath/empty748=== PAUSE TestIsValidCachePath/empty749=== RUN TestIsValidCachePath/leading_slash750=== RUN TestParseSingleRange/start_far_past_EOF751=== PAUSE TestParseSingleRange/start_far_past_EOF752=== PAUSE TestIsValidUploadKey/realisation753=== CONT TestParseSingleRange/unknown_unit754=== RUN TestIsValidUploadKey/realisation_plus_in_output755=== PAUSE TestIsValidUploadKey/realisation_plus_in_output756=== RUN TestIsValidUploadKey/nix-cache-info757=== PAUSE TestIsValidUploadKey/nix-cache-info758=== RUN TestIsValidUploadKey/index.html759=== PAUSE TestIsValidUploadKey/index.html760=== RUN TestIsValidUploadKey/narinfo_key,_nar_type761=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type762=== RUN TestIsValidUploadKey/nar_key,_narinfo_type763=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type764=== PAUSE TestIsValidCachePath/leading_slash765=== CONT TestParseSingleRange/none766=== CONT TestParseSingleRange/closed767=== CONT TestParseSingleRange/open-ended768=== CONT TestParseSingleRange/malformed_end_before_start769=== CONT TestParseSingleRange/suffix_exceeds_size770=== CONT TestParseSingleRange/malformed_both_empty771=== CONT TestParseSingleRange/single_byte772=== CONT TestParseSingleRange/malformed_no_dash773=== CONT TestParseSingleRange/suffix774=== CONT TestParseSingleRange/multi-range_ignored775=== CONT TestParseSingleRange/end_clamped_to_size776=== CONT TestParseSingleRange/start_past_EOF777=== CONT TestParseSingleRange/start_far_past_EOF778--- PASS: TestParseSingleRange (0.01s)779 --- PASS: TestParseSingleRange/unknown_unit (0.00s)780 --- PASS: TestParseSingleRange/none (0.00s)781 --- PASS: TestParseSingleRange/closed (0.00s)782 --- PASS: TestParseSingleRange/open-ended (0.00s)783 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)784 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)785 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)786 --- PASS: TestParseSingleRange/single_byte (0.00s)787 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)788 --- PASS: TestParseSingleRange/suffix (0.00s)789 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)790 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)791 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)792 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)793=== RUN TestIsValidUploadKey/listing_key,_narinfo_type794=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type795=== RUN TestIsValidCachePath/wrong_extension796=== RUN TestIsValidUploadKey/traversal797=== PAUSE TestIsValidCachePath/wrong_extension798=== RUN TestIsValidCachePath/short_hash799=== PAUSE TestIsValidUploadKey/traversal800=== RUN TestIsValidUploadKey/traversal_nar801=== PAUSE TestIsValidUploadKey/traversal_nar802=== PAUSE TestIsValidCachePath/short_hash803=== RUN TestIsValidUploadKey/absolute804=== CONT TestIsValidCachePath/narinfo805=== PAUSE TestIsValidUploadKey/absolute806=== CONT TestIsValidCachePath/short_hash807=== CONT TestIsValidCachePath/wrong_extension808=== CONT TestIsValidCachePath/leading_slash809=== CONT TestIsValidCachePath/empty810=== CONT TestIsValidCachePath/log811=== CONT TestIsValidCachePath/ls812=== CONT TestIsValidCachePath/nar_uncompressed813=== CONT TestIsValidCachePath/nar_bz2814=== CONT TestIsValidCachePath/realisation815=== CONT TestIsValidCachePath/nar_xz816=== CONT TestIsValidCachePath/random_path817=== CONT TestIsValidCachePath/invalid_char_u818=== CONT TestIsValidCachePath/invalid_char_e819=== CONT TestIsValidCachePath/index.html820=== CONT TestIsValidCachePath/traversal_parent821=== CONT TestIsValidCachePath/traversal_in_middle822=== CONT TestIsValidCachePath/nix-cache-info823=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars824=== CONT TestIsValidCachePath/nar_zst825=== RUN TestIsValidUploadKey/empty_key826=== PAUSE TestIsValidUploadKey/empty_key827--- PASS: TestIsValidCachePath (0.01s)828 --- PASS: TestIsValidCachePath/narinfo (0.00s)829 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)830 --- PASS: TestIsValidCachePath/leading_slash (0.00s)831 --- PASS: TestIsValidCachePath/empty (0.00s)832 --- PASS: TestIsValidCachePath/log (0.00s)833 --- PASS: TestIsValidCachePath/ls (0.00s)834 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)835 --- PASS: TestIsValidCachePath/short_hash (0.00s)836 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)837 --- PASS: TestIsValidCachePath/realisation (0.00s)838 --- PASS: TestIsValidCachePath/nar_xz (0.00s)839 --- PASS: TestIsValidCachePath/random_path (0.00s)840 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)841 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)842 --- PASS: TestIsValidCachePath/index.html (0.00s)843 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)844 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)845 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)846 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)847 --- PASS: TestIsValidCachePath/nar_zst (0.00s)848=== RUN TestIsValidUploadKey/unknown_type849=== PAUSE TestIsValidUploadKey/unknown_type850=== CONT TestIsValidUploadKey/narinfo851=== CONT TestIsValidUploadKey/build_log_home-manager_file852=== CONT TestIsValidUploadKey/listing853=== CONT TestIsValidUploadKey/nar_key,_narinfo_type854=== CONT TestIsValidUploadKey/unknown_type855=== CONT TestIsValidUploadKey/empty_key856=== CONT TestIsValidUploadKey/absolute857=== CONT TestIsValidUploadKey/traversal_nar858=== CONT TestIsValidUploadKey/traversal859=== CONT TestIsValidUploadKey/listing_key,_narinfo_type860=== CONT TestIsValidUploadKey/nix-cache-info861=== CONT TestIsValidUploadKey/index.html862=== CONT TestIsValidUploadKey/nar_plain863=== CONT TestIsValidUploadKey/build_log864=== CONT TestIsValidUploadKey/realisation_plus_in_output865=== CONT TestIsValidUploadKey/build_log_equals866=== CONT TestIsValidUploadKey/nar_xz867=== CONT TestIsValidUploadKey/narinfo_key,_nar_type868=== CONT TestIsValidUploadKey/build_log_question_mark869=== CONT TestIsValidUploadKey/nar_zst870=== CONT TestIsValidUploadKey/build_log_plus_in_name871=== CONT TestIsValidUploadKey/realisation872--- PASS: TestIsValidUploadKey (0.02s)873 --- PASS: TestIsValidUploadKey/narinfo (0.00s)874 --- PASS: TestIsValidUploadKey/listing (0.00s)875 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)876 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)877 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)878 --- PASS: TestIsValidUploadKey/empty_key (0.00s)879 --- PASS: TestIsValidUploadKey/absolute (0.00s)880 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)881 --- PASS: TestIsValidUploadKey/traversal (0.00s)882 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)883 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)884 --- PASS: TestIsValidUploadKey/index.html (0.00s)885 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)886 --- PASS: TestIsValidUploadKey/build_log (0.00s)887 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)888 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)889 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)890 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)891 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)892 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)893 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)894 --- PASS: TestIsValidUploadKey/realisation (0.00s)895--- PASS: TestGracefulShutdownDrainsInflight (0.07s)8962026/07/09 07:29:22 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:29:22.996 UTC [1246] ERROR: relation "goose_db_version" does not exist at character 368982026-07-09 07:29:22.996 UTC [1246] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8992026-07-09 07:29:23.006 UTC [1286] ERROR: relation "goose_db_version" does not exist at character 369002026-07-09 07:29:23.006 UTC [1286] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9012026-07-09 07:29:23.007 UTC [1289] ERROR: relation "goose_db_version" does not exist at character 369022026-07-09 07:29:23.007 UTC [1289] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC903=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure904=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure9052026-07-09 07:29:23.040 UTC [1266] ERROR: relation "goose_db_version" does not exist at character 369062026-07-09 07:29:23.040 UTC [1266] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC907=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart908=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart909=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts910=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts911=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart912=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts913=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure9142026/07/09 07:29:23 INFO Received request for more parts method=POST path=/9152026/07/09 07:29:23 INFO Received complete multipart upload request method=POST path=/9162026-07-09 07:29:23.041 UTC [1268] ERROR: relation "goose_db_version" does not exist at character 369172026-07-09 07:29:23.041 UTC [1268] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9182026-07-09 07:29:23.041 UTC [1264] ERROR: relation "goose_db_version" does not exist at character 369192026-07-09 07:29:23.041 UTC [1264] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9202026/07/09 07:29:23 INFO Received uploads request method=POST path=/9212026-07-09 07:29:23.041 UTC [1287] ERROR: relation "goose_db_version" does not exist at character 369222026-07-09 07:29:23.041 UTC [1287] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9232026-07-09 07:29:23.041 UTC [1267] ERROR: relation "goose_db_version" does not exist at character 369242026-07-09 07:29:23.041 UTC [1267] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9252026-07-09 07:29:23.041 UTC [1288] ERROR: relation "goose_db_version" does not exist at character 369262026-07-09 07:29:23.041 UTC [1288] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9272026/07/09 07:29:23 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.266988ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures9282026-07-09 07:29:23.128 UTC [1313] ERROR: relation "goose_db_version" does not exist at character 369292026-07-09 07:29:23.128 UTC [1313] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9302026-07-09 07:29:23.213 UTC [1314] ERROR: relation "goose_db_version" does not exist at character 369312026-07-09 07:29:23.213 UTC [1314] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9322026-07-09 07:29:23.227 UTC [1315] ERROR: relation "goose_db_version" does not exist at character 369332026-07-09 07:29:23.227 UTC [1315] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9342026-07-09 07:29:23.228 UTC [1316] ERROR: relation "goose_db_version" does not exist at character 369352026-07-09 07:29:23.228 UTC [1316] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9362026-07-09 07:29:23.229 UTC [1317] ERROR: relation "goose_db_version" does not exist at character 369372026-07-09 07:29:23.229 UTC [1317] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9382026-07-09 07:29:23.234 UTC [1318] ERROR: relation "goose_db_version" does not exist at character 369392026-07-09 07:29:23.234 UTC [1318] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9402026/07/09 07:29:23 OK 20241026095416_initial_model.sql (203.97ms)9412026/07/09 07:29:23 OK 20241026095416_initial_model.sql (192.54ms)9422026-07-09 07:29:23.264 UTC [1319] ERROR: relation "goose_db_version" does not exist at character 369432026-07-09 07:29:23.264 UTC [1319] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9442026/07/09 07:29:23 OK 20241026095416_initial_model.sql (142.63ms)9452026/07/09 07:29:23 OK 20241026095416_initial_model.sql (153.6ms)9462026/07/09 07:29:23 OK 20241026095416_initial_model.sql (146.6ms)9472026/07/09 07:29:23 OK 20241026095416_initial_model.sql (144.69ms)9482026/07/09 07:29:23 OK 20241026095416_initial_model.sql (147.54ms)9492026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (5.71ms)9502026/07/09 07:29:23 OK 20241026095416_initial_model.sql (142.78ms)9512026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (6.79ms)9522026/07/09 07:29:23 OK 20241026095416_initial_model.sql (146.84ms)9532026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (4.97ms)9542026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (5.39ms)9552026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (4.08ms)9562026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (4.19ms)9572026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (6.23ms)9582026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (6.07ms)9592026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (7.27ms)9602026/07/09 07:29:23 OK 20241026095416_initial_model.sql (71.13ms)9612026/07/09 07:29:23 OK 20241026095416_initial_model.sql (35.49ms)9622026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.83ms)9632026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (5.91ms)9642026/07/09 07:29:23 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=413.762762ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures9652026/07/09 07:29:23 OK 20251218171726_add_pins.sql (20.01ms)9662026-07-09 07:29:23.290 UTC [1320] ERROR: relation "goose_db_version" does not exist at character 369672026-07-09 07:29:23.290 UTC [1320] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9682026/07/09 07:29:23 OK 20251218171726_add_pins.sql (20.78ms)9692026-07-09 07:29:23.293 UTC [1321] ERROR: relation "goose_db_version" does not exist at character 369702026-07-09 07:29:23.293 UTC [1321] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9712026-07-09 07:29:23.293 UTC [1322] ERROR: relation "goose_db_version" does not exist at character 369722026-07-09 07:29:23.293 UTC [1322] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9732026/07/09 07:29:23 OK 20251218171726_add_pins.sql (24.3ms)9742026/07/09 07:29:23 OK 20251218171726_add_pins.sql (38.91ms)9752026/07/09 07:29:23 OK 20251218171726_add_pins.sql (41.83ms)9762026/07/09 07:29:23 OK 20251218171726_add_pins.sql (42.1ms)9772026/07/09 07:29:23 OK 20251218171726_add_pins.sql (37.79ms)9782026/07/09 07:29:23 OK 20251218171726_add_pins.sql (44.55ms)9792026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (32.56ms)9802026/07/09 07:29:23 goose: successfully migrated database to version: 202606281200009812026/07/09 07:29:23 OK 20251218171726_add_pins.sql (50.29ms)9822026-07-09 07:29:23.327 UTC [1323] ERROR: relation "goose_db_version" does not exist at character 369832026-07-09 07:29:23.327 UTC [1323] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9842026/07/09 07:29:23 OK 20251218171726_add_pins.sql (53.49ms)9852026/07/09 07:29:23 OK 1_commit_pending_closure.sql (7.39ms)9862026/07/09 07:29:23 OK 20251218171726_add_pins.sql (47.76ms)9872026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (34.15ms)9882026/07/09 07:29:23 goose: successfully migrated database to version: 202606281200009892026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (44.75ms)9902026/07/09 07:29:23 goose: successfully migrated database to version: 202606281200009912026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (21.32ms)9922026/07/09 07:29:23 goose: successfully migrated database to version: 202606281200009932026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (21.27ms)9942026/07/09 07:29:23 goose: successfully migrated database to version: 202606281200009952026/07/09 07:29:23 OK 2_object_stats_trigger.sql (5.07ms)9962026/07/09 07:29:23 goose: up to current file version: 29972026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (20.92ms)9982026/07/09 07:29:23 goose: successfully migrated database to version: 202606281200009992026/07/09 07:29:23 OK 1_commit_pending_closure.sql (5.91ms)10002026/07/09 07:29:23 OK 1_commit_pending_closure.sql (7.26ms)10012026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (21.47ms)10022026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000010032026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (21.16ms)10042026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000010052026/07/09 07:29:23 OK 1_commit_pending_closure.sql (19.1ms)10062026/07/09 07:29:23 OK 1_commit_pending_closure.sql (19.4ms)10072026/07/09 07:29:23 OK 20241026095416_initial_model.sql (87.44ms)10082026-07-09 07:29:23.357 UTC [1324] ERROR: relation "goose_db_version" does not exist at character 3610092026-07-09 07:29:23.357 UTC [1324] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10102026-07-09 07:29:23.358 UTC [1325] ERROR: relation "goose_db_version" does not exist at character 3610112026-07-09 07:29:23.358 UTC [1325] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10122026-07-09 07:29:23.358 UTC [1326] ERROR: relation "goose_db_version" does not exist at character 3610132026-07-09 07:29:23.358 UTC [1326] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10142026/07/09 07:29:23 OK 2_object_stats_trigger.sql (19.25ms)10152026/07/09 07:29:23 goose: up to current file version: 210162026/07/09 07:29:23 OK 20241026095416_initial_model.sql (91.11ms)10172026/07/09 07:29:23 OK 20241026095416_initial_model.sql (91.54ms)10182026/07/09 07:29:23 OK 1_commit_pending_closure.sql (17.74ms)10192026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (27.71ms)10202026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000010212026/07/09 07:29:23 OK 1_commit_pending_closure.sql (17.8ms)10222026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (32.49ms)10232026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000010242026/07/09 07:29:23 OK 2_object_stats_trigger.sql (19.39ms)10252026/07/09 07:29:23 goose: up to current file version: 210262026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (32.67ms)10272026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000010282026/07/09 07:29:23 OK 1_commit_pending_closure.sql (20.93ms)10292026/07/09 07:29:23 OK 2_object_stats_trigger.sql (8.02ms)10302026/07/09 07:29:23 goose: up to current file version: 210312026/07/09 07:29:23 OK 2_object_stats_trigger.sql (11.02ms)10322026/07/09 07:29:23 goose: up to current file version: 210332026/07/09 07:29:23 OK 20241026095416_initial_model.sql (42.74ms)10342026/07/09 07:29:23 OK 20241026095416_initial_model.sql (48.24ms)10352026/07/09 07:29:23 OK 20241026095416_initial_model.sql (59.46ms)10362026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (76.05ms)10372026/07/09 07:29:23 OK 1_commit_pending_closure.sql (75.5ms)10382026/07/09 07:29:23 OK 20241026095416_initial_model.sql (168.08ms)10392026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (80.54ms)10402026/07/09 07:29:23 OK 20241026095416_initial_model.sql (155.78ms)10412026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.36ms)10422026/07/09 07:29:23 goose: up to current file version: 210432026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.56ms)10442026/07/09 07:29:23 goose: up to current file version: 210452026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.55ms)10462026/07/09 07:29:23 goose: up to current file version: 210472026/07/09 07:29:23 OK 2_object_stats_trigger.sql (1.85ms)10482026/07/09 07:29:23 goose: up to current file version: 210492026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)10502026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.41ms)10512026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.04ms)10522026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.04ms)10532026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.48ms)10542026/07/09 07:29:23 OK 1_commit_pending_closure.sql (4.95ms)10552026/07/09 07:29:23 OK 1_commit_pending_closure.sql (5.18ms)10562026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (4.12ms)10572026/07/09 07:29:23 OK 20251218171726_add_pins.sql (4.86ms)10582026/07/09 07:29:23 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10592026/07/09 07:29:23 WARN mTLS auth: subject not in bound subjects subject="CN=writer"10602026/07/09 07:29:23 OK 20251218171726_add_pins.sql (5.26ms)1061--- PASS: TestService_NativeMTLS (0.63s)10622026/07/09 07:29:23 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1063--- PASS: TestService_ReadAuthMiddleware (0.63s)10642026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.21ms)10652026/07/09 07:29:23 goose: up to current file version: 21066--- PASS: TestReadProxyDisabled (0.62s)10672026-07-09 07:29:23.445 UTC [1327] ERROR: relation "goose_db_version" does not exist at character 3610682026-07-09 07:29:23.445 UTC [1327] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10692026/07/09 07:29:23 OK 20251218171726_add_pins.sql (7.75ms)10702026/07/09 07:29:23 OK 20251218171726_add_pins.sql (7.73ms)10712026/07/09 07:29:23 OK 2_object_stats_trigger.sql (5.94ms)10722026/07/09 07:29:23 goose: up to current file version: 210732026/07/09 07:29:23 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1074--- PASS: TestService_AuthMiddleware (0.64s)10752026-07-09 07:29:23.447 UTC [1337] ERROR: relation "goose_db_version" does not exist at character 3610762026-07-09 07:29:23.447 UTC [1337] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10772026-07-09 07:29:23.447 UTC [1335] ERROR: relation "goose_db_version" does not exist at character 3610782026-07-09 07:29:23.447 UTC [1335] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10792026/07/09 07:29:23 OK 20251218171726_add_pins.sql (7.97ms)10802026-07-09 07:29:23.449 UTC [1336] ERROR: relation "goose_db_version" does not exist at character 3610812026-07-09 07:29:23.449 UTC [1336] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10822026/07/09 07:29:23 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"10832026/07/09 07:29:23 WARN mTLS auth: bound subjects configured but subject DN unavailable10842026/07/09 07:29:23 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1085--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.64s)10862026-07-09 07:29:23.450 UTC [1339] ERROR: relation "goose_db_version" does not exist at character 3610872026-07-09 07:29:23.450 UTC [1339] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10882026-07-09 07:29:23.450 UTC [1338] ERROR: relation "goose_db_version" does not exist at character 3610892026-07-09 07:29:23.450 UTC [1338] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10902026-07-09 07:29:23.451 UTC [1340] ERROR: relation "goose_db_version" does not exist at character 3610912026-07-09 07:29:23.451 UTC [1340] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1092{"timestamp":"2026-07-09T07:29:23.451621095Z","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(688)"}1093{"timestamp":"2026-07-09T07:29:23.452721824Z","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(761)"}10942026/07/09 07:29:23 OK 20251218171726_add_pins.sql (13.23ms)10952026/07/09 07:29:23 OK 20251218171726_add_pins.sql (14.61ms)10962026/07/09 07:29:23 INFO Created nix-cache-info in bucket bucket=bucket910972026/07/09 07:29:23 OK 20251218171726_add_pins.sql (14.67ms)10982026/07/09 07:29:23 INFO Created nix-cache-info in bucket bucket=bucket410992026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (11.63ms)11002026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000011012026/07/09 07:29:23 OK 20241026095416_initial_model.sql (18.32ms)11022026-07-09 07:29:23.454 UTC [1328] ERROR: relation "goose_db_version" does not exist at character 3611032026-07-09 07:29:23.454 UTC [1328] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11042026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures11052026-07-09 07:29:23.454 UTC [1341] ERROR: relation "goose_db_version" does not exist at character 3611062026-07-09 07:29:23.454 UTC [1341] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11072026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (11.74ms)11082026-07-09 07:29:23.454 UTC [1333] ERROR: relation "goose_db_version" does not exist at character 3611092026-07-09 07:29:23.454 UTC [1333] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11102026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000011112026-07-09 07:29:23.454 UTC [1330] ERROR: relation "goose_db_version" does not exist at character 3611122026-07-09 07:29:23.454 UTC [1330] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11132026-07-09 07:29:23.454 UTC [1342] ERROR: relation "goose_db_version" does not exist at character 3611142026-07-09 07:29:23.454 UTC [1342] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11152026-07-09 07:29:23.454 UTC [1343] ERROR: relation "goose_db_version" does not exist at character 3611162026-07-09 07:29:23.454 UTC [1343] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11172026-07-09 07:29:23.454 UTC [1345] ERROR: relation "goose_db_version" does not exist at character 3611182026-07-09 07:29:23.454 UTC [1345] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11192026-07-09 07:29:23.454 UTC [1344] ERROR: relation "goose_db_version" does not exist at character 3611202026-07-09 07:29:23.454 UTC [1344] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11212026-07-09 07:29:23.454 UTC [1346] ERROR: relation "goose_db_version" does not exist at character 3611222026-07-09 07:29:23.454 UTC [1346] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11232026-07-09 07:29:23.455 UTC [1347] ERROR: relation "goose_db_version" does not exist at character 3611242026-07-09 07:29:23.455 UTC [1347] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11252026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (8.66ms)11262026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000011272026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (9.94ms)11282026-07-09 07:29:23.456 UTC [1348] ERROR: relation "goose_db_version" does not exist at character 3611292026-07-09 07:29:23.456 UTC [1348] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11302026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000011312026/07/09 07:29:23 OK 20241026095416_initial_model.sql (19.36ms)11322026-07-09 07:29:23.458 UTC [1349] ERROR: relation "goose_db_version" does not exist at character 3611332026-07-09 07:29:23.458 UTC [1349] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11342026/07/09 07:29:23 OK 20241026095416_initial_model.sql (18.97ms)11352026-07-09 07:29:23.458 UTC [1350] ERROR: relation "goose_db_version" does not exist at character 3611362026-07-09 07:29:23.458 UTC [1350] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11372026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (4.4ms)11382026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (9.35ms)11392026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000011402026/07/09 07:29:23 OK 1_commit_pending_closure.sql (4.78ms)11412026/07/09 07:29:23 OK 1_commit_pending_closure.sql (4.81ms)11422026/07/09 07:29:23 OK 1_commit_pending_closure.sql (4.08ms)11432026/07/09 07:29:23 OK 20241026095416_initial_model.sql (20.6ms)11442026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (6.87ms)11452026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000011462026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (6.74ms)11472026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000011482026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.15ms)11492026/07/09 07:29:23 goose: up to current file version: 211502026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (7.71ms)11512026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000011522026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.11ms)11532026/07/09 07:29:23 goose: up to current file version: 211542026/07/09 07:29:23 OK 1_commit_pending_closure.sql (4.4ms)11552026/07/09 07:29:23 INFO Aborted multipart uploads count=011562026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.16ms)11572026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.5ms)11582026/07/09 07:29:23 goose: up to current file version: 211592026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)11602026/07/09 07:29:23 OK 1_commit_pending_closure.sql (4.33ms)11612026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.63ms)11622026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures11632026/07/09 07:29:23 OK 1_commit_pending_closure.sql (3.31ms)11642026/07/09 07:29:23 OK 20251218171726_add_pins.sql (5.46ms)11652026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.58ms)11662026/07/09 07:29:23 goose: up to current file version: 211672026/07/09 07:29:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11682026/07/09 07:29:23 OK 1_commit_pending_closure.sql (3.49ms)11692026/07/09 07:29:23 OK 1_commit_pending_closure.sql (3.54ms)11702026/07/09 07:29:23 WARN Force mode enabled - objects will be deleted immediately without grace period11712026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.68ms)11722026/07/09 07:29:23 goose: up to current file version: 21173--- PASS: TestReadProxyHead (0.65s)11742026/07/09 07:29:23 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1175--- PASS: TestCompleteMultipartUnregistered (0.65s)11762026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.43ms)11772026/07/09 07:29:23 goose: up to current file version: 211782026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.57ms)11792026/07/09 07:29:23 goose: up to current file version: 211802026/07/09 07:29:23 INFO Received cleanup request method=DELETE path=/api/pending_closures11812026/07/09 07:29:23 OK 20251218171726_add_pins.sql (5.33ms)11822026/07/09 07:29:23 OK 2_object_stats_trigger.sql (3ms)11832026/07/09 07:29:23 goose: up to current file version: 211842026/07/09 07:29:23 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=011852026/07/09 07:29:23 OK 20251218171726_add_pins.sql (6.25ms)11862026/07/09 07:29:23 INFO Vacuumed table table=pending_closures11872026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures1188--- PASS: TestService_Rustfstest (0.65s)11892026/07/09 07:29:23 OK 20251218171726_add_pins.sql (6.59ms)1190--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.64s)11912026/07/09 07:29:23 INFO Aborted multipart uploads count=011922026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures11932026/07/09 07:29:23 INFO Vacuumed table table=pending_objects1194--- PASS: TestCacheStatsHandler (0.66s)11952026/07/09 07:29:23 INFO Vacuumed table table=multipart_uploads11962026/07/09 07:29:23 INFO Vacuumed table table=closures11972026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (8.17ms)11982026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000011992026/07/09 07:29:23 INFO Vacuumed table table=objects12002026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures12012026/07/09 07:29:23 OK 20241026095416_initial_model.sql (15.3ms)12022026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (6.07ms)12032026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000012042026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (7.65ms)12052026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000012062026/07/09 07:29:23 OK 20241026095416_initial_model.sql (14.76ms)12072026/07/09 07:29:23 OK 20241026095416_initial_model.sql (15.34ms)12082026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3ms)1209--- PASS: TestReadProxyRangeRequest (0.66s)12102026/07/09 07:29:23 OK 1_commit_pending_closure.sql (5.05ms)12112026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (7.47ms)12122026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000012132026/07/09 07:29:23 OK 20241026095416_initial_model.sql (14.29ms)12142026/07/09 07:29:23 OK 1_commit_pending_closure.sql (3.51ms)12152026/07/09 07:29:23 OK 1_commit_pending_closure.sql (3.49ms)12162026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)12172026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.55ms)12182026/07/09 07:29:23 OK 20241026095416_initial_model.sql (18.06ms)1219--- PASS: TestGCMetrics (0.67s)12202026/07/09 07:29:23 OK 2_object_stats_trigger.sql (3ms)12212026/07/09 07:29:23 goose: up to current file version: 212222026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.09ms)12232026/07/09 07:29:23 goose: up to current file version: 212242026/07/09 07:29:23 OK 20241026095416_initial_model.sql (16.77ms)12252026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.08ms)12262026/07/09 07:29:23 OK 2_object_stats_trigger.sql (3.02ms)12272026/07/09 07:29:23 goose: up to current file version: 212282026/07/09 07:29:23 OK 20241026095416_initial_model.sql (17.19ms)12292026/07/09 07:29:23 OK 20241026095416_initial_model.sql (16.78ms)12302026/07/09 07:29:23 OK 20241026095416_initial_model.sql (17.62ms)12312026/07/09 07:29:23 OK 20241026095416_initial_model.sql (16.66ms)12322026/07/09 07:29:23 INFO Received cleanup request method=DELETE path=/api/pending_closures12332026/07/09 07:29:23 OK 1_commit_pending_closure.sql (5.03ms)12342026/07/09 07:29:23 OK 20251218171726_add_pins.sql (5.87ms)12352026/07/09 07:29:23 OK 20241026095416_initial_model.sql (19.41ms)12362026/07/09 07:29:23 OK 20241026095416_initial_model.sql (16.94ms)12372026/07/09 07:29:23 OK 20241026095416_initial_model.sql (18.69ms)12382026/07/09 07:29:23 OK 20241026095416_initial_model.sql (17.55ms)12392026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.96ms)12402026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.1ms)12412026/07/09 07:29:23 INFO Aborted multipart uploads count=112422026/07/09 07:29:23 OK 20241026095416_initial_model.sql (18.67ms)12432026/07/09 07:29:23 OK 20251218171726_add_pins.sql (6.21ms)12442026/07/09 07:29:23 OK 20251218171726_add_pins.sql (6.24ms)12452026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (2.8ms)12462026/07/09 07:29:23 OK 20241026095416_initial_model.sql (16.81ms)12472026/07/09 07:29:23 OK 20241026095416_initial_model.sql (19.14ms)12482026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.22ms)12492026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.83ms)12502026/07/09 07:29:23 OK 2_object_stats_trigger.sql (3.31ms)12512026/07/09 07:29:23 goose: up to current file version: 212522026/07/09 07:29:23 OK 20241026095416_initial_model.sql (16.58ms)12532026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.31ms)12542026/07/09 07:29:23 INFO Created nix-cache-info in bucket bucket=bucket2112552026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.32ms)1256--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.66s)12572026/07/09 07:29:23 OK 20251218171726_add_pins.sql (5.13ms)12582026/07/09 07:29:23 OK 20241026095416_initial_model.sql (16.26ms)12592026/07/09 07:29:23 INFO Created nix-cache-info in bucket bucket=bucket2212602026/07/09 07:29:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12612026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (2.98ms)12622026/07/09 07:29:23 OK 20241026095416_initial_model.sql (19.13ms)12632026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (4.31ms)12642026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (2.71ms)1265--- PASS: TestMetricsInventory (0.66s)12662026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (4.28ms)12672026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)12682026-07-09 07:29:23.488 UTC [1321] ERROR: Closure does not exist: id=112692026-07-09 07:29:23.488 UTC [1321] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE12702026-07-09 07:29:23.488 UTC [1321] STATEMENT: -- name: CommitPendingClosure :exec1271 SELECT commit_pending_closure($1::bigint)1272 1273--- PASS: TestService_cleanupPendingClosuresHandler (0.67s)12742026/07/09 07:29:23 OK 20251218171726_add_pins.sql (4.56ms)12752026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (5.29ms)12762026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000012772026/07/09 07:29:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12782026/07/09 07:29:23 OK 20251218171726_add_pins.sql (5.3ms)12792026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.09ms)12802026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (4.3ms)1281--- PASS: TestReadProxy404 (0.66s)12822026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (5.11ms)12832026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000012842026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (5.32ms)12852026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000012862026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.27ms)12872026/07/09 07:29:23 OK 20251210153512_drop_unused_gin_index.sql (3.54ms)12882026/07/09 07:29:23 OK 20251218171726_add_pins.sql (4.68ms)12892026/07/09 07:29:23 OK 20251218171726_add_pins.sql (4.47ms)12902026/07/09 07:29:23 OK 20251218171726_add_pins.sql (5.66ms)12912026/07/09 07:29:23 OK 20251218171726_add_pins.sql (4.39ms)12922026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (4.35ms)12932026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000012942026/07/09 07:29:23 OK 20251218171726_add_pins.sql (5.92ms)1295{"timestamp":"2026-07-09T07:29:23.491682837Z","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(688)"}1296{"timestamp":"2026-07-09T07:29:23.491720257Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket13, 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(688)"}12972026/07/09 07:29:23 OK 20251218171726_add_pins.sql (4.7ms)12982026/07/09 07:29:23 OK 1_commit_pending_closure.sql (4.24ms)12992026/07/09 07:29:23 OK 20251218171726_add_pins.sql (4.82ms)13002026/07/09 07:29:23 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=M2MyNzcxNGEtYzE2Yi00ZmVmLTg3ODItZTQyY2M1MzQ4NWI1LmVhM2FlYmRhLTliMjgtNGM5OC1iOGJiLTMyZjRiYjBmM2UxMHgxNzgzNTgyMTYzNDc1MjU4NjAy13012026/07/09 07:29:23 OK 20251218171726_add_pins.sql (5.58ms)13022026/07/09 07:29:23 OK 20251218171726_add_pins.sql (4.99ms)13032026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (3.86ms)13042026/07/09 07:29:23 OK 1_commit_pending_closure.sql (2.97ms)13052026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000013062026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (4.87ms)13072026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000013082026/07/09 07:29:23 OK 1_commit_pending_closure.sql (2.86ms)13092026/07/09 07:29:23 OK 20251218171726_add_pins.sql (3.7ms)13102026/07/09 07:29:23 OK 1_commit_pending_closure.sql (2.7ms)13112026/07/09 07:29:23 OK 20251218171726_add_pins.sql (4.28ms)13122026/07/09 07:29:23 OK 2_object_stats_trigger.sql (1.61ms)13132026/07/09 07:29:23 goose: up to current file version: 213142026/07/09 07:29:23 OK 20251218171726_add_pins.sql (3.95ms)13152026/07/09 07:29:23 OK 20251218171726_add_pins.sql (3.87ms)13162026/07/09 07:29:23 OK 20251218171726_add_pins.sql (6.62ms)13172026/07/09 07:29:23 OK 2_object_stats_trigger.sql (1.38ms)13182026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)13192026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000013202026/07/09 07:29:23 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2MyNzcxNGEtYzE2Yi00ZmVmLTg3ODItZTQyY2M1MzQ4NWI1LmVhM2FlYmRhLTliMjgtNGM5OC1iOGJiLTMyZjRiYjBmM2UxMHgxNzgzNTgyMTYzNDc1MjU4NjAy parts=113212026/07/09 07:29:23 goose: up to current file version: 21322--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.67s)13232026/07/09 07:29:23 OK 2_object_stats_trigger.sql (1.54ms)13242026/07/09 07:29:23 goose: up to current file version: 213252026/07/09 07:29:23 OK 2_object_stats_trigger.sql (1.46ms)13262026/07/09 07:29:23 goose: up to current file version: 213272026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (4.44ms)13282026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000013292026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (4.68ms)13302026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000013312026/07/09 07:29:23 OK 1_commit_pending_closure.sql (2.43ms)13322026/07/09 07:29:23 OK 1_commit_pending_closure.sql (2.49ms)13332026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (4.77ms)13342026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000013352026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (4.89ms)13362026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000013372026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (4.98ms)13382026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000013392026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (5.38ms)13402026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000013412026/07/09 07:29:23 OK 1_commit_pending_closure.sql (2.75ms)13422026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (5.26ms)13432026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000013442026/07/09 07:29:23 OK 1_commit_pending_closure.sql (2.34ms)13452026/07/09 07:29:23 OK 1_commit_pending_closure.sql (2.21ms)13462026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.06ms)13472026/07/09 07:29:23 goose: up to current file version: 213482026/07/09 07:29:23 OK 1_commit_pending_closure.sql (3.2ms)13492026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (5.14ms)13502026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000013512026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (5.24ms)13522026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000013532026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (4.69ms)13542026/07/09 07:29:23 OK 1_commit_pending_closure.sql (2.46ms)13552026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000013562026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures13572026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.39ms)13582026/07/09 07:29:23 goose: up to current file version: 213592026/07/09 07:29:23 OK 1_commit_pending_closure.sql (2.69ms)13602026/07/09 07:29:23 OK 1_commit_pending_closure.sql (2.33ms)13612026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.82ms)13622026/07/09 07:29:23 goose: up to current file version: 213632026/07/09 07:29:23 OK 2_object_stats_trigger.sql (5.54ms)13642026/07/09 07:29:23 goose: up to current file version: 213652026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (7.19ms)13662026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000013672026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (8.23ms)13682026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000013692026/07/09 07:29:23 OK 20260628120000_add_object_size_and_stats.sql (6.95ms)13702026/07/09 07:29:23 goose: successfully migrated database to version: 2026062812000013712026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.26ms)13722026/07/09 07:29:23 goose: up to current file version: 213732026/07/09 07:29:23 OK 1_commit_pending_closure.sql (3.08ms)13742026/07/09 07:29:23 OK 1_commit_pending_closure.sql (6.18ms)13752026/07/09 07:29:23 OK 2_object_stats_trigger.sql (1.01ms)13762026/07/09 07:29:23 goose: up to current file version: 213772026/07/09 07:29:23 OK 2_object_stats_trigger.sql (4.52ms)13782026/07/09 07:29:23 goose: up to current file version: 213792026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.32ms)13802026/07/09 07:29:23 OK 1_commit_pending_closure.sql (4.13ms)1381--- PASS: TestService_healthCheckHandler (0.68s)13822026/07/09 07:29:23 goose: up to current file version: 213832026/07/09 07:29:23 OK 1_commit_pending_closure.sql (2.2ms)13842026/07/09 07:29:23 OK 2_object_stats_trigger.sql (2.22ms)13852026/07/09 07:29:23 goose: up to current file version: 213862026/07/09 07:29:23 OK 1_commit_pending_closure.sql (4.06ms)1387--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.68s)13882026/07/09 07:29:23 OK 2_object_stats_trigger.sql (4.72ms)13892026/07/09 07:29:23 goose: up to current file version: 213902026/07/09 07:29:23 OK 1_commit_pending_closure.sql (5.49ms)13912026/07/09 07:29:23 OK 1_commit_pending_closure.sql (5.34ms)13922026/07/09 07:29:23 OK 2_object_stats_trigger.sql (4.64ms)13932026/07/09 07:29:23 goose: up to current file version: 213942026/07/09 07:29:23 OK 2_object_stats_trigger.sql (3.61ms)13952026/07/09 07:29:23 goose: up to current file version: 213962026/07/09 07:29:23 OK 2_object_stats_trigger.sql (1.64ms)13972026/07/09 07:29:23 goose: up to current file version: 213982026/07/09 07:29:23 OK 2_object_stats_trigger.sql (1.15ms)13992026/07/09 07:29:23 goose: up to current file version: 214002026/07/09 07:29:23 OK 2_object_stats_trigger.sql (1.12ms)14012026/07/09 07:29:23 goose: up to current file version: 214022026/07/09 07:29:23 OK 2_object_stats_trigger.sql (1.3ms)14032026/07/09 07:29:23 goose: up to current file version: 214042026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures14052026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures14062026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures1407=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1408=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1409=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1410=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1411=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1412=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1413=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1414=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1415=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token14162026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures1417=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1418=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1419=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected14202026/07/09 07:29:23 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]14212026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures14222026/07/09 07:29:23 INFO Created nix-cache-info in bucket bucket=bucket341423--- PASS: TestReadProxyInvalidPath (0.69s)14242026/07/09 07:29:23 INFO OIDC auth successful provider=test14252026/07/09 07:29:23 WARN Authentication failed token_preview=eyJhbGciOi...MhJI_rVlhQ 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]14262026/07/09 07:29:23 INFO Created nix-cache-info in bucket bucket=bucket411427--- PASS: TestService_AuthMiddleware_OIDC (0.70s)1428 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1429 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1430 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1431 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1432--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.69s)1433--- PASS: TestReadProxyNarStreaming (0.69s)1434=== NAME TestNARDeduplicationMetadataUploadBug1435 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug138178760/001/store/hhd986lv726vf1dgx6993pqmv1rknx9a-file1.txt1436--- PASS: TestObjectStatsTrigger (0.70s)14372026/07/09 07:29:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1438=== NAME TestClientCADerivations1439 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2339689088/001/store/hqkzp816aib3408ign1s554m2xjg63v6-ca-test1440--- PASS: TestResurrectedObjectNotDeleted (0.72s)1441=== NAME TestClientMultipleUploads1442 client_integration_test.go:338: Created store path 0: /build/TestClientMultipleUploads2760649153/001/store/bmpi43wjg2dnpwy653l339vib5r6ks76-test-file-0.txt1443=== NAME TestClientWithDependencies1444 client_integration_test.go:593: Built derivation: /build/TestClientWithDependencies2251849220/001/store/byw139pnjfd6mnnp822dy59235iahxdv-test-script1445=== NAME TestClientIntegration1446 client_integration_test.go:276: Created store path: /build/TestClientIntegration1042303545/002/store/dn22p111775ccpl4chry6bninivzdr61-test-file.txt1447=== NAME TestPinProtectsFromGC1448 client_integration_test.go:646: Pinned store path: /build/TestPinProtectsFromGC3545271379/001/store/2wjkv9vmf04c745zmibg3dr70ch6hl2f-pinned-file.txt1449 client_integration_test.go:647: Unpinned store path: /build/TestPinProtectsFromGC3545271379/001/store/2xkqpaa8wcdkpmq4bz9k4bc5r256xzfm-unpinned-file.txt1450=== NAME TestClientWithDependencies1451 client_integration_test.go:595: Found 1 dependencies (including self)1452=== NAME TestClientMultipleUploads1453 client_integration_test.go:338: Created store path 1: /build/TestClientMultipleUploads2760649153/001/store/m8kip3ij3128dvicxqcw2a8b0y7f3wk2-test-file-1.txt1454=== NAME TestClientCADerivations1455 client_ca_test.go:139: Found 1 dependencies (including self)1456=== NAME TestClientMultipleUploads1457 client_integration_test.go:338: Created store path 2: /build/TestClientMultipleUploads2760649153/001/store/z1fpzkyflrgyphs3zddvxspgs1d33zgq-test-file-2.txt14582026/07/09 07:29:23 INFO Received cleanup request method=DELETE path=/api/pending_closures14592026/07/09 07:29:23 INFO Aborted multipart uploads count=11460--- PASS: TestMultipartCleanup (0.80s)14612026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures14622026/07/09 07:29:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14632026/07/09 07:29:23 INFO Uploading hhd986lv726vf1dgx6993pqmv1rknx9a-file1.txt (160B)14642026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures14652026/07/09 07:29:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14662026/07/09 07:29:23 INFO Uploading byw139pnjfd6mnnp822dy59235iahxdv-test-script (136B)14672026/07/09 07:29:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14682026/07/09 07:29:23 INFO Signed narinfos id=1 count=114692026/07/09 07:29:23 INFO Uploading 1 narinfos14702026/07/09 07:29:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14712026/07/09 07:29:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14722026/07/09 07:29:23 INFO Signed narinfos id=1 count=114732026/07/09 07:29:23 INFO Uploading 1 narinfos14742026/07/09 07:29:23 INFO Completed upload id=114752026/07/09 07:29:23 INFO Upload complete. (86ms)14762026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures14772026/07/09 07:29:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1478=== NAME TestNARDeduplicationMetadataUploadBug1479 metadata_upload_test.go:54: Retrieved narinfo from S3:1480 StorePath: /build/TestNARDeduplicationMetadataUploadBug138178760/001/store/hhd986lv726vf1dgx6993pqmv1rknx9a-file1.txt1481 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1482 Compression: zstd1483 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1484 NarSize: 1601485 References: 1486 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1487 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1488 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1489 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}14902026/07/09 07:29:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14912026/07/09 07:29:23 INFO Uploading dn22p111775ccpl4chry6bninivzdr61-test-file.txt (152B)14922026/07/09 07:29:23 INFO Completed upload id=114932026/07/09 07:29:23 INFO Upload complete. (55ms)14942026/07/09 07:29:23 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"14952026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures1496=== NAME TestClientWithDependencies1497 client_integration_test.go:597: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2251849220/001/store) requires matching store prefix14982026/07/09 07:29:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14992026/07/09 07:29:23 INFO Signed narinfos id=1 count=115002026/07/09 07:29:23 INFO Uploading 1 narinfos1501--- PASS: TestClientWithDependencies (0.86s)15022026/07/09 07:29:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15032026/07/09 07:29:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15042026/07/09 07:29:23 INFO Uploading 2wjkv9vmf04c745zmibg3dr70ch6hl2f-pinned-file.txt (128B)15052026/07/09 07:29:23 INFO Completed upload id=115062026/07/09 07:29:23 INFO Upload complete. (79ms)1507=== NAME TestClientIntegration1508 client_integration_test.go:292: Retrieved narinfo from S3:1509 StorePath: /build/TestClientIntegration1042303545/002/store/dn22p111775ccpl4chry6bninivzdr61-test-file.txt1510 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1511 Compression: zstd1512 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11513 NarSize: 1521514 References: 15152026/07/09 07:29:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1516 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk115172026/07/09 07:29:23 INFO Signed narinfos id=1 count=115182026/07/09 07:29:23 INFO Uploading 1 narinfos15192026/07/09 07:29:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1520 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1521 client_integration_test.go:293: Decompressed .ls content (64 bytes):1522 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1523 client_integration_test.go:296: Testing garbage collection...15242026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures15252026/07/09 07:29:23 INFO Completed upload id=115262026/07/09 07:29:23 INFO Upload complete. (80ms)1527=== NAME TestNARDeduplicationMetadataUploadBug1528 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug138178760/001/store/b17rnxinj8yvagvxpk7aqfpwzhswbzi1-file2.txt15292026/07/09 07:29:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15302026/07/09 07:29:23 INFO Uploading hqkzp816aib3408ign1s554m2xjg63v6-ca-test (144B)15312026/07/09 07:29:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15322026/07/09 07:29:23 INFO Signed narinfos id=1 count=115332026/07/09 07:29:23 INFO Uploading 1 narinfos15342026/07/09 07:29:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15352026/07/09 07:29:23 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=799.869914ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures15362026/07/09 07:29:23 INFO Completed upload id=115372026/07/09 07:29:23 INFO Upload complete. (82ms)1538=== NAME TestClientCADerivations1539 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2339689088/001/store/hqkzp816aib3408ign1s554m2xjg63v6-ca-test1540 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1541 Compression: zstd1542 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1543 NarSize: 1441544 References: 1545 Deriver: /build/TestClientCADerivations2339689088/001/store/jzyg03hr5rbmp6skvk537k97wi0qnw63-ca-test.drv1546 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1547 client_ca_test.go:185: Checking for realisation files in S3...1548 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1549 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15502026/07/09 07:29:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures15512026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures15522026/07/09 07:29:23 INFO Garbage collection started15532026/07/09 07:29:23 INFO Aborted multipart uploads count=015542026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures15552026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures15562026/07/09 07:29:23 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15572026/07/09 07:29:23 INFO Uploading bmpi43wjg2dnpwy653l339vib5r6ks76-test-file-0.txt (160B)15582026/07/09 07:29:23 INFO Uploading z1fpzkyflrgyphs3zddvxspgs1d33zgq-test-file-2.txt (160B)15592026/07/09 07:29:23 WARN Force mode enabled - objects will be deleted immediately without grace period15602026/07/09 07:29:23 INFO Uploading m8kip3ij3128dvicxqcw2a8b0y7f3wk2-test-file-1.txt (160B)1561--- PASS: TestGCBugBareHashReferences (0.90s)15622026/07/09 07:29:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15632026/07/09 07:29:23 INFO Signed narinfos id=2 count=115642026/07/09 07:29:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15652026/07/09 07:29:23 INFO Signed narinfos id=3 count=115662026/07/09 07:29:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15672026/07/09 07:29:23 INFO Signed narinfos id=1 count=115682026/07/09 07:29:23 INFO Uploading 3 narinfos15692026/07/09 07:29:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15702026/07/09 07:29:23 INFO Completed upload id=115712026/07/09 07:29:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15722026/07/09 07:29:23 INFO Completed upload id=215732026/07/09 07:29:23 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete15742026/07/09 07:29:23 INFO Completed upload id=315752026/07/09 07:29:23 INFO Upload complete. (91ms)1576=== NAME TestClientMultipleUploads1577 client_integration_test.go:349: Uploaded 3 paths in 130.410787ms1578--- PASS: TestClientMultipleUploads (0.92s)15792026/07/09 07:29:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15802026/07/09 07:29:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1581--- PASS: TestReadProxyNarinfo (0.94s)15822026/07/09 07:29:23 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=M2MyNzcxNGEtYzE2Yi00ZmVmLTg3ODItZTQyY2M1MzQ4NWI1LjdjZjNkM2RlLTNhZjMtNDY2Mi1iNTUyLTkzNzQ5YmE0NDJhNngxNzgzNTgyMTYzNTIwOTQ1NjU5 parts=1015832026/07/09 07:29:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15842026/07/09 07:29:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15852026/07/09 07:29:23 INFO Completed upload id=115862026/07/09 07:29:23 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=M2MyNzcxNGEtYzE2Yi00ZmVmLTg3ODItZTQyY2M1MzQ4NWI1LjE4ZGVjMTY2LWZlODEtNDA1Mi05YTM4LWU3MjZjYzc5YjkzYngxNzgzNTgyMTYzNTE1ODQ0Nzk0 parts=1015872026/07/09 07:29:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15882026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures15892026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures15902026/07/09 07:29:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15912026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures15922026/07/09 07:29:23 INFO Uploading 2xkqpaa8wcdkpmq4bz9k4bc5r256xzfm-unpinned-file.txt (128B)15932026/07/09 07:29:23 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo15942026/07/09 07:29:23 WARN Found objects in DB but missing from S3, will re-upload count=115952026/07/09 07:29:23 INFO Completed upload id=115962026/07/09 07:29:23 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001597--- PASS: TestService_verifyS3Integrity (0.96s)15982026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures15992026/07/09 07:29:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures16002026/07/09 07:29:23 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=M2MyNzcxNGEtYzE2Yi00ZmVmLTg3ODItZTQyY2M1MzQ4NWI1LjM2MTdjZjI1LTNhMjktNDBhYS1hOWU4LTU5Y2MxYjBmNjFhYXgxNzgzNTgyMTYzNDY0OTA0MDEy parts=1216012026/07/09 07:29:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16022026/07/09 07:29:23 INFO Signed narinfos id=2 count=116032026/07/09 07:29:23 INFO Uploading 1 narinfos1604--- PASS: TestRedundantMultipartUpload (0.95s)16052026/07/09 07:29:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16062026/07/09 07:29:23 INFO Received uploads request method=POST path=/api/pending_closures16072026/07/09 07:29:23 INFO Completed upload id=216082026/07/09 07:29:23 INFO Upload complete. (65ms)16092026/07/09 07:29:23 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1610=== NAME TestOrphanedObjectsGC1611 orphaned_objects_gc_test.go:290: GC Test Summary:1612 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1613 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1614 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1615 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1616 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1617--- PASS: TestOrphanedObjectsGC (0.95s)16182026/07/09 07:29:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16192026/07/09 07:29:23 INFO Signed narinfos id=2 count=116202026/07/09 07:29:23 INFO Uploading 1 narinfos16212026/07/09 07:29:23 INFO Aborted multipart uploads count=016222026/07/09 07:29:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16232026/07/09 07:29:23 INFO Completed upload id=216242026/07/09 07:29:23 INFO Upload complete. (68ms)1625=== NAME TestNARDeduplicationMetadataUploadBug1626 metadata_upload_test.go:76: Retrieved narinfo from S3:1627 StorePath: /build/TestNARDeduplicationMetadataUploadBug138178760/001/store/b17rnxinj8yvagvxpk7aqfpwzhswbzi1-file2.txt1628 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1629 Compression: zstd1630 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1631 NarSize: 1601632 References: 1633 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1634 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1635 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1636 {"version":1,"root":{"type":"regular","size":44}}16372026/07/09 07:29:23 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=01638--- PASS: TestNARDeduplicationMetadataUploadBug (0.97s)16392026/07/09 07:29:23 INFO Vacuumed table table=pending_closures16402026/07/09 07:29:23 INFO Vacuumed table table=pending_objects16412026/07/09 07:29:23 INFO Vacuumed table table=multipart_uploads16422026/07/09 07:29:23 INFO Vacuumed table table=closures16432026/07/09 07:29:23 INFO Vacuumed table table=objects16442026/07/09 07:29:23 INFO Received create pin request method=POST path=/api/pins/myapp16452026/07/09 07:29:23 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3545271379/001/store/2wjkv9vmf04c745zmibg3dr70ch6hl2f-pinned-file.txt narinfo_key=2wjkv9vmf04c745zmibg3dr70ch6hl2f.narinfo16462026/07/09 07:29:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures16472026/07/09 07:29:23 INFO Garbage collection started1648--- PASS: TestReadProxyConditionalGet (0.99s)16492026/07/09 07:29:23 INFO Aborted multipart uploads count=016502026/07/09 07:29:23 WARN Force mode enabled - objects will be deleted immediately without grace period16512026/07/09 07:29:23 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001652--- PASS: TestService_createPendingClosureHandler (1.00s)1653=== NAME TestClientCADerivations1654 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1655 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1656 error: binary cache 's3://bucket9?endpoint=http://localhost:41945®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2339689088/001/store'1657 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11658--- PASS: TestClientCADerivations (1.02s)1659--- PASS: TestUploadHandlersRejectOversizedBody (0.22s)1660 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)1661 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1662 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.84s)1663=== NAME TestOrphanedObjectsGCStressTest1664 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1665 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion16662026/07/09 07:29:24 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=016672026/07/09 07:29:24 INFO Vacuumed table table=pending_closures16682026/07/09 07:29:24 INFO Vacuumed table table=pending_objects16692026/07/09 07:29:24 INFO Vacuumed table table=multipart_uploads16702026/07/09 07:29:24 INFO Vacuumed table table=closures16712026/07/09 07:29:24 INFO Vacuumed table table=objects16722026/07/09 07:29:24 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=016732026/07/09 07:29:24 INFO Vacuumed table table=pending_closures16742026/07/09 07:29:24 INFO Vacuumed table table=pending_objects16752026/07/09 07:29:24 INFO Vacuumed table table=multipart_uploads16762026/07/09 07:29:24 INFO Vacuumed table table=closures16772026/07/09 07:29:24 INFO Vacuumed table table=objects1678 orphaned_objects_gc_test.go:509: Stress test completed successfully:1679 orphaned_objects_gc_test.go:510: - Active objects preserved: 201680 orphaned_objects_gc_test.go:511: - Objects deleted: 2101681 orphaned_objects_gc_test.go:512: - Total GC'd: 2101682--- PASS: TestOrphanedObjectsGCStressTest (1.45s)16832026/07/09 07:29:24 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.734973491s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16842026/07/09 07:29:25 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01685=== NAME TestClientIntegration1686 client_integration_test.go:303: Objects in database after GC:1687 client_integration_test.go:303: Successfully deleted all objects with GC --force1688--- PASS: TestClientIntegration (2.90s)16892026/07/09 07:29:25 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01690=== NAME TestPinProtectsFromGC1691 client_integration_test.go:709: Pin successfully protected closure from garbage collection1692--- PASS: TestPinProtectsFromGC (2.99s)1693--- PASS: TestClientErrorHandling (0.00s)1694 --- PASS: TestClientErrorHandling/InvalidStorePath (0.71s)1695 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.84s)1696 --- PASS: TestClientErrorHandling/ServerNotAvailable (3.41s)16972026/07/09 07:29:27 WARN Rate limiter enabled after throttle name=s3-test rate=516982026/07/09 07:29:27 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1699=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1700 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101701 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001702--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.83s)1703PASS1704{"timestamp":"2026-07-09T07:29:28.154224457Z","level":"ERROR","fields":{"message":"Unknown connection IO error:Cancelled","peer_addr":"127.0.0.1:60390"},"target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":973,"threadName":"rustfs-worker","threadId":"ThreadId(761)"}17052026-07-09 07:29:28.274 UTC [298] LOG: received smart shutdown request17062026-07-09 07:29:28.278 UTC [298] LOG: background worker "logical replication launcher" (PID 308) exited with exit code 117072026-07-09 07:29:28.282 UTC [303] LOG: shutting down17082026-07-09 07:29:28.282 UTC [303] LOG: checkpoint starting: shutdown immediate17092026-07-09 07:29:29.971 UTC [303] LOG: checkpoint complete: wrote 8739 buffers (53.3%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 12 recycled; write=0.163 s, sync=1.514 s, total=1.690 s; sync files=14509, longest=0.007 s, average=0.001 s; distance=199419 kB, estimate=199419 kB; lsn=0/DA1E140, redo lsn=0/DA1E14017102026-07-09 07:29:30.061 UTC [298] LOG: database system is shut down1711Running OIDC tests...1712=== RUN TestGlobMatch1713=== PAUSE TestGlobMatch1714=== RUN TestAudienceForIssuer1715=== PAUSE TestAudienceForIssuer1716=== RUN TestValidateToken_ValidToken1717=== PAUSE TestValidateToken_ValidToken1718=== RUN TestValidateToken_WrongAudience1719=== PAUSE TestValidateToken_WrongAudience1720=== RUN TestValidateToken_Expired1721=== PAUSE TestValidateToken_Expired1722=== RUN TestValidateToken_BoundClaimsMismatch1723=== PAUSE TestValidateToken_BoundClaimsMismatch1724=== RUN TestValidateToken_BoundSubjectMismatch1725=== PAUSE TestValidateToken_BoundSubjectMismatch1726=== RUN TestValidateToken_MultipleProviders1727=== PAUSE TestValidateToken_MultipleProviders1728=== RUN TestValidateToken_NoMatchingProvider1729=== PAUSE TestValidateToken_NoMatchingProvider1730=== CONT TestGlobMatch1731=== RUN TestGlobMatch/foo_foo1732=== PAUSE TestGlobMatch/foo_foo1733=== CONT TestValidateToken_Expired1734=== CONT TestValidateToken_MultipleProviders1735=== CONT TestValidateToken_NoMatchingProvider1736=== CONT TestValidateToken_ValidToken1737=== CONT TestValidateToken_BoundSubjectMismatch1738=== CONT TestValidateToken_BoundClaimsMismatch1739=== CONT TestAudienceForIssuer1740=== RUN TestGlobMatch/foo_bar1741=== PAUSE TestGlobMatch/foo_bar1742=== CONT TestValidateToken_WrongAudience1743=== RUN TestGlobMatch/*_1744=== PAUSE TestGlobMatch/*_1745=== RUN TestGlobMatch/*_anything1746=== PAUSE TestGlobMatch/*_anything1747=== RUN TestGlobMatch/foo*_foo1748=== PAUSE TestGlobMatch/foo*_foo1749=== RUN TestGlobMatch/foo*_foobar1750=== PAUSE TestGlobMatch/foo*_foobar1751=== RUN TestGlobMatch/foo*_bar1752--- PASS: TestAudienceForIssuer (0.00s)1753=== PAUSE TestGlobMatch/foo*_bar1754=== RUN TestGlobMatch/*bar_bar1755=== PAUSE TestGlobMatch/*bar_bar1756=== RUN TestGlobMatch/*bar_foobar1757=== PAUSE TestGlobMatch/*bar_foobar1758=== RUN TestGlobMatch/*bar_foo1759=== PAUSE TestGlobMatch/*bar_foo1760=== RUN TestGlobMatch/foo*bar_foobar1761=== PAUSE TestGlobMatch/foo*bar_foobar1762=== RUN TestGlobMatch/foo*bar_foo123bar1763=== PAUSE TestGlobMatch/foo*bar_foo123bar1764=== RUN TestGlobMatch/foo*bar_foobarbaz1765=== PAUSE TestGlobMatch/foo*bar_foobarbaz1766=== RUN TestGlobMatch/*/*_foo/bar1767=== PAUSE TestGlobMatch/*/*_foo/bar1768=== RUN TestGlobMatch/*/*_foo1769=== PAUSE TestGlobMatch/*/*_foo1770=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1771=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1772=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01773=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01774=== RUN TestGlobMatch/refs/*/main_refs/heads/main1775=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1776=== RUN TestGlobMatch/fo?_foo1777=== PAUSE TestGlobMatch/fo?_foo1778=== RUN TestGlobMatch/fo?_fo1779=== PAUSE TestGlobMatch/fo?_fo1780=== RUN TestGlobMatch/fo?_fooo1781=== PAUSE TestGlobMatch/fo?_fooo1782=== RUN TestGlobMatch/?oo_foo1783=== PAUSE TestGlobMatch/?oo_foo1784=== RUN TestGlobMatch/?oo_boo1785=== PAUSE TestGlobMatch/?oo_boo1786=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1787=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1788=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1789=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1790=== CONT TestGlobMatch/foo_foo1791=== CONT TestGlobMatch/foo*_bar1792=== CONT TestGlobMatch/foo*_foo1793=== CONT TestGlobMatch/*bar_bar1794=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1795=== CONT TestGlobMatch/*/*_foo/bar1796=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1797=== CONT TestGlobMatch/foo*bar_foobarbaz1798=== CONT TestGlobMatch/foo*bar_foo123bar1799=== CONT TestGlobMatch/?oo_boo1800=== CONT TestGlobMatch/foo*bar_foobar1801=== CONT TestGlobMatch/?oo_foo1802=== CONT TestGlobMatch/fo?_fooo1803=== CONT TestGlobMatch/fo?_fo1804=== CONT TestGlobMatch/fo?_foo1805=== CONT TestGlobMatch/*bar_foobar1806=== CONT TestGlobMatch/refs/*/main_refs/heads/main1807=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01808=== CONT TestGlobMatch/*bar_foo1809=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1810=== CONT TestGlobMatch/foo*_foobar1811=== CONT TestGlobMatch/*_1812=== CONT TestGlobMatch/foo_bar1813=== CONT TestGlobMatch/*_anything1814=== CONT TestGlobMatch/*/*_foo1815--- PASS: TestGlobMatch (0.00s)1816 --- PASS: TestGlobMatch/foo_foo (0.00s)1817 --- PASS: TestGlobMatch/foo*_bar (0.00s)1818 --- PASS: TestGlobMatch/foo*_foo (0.00s)1819 --- PASS: TestGlobMatch/*bar_bar (0.00s)1820 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1821 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1822 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1823 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1824 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1825 --- PASS: TestGlobMatch/?oo_boo (0.00s)1826 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1827 --- PASS: TestGlobMatch/?oo_foo (0.00s)1828 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1829 --- PASS: TestGlobMatch/fo?_fo (0.00s)1830 --- PASS: TestGlobMatch/fo?_foo (0.00s)1831 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1832 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1833 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1834 --- PASS: TestGlobMatch/*bar_foo (0.00s)1835 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1836 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1837 --- PASS: TestGlobMatch/*_ (0.00s)1838 --- PASS: TestGlobMatch/foo_bar (0.00s)1839 --- PASS: TestGlobMatch/*_anything (0.00s)1840 --- PASS: TestGlobMatch/*/*_foo (0.00s)18412026/07/09 07:29:30 INFO OIDC provider initialized name=provider118422026/07/09 07:29:30 INFO OIDC provider initialized name=provider118432026/07/09 07:29:30 INFO OIDC provider initialized name=test18442026/07/09 07:29:30 INFO OIDC provider initialized name=test18452026/07/09 07:29:30 INFO OIDC provider initialized name=test18462026/07/09 07:29:30 INFO OIDC provider initialized name=test18472026/07/09 07:29:30 INFO OIDC provider initialized name=provider218482026/07/09 07:29:30 INFO OIDC provider initialized name=test1849--- PASS: TestValidateToken_WrongAudience (0.01s)1850--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1851--- PASS: TestValidateToken_Expired (0.01s)1852--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1853--- PASS: TestValidateToken_ValidToken (0.01s)1854--- PASS: TestValidateToken_MultipleProviders (0.01s)1855--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1856PASS1857Running hook tests...1858=== RUN TestSendPathsEmpty1859=== PAUSE TestSendPathsEmpty1860=== RUN TestQueueEnqueueAndFetch1861=== PAUSE TestQueueEnqueueAndFetch1862=== RUN TestQueueDeduplication1863=== PAUSE TestQueueDeduplication1864=== RUN TestQueueRemove1865=== PAUSE TestQueueRemove1866=== RUN TestQueueFetchBatchLimit1867=== PAUSE TestQueueFetchBatchLimit1868=== RUN TestQueueFetchRemoveLifecycle1869=== PAUSE TestQueueFetchRemoveLifecycle1870=== RUN TestQueueConcurrentWriters1871=== PAUSE TestQueueConcurrentWriters1872=== RUN TestServerClientIntegration1873=== PAUSE TestServerClientIntegration1874=== RUN TestServerQueueError1875=== PAUSE TestServerQueueError1876=== RUN TestGetListenerSocketActivation1877 server_test.go:210: === RUN TestGetListenerSocketActivation1878 --- PASS: TestGetListenerSocketActivation (0.00s)1879 PASS1880 1881--- PASS: TestGetListenerSocketActivation (0.02s)1882=== RUN TestWorkerUploadsAndRemoves1883=== PAUSE TestWorkerUploadsAndRemoves1884=== RUN TestWorkerSkipsGCdPaths1885=== PAUSE TestWorkerSkipsGCdPaths1886=== RUN TestWorkerPrunesClosureDeps1887=== PAUSE TestWorkerPrunesClosureDeps1888=== CONT TestSendPathsEmpty1889=== CONT TestQueueConcurrentWriters1890--- PASS: TestSendPathsEmpty (0.00s)1891=== CONT TestQueueRemove1892=== CONT TestQueueFetchRemoveLifecycle1893=== CONT TestQueueEnqueueAndFetch1894=== CONT TestWorkerUploadsAndRemoves1895=== CONT TestWorkerPrunesClosureDeps1896=== CONT TestQueueFetchBatchLimit1897=== CONT TestWorkerSkipsGCdPaths1898=== CONT TestQueueDeduplication1899=== CONT TestServerQueueError1900=== CONT TestServerClientIntegration19012026/07/09 07:29:31 ERROR Failed to queue paths error="permission denied" count=11902--- PASS: TestServerClientIntegration (0.00s)1903--- PASS: TestServerQueueError (0.00s)19042026/07/09 07:29:31 INFO Upload queue status pending=219052026/07/09 07:29:31 INFO Uploading batch count=11906--- PASS: TestQueueFetchBatchLimit (0.01s)19072026/07/09 07:29:31 INFO Upload queue status pending=219082026/07/09 07:29:31 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3757875908/002/nonexistent1909--- PASS: TestQueueFetchRemoveLifecycle (0.02s)1910--- PASS: TestQueueDeduplication (0.02s)1911--- PASS: TestQueueEnqueueAndFetch (0.02s)1912--- PASS: TestQueueRemove (0.02s)19132026/07/09 07:29:31 INFO Upload queue status pending=219142026/07/09 07:29:31 INFO Uploading batch count=219152026/07/09 07:29:31 INFO Uploading batch count=11916--- PASS: TestWorkerPrunesClosureDeps (0.06s)1917--- PASS: TestWorkerSkipsGCdPaths (0.07s)1918--- PASS: TestWorkerUploadsAndRemoves (0.07s)1919--- PASS: TestQueueConcurrentWriters (0.37s)1920PASS