niks3-go-unit-tests
aarch64-linux.go-unit-tests
· build #96
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestCaseHackSuffix6=== PAUSE TestCaseHackSuffix7=== RUN TestPartSizeForNAR8=== PAUSE TestPartSizeForNAR9=== RUN TestUploadMultipart_SupersededByPeer10=== PAUSE TestUploadMultipart_SupersededByPeer11=== RUN TestDumpPathMatchesNix12=== PAUSE TestDumpPathMatchesNix13=== RUN TestDumpPathSingleFile14=== PAUSE TestDumpPathSingleFile15=== RUN TestDumpPathWriterError16=== PAUSE TestDumpPathWriterError17=== RUN TestEncodeNixBase3218=== PAUSE TestEncodeNixBase3219=== RUN TestEncodeNixBase32WithRealHash20=== PAUSE TestEncodeNixBase32WithRealHash21=== RUN TestConvertHashToNix3222=== PAUSE TestConvertHashToNix3223=== RUN TestGetStorePathHash24=== PAUSE TestGetStorePathHash25=== RUN TestPathInfoHashCompatibility26=== PAUSE TestPathInfoHashCompatibility27=== RUN TestParsePathInfoJSON28=== PAUSE TestParsePathInfoJSON29=== RUN TestParsePathInfoJSONMultiplePaths30=== PAUSE TestParsePathInfoJSONMultiplePaths31=== RUN TestPathInfoCACompatibility32=== PAUSE TestPathInfoCACompatibility33=== RUN TestRateLimiterFeedback34=== PAUSE TestRateLimiterFeedback35=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess36=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess37=== RUN TestResolveStorePath38=== PAUSE TestResolveStorePath39=== RUN TestDoWithRetry_BodyReplayedViaGetBody40=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody41=== RUN TestShellSplit42=== PAUSE TestShellSplit43=== RUN TestShellSplitErrors44=== PAUSE TestShellSplitErrors45=== RUN TestSetClientTLS46=== PAUSE TestSetClientTLS47=== RUN TestSetClientTLSDoesNotMutateDefaultTransport48=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport49=== RUN TestSetClientTLSErrors50=== PAUSE TestSetClientTLSErrors51=== RUN TestStaticToken52=== PAUSE TestStaticToken53=== RUN TestFileTokenReadsAndCaches54=== PAUSE TestFileTokenReadsAndCaches55=== RUN TestFileTokenMissing56=== PAUSE TestFileTokenMissing57=== RUN TestFileTokenEmpty58=== PAUSE TestFileTokenEmpty59=== RUN TestScriptTokenNoExpiryRerunsEveryCall60=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall61=== RUN TestScriptTokenCachesUntilRefresh62=== PAUSE TestScriptTokenCachesUntilRefresh63=== RUN TestScriptTokenEmptyToken64=== PAUSE TestScriptTokenEmptyToken65=== RUN TestScriptTokenBadJSON66=== PAUSE TestScriptTokenBadJSON67=== RUN TestScriptTokenScriptFails68=== PAUSE TestScriptTokenScriptFails69=== RUN TestScriptTokenEmptyCommand70=== PAUSE TestScriptTokenEmptyCommand71=== CONT TestDoServerRequestAttachesToken72=== CONT TestScriptTokenEmptyCommand73=== CONT TestResolveStorePath74--- PASS: TestScriptTokenEmptyCommand (0.00s)75=== CONT TestDumpPathSingleFile76=== CONT TestConvertHashToNix3277=== RUN TestConvertHashToNix32/SRI_format_to_Nix3278=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix3279=== RUN TestConvertHashToNix32/already_Nix32_format80=== PAUSE TestConvertHashToNix32/already_Nix32_format81=== RUN TestConvertHashToNix32/invalid_format82=== CONT TestParsePathInfoJSONMultiplePaths83=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess84=== CONT TestRateLimiterFeedback85=== RUN TestRateLimiterFeedback/429_enables_limiter86=== CONT TestPathInfoCACompatibility87=== RUN TestPathInfoCACompatibility/null_ca_field88=== CONT TestEncodeNixBase32WithRealHash89=== CONT TestFileTokenReadsAndCaches90=== CONT TestEncodeNixBase3291=== CONT TestScriptTokenScriptFails92=== CONT TestDumpPathWriterError93=== CONT TestScriptTokenBadJSON94=== CONT TestSetClientTLS95=== CONT TestScriptTokenEmptyToken96=== CONT TestStaticToken97=== CONT TestSetClientTLSErrors98=== CONT TestScriptTokenCachesUntilRefresh99=== CONT TestSetClientTLSDoesNotMutateDefaultTransport100=== CONT TestScriptTokenNoExpiryRerunsEveryCall101=== CONT TestFileTokenEmpty102=== CONT TestFileTokenMissing103=== CONT TestPathInfoHashCompatibility104=== CONT TestUploadMultipart_SupersededByPeer105=== CONT TestParsePathInfoJSON106=== CONT TestDumpPathMatchesNix107=== CONT TestGetStorePathHash108=== CONT TestPartSizeForNAR109=== CONT TestShellSplit110=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)111=== RUN TestUploadMultipart_SupersededByPeer/exists112=== CONT TestDoWithRetry_BodyReplayedViaGetBody113=== PAUSE TestUploadMultipart_SupersededByPeer/exists114=== RUN TestUploadMultipart_SupersededByPeer/missing115=== CONT TestCaseHackSuffix116--- PASS: TestEncodeNixBase32WithRealHash (0.00s)117--- PASS: TestStaticToken (0.00s)118--- PASS: TestShellSplit (0.00s)119=== RUN TestParsePathInfoJSON/Nix_format120=== PAUSE TestParsePathInfoJSON/Nix_format121=== RUN TestParsePathInfoJSON/Lix_format122=== PAUSE TestParsePathInfoJSON/Lix_format123=== RUN TestParsePathInfoJSON/empty_input124=== PAUSE TestParsePathInfoJSON/empty_input125=== RUN TestParsePathInfoJSON/whitespace_only126=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths127=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1282026/07/09 07:47:22 WARN Rate limiter enabled after throttle name=server-test rate=5129=== PAUSE TestRateLimiterFeedback/429_enables_limiter130=== RUN TestRateLimiterFeedback/503_enables_limiter131=== PAUSE TestRateLimiterFeedback/503_enables_limiter132=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter133=== RUN TestEncodeNixBase32/test_string_hash134=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)135=== CONT TestShellSplitErrors136=== PAUSE TestConvertHashToNix32/invalid_format137=== PAUSE TestPathInfoCACompatibility/null_ca_field138=== PAUSE TestParsePathInfoJSON/whitespace_only139=== RUN TestGetStorePathHash/valid_store_path140=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths141=== RUN TestPartSizeForNAR/zero_stays_at_minimum142--- PASS: TestFileTokenReadsAndCaches (0.00s)143=== PAUSE TestUploadMultipart_SupersededByPeer/missing144=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon145=== CONT TestUploadMultipart_SupersededByPeer/missing146=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter147=== CONT TestConvertHashToNix32/SRI_format_to_Nix32148=== CONT TestConvertHashToNix32/already_Nix32_format149=== CONT TestConvertHashToNix32/invalid_format150=== PAUSE TestEncodeNixBase32/test_string_hash151=== RUN TestEncodeNixBase32/empty_input152=== PAUSE TestEncodeNixBase32/empty_input153=== CONT TestEncodeNixBase32/test_string_hash154=== RUN TestPathInfoCACompatibility/old_string_format_-_text155=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text156=== RUN TestParsePathInfoJSON/invalid_JSON157=== CONT TestEncodeNixBase32/empty_input158--- PASS: TestFileTokenEmpty (0.00s)159=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon160=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum161=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI162=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths163=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1642026/07/09 07:47:22 WARN Rate limiter enabled after throttle name=server-test rate=5165=== CONT TestUploadMultipart_SupersededByPeer/exists166=== PAUSE TestGetStorePathHash/valid_store_path167=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter1682026/07/09 07:47:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35561169=== RUN TestSetClientTLSErrors/missing_cert_file170=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive171=== PAUSE TestParsePathInfoJSON/invalid_JSON172--- PASS: TestResolveStorePath (0.01s)173=== RUN TestSetClientTLS/rejects_connection_without_client_cert174=== RUN TestPartSizeForNAR/small_stays_at_minimum175=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI176=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths177=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512178=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512179=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)180=== RUN TestGetStorePathHash/basename_without_hyphen_should_error181=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI182=== PAUSE TestSetClientTLSErrors/missing_cert_file183=== CONT TestParsePathInfoJSON/Nix_format1842026/07/09 07:47:22 WARN Rate limiter backed off name=server-test rate=51852026/07/09 07:47:22 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35561186=== CONT TestParsePathInfoJSON/whitespace_only187=== CONT TestParsePathInfoJSON/empty_input188=== CONT TestParsePathInfoJSON/invalid_JSON189--- PASS: TestScriptTokenScriptFails (0.01s)190=== CONT TestParsePathInfoJSON/Lix_format191=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive192=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert193=== PAUSE TestPartSizeForNAR/small_stays_at_minimum194=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512195=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon196=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter197=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error198=== RUN TestSetClientTLSErrors/missing_key_file199--- PASS: TestFileTokenMissing (0.01s)200--- PASS: TestShellSplitErrors (0.00s)201=== RUN TestPathInfoCACompatibility/new_structured_format_-_text202=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA203=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum204=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum205=== CONT TestRateLimiterFeedback/429_enables_limiter206=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter207=== CONT TestRateLimiterFeedback/503_enables_limiter208=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter209=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error210=== PAUSE TestSetClientTLSErrors/missing_key_file211--- PASS: TestScriptTokenBadJSON (0.01s)212=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text213=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA214=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error215=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts216=== RUN TestSetClientTLSErrors/missing_ca_file217--- PASS: TestScriptTokenEmptyToken (0.01s)218--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)219=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method220=== RUN TestSetClientTLS/preserves_debug_logging_transport221=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts222=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error2232026/07/09 07:47:22 WARN Rate limiter enabled after throttle name=server-test rate=5224=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error225=== PAUSE TestSetClientTLSErrors/missing_ca_file2262026/07/09 07:47:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:43495227--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)2282026/07/09 07:47:22 WARN Rate limiter enabled after throttle name=server-test rate=5229--- PASS: TestEncodeNixBase32 (0.01s)230 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)231 --- PASS: TestEncodeNixBase32/empty_input (0.00s)232=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method2332026/07/09 07:47:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:44523234=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method235=== PAUSE TestSetClientTLS/preserves_debug_logging_transport236=== CONT TestSetClientTLS/preserves_debug_logging_transport237=== CONT TestSetClientTLS/rejects_connection_without_client_cert2382026/07/09 07:47:22 WARN Rate limiter backed off name=server-test rate=5239=== CONT TestGetStorePathHash/valid_store_path240=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error2412026/07/09 07:47:22 WARN Rate limiter backed off name=server-test rate=5242=== CONT TestGetStorePathHash/basename_without_hyphen_should_error243=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error244=== RUN TestSetClientTLSErrors/invalid_ca_file245=== PAUSE TestSetClientTLSErrors/invalid_ca_file246=== CONT TestSetClientTLSErrors/missing_cert_file247=== CONT TestSetClientTLSErrors/missing_key_file248=== CONT TestSetClientTLSErrors/invalid_ca_file249=== CONT TestPathInfoCACompatibility/null_ca_field250=== CONT TestPathInfoCACompatibility/new_structured_format_-_text251=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive252=== CONT TestPathInfoCACompatibility/old_string_format_-_text253=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA254=== RUN TestPartSizeForNAR/1_TiB255--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)256=== CONT TestSetClientTLSErrors/missing_ca_file257=== PAUSE TestPartSizeForNAR/1_TiB258=== RUN TestPartSizeForNAR/5_TiB_S3_max_object259--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)260 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)261 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)262=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object263=== RUN TestPartSizeForNAR/capped_at_5_GiB264--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)265=== PAUSE TestPartSizeForNAR/capped_at_5_GiB266--- PASS: TestConvertHashToNix32 (0.01s)267 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)268 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)269 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)270--- PASS: TestDoServerRequestAttachesToken (0.03s)271=== CONT TestPartSizeForNAR/zero_stays_at_minimum272=== CONT TestPartSizeForNAR/1_TiB273=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum274=== CONT TestPartSizeForNAR/small_stays_at_minimum275=== CONT TestPartSizeForNAR/capped_at_5_GiB276=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts277=== CONT TestPartSizeForNAR/5_TiB_S3_max_object278--- PASS: TestRateLimiterFeedback (0.03s)279 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)280 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)281 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)282 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)283--- PASS: TestPathInfoCACompatibility (0.03s)284 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)285 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)286 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)287 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)288 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)289--- PASS: TestParsePathInfoJSON (0.03s)290 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)291 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)292 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)293 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)294 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)295--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)296 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.02s)297 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)298--- PASS: TestPathInfoHashCompatibility (0.03s)299 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)300 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)301 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)302 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)303--- PASS: TestGetStorePathHash (0.03s)304 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)305 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)306 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)307 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)308--- PASS: TestPartSizeForNAR (0.03s)309 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)310 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)311 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)312 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)313 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)314 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)315 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)316--- PASS: TestSetClientTLSErrors (0.03s)317 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)318 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)319 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)320 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)321--- PASS: TestDumpPathSingleFile (0.04s)3222026/07/09 07:47:22 http: TLS handshake error from 127.0.0.1:44998: remote error: tls: bad certificate323--- PASS: TestSetClientTLS (0.03s)324 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.00s)325 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)326 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)327--- PASS: TestCaseHackSuffix (0.04s)328--- PASS: TestDumpPathWriterError (0.07s)329--- PASS: TestDumpPathMatchesNix (0.11s)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/postgres651119037/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/postgres651119037/data -l logfile start359360/build/postgres651119037:5432 - no response3612026-07-09 07:47:24.217 UTC [235] LOG: starting PostgreSQL 18.4 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit3622026-07-09 07:47:24.217 UTC [235] LOG: listening on Unix socket "/build/postgres651119037/.s.PGSQL.5432"3632026-07-09 07:47:24.221 UTC [242] LOG: database system was shut down at 2026-07-09 07:47:23 UTC3642026-07-09 07:47:24.225 UTC [235] LOG: database system is ready to accept connections365/build/postgres651119037:5432 - accepting connections366{"timestamp":"2026-07-09T07:47:24.445001357Z","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(385)"}367368thread 'rustfs-worker' (635) 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:47:24.606 UTC [652] ERROR: relation "goose_db_version" does not exist at character 363992026-07-09 07:47:24.606 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4002026/07/09 07:47:24 OK 20241026095416_initial_model.sql (14.95ms)4012026/07/09 07:47:24 OK 20251210153512_drop_unused_gin_index.sql (3.11ms)4022026/07/09 07:47:24 OK 20251218171726_add_pins.sql (4.91ms)4032026/07/09 07:47:24 OK 20260628120000_add_object_size_and_stats.sql (4.17ms)4042026/07/09 07:47:24 goose: successfully migrated database to version: 202606281200004052026/07/09 07:47:24 OK 1_commit_pending_closure.sql (2.36ms)4062026/07/09 07:47:24 OK 2_object_stats_trigger.sql (1.01ms)4072026/07/09 07:47:24 goose: up to current file version: 2408--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.15s)409=== RUN TestGCBugBareHashReferences410=== PAUSE TestGCBugBareHashReferences411=== RUN TestGCMetrics412=== PAUSE TestGCMetrics413=== RUN TestGCTaskStore_StartNew414=== PAUSE TestGCTaskStore_StartNew415=== RUN TestGCTaskStore_DeduplicateSameParams416=== PAUSE TestGCTaskStore_DeduplicateSameParams417=== RUN TestGCTaskStore_ConflictDifferentParams418=== PAUSE TestGCTaskStore_ConflictDifferentParams419=== RUN TestGCTaskStore_GetEmpty420=== PAUSE TestGCTaskStore_GetEmpty421=== RUN TestGCTaskStore_GetReturnsLatest422=== PAUSE TestGCTaskStore_GetReturnsLatest423=== RUN TestGCTaskStore_CompletedAllowsNewTask424=== PAUSE TestGCTaskStore_CompletedAllowsNewTask425=== RUN TestGCTaskStore_PhaseUpdates426=== PAUSE TestGCTaskStore_PhaseUpdates427=== RUN TestGCTaskStore_Fail428=== PAUSE TestGCTaskStore_Fail429=== RUN TestGracefulShutdownDrainsInflight430=== PAUSE TestGracefulShutdownDrainsInflight431=== RUN TestService_healthCheckHandler432=== PAUSE TestService_healthCheckHandler433=== RUN TestGenerateLandingPage434=== PAUSE TestGenerateLandingPage435=== RUN TestNARDeduplicationMetadataUploadBug436=== PAUSE TestNARDeduplicationMetadataUploadBug437=== RUN TestMetricsInventory438=== PAUSE TestMetricsInventory439=== RUN TestService_NativeMTLS440=== PAUSE TestService_NativeMTLS441=== RUN TestServerTLSConfig442=== PAUSE TestServerTLSConfig443=== RUN TestMultipartCleanup444=== PAUSE TestMultipartCleanup445=== RUN TestObjectStatsTrigger446=== PAUSE TestObjectStatsTrigger447=== RUN TestOrphanedObjectsGC448=== PAUSE TestOrphanedObjectsGC449=== RUN TestOrphanedObjectsGCStressTest450=== PAUSE TestOrphanedObjectsGCStressTest451=== RUN TestResurrectedObjectNotDeleted452=== PAUSE TestResurrectedObjectNotDeleted453=== RUN TestParseSingleRange454=== PAUSE TestParseSingleRange455=== RUN TestIsValidCachePath456=== PAUSE TestIsValidCachePath457=== RUN TestReadProxyNarinfo458=== PAUSE TestReadProxyNarinfo459=== RUN TestReadProxyNarinfoAlreadyDecompressed460=== PAUSE TestReadProxyNarinfoAlreadyDecompressed461=== RUN TestReadProxyNarStreaming462=== PAUSE TestReadProxyNarStreaming463=== RUN TestReadProxy404464=== PAUSE TestReadProxy404465=== RUN TestReadProxyInvalidPath466=== PAUSE TestReadProxyInvalidPath467=== RUN TestReadProxyHead468=== PAUSE TestReadProxyHead469=== RUN TestReadProxyConditionalGet470=== PAUSE TestReadProxyConditionalGet471=== RUN TestReadProxyRootRedirectsToIndexHTML472=== PAUSE TestReadProxyRootRedirectsToIndexHTML473=== RUN TestReadProxyDisabled474=== PAUSE TestReadProxyDisabled475=== RUN TestReadProxyRangeRequest476=== PAUSE TestReadProxyRangeRequest477=== RUN TestRedundantMultipartUpload478=== PAUSE TestRedundantMultipartUpload479=== RUN TestCompleteMultipartUpload_ErrorButObjectExists480=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists481=== RUN TestService_Rustfstest482=== PAUSE TestService_Rustfstest483=== RUN TestSystemdListenerNotActivated484--- PASS: TestSystemdListenerNotActivated (0.00s)485=== RUN TestWatchdogBeatsWhenHealthy486--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)487=== RUN TestWatchdogSkipsWhenUnhealthy4882026/07/09 07:47:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4892026/07/09 07:47:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4902026/07/09 07:47:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4912026/07/09 07:47:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4922026/07/09 07:47:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4932026/07/09 07:47:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4942026/07/09 07:47:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4952026/07/09 07:47:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4962026/07/09 07:47:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4972026/07/09 07:47:24 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 TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle520=== CONT TestUploadHandlersRejectOversizedBody521=== CONT TestService_AuthMiddleware522=== CONT TestService_NativeMTLS523=== CONT TestService_Rustfstest524=== CONT TestCompleteMultipartUpload_ErrorButObjectExists525=== CONT TestRedundantMultipartUpload526=== CONT TestReadProxyRangeRequest527=== CONT TestReadProxyDisabled528=== CONT TestReadProxyRootRedirectsToIndexHTML529=== CONT TestReadProxyConditionalGet530=== CONT TestService_cleanupPendingClosuresHandler531=== CONT TestReadProxyHead532=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT533=== CONT TestReadProxyInvalidPath534=== CONT TestCompleteMultipartUnregistered535=== CONT TestReadProxy404536=== CONT TestService_verifyS3Integrity537=== CONT TestReadProxyNarStreaming538=== CONT TestReadProxyNarinfoAlreadyDecompressed539=== CONT TestService_createPendingClosureHandler540=== CONT TestReadProxyNarinfo541=== CONT TestIsValidCachePath542=== CONT TestGCTaskStore_GetEmpty543--- PASS: TestGCTaskStore_GetEmpty (0.00s)544=== CONT TestGCTaskStore_ConflictDifferentParams545=== CONT TestParseSingleRange546=== CONT TestGCTaskStore_DeduplicateSameParams547=== CONT TestResurrectedObjectNotDeleted548=== CONT TestGCTaskStore_StartNew549=== CONT TestOrphanedObjectsGCStressTest550=== CONT TestGCMetrics551=== CONT TestOrphanedObjectsGC552=== CONT TestGCBugBareHashReferences553=== CONT TestObjectStatsTrigger554=== CONT TestPinProtectsFromGC555=== CONT TestMultipartCleanup556=== CONT TestClientWithDependencies557=== CONT TestUploadHandlersRejectInvalidKeys558=== CONT TestServerTLSConfig559=== CONT TestClientMultipleUploads560=== CONT TestMetricsInventory561=== CONT TestNARDeduplicationMetadataUploadBug562=== CONT TestClientIntegration563=== CONT TestGenerateLandingPage564=== CONT TestClientErrorHandling565=== CONT TestService_healthCheckHandler566=== CONT TestClientCADerivations567=== CONT TestGracefulShutdownDrainsInflight568=== CONT TestCacheStatsHandler569=== CONT TestGCTaskStore_Fail570=== CONT TestCacheConfigHandler571=== CONT TestGCTaskStore_PhaseUpdates572=== CONT TestService_AuthMiddleware_OIDC573=== CONT TestGCTaskStore_CompletedAllowsNewTask574=== CONT TestService_ReadAuthMiddleware575=== CONT TestGCTaskStore_GetReturnsLatest576=== CONT TestService_AuthMiddleware_MTLSBoundSubjects577=== CONT TestService_AuthMiddleware_MTLSProxyHeader578=== CONT TestIsValidUploadKey579=== CONT TestProxyWriteTimeout580=== RUN TestIsValidCachePath/narinfo581=== PAUSE TestIsValidCachePath/narinfo582=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars583=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars584=== RUN TestIsValidCachePath/nar_zst585=== PAUSE TestIsValidCachePath/nar_zst586=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info587--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)588--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)589--- PASS: TestGCTaskStore_StartNew (0.00s)590--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)591--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)592=== RUN TestProxyWriteTimeout/narinfo593=== RUN TestClientErrorHandling/InvalidStorePath594=== PAUSE TestProxyWriteTimeout/narinfo595=== RUN TestCacheConfigHandler/full_config,_no_issuer596=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info597=== RUN TestParseSingleRange/none598=== PAUSE TestCacheConfigHandler/full_config,_no_issuer599=== RUN TestIsValidUploadKey/narinfo600--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)601--- PASS: TestGCTaskStore_Fail (0.00s)602=== RUN TestProxyWriteTimeout/1_GiB_nar6032026/07/09 07:47:24 INFO Starting HTTP server address=127.0.0.1:41577604=== RUN TestServerTLSConfig/no_client_CA605=== PAUSE TestClientErrorHandling/InvalidStorePath606=== PAUSE TestServerTLSConfig/no_client_CA607=== RUN TestClientErrorHandling/InvalidAuthToken608=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal609=== PAUSE TestParseSingleRange/none610=== RUN TestCacheConfigHandler/no_cache_url_configured611=== RUN TestIsValidCachePath/nar_xz612=== PAUSE TestProxyWriteTimeout/1_GiB_nar613=== RUN TestProxyWriteTimeout/10_GiB_nar614=== RUN TestServerTLSConfig/missing_CA_file615=== RUN TestParseSingleRange/unknown_unit616=== PAUSE TestServerTLSConfig/missing_CA_file617=== PAUSE TestProxyWriteTimeout/10_GiB_nar618=== RUN TestServerTLSConfig/not_a_PEM_file619=== RUN TestProxyWriteTimeout/unknown_size620--- PASS: TestGenerateLandingPage (0.01s)621=== PAUSE TestIsValidUploadKey/narinfo622=== PAUSE TestClientErrorHandling/InvalidAuthToken623=== RUN TestIsValidUploadKey/nar_zst624=== RUN TestClientErrorHandling/ServerNotAvailable625=== PAUSE TestParseSingleRange/unknown_unit626=== PAUSE TestIsValidCachePath/nar_xz627=== PAUSE TestServerTLSConfig/not_a_PEM_file628=== CONT TestServerTLSConfig/no_client_CA629=== PAUSE TestProxyWriteTimeout/unknown_size630=== CONT TestProxyWriteTimeout/narinfo631=== CONT TestServerTLSConfig/not_a_PEM_file632=== CONT TestProxyWriteTimeout/10_GiB_nar6332026/07/09 07:47:24 INFO Shutdown signal received, draining in-flight requests timeout=10s634=== CONT TestProxyWriteTimeout/unknown_size635=== CONT TestProxyWriteTimeout/1_GiB_nar636=== RUN TestParseSingleRange/multi-range_ignored637=== PAUSE TestCacheConfigHandler/no_cache_url_configured638=== RUN TestIsValidCachePath/nar_bz2639=== PAUSE TestIsValidCachePath/nar_bz2640=== RUN TestIsValidCachePath/nar_uncompressed641=== PAUSE TestIsValidUploadKey/nar_zst642=== PAUSE TestClientErrorHandling/ServerNotAvailable643=== CONT TestClientErrorHandling/InvalidStorePath644=== CONT TestClientErrorHandling/ServerNotAvailable645=== CONT TestServerTLSConfig/missing_CA_file646=== PAUSE TestParseSingleRange/multi-range_ignored647--- PASS: TestProxyWriteTimeout (0.09s)648 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)649 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)650 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)651 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)652=== RUN TestCacheConfigHandler/no_signing_keys653=== PAUSE TestIsValidCachePath/nar_uncompressed654=== RUN TestIsValidUploadKey/nar_xz655=== RUN TestIsValidCachePath/ls656=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal657=== CONT TestClientErrorHandling/InvalidAuthToken658=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key659=== RUN TestParseSingleRange/malformed_no_dash660=== PAUSE TestParseSingleRange/malformed_no_dash661=== RUN TestParseSingleRange/malformed_both_empty662=== PAUSE TestParseSingleRange/malformed_both_empty663--- PASS: TestServerTLSConfig (0.09s)664 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)665 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)666 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)667=== PAUSE TestCacheConfigHandler/no_signing_keys668=== PAUSE TestIsValidUploadKey/nar_xz669=== PAUSE TestIsValidCachePath/ls670=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key671=== RUN TestParseSingleRange/malformed_end_before_start672=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator673=== RUN TestIsValidUploadKey/nar_plain674=== RUN TestIsValidCachePath/log675=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key676=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key677=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info678=== PAUSE TestParseSingleRange/malformed_end_before_start679=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal6802026/07/09 07:47:24 INFO OIDC provider initialized name=test681=== RUN TestParseSingleRange/closed682=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key683=== PAUSE TestParseSingleRange/closed684=== RUN TestParseSingleRange/open-ended685=== PAUSE TestParseSingleRange/open-ended686=== RUN TestParseSingleRange/end_clamped_to_size6872026/07/09 07:47:24 INFO Received uploads request method=POST path=/688=== PAUSE TestIsValidUploadKey/nar_plain689=== PAUSE TestIsValidCachePath/log6902026/07/09 07:47:24 INFO Received uploads request method=POST path=/691=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key6922026/07/09 07:47:24 INFO Received request for more parts method=POST path=/693=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator694=== CONT TestCacheConfigHandler/full_config,_no_issuer6952026/07/09 07:47:24 INFO Received complete multipart upload request method=POST path=/696=== PAUSE TestParseSingleRange/end_clamped_to_size697=== RUN TestIsValidUploadKey/listing698=== RUN TestIsValidCachePath/realisation699=== CONT TestCacheConfigHandler/no_signing_keys700=== CONT TestCacheConfigHandler/no_cache_url_configured701=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator702=== RUN TestParseSingleRange/suffix703=== PAUSE TestIsValidUploadKey/listing704--- PASS: TestUploadHandlersRejectInvalidKeys (0.09s)705 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)706 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)707 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)708 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)709=== PAUSE TestIsValidCachePath/realisation710=== RUN TestIsValidCachePath/nix-cache-info711=== PAUSE TestParseSingleRange/suffix712=== RUN TestIsValidUploadKey/build_log713=== RUN TestParseSingleRange/suffix_exceeds_size714=== PAUSE TestIsValidUploadKey/build_log715=== PAUSE TestIsValidCachePath/nix-cache-info716--- PASS: TestCacheConfigHandler (0.09s)717 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)718 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)719 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)720 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)721=== PAUSE TestParseSingleRange/suffix_exceeds_size722=== RUN TestIsValidUploadKey/build_log_home-manager_file723=== RUN TestIsValidCachePath/index.html724=== PAUSE TestIsValidCachePath/index.html725=== RUN TestIsValidCachePath/traversal_parent726=== PAUSE TestIsValidCachePath/traversal_parent727=== RUN TestParseSingleRange/single_byte728=== PAUSE TestIsValidUploadKey/build_log_home-manager_file729=== RUN TestIsValidUploadKey/build_log_plus_in_name730=== RUN TestIsValidCachePath/traversal_in_middle731=== PAUSE TestParseSingleRange/single_byte732=== PAUSE TestIsValidUploadKey/build_log_plus_in_name733=== PAUSE TestIsValidCachePath/traversal_in_middle734=== RUN TestParseSingleRange/start_past_EOF735=== PAUSE TestParseSingleRange/start_past_EOF736=== RUN TestParseSingleRange/start_far_past_EOF737=== PAUSE TestParseSingleRange/start_far_past_EOF738=== CONT TestParseSingleRange/none739=== CONT TestParseSingleRange/start_far_past_EOF740=== CONT TestParseSingleRange/unknown_unit741=== RUN TestIsValidUploadKey/build_log_question_mark742=== CONT TestParseSingleRange/single_byte743=== CONT TestParseSingleRange/end_clamped_to_size744=== RUN TestIsValidCachePath/invalid_char_e745=== CONT TestParseSingleRange/start_past_EOF746=== CONT TestParseSingleRange/malformed_both_empty747=== CONT TestParseSingleRange/open-ended748=== CONT TestParseSingleRange/closed749=== CONT TestParseSingleRange/malformed_end_before_start750=== CONT TestParseSingleRange/suffix751=== CONT TestParseSingleRange/multi-range_ignored752=== CONT TestParseSingleRange/suffix_exceeds_size753=== CONT TestParseSingleRange/malformed_no_dash754--- PASS: TestParseSingleRange (0.09s)755 --- PASS: TestParseSingleRange/none (0.00s)756 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)757 --- PASS: TestParseSingleRange/unknown_unit (0.00s)758 --- PASS: TestParseSingleRange/single_byte (0.00s)759 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)760 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)761 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)762 --- PASS: TestParseSingleRange/open-ended (0.00s)763 --- PASS: TestParseSingleRange/closed (0.00s)764 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)765 --- PASS: TestParseSingleRange/suffix (0.00s)766 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)767 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)768 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)769=== PAUSE TestIsValidUploadKey/build_log_question_mark770=== PAUSE TestIsValidCachePath/invalid_char_e771=== RUN TestIsValidUploadKey/build_log_equals772=== RUN TestIsValidCachePath/invalid_char_u773=== PAUSE TestIsValidUploadKey/build_log_equals774=== PAUSE TestIsValidCachePath/invalid_char_u775=== RUN TestIsValidUploadKey/realisation776=== PAUSE TestIsValidUploadKey/realisation777=== RUN TestIsValidUploadKey/realisation_plus_in_output778=== PAUSE TestIsValidUploadKey/realisation_plus_in_output779=== RUN TestIsValidCachePath/random_path780=== PAUSE TestIsValidCachePath/random_path781=== RUN TestIsValidUploadKey/nix-cache-info782=== PAUSE TestIsValidUploadKey/nix-cache-info783=== RUN TestIsValidCachePath/empty784=== PAUSE TestIsValidCachePath/empty785=== RUN TestIsValidUploadKey/index.html786=== PAUSE TestIsValidUploadKey/index.html787=== RUN TestIsValidCachePath/leading_slash788=== PAUSE TestIsValidCachePath/leading_slash789=== RUN TestIsValidUploadKey/narinfo_key,_nar_type790=== RUN TestIsValidCachePath/wrong_extension791=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type792=== RUN TestIsValidUploadKey/nar_key,_narinfo_type793=== PAUSE TestIsValidCachePath/wrong_extension794=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type795=== RUN TestIsValidCachePath/short_hash796=== RUN TestIsValidUploadKey/listing_key,_narinfo_type797=== PAUSE TestIsValidCachePath/short_hash798=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type799=== CONT TestIsValidCachePath/invalid_char_u800=== CONT TestIsValidCachePath/nix-cache-info801=== CONT TestIsValidCachePath/nar_xz802=== CONT TestIsValidCachePath/short_hash803=== CONT TestIsValidCachePath/wrong_extension804=== CONT TestIsValidCachePath/leading_slash805=== CONT TestIsValidCachePath/empty806=== CONT TestIsValidCachePath/random_path807=== CONT TestIsValidCachePath/log808=== CONT TestIsValidCachePath/ls809=== CONT TestIsValidCachePath/nar_uncompressed810=== CONT TestIsValidCachePath/realisation811=== CONT TestIsValidCachePath/nar_bz2812=== CONT TestIsValidCachePath/nar_zst813=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars814=== RUN TestIsValidUploadKey/traversal815=== CONT TestIsValidCachePath/traversal_parent816=== CONT TestIsValidCachePath/narinfo817=== CONT TestIsValidCachePath/invalid_char_e818=== CONT TestIsValidCachePath/index.html819=== CONT TestIsValidCachePath/traversal_in_middle820=== PAUSE TestIsValidUploadKey/traversal821--- PASS: TestIsValidCachePath (0.10s)822 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)823 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)824 --- PASS: TestIsValidCachePath/nar_xz (0.00s)825 --- PASS: TestIsValidCachePath/short_hash (0.00s)826 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)827 --- PASS: TestIsValidCachePath/leading_slash (0.00s)828 --- PASS: TestIsValidCachePath/empty (0.00s)829 --- PASS: TestIsValidCachePath/random_path (0.00s)830 --- PASS: TestIsValidCachePath/log (0.00s)831 --- PASS: TestIsValidCachePath/ls (0.00s)832 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)833 --- PASS: TestIsValidCachePath/realisation (0.00s)834 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)835 --- PASS: TestIsValidCachePath/nar_zst (0.00s)836 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)837 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)838 --- PASS: TestIsValidCachePath/narinfo (0.00s)839 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)840 --- PASS: TestIsValidCachePath/index.html (0.00s)841 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)842=== RUN TestIsValidUploadKey/traversal_nar843=== PAUSE TestIsValidUploadKey/traversal_nar844=== RUN TestIsValidUploadKey/absolute845=== PAUSE TestIsValidUploadKey/absolute846=== RUN TestIsValidUploadKey/empty_key847=== PAUSE TestIsValidUploadKey/empty_key848=== RUN TestIsValidUploadKey/unknown_type849=== PAUSE TestIsValidUploadKey/unknown_type850=== CONT TestIsValidUploadKey/narinfo851=== CONT TestIsValidUploadKey/build_log_question_mark852=== CONT TestIsValidUploadKey/realisation_plus_in_output853=== CONT TestIsValidUploadKey/listing854=== CONT TestIsValidUploadKey/nar_key,_narinfo_type855=== CONT TestIsValidUploadKey/unknown_type856=== CONT TestIsValidUploadKey/traversal857=== CONT TestIsValidUploadKey/listing_key,_narinfo_type858=== CONT TestIsValidUploadKey/traversal_nar859=== CONT TestIsValidUploadKey/empty_key860=== CONT TestIsValidUploadKey/absolute861=== CONT TestIsValidUploadKey/build_log_plus_in_name862=== CONT TestIsValidUploadKey/build_log_home-manager_file863=== CONT TestIsValidUploadKey/build_log864=== CONT TestIsValidUploadKey/nix-cache-info865=== CONT TestIsValidUploadKey/nar_xz866=== CONT TestIsValidUploadKey/narinfo_key,_nar_type867=== CONT TestIsValidUploadKey/nar_plain868=== CONT TestIsValidUploadKey/index.html869=== CONT TestIsValidUploadKey/nar_zst870=== CONT TestIsValidUploadKey/realisation871=== CONT TestIsValidUploadKey/build_log_equals872--- PASS: TestIsValidUploadKey (0.10s)873 --- PASS: TestIsValidUploadKey/narinfo (0.00s)874 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)875 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)876 --- PASS: TestIsValidUploadKey/listing (0.00s)877 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)878 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)879 --- PASS: TestIsValidUploadKey/traversal (0.00s)880 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)881 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)882 --- PASS: TestIsValidUploadKey/empty_key (0.00s)883 --- PASS: TestIsValidUploadKey/absolute (0.00s)884 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)885 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)886 --- PASS: TestIsValidUploadKey/build_log (0.00s)887 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)888 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)889 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)890 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)891 --- PASS: TestIsValidUploadKey/index.html (0.00s)892 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)893 --- PASS: TestIsValidUploadKey/realisation (0.00s)894 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)8952026-07-09 07:47:25.051 UTC [740] ERROR: relation "goose_db_version" does not exist at character 368962026-07-09 07:47:25.051 UTC [740] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8972026-07-09 07:47:25.052 UTC [769] ERROR: relation "goose_db_version" does not exist at character 368982026-07-09 07:47:25.052 UTC [769] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8992026-07-09 07:47:25.052 UTC [742] ERROR: relation "goose_db_version" does not exist at character 369002026-07-09 07:47:25.052 UTC [742] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9012026-07-09 07:47:25.052 UTC [748] ERROR: relation "goose_db_version" does not exist at character 369022026-07-09 07:47:25.052 UTC [748] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9032026-07-09 07:47:25.053 UTC [749] ERROR: relation "goose_db_version" does not exist at character 369042026-07-09 07:47:25.053 UTC [749] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC905--- PASS: TestGracefulShutdownDrainsInflight (0.16s)9062026-07-09 07:47:25.063 UTC [751] ERROR: relation "goose_db_version" does not exist at character 369072026-07-09 07:47:25.063 UTC [751] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9082026-07-09 07:47:25.063 UTC [750] ERROR: relation "goose_db_version" does not exist at character 369092026-07-09 07:47:25.063 UTC [750] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9102026-07-09 07:47:25.082 UTC [770] ERROR: relation "goose_db_version" does not exist at character 369112026-07-09 07:47:25.082 UTC [770] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9122026-07-09 07:47:25.083 UTC [788] ERROR: relation "goose_db_version" does not exist at character 369132026-07-09 07:47:25.083 UTC [788] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC914=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure915=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure916=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart917=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart918=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts919=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts920=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure921=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts922=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart9232026/07/09 07:47:25 INFO Received uploads request method=POST path=/9242026/07/09 07:47:25 INFO Received request for more parts method=POST path=/9252026/07/09 07:47:25 INFO Received complete multipart upload request method=POST path=/9262026/07/09 07:47:25 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_closures9272026/07/09 07:47:25 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=186.898102ms 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:47:25 OK 20241026095416_initial_model.sql (297.92ms)9292026/07/09 07:47:25 OK 20241026095416_initial_model.sql (300.11ms)9302026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (4.53ms)9312026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (15.84ms)9322026/07/09 07:47:25 OK 20241026095416_initial_model.sql (286.79ms)9332026/07/09 07:47:25 OK 20241026095416_initial_model.sql (286.87ms)9342026/07/09 07:47:25 OK 20241026095416_initial_model.sql (285.15ms)9352026/07/09 07:47:25 OK 20241026095416_initial_model.sql (284.82ms)9362026/07/09 07:47:25 OK 20241026095416_initial_model.sql (287.38ms)9372026/07/09 07:47:25 OK 20241026095416_initial_model.sql (280.49ms)9382026/07/09 07:47:25 OK 20251218171726_add_pins.sql (21.76ms)9392026/07/09 07:47:25 OK 20241026095416_initial_model.sql (278.65ms)9402026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (4.82ms)9412026/07/09 07:47:25 OK 20251218171726_add_pins.sql (9.11ms)9422026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (4.25ms)9432026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (5.94ms)9442026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (4.9ms)9452026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (5.76ms)9462026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (5.86ms)9472026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (4.39ms)9482026-07-09 07:47:25.409 UTC [859] ERROR: relation "goose_db_version" does not exist at character 369492026-07-09 07:47:25.409 UTC [859] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9502026-07-09 07:47:25.410 UTC [860] ERROR: relation "goose_db_version" does not exist at character 369512026-07-09 07:47:25.410 UTC [860] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9522026-07-09 07:47:25.411 UTC [861] ERROR: relation "goose_db_version" does not exist at character 369532026-07-09 07:47:25.411 UTC [861] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9542026-07-09 07:47:25.412 UTC [862] ERROR: relation "goose_db_version" does not exist at character 369552026-07-09 07:47:25.412 UTC [862] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9562026-07-09 07:47:25.414 UTC [864] ERROR: relation "goose_db_version" does not exist at character 369572026-07-09 07:47:25.414 UTC [864] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9582026-07-09 07:47:25.415 UTC [865] ERROR: relation "goose_db_version" does not exist at character 369592026-07-09 07:47:25.415 UTC [865] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9602026/07/09 07:47:25 OK 20251218171726_add_pins.sql (13.83ms)9612026-07-09 07:47:25.416 UTC [866] ERROR: relation "goose_db_version" does not exist at character 369622026-07-09 07:47:25.416 UTC [866] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9632026-07-09 07:47:25.417 UTC [867] ERROR: relation "goose_db_version" does not exist at character 369642026-07-09 07:47:25.417 UTC [867] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9652026-07-09 07:47:25.417 UTC [863] ERROR: relation "goose_db_version" does not exist at character 369662026-07-09 07:47:25.417 UTC [863] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9672026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (16.94ms)9682026/07/09 07:47:25 goose: successfully migrated database to version: 202606281200009692026-07-09 07:47:25.420 UTC [868] ERROR: relation "goose_db_version" does not exist at character 369702026-07-09 07:47:25.420 UTC [868] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9712026/07/09 07:47:25 OK 20251218171726_add_pins.sql (25.35ms)9722026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (25.96ms)9732026/07/09 07:47:25 goose: successfully migrated database to version: 202606281200009742026/07/09 07:47:25 OK 20251218171726_add_pins.sql (27.35ms)9752026/07/09 07:47:25 OK 20251218171726_add_pins.sql (25.64ms)9762026/07/09 07:47:25 OK 20251218171726_add_pins.sql (28.97ms)9772026/07/09 07:47:25 OK 1_commit_pending_closure.sql (6.99ms)9782026/07/09 07:47:25 OK 1_commit_pending_closure.sql (16.85ms)9792026/07/09 07:47:25 OK 20251218171726_add_pins.sql (31.14ms)9802026/07/09 07:47:25 OK 20251218171726_add_pins.sql (31.54ms)9812026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (24.18ms)9822026/07/09 07:47:25 goose: successfully migrated database to version: 202606281200009832026/07/09 07:47:25 OK 2_object_stats_trigger.sql (5.71ms)9842026/07/09 07:47:25 goose: up to current file version: 29852026/07/09 07:47:25 OK 2_object_stats_trigger.sql (5.78ms)9862026/07/09 07:47:25 goose: up to current file version: 29872026/07/09 07:47:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=400.224603ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures9882026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures989--- PASS: TestReadProxyDisabled (0.55s)9902026/07/09 07:47:25 OK 1_commit_pending_closure.sql (13.13ms)9912026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (26.85ms)9922026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (24.99ms)9932026/07/09 07:47:25 goose: successfully migrated database to version: 202606281200009942026/07/09 07:47:25 goose: successfully migrated database to version: 202606281200009952026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (24.9ms)9962026/07/09 07:47:25 goose: successfully migrated database to version: 202606281200009972026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (23.53ms)9982026/07/09 07:47:25 goose: successfully migrated database to version: 202606281200009992026/07/09 07:47:25 OK 2_object_stats_trigger.sql (5.74ms)10002026/07/09 07:47:25 goose: up to current file version: 210012026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (23.3ms)10022026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000010032026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (21.37ms)10042026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000010052026/07/09 07:47:25 OK 1_commit_pending_closure.sql (5.35ms)10062026/07/09 07:47:25 OK 1_commit_pending_closure.sql (4.75ms)10072026/07/09 07:47:25 OK 1_commit_pending_closure.sql (6.57ms)10082026/07/09 07:47:25 OK 1_commit_pending_closure.sql (6.78ms)10092026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures10102026/07/09 07:47:25 OK 1_commit_pending_closure.sql (5.1ms)10112026/07/09 07:47:25 OK 2_object_stats_trigger.sql (3.62ms)10122026/07/09 07:47:25 goose: up to current file version: 210132026/07/09 07:47:25 OK 2_object_stats_trigger.sql (4.9ms)10142026/07/09 07:47:25 goose: up to current file version: 210152026/07/09 07:47:25 OK 1_commit_pending_closure.sql (6.91ms)10162026/07/09 07:47:25 OK 2_object_stats_trigger.sql (5.16ms)10172026/07/09 07:47:25 OK 2_object_stats_trigger.sql (5.29ms)10182026/07/09 07:47:25 goose: up to current file version: 210192026/07/09 07:47:25 goose: up to current file version: 210202026/07/09 07:47:25 OK 2_object_stats_trigger.sql (4.78ms)10212026/07/09 07:47:25 goose: up to current file version: 210222026/07/09 07:47:25 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10232026/07/09 07:47:25 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1024--- PASS: TestService_NativeMTLS (0.58s)10252026/07/09 07:47:25 OK 2_object_stats_trigger.sql (4.15ms)10262026/07/09 07:47:25 goose: up to current file version: 210272026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures1028--- PASS: TestService_Rustfstest (0.58s)10292026/07/09 07:47:25 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1030--- PASS: TestService_AuthMiddleware (0.58s)10312026/07/09 07:47:25 OK 20241026095416_initial_model.sql (32.71ms)10322026/07/09 07:47:25 OK 20241026095416_initial_model.sql (19.27ms)10332026/07/09 07:47:25 OK 20241026095416_initial_model.sql (19.22ms)1034{"timestamp":"2026-07-09T07:47:25.475732137Z","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(195)"}10352026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures10362026/07/09 07:47:25 OK 20241026095416_initial_model.sql (22.29ms)10372026/07/09 07:47:25 OK 20241026095416_initial_model.sql (24.31ms)10382026/07/09 07:47:25 OK 20241026095416_initial_model.sql (34ms)10392026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (4.42ms)1040--- PASS: TestReadProxyRangeRequest (0.59s)10412026/07/09 07:47:25 OK 20241026095416_initial_model.sql (41.2ms)10422026/07/09 07:47:25 OK 20241026095416_initial_model.sql (32.74ms)10432026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (13.38ms)10442026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (13.45ms)10452026-07-09 07:47:25.489 UTC [871] ERROR: relation "goose_db_version" does not exist at character 3610462026-07-09 07:47:25.489 UTC [871] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10472026-07-09 07:47:25.489 UTC [873] ERROR: relation "goose_db_version" does not exist at character 3610482026-07-09 07:47:25.489 UTC [873] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10492026-07-09 07:47:25.489 UTC [872] ERROR: relation "goose_db_version" does not exist at character 3610502026-07-09 07:47:25.489 UTC [872] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10512026-07-09 07:47:25.491 UTC [874] ERROR: relation "goose_db_version" does not exist at character 3610522026-07-09 07:47:25.491 UTC [874] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10532026/07/09 07:47:25 OK 20241026095416_initial_model.sql (44.68ms)10542026-07-09 07:47:25.492 UTC [878] ERROR: relation "goose_db_version" does not exist at character 3610552026-07-09 07:47:25.492 UTC [878] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10562026-07-09 07:47:25.492 UTC [875] ERROR: relation "goose_db_version" does not exist at character 3610572026-07-09 07:47:25.492 UTC [875] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10582026-07-09 07:47:25.492 UTC [876] ERROR: relation "goose_db_version" does not exist at character 3610592026-07-09 07:47:25.492 UTC [876] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10602026-07-09 07:47:25.493 UTC [877] ERROR: relation "goose_db_version" does not exist at character 3610612026-07-09 07:47:25.493 UTC [877] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10622026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (14.82ms)10632026/07/09 07:47:25 OK 20251218171726_add_pins.sql (14.75ms)10642026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (14.95ms)10652026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (16.71ms)10662026-07-09 07:47:25.494 UTC [879] ERROR: relation "goose_db_version" does not exist at character 3610672026-07-09 07:47:25.494 UTC [879] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10682026-07-09 07:47:25.494 UTC [881] ERROR: relation "goose_db_version" does not exist at character 3610692026-07-09 07:47:25.494 UTC [881] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10702026-07-09 07:47:25.494 UTC [880] ERROR: relation "goose_db_version" does not exist at character 3610712026-07-09 07:47:25.494 UTC [880] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10722026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (7.91ms)10732026/07/09 07:47:25 OK 20251218171726_add_pins.sql (8.39ms)10742026/07/09 07:47:25 OK 20251218171726_add_pins.sql (8.3ms)10752026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (8.92ms)10762026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (5.82ms)10772026/07/09 07:47:25 OK 20241026095416_initial_model.sql (38.66ms)10782026/07/09 07:47:25 OK 20251218171726_add_pins.sql (6.65ms)10792026/07/09 07:47:25 OK 20251218171726_add_pins.sql (8.37ms)10802026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (8.46ms)10812026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000010822026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (5.69ms)10832026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000010842026/07/09 07:47:25 OK 20251218171726_add_pins.sql (6.59ms)10852026/07/09 07:47:25 OK 20251218171726_add_pins.sql (8.59ms)10862026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (5.79ms)10872026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000010882026/07/09 07:47:25 OK 20251218171726_add_pins.sql (8.44ms)10892026/07/09 07:47:25 OK 20251218171726_add_pins.sql (8.52ms)10902026/07/09 07:47:25 OK 1_commit_pending_closure.sql (3.33ms)10912026/07/09 07:47:25 OK 1_commit_pending_closure.sql (3.79ms)10922026/07/09 07:47:25 OK 1_commit_pending_closure.sql (3.94ms)10932026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (6.04ms)10942026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000010952026/07/09 07:47:25 OK 2_object_stats_trigger.sql (3.76ms)10962026/07/09 07:47:25 goose: up to current file version: 210972026/07/09 07:47:25 OK 2_object_stats_trigger.sql (5.53ms)10982026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (6.22ms)10992026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000011002026/07/09 07:47:25 goose: up to current file version: 211012026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (9.33ms)11022026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000011032026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (6.95ms)11042026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (9.4ms)11052026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000011062026-07-09 07:47:25.513 UTC [884] ERROR: relation "goose_db_version" does not exist at character 3611072026-07-09 07:47:25.513 UTC [884] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11082026-07-09 07:47:25.513 UTC [883] ERROR: relation "goose_db_version" does not exist at character 3611092026-07-09 07:47:25.513 UTC [883] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11102026-07-09 07:47:25.513 UTC [882] ERROR: relation "goose_db_version" does not exist at character 3611112026-07-09 07:47:25.513 UTC [882] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11122026-07-09 07:47:25.514 UTC [885] ERROR: relation "goose_db_version" does not exist at character 3611132026-07-09 07:47:25.514 UTC [885] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11142026/07/09 07:47:25 OK 2_object_stats_trigger.sql (5.96ms)11152026/07/09 07:47:25 goose: up to current file version: 211162026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (7.92ms)11172026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000011182026/07/09 07:47:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11192026/07/09 07:47:25 OK 1_commit_pending_closure.sql (6.37ms)11202026-07-09 07:47:25.517 UTC [887] ERROR: relation "goose_db_version" does not exist at character 3611212026-07-09 07:47:25.517 UTC [887] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11222026/07/09 07:47:25 INFO Received cleanup request method=DELETE path=/api/pending_closures11232026-07-09 07:47:25.517 UTC [886] ERROR: relation "goose_db_version" does not exist at character 3611242026-07-09 07:47:25.517 UTC [886] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11252026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures11262026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures11272026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures1128{"timestamp":"2026-07-09T07:47:25.518237279Z","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(384)"}11292026/07/09 07:47:25 OK 1_commit_pending_closure.sql (4.73ms)1130{"timestamp":"2026-07-09T07:47:25.5182848Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket6, 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(384)"}11312026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (10.55ms)11322026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000011332026/07/09 07:47:25 OK 20241026095416_initial_model.sql (15.36ms)11342026/07/09 07:47:25 OK 1_commit_pending_closure.sql (5.37ms)11352026/07/09 07:47:25 OK 1_commit_pending_closure.sql (5.11ms)1136--- PASS: TestReadProxyConditionalGet (0.62s)11372026-07-09 07:47:25.519 UTC [891] ERROR: relation "goose_db_version" does not exist at character 3611382026-07-09 07:47:25.519 UTC [891] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11392026-07-09 07:47:25.519 UTC [888] ERROR: relation "goose_db_version" does not exist at character 3611402026-07-09 07:47:25.519 UTC [888] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11412026/07/09 07:47:25 INFO Aborted multipart uploads count=011422026/07/09 07:47:25 WARN CompleteMultipartUpload errored but object exists; treating as success error="One or more of the specified parts could not be found. The part may not have been uploaded, or the specified entity tag may not match the part's entity tag." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzY4YjI0NGEtMjMxMy00OThmLTg0NmMtY2JkMjIyYzBmNmQ0LmUzNTY5MWU3LWNkYjAtNDM0ZS04MmUwLWE3NTQ1ZWJiYjRlZHgxNzgzNTgzMjQ1NDk1OTE4NTQ511432026-07-09 07:47:25.520 UTC [889] ERROR: relation "goose_db_version" does not exist at character 3611442026-07-09 07:47:25.520 UTC [889] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11452026/07/09 07:47:25 OK 1_commit_pending_closure.sql (5.55ms)11462026/07/09 07:47:25 OK 2_object_stats_trigger.sql (3.89ms)11472026/07/09 07:47:25 goose: up to current file version: 211482026/07/09 07:47:25 OK 20241026095416_initial_model.sql (16.1ms)11492026-07-09 07:47:25.521 UTC [894] ERROR: relation "goose_db_version" does not exist at character 3611502026-07-09 07:47:25.521 UTC [894] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11512026-07-09 07:47:25.521 UTC [892] ERROR: relation "goose_db_version" does not exist at character 3611522026-07-09 07:47:25.521 UTC [892] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11532026/07/09 07:47:25 OK 2_object_stats_trigger.sql (3.52ms)11542026/07/09 07:47:25 goose: up to current file version: 211552026-07-09 07:47:25.521 UTC [895] ERROR: relation "goose_db_version" does not exist at character 3611562026-07-09 07:47:25.521 UTC [895] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11572026/07/09 07:47:25 OK 20241026095416_initial_model.sql (18.07ms)11582026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures11592026-07-09 07:47:25.522 UTC [896] ERROR: relation "goose_db_version" does not exist at character 3611602026-07-09 07:47:25.522 UTC [896] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11612026/07/09 07:47:25 OK 20251218171726_add_pins.sql (10.47ms)11622026/07/09 07:47:25 OK 1_commit_pending_closure.sql (5.25ms)11632026/07/09 07:47:25 OK 20241026095416_initial_model.sql (17.61ms)11642026/07/09 07:47:25 OK 2_object_stats_trigger.sql (5.12ms)11652026/07/09 07:47:25 goose: up to current file version: 211662026/07/09 07:47:25 OK 2_object_stats_trigger.sql (5.01ms)11672026/07/09 07:47:25 goose: up to current file version: 211682026/07/09 07:47:25 OK 2_object_stats_trigger.sql (3.67ms)11692026/07/09 07:47:25 goose: up to current file version: 211702026/07/09 07:47:25 OK 20241026095416_initial_model.sql (14.55ms)11712026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (5.85ms)11722026/07/09 07:47:25 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzY4YjI0NGEtMjMxMy00OThmLTg0NmMtY2JkMjIyYzBmNmQ0LmUzNTY5MWU3LWNkYjAtNDM0ZS04MmUwLWE3NTQ1ZWJiYjRlZHgxNzgzNTgzMjQ1NDk1OTE4NTQ5 parts=11173--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.63s)11742026/07/09 07:47:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11752026/07/09 07:47:25 OK 20241026095416_initial_model.sql (18.31ms)11762026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (4.87ms)11772026/07/09 07:47:25 OK 20241026095416_initial_model.sql (18.57ms)11782026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (4.46ms)11792026/07/09 07:47:25 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1180--- PASS: TestReadProxyNarinfo (0.63s)1181--- PASS: TestCompleteMultipartUnregistered (0.63s)11822026/07/09 07:47:25 OK 2_object_stats_trigger.sql (3.74ms)11832026/07/09 07:47:25 goose: up to current file version: 211842026/07/09 07:47:25 INFO Created nix-cache-info in bucket bucket=bucket1411852026/07/09 07:47:25 OK 20241026095416_initial_model.sql (20.02ms)11862026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (4.03ms)11872026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (3.57ms)1188--- PASS: TestReadProxy404 (0.63s)11892026/07/09 07:47:25 OK 20241026095416_initial_model.sql (18.53ms)11902026/07/09 07:47:25 OK 20241026095416_initial_model.sql (20.48ms)1191--- PASS: TestReadProxyInvalidPath (0.63s)11922026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (3.74ms)11932026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (2.71ms)11942026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (6.34ms)11952026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000011962026/07/09 07:47:25 OK 20251218171726_add_pins.sql (6.04ms)11972026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (3.07ms)11982026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (4.15ms)11992026/07/09 07:47:25 OK 20251218171726_add_pins.sql (6.39ms)12002026/07/09 07:47:25 INFO Received cleanup request method=DELETE path=/api/pending_closures12012026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (4.62ms)12022026/07/09 07:47:25 INFO Aborted multipart uploads count=11203--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.64s)12042026/07/09 07:47:25 OK 1_commit_pending_closure.sql (4.4ms)12052026/07/09 07:47:25 OK 20241026095416_initial_model.sql (23.89ms)12062026/07/09 07:47:25 OK 20251218171726_add_pins.sql (8ms)12072026/07/09 07:47:25 OK 20251218171726_add_pins.sql (6.72ms)12082026/07/09 07:47:25 OK 20251218171726_add_pins.sql (6.94ms)12092026/07/09 07:47:25 OK 20251218171726_add_pins.sql (8.21ms)12102026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (5.65ms)12112026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000012122026/07/09 07:47:25 OK 20251218171726_add_pins.sql (7.16ms)12132026/07/09 07:47:25 OK 2_object_stats_trigger.sql (2.6ms)12142026/07/09 07:47:25 goose: up to current file version: 212152026/07/09 07:47:25 OK 20251218171726_add_pins.sql (5.2ms)1216--- PASS: TestReadProxyHead (0.64s)12172026/07/09 07:47:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12182026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (6.54ms)12192026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000012202026/07/09 07:47:25 OK 20251218171726_add_pins.sql (6.6ms)12212026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (3.98ms)12222026-07-09 07:47:25.539 UTC [862] ERROR: Closure does not exist: id=112232026-07-09 07:47:25.539 UTC [862] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE12242026-07-09 07:47:25.539 UTC [862] STATEMENT: -- name: CommitPendingClosure :exec1225 SELECT commit_pending_closure($1::bigint)1226 12272026/07/09 07:47:25 OK 1_commit_pending_closure.sql (3.72ms)12282026/07/09 07:47:25 OK 20251218171726_add_pins.sql (6.4ms)1229--- PASS: TestService_cleanupPendingClosuresHandler (0.64s)12302026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures12312026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (6.68ms)12322026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000012332026/07/09 07:47:25 OK 2_object_stats_trigger.sql (3.02ms)12342026/07/09 07:47:25 goose: up to current file version: 212352026/07/09 07:47:25 OK 20241026095416_initial_model.sql (16.62ms)12362026/07/09 07:47:25 OK 20241026095416_initial_model.sql (16.1ms)12372026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (6.9ms)12382026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000012392026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (7.21ms)12402026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000012412026/07/09 07:47:25 OK 1_commit_pending_closure.sql (4.6ms)12422026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (7.2ms)12432026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000012442026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (8.23ms)12452026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000012462026/07/09 07:47:25 OK 20241026095416_initial_model.sql (16.73ms)12472026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (5.88ms)12482026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000012492026/07/09 07:47:25 OK 20241026095416_initial_model.sql (17.04ms)12502026/07/09 07:47:25 OK 20251218171726_add_pins.sql (6.07ms)12512026/07/09 07:47:25 OK 20241026095416_initial_model.sql (12.93ms)12522026/07/09 07:47:25 OK 20241026095416_initial_model.sql (14.14ms)12532026/07/09 07:47:25 OK 20241026095416_initial_model.sql (15.44ms)12542026/07/09 07:47:25 OK 1_commit_pending_closure.sql (4.49ms)12552026/07/09 07:47:25 OK 20241026095416_initial_model.sql (16.44ms)12562026/07/09 07:47:25 OK 2_object_stats_trigger.sql (2.7ms)12572026/07/09 07:47:25 goose: up to current file version: 212582026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (6.17ms)12592026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000012602026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (7.47ms)12612026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000012622026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (3.26ms)12632026/07/09 07:47:25 OK 1_commit_pending_closure.sql (3.29ms)12642026/07/09 07:47:25 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1265--- PASS: TestService_ReadAuthMiddleware (0.65s)12662026/07/09 07:47:25 OK 1_commit_pending_closure.sql (2.98ms)12672026/07/09 07:47:25 OK 1_commit_pending_closure.sql (3.3ms)12682026/07/09 07:47:25 OK 20241026095416_initial_model.sql (17.83ms)12692026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (3.22ms)12702026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)12712026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)12722026/07/09 07:47:25 OK 20241026095416_initial_model.sql (19.96ms)12732026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)12742026/07/09 07:47:25 OK 1_commit_pending_closure.sql (2.74ms)12752026/07/09 07:47:25 OK 1_commit_pending_closure.sql (3.28ms)12762026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (3.63ms)12772026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (3.01ms)12782026/07/09 07:47:25 OK 2_object_stats_trigger.sql (2.12ms)12792026/07/09 07:47:25 goose: up to current file version: 212802026/07/09 07:47:25 OK 2_object_stats_trigger.sql (2.53ms)12812026/07/09 07:47:25 OK 2_object_stats_trigger.sql (2.49ms)12822026/07/09 07:47:25 goose: up to current file version: 212832026/07/09 07:47:25 goose: up to current file version: 212842026/07/09 07:47:25 OK 2_object_stats_trigger.sql (2.67ms)12852026/07/09 07:47:25 goose: up to current file version: 212862026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (3.48ms)12872026/07/09 07:47:25 OK 2_object_stats_trigger.sql (2.41ms)12882026/07/09 07:47:25 goose: up to current file version: 212892026/07/09 07:47:25 OK 2_object_stats_trigger.sql (3.3ms)12902026/07/09 07:47:25 goose: up to current file version: 212912026/07/09 07:47:25 OK 1_commit_pending_closure.sql (4.2ms)12922026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (3.74ms)12932026/07/09 07:47:25 OK 20241026095416_initial_model.sql (20.85ms)12942026/07/09 07:47:25 OK 20251218171726_add_pins.sql (4.88ms)12952026/07/09 07:47:25 OK 20251218171726_add_pins.sql (4.82ms)12962026/07/09 07:47:25 OK 20251218171726_add_pins.sql (5.34ms)12972026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (7.06ms)12982026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000012992026/07/09 07:47:25 OK 20251218171726_add_pins.sql (5.08ms)13002026/07/09 07:47:25 OK 20251218171726_add_pins.sql (4.91ms)13012026/07/09 07:47:25 OK 1_commit_pending_closure.sql (5.34ms)13022026/07/09 07:47:25 OK 20251218171726_add_pins.sql (5.49ms)13032026/07/09 07:47:25 OK 2_object_stats_trigger.sql (1.69ms)13042026/07/09 07:47:25 goose: up to current file version: 213052026/07/09 07:47:25 OK 20241026095416_initial_model.sql (17.61ms)13062026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (5.15ms)13072026/07/09 07:47:25 OK 20251218171726_add_pins.sql (5.36ms)13082026/07/09 07:47:25 OK 20251218171726_add_pins.sql (3.58ms)13092026/07/09 07:47:25 INFO Created nix-cache-info in bucket bucket=bucket221310--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.65s)13112026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (2.56ms)13122026/07/09 07:47:25 OK 2_object_stats_trigger.sql (3.76ms)13132026/07/09 07:47:25 goose: up to current file version: 213142026/07/09 07:47:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13152026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (3.66ms)1316--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.66s)13172026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (5.59ms)13182026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000013192026/07/09 07:47:25 INFO Created nix-cache-info in bucket bucket=bucket2613202026/07/09 07:47:25 INFO Created nix-cache-info in bucket bucket=bucket2813212026/07/09 07:47:25 INFO Created nix-cache-info in bucket bucket=bucket2413222026/07/09 07:47:25 OK 1_commit_pending_closure.sql (5.37ms)13232026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (4.86ms)13242026/07/09 07:47:25 OK 20241026095416_initial_model.sql (23.69ms)1325--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.66s)13262026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000013272026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (6.15ms)13282026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000013292026/07/09 07:47:25 OK 20251218171726_add_pins.sql (4.05ms)13302026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (5.44ms)13312026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000013322026/07/09 07:47:25 OK 20251218171726_add_pins.sql (7.38ms)13332026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (5.99ms)13342026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000013352026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (5.78ms)13362026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000013372026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (5.94ms)13382026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000013392026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (6.6ms)13402026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000013412026/07/09 07:47:25 OK 2_object_stats_trigger.sql (1.28ms)13422026/07/09 07:47:25 goose: up to current file version: 213432026/07/09 07:47:25 OK 20251218171726_add_pins.sql (6.57ms)13442026/07/09 07:47:25 OK 20251218171726_add_pins.sql (3.1ms)13452026/07/09 07:47:25 OK 1_commit_pending_closure.sql (1.94ms)13462026/07/09 07:47:25 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)13472026/07/09 07:47:25 OK 1_commit_pending_closure.sql (2.56ms)13482026/07/09 07:47:25 OK 2_object_stats_trigger.sql (2.78ms)13492026/07/09 07:47:25 OK 1_commit_pending_closure.sql (3.62ms)13502026/07/09 07:47:25 OK 1_commit_pending_closure.sql (3.42ms)13512026/07/09 07:47:25 OK 1_commit_pending_closure.sql (4.06ms)1352--- PASS: TestReadProxyNarStreaming (0.66s)13532026/07/09 07:47:25 OK 1_commit_pending_closure.sql (3.54ms)13542026/07/09 07:47:25 OK 1_commit_pending_closure.sql (3.83ms)13552026/07/09 07:47:25 OK 1_commit_pending_closure.sql (4.08ms)13562026/07/09 07:47:25 goose: up to current file version: 213572026/07/09 07:47:25 OK 2_object_stats_trigger.sql (2.27ms)13582026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (5.13ms)13592026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000013602026/07/09 07:47:25 goose: up to current file version: 213612026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (4.36ms)13622026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000013632026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (4.99ms)13642026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000013652026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (4.8ms)13662026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000013672026/07/09 07:47:25 OK 2_object_stats_trigger.sql (1.79ms)13682026/07/09 07:47:25 goose: up to current file version: 213692026/07/09 07:47:25 OK 2_object_stats_trigger.sql (1.72ms)13702026/07/09 07:47:25 goose: up to current file version: 213712026/07/09 07:47:25 OK 2_object_stats_trigger.sql (2.13ms)13722026/07/09 07:47:25 goose: up to current file version: 213732026/07/09 07:47:25 OK 2_object_stats_trigger.sql (1.88ms)13742026/07/09 07:47:25 goose: up to current file version: 213752026/07/09 07:47:25 OK 20251218171726_add_pins.sql (4.3ms)13762026/07/09 07:47:25 OK 2_object_stats_trigger.sql (1.86ms)13772026/07/09 07:47:25 goose: up to current file version: 213782026/07/09 07:47:25 OK 2_object_stats_trigger.sql (1.66ms)13792026/07/09 07:47:25 goose: up to current file version: 213802026/07/09 07:47:25 OK 1_commit_pending_closure.sql (1.59ms)13812026/07/09 07:47:25 OK 1_commit_pending_closure.sql (1.86ms)13822026/07/09 07:47:25 OK 2_object_stats_trigger.sql (2.11ms)13832026/07/09 07:47:25 goose: up to current file version: 213842026/07/09 07:47:25 OK 1_commit_pending_closure.sql (3.43ms)13852026/07/09 07:47:25 OK 1_commit_pending_closure.sql (3.76ms)13862026/07/09 07:47:25 OK 2_object_stats_trigger.sql (1.87ms)13872026/07/09 07:47:25 goose: up to current file version: 213882026/07/09 07:47:25 OK 20260628120000_add_object_size_and_stats.sql (3.5ms)13892026/07/09 07:47:25 goose: successfully migrated database to version: 2026062812000013902026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures13912026/07/09 07:47:25 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13922026/07/09 07:47:25 WARN mTLS auth: bound subjects configured but subject DN unavailable13932026/07/09 07:47:25 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1394--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.67s)13952026/07/09 07:47:25 OK 2_object_stats_trigger.sql (1.24ms)13962026/07/09 07:47:25 goose: up to current file version: 213972026/07/09 07:47:25 OK 2_object_stats_trigger.sql (1.36ms)13982026/07/09 07:47:25 goose: up to current file version: 213992026/07/09 07:47:25 OK 1_commit_pending_closure.sql (2.9ms)1400--- PASS: TestService_healthCheckHandler (0.67s)14012026/07/09 07:47:25 INFO Created nix-cache-info in bucket bucket=bucket3314022026/07/09 07:47:25 OK 2_object_stats_trigger.sql (1.32ms)14032026/07/09 07:47:25 goose: up to current file version: 214042026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures1405--- PASS: TestCacheStatsHandler (0.67s)1406=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1407=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1408=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1409=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1410=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1411=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1412=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1413=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1414=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1415=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1416=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1417=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected14182026/07/09 07:47:25 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1419--- PASS: TestMetricsInventory (0.68s)1420--- PASS: TestObjectStatsTrigger (0.68s)14212026/07/09 07:47:25 INFO Aborted multipart uploads count=014222026/07/09 07:47:25 WARN Authentication failed token_preview=eyJhbGciOi...cMxb3Xt1Nw 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]14232026/07/09 07:47:25 INFO OIDC auth successful provider=test1424--- PASS: TestResurrectedObjectNotDeleted (0.69s)14252026/07/09 07:47:25 WARN Force mode enabled - objects will be deleted immediately without grace period1426--- PASS: TestService_AuthMiddleware_OIDC (0.68s)1427 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1428 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1429 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)1430 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)14312026/07/09 07:47:25 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01432=== NAME TestClientMultipleUploads1433 client_integration_test.go:338: Created store path 0: /build/TestClientMultipleUploads3187818322/001/store/d3az7c6c3pjqp4zyq94k6kngrqkkscc0-test-file-0.txt1434=== NAME TestClientIntegration1435 client_integration_test.go:276: Created store path: /build/TestClientIntegration1640934166/002/store/vdzibbagidn188mgnrybif9fixg3pf97-test-file.txt14362026/07/09 07:47:25 INFO Vacuumed table table=pending_closures1437=== NAME TestNARDeduplicationMetadataUploadBug1438 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2548041863/001/store/4imqsqgvjmhc0pf4ra2yq1b0ansjvihx-file1.txt14392026/07/09 07:47:25 INFO Vacuumed table table=pending_objects14402026/07/09 07:47:25 INFO Vacuumed table table=multipart_uploads14412026/07/09 07:47:25 INFO Vacuumed table table=closures14422026/07/09 07:47:25 INFO Vacuumed table table=objects1443--- PASS: TestGCMetrics (0.70s)1444=== NAME TestClientWithDependencies1445 client_integration_test.go:593: Built derivation: /build/TestClientWithDependencies128022519/001/store/miba43sjma05yp3cd1h05y0gcy4qbkg2-test-script1446=== NAME TestClientMultipleUploads1447 client_integration_test.go:338: Created store path 1: /build/TestClientMultipleUploads3187818322/001/store/8iw19awy044ra57bz2fly7m1j3nhgw5b-test-file-1.txt1448=== NAME TestPinProtectsFromGC1449 client_integration_test.go:646: Pinned store path: /build/TestPinProtectsFromGC3736952530/001/store/pm65raa2id68wmxv2b29hdgb3pg9y7r6-pinned-file.txt1450 client_integration_test.go:647: Unpinned store path: /build/TestPinProtectsFromGC3736952530/001/store/46jrjbv0n2r5vvjzr2py8pskldq54j6i-unpinned-file.txt1451=== NAME TestClientWithDependencies1452 client_integration_test.go:595: Found 1 dependencies (including self)1453=== NAME TestClientCADerivations1454 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2512305492/001/store/11pi191l9xzb5w0v5yys0jvk7a72wzqi-ca-test1455=== NAME TestClientMultipleUploads1456 client_integration_test.go:338: Created store path 2: /build/TestClientMultipleUploads3187818322/001/store/9d6z35rwl55l8jk06ik4ipdfddk6g6nl-test-file-2.txt1457=== NAME TestClientCADerivations1458 client_ca_test.go:139: Found 1 dependencies (including self)14592026/07/09 07:47:25 INFO Received cleanup request method=DELETE path=/api/pending_closures14602026/07/09 07:47:25 INFO Aborted multipart uploads count=11461--- PASS: TestMultipartCleanup (0.79s)14622026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures14632026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures14642026/07/09 07:47:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14652026/07/09 07:47:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14662026/07/09 07:47:25 INFO Uploading 4imqsqgvjmhc0pf4ra2yq1b0ansjvihx-file1.txt (160B)14672026/07/09 07:47:25 INFO Uploading vdzibbagidn188mgnrybif9fixg3pf97-test-file.txt (152B)14682026/07/09 07:47:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14692026/07/09 07:47:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14702026/07/09 07:47:25 INFO Signed narinfos id=1 count=114712026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures14722026/07/09 07:47:25 INFO Uploading 1 narinfos14732026/07/09 07:47:25 INFO Signed narinfos id=1 count=114742026/07/09 07:47:25 INFO Uploading 1 narinfos14752026/07/09 07:47:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14762026/07/09 07:47:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14772026/07/09 07:47:25 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"14782026/07/09 07:47:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14792026/07/09 07:47:25 INFO Uploading miba43sjma05yp3cd1h05y0gcy4qbkg2-test-script (136B)14802026/07/09 07:47:25 INFO Completed upload id=114812026/07/09 07:47:25 INFO Upload complete. (104ms)14822026/07/09 07:47:25 INFO Completed upload id=114832026/07/09 07:47:25 INFO Upload complete. (105ms)1484=== NAME TestClientIntegration1485 client_integration_test.go:292: Retrieved narinfo from S3:1486 StorePath: /build/TestClientIntegration1640934166/002/store/vdzibbagidn188mgnrybif9fixg3pf97-test-file.txt1487 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1488 Compression: zstd1489 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11490 NarSize: 1521491 References: 1492 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11493=== NAME TestNARDeduplicationMetadataUploadBug1494 metadata_upload_test.go:54: Retrieved narinfo from S3:1495 StorePath: /build/TestNARDeduplicationMetadataUploadBug2548041863/001/store/4imqsqgvjmhc0pf4ra2yq1b0ansjvihx-file1.txt1496 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1497 Compression: zstd1498 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1499 NarSize: 1601500 References: 1501 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf15022026/07/09 07:47:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1503=== NAME TestClientIntegration1504 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1505 client_integration_test.go:293: Decompressed .ls content (64 bytes):1506 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1507 client_integration_test.go:296: Testing garbage collection...15082026/07/09 07:47:25 INFO Signed narinfos id=1 count=115092026/07/09 07:47:25 INFO Uploading 1 narinfos1510=== NAME TestNARDeduplicationMetadataUploadBug1511 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1512 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1513 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}15142026/07/09 07:47:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15152026/07/09 07:47:25 INFO Completed upload id=115162026/07/09 07:47:25 INFO Upload complete. (62ms)1517=== NAME TestClientWithDependencies1518 client_integration_test.go:597: Skipping nix copy test - isolated store (/build/TestClientWithDependencies128022519/001/store) requires matching store prefix1519--- PASS: TestClientWithDependencies (0.85s)15202026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures15212026/07/09 07:47:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15222026/07/09 07:47:25 INFO Uploading pm65raa2id68wmxv2b29hdgb3pg9y7r6-pinned-file.txt (128B)15232026/07/09 07:47:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures15242026/07/09 07:47:25 INFO Garbage collection started1525=== NAME TestNARDeduplicationMetadataUploadBug1526 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2548041863/001/store/7lagczyxlhy7c47v2q7pq5l3zrxp81hx-file2.txt15272026/07/09 07:47:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15282026/07/09 07:47:25 INFO Signed narinfos id=1 count=115292026/07/09 07:47:25 INFO Uploading 1 narinfos15302026/07/09 07:47:25 INFO Aborted multipart uploads count=015312026/07/09 07:47:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15322026/07/09 07:47:25 WARN Force mode enabled - objects will be deleted immediately without grace period15332026/07/09 07:47:25 INFO Completed upload id=115342026/07/09 07:47:25 INFO Upload complete. (121ms)15352026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures15362026/07/09 07:47:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15372026/07/09 07:47:25 INFO Uploading 11pi191l9xzb5w0v5yys0jvk7a72wzqi-ca-test (144B)1538--- PASS: TestGCBugBareHashReferences (0.89s)15392026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures15402026/07/09 07:47:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15412026/07/09 07:47:25 INFO Signed narinfos id=1 count=115422026/07/09 07:47:25 INFO Uploading 1 narinfos15432026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures15442026/07/09 07:47:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15452026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures15462026/07/09 07:47:25 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15472026/07/09 07:47:25 INFO Uploading 9d6z35rwl55l8jk06ik4ipdfddk6g6nl-test-file-2.txt (160B)15482026/07/09 07:47:25 INFO Uploading d3az7c6c3pjqp4zyq94k6kngrqkkscc0-test-file-0.txt (160B)15492026/07/09 07:47:25 INFO Uploading 8iw19awy044ra57bz2fly7m1j3nhgw5b-test-file-1.txt (160B)15502026/07/09 07:47:25 INFO Completed upload id=115512026/07/09 07:47:25 INFO Upload complete. (92ms)1552=== NAME TestClientCADerivations1553 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2512305492/001/store/11pi191l9xzb5w0v5yys0jvk7a72wzqi-ca-test1554 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1555 Compression: zstd1556 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1557 NarSize: 1441558 References: 1559 Deriver: /build/TestClientCADerivations2512305492/001/store/c949h1k99gyfqa2d8wsc6hsjv3m632lx-ca-test.drv1560 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1561 client_ca_test.go:185: Checking for realisation files in S3...1562 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1563 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15642026/07/09 07:47:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15652026/07/09 07:47:25 INFO Signed narinfos id=3 count=115662026/07/09 07:47:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15672026/07/09 07:47:25 INFO Signed narinfos id=1 count=115682026/07/09 07:47:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15692026/07/09 07:47:25 INFO Signed narinfos id=2 count=115702026/07/09 07:47:25 INFO Uploading 3 narinfos15712026/07/09 07:47:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15722026/07/09 07:47:25 INFO Completed upload id=115732026/07/09 07:47:25 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15742026/07/09 07:47:25 INFO Completed upload id=215752026/07/09 07:47:25 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete15762026/07/09 07:47:25 INFO Completed upload id=315772026/07/09 07:47:25 INFO Upload complete. (113ms)1578=== NAME TestClientMultipleUploads1579 client_integration_test.go:349: Uploaded 3 paths in 171.922005ms15802026/07/09 07:47:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1581=== NAME TestOrphanedObjectsGC1582 orphaned_objects_gc_test.go:290: GC Test Summary:1583 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1584 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1585 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1586 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1587 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1588--- PASS: TestOrphanedObjectsGC (0.94s)15892026/07/09 07:47:25 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=778.832392ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1590--- PASS: TestClientMultipleUploads (0.94s)15912026/07/09 07:47:25 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NzY4YjI0NGEtMjMxMy00OThmLTg0NmMtY2JkMjIyYzBmNmQ0LjMwYWQxODc2LTEwMGItNGRkNi1hZGZmLWNlYzBmOGU1NDljMngxNzgzNTgzMjQ1NTI2NDM0MTI5 parts=1015922026/07/09 07:47:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15932026/07/09 07:47:25 INFO Completed upload id=115942026/07/09 07:47:25 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015952026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures15962026/07/09 07:47:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures15972026/07/09 07:47:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15982026/07/09 07:47:25 INFO Aborted multipart uploads count=015992026/07/09 07:47:25 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NzY4YjI0NGEtMjMxMy00OThmLTg0NmMtY2JkMjIyYzBmNmQ0LjlmYzU4YWRmLTk5NzgtNDk2OC1hYTIxLTU5OTc2MjVhOGFiOXgxNzgzNTgzMjQ1NDY5MjAyMTIy parts=121600--- PASS: TestRedundantMultipartUpload (0.97s)16012026/07/09 07:47:25 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=016022026/07/09 07:47:25 INFO Vacuumed table table=pending_closures16032026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures16042026/07/09 07:47:25 INFO Vacuumed table table=pending_objects16052026/07/09 07:47:25 INFO Vacuumed table table=multipart_uploads16062026/07/09 07:47:25 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16072026/07/09 07:47:25 INFO Vacuumed table table=closures16082026/07/09 07:47:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16092026/07/09 07:47:25 INFO Signed narinfos id=2 count=116102026/07/09 07:47:25 INFO Uploading 1 narinfos16112026/07/09 07:47:25 INFO Vacuumed table table=objects16122026/07/09 07:47:25 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16132026/07/09 07:47:25 INFO Completed upload id=216142026/07/09 07:47:25 INFO Upload complete. (86ms)16152026/07/09 07:47:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16162026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures1617=== NAME TestNARDeduplicationMetadataUploadBug1618 metadata_upload_test.go:76: Retrieved narinfo from S3:1619 StorePath: /build/TestNARDeduplicationMetadataUploadBug2548041863/001/store/7lagczyxlhy7c47v2q7pq5l3zrxp81hx-file2.txt1620 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1621 Compression: zstd1622 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1623 NarSize: 1601624 References: 1625 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf16262026/07/09 07:47:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16272026/07/09 07:47:25 INFO Uploading 46jrjbv0n2r5vvjzr2py8pskldq54j6i-unpinned-file.txt (128B)1628 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1629=== NAME TestClientCADerivations1630 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1631 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1632 error: binary cache 's3://bucket33?endpoint=http://localhost:34897®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2512305492/001/store'1633=== NAME TestNARDeduplicationMetadataUploadBug1634 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1635 {"version":1,"root":{"type":"regular","size":44}}1636=== NAME TestClientCADerivations1637 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 116382026/07/09 07:47:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NzY4YjI0NGEtMjMxMy00OThmLTg0NmMtY2JkMjIyYzBmNmQ0LjkzMjZlMWRmLTViNjEtNDA1My1hMTNhLWU3M2I0YzBjYzI5Y3gxNzgzNTgzMjQ1NTc1NjY1Mjg4 parts=1016392026/07/09 07:47:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16402026/07/09 07:47:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16412026/07/09 07:47:25 INFO Signed narinfos id=2 count=11642--- PASS: TestNARDeduplicationMetadataUploadBug (0.99s)16432026/07/09 07:47:25 INFO Uploading 1 narinfos1644--- PASS: TestClientCADerivations (0.99s)16452026/07/09 07:47:25 INFO Completed upload id=116462026/07/09 07:47:25 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16472026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures16482026/07/09 07:47:25 INFO Received uploads request method=POST path=/api/pending_closures16492026/07/09 07:47:25 INFO Completed upload id=216502026/07/09 07:47:25 INFO Upload complete. (80ms)16512026/07/09 07:47:25 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16522026/07/09 07:47:25 WARN Found objects in DB but missing from S3, will re-upload count=11653--- PASS: TestService_verifyS3Integrity (1.00s)16542026/07/09 07:47:25 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001655--- PASS: TestService_createPendingClosureHandler (1.00s)16562026/07/09 07:47:25 INFO Received create pin request method=POST path=/api/pins/myapp16572026/07/09 07:47:25 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3736952530/001/store/pm65raa2id68wmxv2b29hdgb3pg9y7r6-pinned-file.txt narinfo_key=pm65raa2id68wmxv2b29hdgb3pg9y7r6.narinfo16582026/07/09 07:47:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures16592026/07/09 07:47:25 INFO Garbage collection started16602026/07/09 07:47:25 INFO Aborted multipart uploads count=016612026/07/09 07:47:25 WARN Force mode enabled - objects will be deleted immediately without grace period1662--- PASS: TestUploadHandlersRejectOversizedBody (0.22s)1663 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)1664 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)1665 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.13s)1666=== NAME TestOrphanedObjectsGCStressTest1667 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1668 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1669 orphaned_objects_gc_test.go:509: Stress test completed successfully:1670 orphaned_objects_gc_test.go:510: - Active objects preserved: 2016712026/07/09 07:47:26 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=01672 orphaned_objects_gc_test.go:511: - Objects deleted: 2101673 orphaned_objects_gc_test.go:512: - Total GC'd: 2101674--- PASS: TestOrphanedObjectsGCStressTest (1.62s)16752026/07/09 07:47:26 INFO Vacuumed table table=pending_closures16762026/07/09 07:47:26 INFO Vacuumed table table=pending_objects16772026/07/09 07:47:26 INFO Vacuumed table table=multipart_uploads16782026/07/09 07:47:26 INFO Vacuumed table table=closures16792026/07/09 07:47:26 INFO Vacuumed table table=objects16802026/07/09 07:47:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.665521364s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16812026/07/09 07:47:26 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=016822026/07/09 07:47:26 INFO Vacuumed table table=pending_closures16832026/07/09 07:47:26 INFO Vacuumed table table=pending_objects16842026/07/09 07:47:26 INFO Vacuumed table table=multipart_uploads16852026/07/09 07:47:26 INFO Vacuumed table table=closures16862026/07/09 07:47:26 INFO Vacuumed table table=objects16872026/07/09 07:47:27 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01688=== NAME TestClientIntegration1689 client_integration_test.go:303: Objects in database after GC:1690 client_integration_test.go:303: Successfully deleted all objects with GC --force1691--- PASS: TestClientIntegration (2.87s)16922026/07/09 07:47:27 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01693=== NAME TestPinProtectsFromGC1694 client_integration_test.go:709: Pin successfully protected closure from garbage collection1695--- PASS: TestPinProtectsFromGC (3.04s)1696--- PASS: TestClientErrorHandling (0.09s)1697 --- PASS: TestClientErrorHandling/InvalidStorePath (0.61s)1698 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.73s)1699 --- PASS: TestClientErrorHandling/ServerNotAvailable (3.30s)17002026/07/09 07:47:30 WARN Rate limiter enabled after throttle name=s3-test rate=517012026/07/09 07:47:30 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1702=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1703 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101704 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001705--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.25s)1706PASS1707{"timestamp":"2026-07-09T07:47:30.645478831Z","level":"ERROR","fields":{"message":"Unknown connection IO error:Cancelled","peer_addr":"127.0.0.1:60294"},"target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":973,"threadName":"rustfs-worker","threadId":"ThreadId(380)"}17082026-07-09 07:47:30.817 UTC [235] LOG: received smart shutdown request17092026-07-09 07:47:30.822 UTC [235] LOG: background worker "logical replication launcher" (PID 245) exited with exit code 117102026-07-09 07:47:30.830 UTC [240] LOG: shutting down17112026-07-09 07:47:30.831 UTC [240] LOG: checkpoint starting: shutdown immediate17122026-07-09 07:47:31.746 UTC [240] LOG: checkpoint complete: wrote 8342 buffers (50.9%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 12 recycled; write=0.177 s, sync=0.730 s, total=0.916 s; sync files=14509, longest=0.001 s, average=0.001 s; distance=199420 kB, estimate=199420 kB; lsn=0/DA1E310, redo lsn=0/DA1E31017132026-07-09 07:47:31.863 UTC [235] LOG: database system is shut down1714Running OIDC tests...1715=== RUN TestGlobMatch1716=== PAUSE TestGlobMatch1717=== RUN TestAudienceForIssuer1718=== PAUSE TestAudienceForIssuer1719=== RUN TestValidateToken_ValidToken1720=== PAUSE TestValidateToken_ValidToken1721=== RUN TestValidateToken_WrongAudience1722=== PAUSE TestValidateToken_WrongAudience1723=== RUN TestValidateToken_Expired1724=== PAUSE TestValidateToken_Expired1725=== RUN TestValidateToken_BoundClaimsMismatch1726=== PAUSE TestValidateToken_BoundClaimsMismatch1727=== RUN TestValidateToken_BoundSubjectMismatch1728=== PAUSE TestValidateToken_BoundSubjectMismatch1729=== RUN TestValidateToken_MultipleProviders1730=== PAUSE TestValidateToken_MultipleProviders1731=== RUN TestValidateToken_NoMatchingProvider1732=== PAUSE TestValidateToken_NoMatchingProvider1733=== CONT TestGlobMatch1734=== CONT TestValidateToken_MultipleProviders1735=== RUN TestGlobMatch/foo_foo1736=== PAUSE TestGlobMatch/foo_foo1737=== CONT TestValidateToken_BoundClaimsMismatch1738=== CONT TestValidateToken_WrongAudience1739=== CONT TestValidateToken_ValidToken1740=== CONT TestValidateToken_BoundSubjectMismatch1741=== CONT TestAudienceForIssuer1742=== CONT TestValidateToken_Expired1743=== CONT TestValidateToken_NoMatchingProvider1744=== RUN TestGlobMatch/foo_bar1745--- PASS: TestAudienceForIssuer (0.00s)1746=== PAUSE TestGlobMatch/foo_bar1747=== RUN TestGlobMatch/*_1748=== PAUSE TestGlobMatch/*_1749=== RUN TestGlobMatch/*_anything1750=== PAUSE TestGlobMatch/*_anything1751=== RUN TestGlobMatch/foo*_foo1752=== PAUSE TestGlobMatch/foo*_foo1753=== RUN TestGlobMatch/foo*_foobar1754=== PAUSE TestGlobMatch/foo*_foobar1755=== RUN TestGlobMatch/foo*_bar1756=== PAUSE TestGlobMatch/foo*_bar1757=== RUN TestGlobMatch/*bar_bar1758=== PAUSE TestGlobMatch/*bar_bar1759=== RUN TestGlobMatch/*bar_foobar1760=== PAUSE TestGlobMatch/*bar_foobar1761=== RUN TestGlobMatch/*bar_foo1762=== PAUSE TestGlobMatch/*bar_foo1763=== RUN TestGlobMatch/foo*bar_foobar1764=== PAUSE TestGlobMatch/foo*bar_foobar1765=== RUN TestGlobMatch/foo*bar_foo123bar1766=== PAUSE TestGlobMatch/foo*bar_foo123bar1767=== RUN TestGlobMatch/foo*bar_foobarbaz1768=== PAUSE TestGlobMatch/foo*bar_foobarbaz1769=== RUN TestGlobMatch/*/*_foo/bar1770=== PAUSE TestGlobMatch/*/*_foo/bar1771=== RUN TestGlobMatch/*/*_foo1772=== PAUSE TestGlobMatch/*/*_foo1773=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1774=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1775=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01776=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01777=== RUN TestGlobMatch/refs/*/main_refs/heads/main1778=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1779=== RUN TestGlobMatch/fo?_foo1780=== PAUSE TestGlobMatch/fo?_foo1781=== RUN TestGlobMatch/fo?_fo1782=== PAUSE TestGlobMatch/fo?_fo1783=== RUN TestGlobMatch/fo?_fooo1784=== PAUSE TestGlobMatch/fo?_fooo1785=== RUN TestGlobMatch/?oo_foo1786=== PAUSE TestGlobMatch/?oo_foo1787=== RUN TestGlobMatch/?oo_boo1788=== PAUSE TestGlobMatch/?oo_boo1789=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1790=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1791=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1792=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1793=== CONT TestGlobMatch/foo_foo1794=== CONT TestGlobMatch/*/*_foo/bar1795=== CONT TestGlobMatch/foo*bar_foobarbaz1796=== CONT TestGlobMatch/foo*bar_foo123bar1797=== CONT TestGlobMatch/foo*bar_foobar1798=== CONT TestGlobMatch/*bar_foo1799=== CONT TestGlobMatch/*bar_foobar1800=== CONT TestGlobMatch/*bar_bar1801=== CONT TestGlobMatch/foo*_bar1802=== CONT TestGlobMatch/foo*_foobar1803=== CONT TestGlobMatch/foo*_foo1804=== CONT TestGlobMatch/*_anything1805=== CONT TestGlobMatch/*_1806=== CONT TestGlobMatch/foo_bar1807=== CONT TestGlobMatch/fo?_fo1808=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1809=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1810=== CONT TestGlobMatch/?oo_boo1811=== CONT TestGlobMatch/?oo_foo1812=== CONT TestGlobMatch/fo?_fooo1813=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01814=== CONT TestGlobMatch/fo?_foo1815=== CONT TestGlobMatch/refs/*/main_refs/heads/main1816=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1817=== CONT TestGlobMatch/*/*_foo1818--- PASS: TestGlobMatch (0.01s)1819 --- PASS: TestGlobMatch/foo_foo (0.00s)1820 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1821 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1822 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1823 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1824 --- PASS: TestGlobMatch/*bar_foo (0.00s)1825 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1826 --- PASS: TestGlobMatch/*bar_bar (0.00s)1827 --- PASS: TestGlobMatch/foo*_bar (0.00s)1828 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1829 --- PASS: TestGlobMatch/foo*_foo (0.00s)1830 --- PASS: TestGlobMatch/*_anything (0.00s)1831 --- PASS: TestGlobMatch/*_ (0.00s)1832 --- PASS: TestGlobMatch/foo_bar (0.00s)1833 --- PASS: TestGlobMatch/fo?_fo (0.00s)1834 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1835 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1836 --- PASS: TestGlobMatch/?oo_boo (0.00s)1837 --- PASS: TestGlobMatch/?oo_foo (0.00s)1838 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1839 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1840 --- PASS: TestGlobMatch/fo?_foo (0.00s)1841 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1842 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1843 --- PASS: TestGlobMatch/*/*_foo (0.00s)18442026/07/09 07:47:32 INFO OIDC provider initialized name=test18452026/07/09 07:47:32 INFO OIDC provider initialized name=test18462026/07/09 07:47:32 INFO OIDC provider initialized name=test18472026/07/09 07:47:32 INFO OIDC provider initialized name=test18482026/07/09 07:47:32 INFO OIDC provider initialized name=test18492026/07/09 07:47:32 INFO OIDC provider initialized name=provider118502026/07/09 07:47:32 INFO OIDC provider initialized name=provider118512026/07/09 07:47:32 INFO OIDC provider initialized name=provider21852--- PASS: TestValidateToken_ValidToken (0.02s)1853--- PASS: TestValidateToken_WrongAudience (0.02s)1854--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)1855--- PASS: TestValidateToken_Expired (0.01s)1856--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)1857--- PASS: TestValidateToken_MultipleProviders (0.02s)1858--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1859PASS1860Running hook tests...1861=== RUN TestSendPathsEmpty1862=== PAUSE TestSendPathsEmpty1863=== RUN TestQueueEnqueueAndFetch1864=== PAUSE TestQueueEnqueueAndFetch1865=== RUN TestQueueDeduplication1866=== PAUSE TestQueueDeduplication1867=== RUN TestQueueRemove1868=== PAUSE TestQueueRemove1869=== RUN TestQueueFetchBatchLimit1870=== PAUSE TestQueueFetchBatchLimit1871=== RUN TestQueueFetchRemoveLifecycle1872=== PAUSE TestQueueFetchRemoveLifecycle1873=== RUN TestQueueConcurrentWriters1874=== PAUSE TestQueueConcurrentWriters1875=== RUN TestServerClientIntegration1876=== PAUSE TestServerClientIntegration1877=== RUN TestServerQueueError1878=== PAUSE TestServerQueueError1879=== RUN TestGetListenerSocketActivation1880 server_test.go:210: === RUN TestGetListenerSocketActivation1881 --- PASS: TestGetListenerSocketActivation (0.00s)1882 PASS1883 1884--- PASS: TestGetListenerSocketActivation (0.01s)1885=== RUN TestWorkerUploadsAndRemoves1886=== PAUSE TestWorkerUploadsAndRemoves1887=== RUN TestWorkerSkipsGCdPaths1888=== PAUSE TestWorkerSkipsGCdPaths1889=== RUN TestWorkerPrunesClosureDeps1890=== PAUSE TestWorkerPrunesClosureDeps1891=== CONT TestSendPathsEmpty1892=== CONT TestQueueConcurrentWriters1893=== CONT TestServerQueueError1894--- PASS: TestSendPathsEmpty (0.00s)1895=== CONT TestQueueFetchRemoveLifecycle1896=== CONT TestQueueFetchBatchLimit1897=== CONT TestQueueRemove1898=== CONT TestWorkerUploadsAndRemoves1899=== CONT TestQueueDeduplication1900=== CONT TestQueueEnqueueAndFetch1901=== CONT TestWorkerPrunesClosureDeps1902=== CONT TestWorkerSkipsGCdPaths1903=== CONT TestServerClientIntegration19042026/07/09 07:47:32 ERROR Failed to queue paths error="permission denied" count=11905--- PASS: TestServerQueueError (0.01s)1906--- PASS: TestServerClientIntegration (0.00s)19072026/07/09 07:47:32 INFO Upload queue status pending=219082026/07/09 07:47:32 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths283029456/002/nonexistent19092026/07/09 07:47:32 INFO Uploading batch count=11910--- PASS: TestQueueEnqueueAndFetch (0.02s)1911--- PASS: TestQueueDeduplication (0.02s)1912--- PASS: TestQueueFetchBatchLimit (0.03s)19132026/07/09 07:47:32 INFO Upload queue status pending=219142026/07/09 07:47:32 INFO Uploading batch count=219152026/07/09 07:47:32 INFO Upload queue status pending=219162026/07/09 07:47:32 INFO Uploading batch count=11917--- PASS: TestQueueRemove (0.02s)1918--- PASS: TestQueueFetchRemoveLifecycle (0.03s)1919--- PASS: TestWorkerSkipsGCdPaths (0.07s)1920--- PASS: TestWorkerPrunesClosureDeps (0.07s)1921--- PASS: TestWorkerUploadsAndRemoves (0.07s)1922--- PASS: TestQueueConcurrentWriters (0.23s)1923PASS