niks3-go-unit-tests
x86_64-linux.go-unit-tests
· build #102
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestCaseHackSuffix6=== PAUSE TestCaseHackSuffix7=== RUN TestPartSizeForNAR8=== PAUSE TestPartSizeForNAR9=== RUN TestUploadMultipart_SupersededByPeer10=== PAUSE TestUploadMultipart_SupersededByPeer11=== RUN TestDumpPathMatchesNix12=== PAUSE TestDumpPathMatchesNix13=== RUN TestDumpPathSingleFile14=== PAUSE TestDumpPathSingleFile15=== RUN TestDumpPathWriterError16=== PAUSE TestDumpPathWriterError17=== RUN TestEncodeNixBase3218=== PAUSE TestEncodeNixBase3219=== RUN TestEncodeNixBase32WithRealHash20=== PAUSE TestEncodeNixBase32WithRealHash21=== RUN TestConvertHashToNix3222=== PAUSE TestConvertHashToNix3223=== RUN TestGetStorePathHash24=== PAUSE TestGetStorePathHash25=== RUN TestPathInfoHashCompatibility26=== PAUSE TestPathInfoHashCompatibility27=== RUN TestParsePathInfoJSON28=== PAUSE TestParsePathInfoJSON29=== RUN TestParsePathInfoJSONMultiplePaths30=== PAUSE TestParsePathInfoJSONMultiplePaths31=== RUN TestPathInfoCACompatibility32=== PAUSE TestPathInfoCACompatibility33=== RUN TestRateLimiterFeedback34=== PAUSE TestRateLimiterFeedback35=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess36=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess37=== RUN TestResolveStorePath38=== PAUSE TestResolveStorePath39=== RUN TestDoWithRetry_BodyReplayedViaGetBody40=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody41=== RUN TestShellSplit42=== PAUSE TestShellSplit43=== RUN TestShellSplitErrors44=== PAUSE TestShellSplitErrors45=== RUN TestSetClientTLS46=== PAUSE TestSetClientTLS47=== RUN TestSetClientTLSDoesNotMutateDefaultTransport48=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport49=== RUN TestSetClientTLSErrors50=== PAUSE TestSetClientTLSErrors51=== RUN TestStaticToken52=== PAUSE TestStaticToken53=== RUN TestFileTokenReadsAndCaches54=== PAUSE TestFileTokenReadsAndCaches55=== RUN TestFileTokenMissing56=== PAUSE TestFileTokenMissing57=== RUN TestFileTokenEmpty58=== PAUSE TestFileTokenEmpty59=== RUN TestScriptTokenNoExpiryRerunsEveryCall60=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall61=== RUN TestScriptTokenCachesUntilRefresh62=== PAUSE TestScriptTokenCachesUntilRefresh63=== RUN TestScriptTokenEmptyToken64=== PAUSE TestScriptTokenEmptyToken65=== RUN TestScriptTokenBadJSON66=== PAUSE TestScriptTokenBadJSON67=== RUN TestScriptTokenScriptFails68=== PAUSE TestScriptTokenScriptFails69=== RUN TestScriptTokenEmptyCommand70=== PAUSE TestScriptTokenEmptyCommand71=== CONT TestDoServerRequestAttachesToken72=== CONT TestScriptTokenEmptyCommand73=== CONT TestConvertHashToNix3274=== CONT TestEncodeNixBase32WithRealHash75=== CONT TestSetClientTLSDoesNotMutateDefaultTransport76=== CONT TestShellSplit77=== CONT TestStaticToken78=== CONT TestDoWithRetry_BodyReplayedViaGetBody79=== CONT TestScriptTokenEmptyToken80=== CONT TestScriptTokenBadJSON81=== CONT TestScriptTokenCachesUntilRefresh82=== CONT TestResolveStorePath83=== CONT TestScriptTokenNoExpiryRerunsEveryCall84=== CONT TestScriptTokenScriptFails85=== CONT TestFileTokenMissing86=== CONT TestDumpPathMatchesNix87=== CONT TestFileTokenReadsAndCaches88=== CONT TestFileTokenEmpty89=== CONT TestEncodeNixBase3290=== RUN TestEncodeNixBase32/test_string_hash91=== CONT TestDumpPathWriterError92=== CONT TestDumpPathSingleFile93=== CONT TestPartSizeForNAR94=== CONT TestParsePathInfoJSON95=== RUN TestParsePathInfoJSON/Nix_format96=== CONT TestPathInfoCACompatibility97=== RUN TestPartSizeForNAR/zero_stays_at_minimum98=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum99=== RUN TestPathInfoCACompatibility/null_ca_field100=== RUN TestPartSizeForNAR/small_stays_at_minimum101=== PAUSE TestPartSizeForNAR/small_stays_at_minimum102=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum103=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum104=== CONT TestRateLimiterFeedback105=== CONT TestSetClientTLS106=== PAUSE TestPathInfoCACompatibility/null_ca_field107=== CONT TestSetClientTLSErrors108=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts109=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts110=== RUN TestPathInfoCACompatibility/old_string_format_-_text1112026/07/19 09:30:09 WARN Rate limiter enabled after throttle name=server-test rate=5112=== RUN TestPartSizeForNAR/1_TiB1132026/07/19 09:30:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33253114=== PAUSE TestPartSizeForNAR/1_TiB115=== CONT TestPathInfoHashCompatibility116=== CONT TestShellSplitErrors117=== CONT TestUploadMultipart_SupersededByPeer118--- PASS: TestScriptTokenEmptyCommand (0.00s)119=== RUN TestConvertHashToNix32/SRI_format_to_Nix32120=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess121=== PAUSE TestEncodeNixBase32/test_string_hash1222026/07/19 09:30:09 WARN Rate limiter backed off name=server-test rate=5123=== PAUSE TestParsePathInfoJSON/Nix_format124=== CONT TestCaseHackSuffix1252026/07/19 09:30:09 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33253126=== CONT TestParsePathInfoJSONMultiplePaths127=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths128=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths129=== RUN TestParsePathInfoJSON/Lix_format130=== CONT TestGetStorePathHash131=== RUN TestGetStorePathHash/valid_store_path1322026/07/19 09:30:09 WARN Rate limiter enabled after throttle name=server-test rate=5133=== PAUSE TestGetStorePathHash/valid_store_path134=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text135=== RUN TestPartSizeForNAR/5_TiB_S3_max_object136=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object137=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)138=== RUN TestUploadMultipart_SupersededByPeer/exists139--- PASS: TestEncodeNixBase32WithRealHash (0.00s)140=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32141=== RUN TestEncodeNixBase32/empty_input142=== RUN TestRateLimiterFeedback/429_enables_limiter143=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths144=== PAUSE TestParsePathInfoJSON/Lix_format145=== RUN TestGetStorePathHash/basename_without_hyphen_should_error146=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive147=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)148=== RUN TestConvertHashToNix32/already_Nix32_format149=== PAUSE TestRateLimiterFeedback/429_enables_limiter150=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths151--- PASS: TestStaticToken (0.00s)152=== PAUSE TestConvertHashToNix32/already_Nix32_format153=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive154=== PAUSE TestEncodeNixBase32/empty_input155=== RUN TestSetClientTLSErrors/missing_cert_file156=== PAUSE TestSetClientTLSErrors/missing_cert_file157=== RUN TestPartSizeForNAR/capped_at_5_GiB158=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon159=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon160=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI161=== RUN TestParsePathInfoJSON/empty_input162=== RUN TestSetClientTLS/rejects_connection_without_client_cert163=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert164=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA165=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA166=== RUN TestSetClientTLS/preserves_debug_logging_transport167=== PAUSE TestUploadMultipart_SupersededByPeer/exists168=== RUN TestRateLimiterFeedback/503_enables_limiter169=== RUN TestUploadMultipart_SupersededByPeer/missing170=== PAUSE TestUploadMultipart_SupersededByPeer/missing171=== PAUSE TestRateLimiterFeedback/503_enables_limiter172--- PASS: TestShellSplit (0.00s)173--- PASS: TestFileTokenReadsAndCaches (0.00s)174=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error175=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths176=== RUN TestConvertHashToNix32/invalid_format177=== RUN TestPathInfoCACompatibility/new_structured_format_-_text178=== PAUSE TestConvertHashToNix32/invalid_format179=== CONT TestEncodeNixBase32/test_string_hash180=== CONT TestEncodeNixBase32/empty_input181=== RUN TestSetClientTLSErrors/missing_key_file182=== PAUSE TestSetClientTLSErrors/missing_key_file183=== RUN TestSetClientTLSErrors/missing_ca_file184=== PAUSE TestSetClientTLSErrors/missing_ca_file185=== PAUSE TestPartSizeForNAR/capped_at_5_GiB186=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI187=== PAUSE TestParsePathInfoJSON/empty_input188=== RUN TestParsePathInfoJSON/whitespace_only189=== PAUSE TestParsePathInfoJSON/whitespace_only190=== PAUSE TestSetClientTLS/preserves_debug_logging_transport191=== CONT TestSetClientTLS/rejects_connection_without_client_cert192=== CONT TestSetClientTLS/preserves_debug_logging_transport193=== CONT TestUploadMultipart_SupersededByPeer/exists194=== CONT TestUploadMultipart_SupersededByPeer/missing195=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter196=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter197=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter198=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter199--- PASS: TestResolveStorePath (0.00s)200=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text201=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error202=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method203=== CONT TestConvertHashToNix32/SRI_format_to_Nix32204=== CONT TestConvertHashToNix32/already_Nix32_format205=== CONT TestConvertHashToNix32/invalid_format206=== RUN TestSetClientTLSErrors/invalid_ca_file207=== CONT TestPartSizeForNAR/zero_stays_at_minimum208=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts209=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum210=== CONT TestPartSizeForNAR/1_TiB211=== CONT TestPartSizeForNAR/capped_at_5_GiB212=== CONT TestPartSizeForNAR/small_stays_at_minimum213=== CONT TestPartSizeForNAR/5_TiB_S3_max_object214=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512215=== RUN TestParsePathInfoJSON/invalid_JSON216=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths217=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA218=== CONT TestRateLimiterFeedback/429_enables_limiter219=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter220=== CONT TestRateLimiterFeedback/503_enables_limiter221=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter222--- PASS: TestFileTokenEmpty (0.00s)223=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error224=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method225=== PAUSE TestSetClientTLSErrors/invalid_ca_file226=== CONT TestSetClientTLSErrors/invalid_ca_file227=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive228=== CONT TestSetClientTLSErrors/missing_cert_file229=== CONT TestPathInfoCACompatibility/old_string_format_-_text230=== PAUSE TestParsePathInfoJSON/invalid_JSON231=== CONT TestParsePathInfoJSON/Nix_format232=== CONT TestParsePathInfoJSON/invalid_JSON233=== CONT TestParsePathInfoJSON/whitespace_only234=== CONT TestSetClientTLSErrors/missing_key_file2352026/07/19 09:30:09 WARN Rate limiter enabled after throttle name=server-test rate=5236=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha5122372026/07/19 09:30:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:34675238--- PASS: TestFileTokenMissing (0.00s)2392026/07/19 09:30:09 WARN Rate limiter enabled after throttle name=server-test rate=5240=== CONT TestPathInfoCACompatibility/null_ca_field2412026/07/19 09:30:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:37709242=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method2432026/07/19 09:30:09 WARN Rate limiter backed off name=server-test rate=5244=== CONT TestPathInfoCACompatibility/new_structured_format_-_text245=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error246=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error247=== CONT TestSetClientTLSErrors/missing_ca_file248=== CONT TestParsePathInfoJSON/empty_input249=== CONT TestParsePathInfoJSON/Lix_format2502026/07/19 09:30:09 WARN Rate limiter backed off name=server-test rate=5251=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)252=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI253=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon254=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5122552026/07/19 09:30:09 http: TLS handshake error from 127.0.0.1:55858: remote error: tls: bad certificate256--- PASS: TestShellSplitErrors (0.00s)257=== CONT TestGetStorePathHash/valid_store_path258=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error259=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error260=== CONT TestGetStorePathHash/basename_without_hyphen_should_error261--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)262--- PASS: TestScriptTokenScriptFails (0.00s)263--- PASS: TestDoServerRequestAttachesToken (0.00s)264--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)265--- PASS: TestScriptTokenBadJSON (0.01s)266--- PASS: TestScriptTokenEmptyToken (0.02s)267--- PASS: TestEncodeNixBase32 (0.01s)268 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)269 --- PASS: TestEncodeNixBase32/empty_input (0.00s)270--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)271--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)272--- PASS: TestConvertHashToNix32 (0.02s)273 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)274 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)275 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)276--- PASS: TestPartSizeForNAR (0.01s)277 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)278 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)279 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)280 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)281 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)282 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)283 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)284--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)285 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)286 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)287--- PASS: TestParsePathInfoJSON (0.02s)288 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)289 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)290 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)291 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)292 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)293--- PASS: TestPathInfoCACompatibility (0.02s)294 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)295 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)296 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)297 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)298 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)299--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)300 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)301 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)302--- PASS: TestRateLimiterFeedback (0.01s)303 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)304 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)305 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)306 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)307--- PASS: TestGetStorePathHash (0.02s)308 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)309 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)310 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)311 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)312--- PASS: TestPathInfoHashCompatibility (0.02s)313 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)314 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)315 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)316 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)317--- PASS: TestSetClientTLSErrors (0.02s)318 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)319 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)320 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)321 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)322--- PASS: TestSetClientTLS (0.02s)323 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)324 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)325 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)326--- PASS: TestDumpPathSingleFile (0.04s)327--- PASS: TestCaseHackSuffix (0.05s)328--- PASS: TestDumpPathWriterError (0.07s)329--- PASS: TestDumpPathMatchesNix (0.10s)330--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)331PASS332Running server tests...333The files belonging to this database system will be owned by user "nixbld".334This user must also own the server process.335336The database cluster will be initialized with locale "C".337The default database encoding has accordingly been set to "SQL_ASCII".338The default text search configuration will be set to "english".339340Data page checksums are enabled.341342creating directory /build/postgres2500882689/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/postgres2500882689/data -l logfile start359360/build/postgres2500882689:5432 - no response3612026-07-19 09:30:11.063 UTC [293] LOG: starting PostgreSQL 18.4 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit3622026-07-19 09:30:11.064 UTC [293] LOG: listening on Unix socket "/build/postgres2500882689/.s.PGSQL.5432"3632026-07-19 09:30:11.069 UTC [300] LOG: database system was shut down at 2026-07-19 09:30:10 UTC3642026-07-19 09:30:11.073 UTC [293] LOG: database system is ready to accept connections365/build/postgres2500882689:5432 - accepting connections366{"timestamp":"2026-07-19T09:30:11.507434058Z","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(762)"}367368thread 'rustfs-worker' (1069) 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-19 09:30:11.645 UTC [1096] ERROR: relation "goose_db_version" does not exist at character 363992026-07-19 09:30:11.645 UTC [1096] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4002026/07/19 09:30:11 OK 20241026095416_initial_model.sql (7.85ms)4012026/07/19 09:30:11 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)4022026/07/19 09:30:11 OK 20251218171726_add_pins.sql (2.29ms)4032026/07/19 09:30:11 OK 20260628120000_add_object_size_and_stats.sql (2.07ms)4042026/07/19 09:30:11 goose: successfully migrated database to version: 202606281200004052026/07/19 09:30:11 OK 1_commit_pending_closure.sql (1.6ms)4062026/07/19 09:30:11 OK 2_object_stats_trigger.sql (793.36µs)4072026/07/19 09:30:11 goose: up to current file version: 2408--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)409=== RUN TestGCBugBareHashReferences410=== PAUSE TestGCBugBareHashReferences411=== RUN TestGCMetrics412=== PAUSE TestGCMetrics413=== RUN TestGCTaskStore_StartNew414=== PAUSE TestGCTaskStore_StartNew415=== RUN TestGCTaskStore_DeduplicateSameParams416=== PAUSE TestGCTaskStore_DeduplicateSameParams417=== RUN TestGCTaskStore_ConflictDifferentParams418=== PAUSE TestGCTaskStore_ConflictDifferentParams419=== RUN TestGCTaskStore_GetEmpty420=== PAUSE TestGCTaskStore_GetEmpty421=== RUN TestGCTaskStore_GetReturnsLatest422=== PAUSE TestGCTaskStore_GetReturnsLatest423=== RUN TestGCTaskStore_CompletedAllowsNewTask424=== PAUSE TestGCTaskStore_CompletedAllowsNewTask425=== RUN TestGCTaskStore_PhaseUpdates426=== PAUSE TestGCTaskStore_PhaseUpdates427=== RUN TestGCTaskStore_Fail428=== PAUSE TestGCTaskStore_Fail429=== RUN TestGracefulShutdownDrainsInflight430=== PAUSE TestGracefulShutdownDrainsInflight431=== RUN TestService_healthCheckHandler432=== PAUSE TestService_healthCheckHandler433=== RUN TestGenerateLandingPage434=== PAUSE TestGenerateLandingPage435=== RUN TestNARDeduplicationMetadataUploadBug436=== PAUSE TestNARDeduplicationMetadataUploadBug437=== RUN TestMetricsInventory438=== PAUSE TestMetricsInventory439=== RUN TestService_NativeMTLS440=== PAUSE TestService_NativeMTLS441=== RUN TestServerTLSConfig442=== PAUSE TestServerTLSConfig443=== RUN TestMultipartCleanup444=== PAUSE TestMultipartCleanup445=== RUN TestObjectStatsTrigger446=== PAUSE TestObjectStatsTrigger447=== RUN TestOrphanedObjectsGC448=== PAUSE TestOrphanedObjectsGC449=== RUN TestOrphanedObjectsGCStressTest450=== PAUSE TestOrphanedObjectsGCStressTest451=== RUN TestResurrectedObjectNotDeleted452=== PAUSE TestResurrectedObjectNotDeleted453=== RUN TestParseSingleRange454=== PAUSE TestParseSingleRange455=== RUN TestIsValidCachePath456=== PAUSE TestIsValidCachePath457=== RUN TestReadProxyNarinfo458=== PAUSE TestReadProxyNarinfo459=== RUN TestReadProxyNarinfoAlreadyDecompressed460=== PAUSE TestReadProxyNarinfoAlreadyDecompressed461=== RUN TestReadProxyNarStreaming462=== PAUSE TestReadProxyNarStreaming463=== RUN TestReadProxy404464=== PAUSE TestReadProxy404465=== RUN TestReadProxyInvalidPath466=== PAUSE TestReadProxyInvalidPath467=== RUN TestReadProxyHead468=== PAUSE TestReadProxyHead469=== RUN TestReadProxyConditionalGet470=== PAUSE TestReadProxyConditionalGet471=== RUN TestReadProxyRootRedirectsToIndexHTML472=== PAUSE TestReadProxyRootRedirectsToIndexHTML473=== RUN TestReadProxyDisabled474=== PAUSE TestReadProxyDisabled475=== RUN TestReadProxyRangeRequest476=== PAUSE TestReadProxyRangeRequest477=== RUN TestRedundantMultipartUpload478=== PAUSE TestRedundantMultipartUpload479=== RUN TestCompleteMultipartUpload_ErrorButObjectExists480=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists481=== RUN TestCompletedNarNotReofferedAcrossClosures482=== PAUSE TestCompletedNarNotReofferedAcrossClosures483=== RUN TestService_Rustfstest484=== PAUSE TestService_Rustfstest485=== RUN TestSystemdListenerNotActivated486--- PASS: TestSystemdListenerNotActivated (0.00s)487=== RUN TestWatchdogBeatsWhenHealthy488--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)489=== RUN TestWatchdogSkipsWhenUnhealthy4902026/07/19 09:30:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4912026/07/19 09:30:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4922026/07/19 09:30:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4932026/07/19 09:30:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4942026/07/19 09:30:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4952026/07/19 09:30:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4962026/07/19 09:30:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4972026/07/19 09:30:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4982026/07/19 09:30:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4992026/07/19 09:30:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"500--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)501=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle502=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle503=== RUN TestProxyWriteTimeout504=== PAUSE TestProxyWriteTimeout505=== RUN TestIsValidUploadKey506=== PAUSE TestIsValidUploadKey507=== RUN TestUploadHandlersRejectInvalidKeys508=== PAUSE TestUploadHandlersRejectInvalidKeys509=== RUN TestUploadHandlersRejectOversizedBody510=== PAUSE TestUploadHandlersRejectOversizedBody511=== RUN TestService_cleanupPendingClosuresHandler512=== PAUSE TestService_cleanupPendingClosuresHandler513=== RUN TestService_createPendingClosureHandler514=== PAUSE TestService_createPendingClosureHandler515=== RUN TestService_verifyS3Integrity516=== PAUSE TestService_verifyS3Integrity517=== RUN TestCompleteMultipartUnregistered518=== PAUSE TestCompleteMultipartUnregistered519=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT520=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT521=== CONT TestService_AuthMiddleware522=== CONT TestObjectStatsTrigger523=== CONT TestGCTaskStore_DeduplicateSameParams524--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)525=== CONT TestMultipartCleanup526=== CONT TestServerTLSConfig527=== RUN TestServerTLSConfig/no_client_CA528=== CONT TestService_NativeMTLS529=== CONT TestMetricsInventory530=== CONT TestNARDeduplicationMetadataUploadBug531=== CONT TestGenerateLandingPage532=== CONT TestService_healthCheckHandler533=== CONT TestGracefulShutdownDrainsInflight534=== CONT TestGCTaskStore_Fail535--- PASS: TestGCTaskStore_Fail (0.00s)536=== CONT TestGCTaskStore_PhaseUpdates537=== CONT TestGCTaskStore_CompletedAllowsNewTask538=== CONT TestGCTaskStore_GetReturnsLatest539=== CONT TestGCTaskStore_GetEmpty540=== CONT TestGCTaskStore_ConflictDifferentParams541=== CONT TestClientErrorHandling542=== CONT TestGCTaskStore_StartNew543=== CONT TestGCMetrics544=== CONT TestGCBugBareHashReferences545=== CONT TestPinProtectsFromGC546=== CONT TestClientWithDependencies547=== CONT TestClientMultipleUploads548=== CONT TestClientIntegration549=== CONT TestReadProxyRangeRequest550=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT551=== CONT TestCompleteMultipartUnregistered552=== CONT TestService_verifyS3Integrity553=== CONT TestService_createPendingClosureHandler554=== CONT TestService_cleanupPendingClosuresHandler555=== CONT TestUploadHandlersRejectOversizedBody556=== CONT TestUploadHandlersRejectInvalidKeys557=== CONT TestIsValidUploadKey558=== CONT TestProxyWriteTimeout559=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle560=== CONT TestService_Rustfstest561=== CONT TestCompletedNarNotReofferedAcrossClosures562=== CONT TestCompleteMultipartUpload_ErrorButObjectExists563=== CONT TestRedundantMultipartUpload564=== CONT TestReadProxyNarStreaming565=== CONT TestReadProxyDisabled566=== CONT TestService_AuthMiddleware_OIDC567=== CONT TestReadProxyRootRedirectsToIndexHTML568=== CONT TestClientCADerivations569=== CONT TestReadProxyConditionalGet570=== CONT TestReadProxyHead571=== CONT TestCacheStatsHandler572=== CONT TestReadProxyInvalidPath573=== CONT TestCacheConfigHandler574=== CONT TestReadProxy404575=== CONT TestParseSingleRange576=== CONT TestReadProxyNarinfo577=== CONT TestIsValidCachePath578=== CONT TestReadProxyNarinfoAlreadyDecompressed579=== CONT TestService_AuthMiddleware_MTLSBoundSubjects580=== CONT TestOrphanedObjectsGCStressTest581=== CONT TestService_ReadAuthMiddleware582=== CONT TestResurrectedObjectNotDeleted583=== CONT TestService_AuthMiddleware_MTLSProxyHeader584=== CONT TestOrphanedObjectsGC585=== PAUSE TestServerTLSConfig/no_client_CA586--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)587=== RUN TestClientErrorHandling/InvalidStorePath588=== RUN TestIsValidUploadKey/narinfo589=== RUN TestProxyWriteTimeout/narinfo590=== PAUSE TestProxyWriteTimeout/narinfo591--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)592=== RUN TestParseSingleRange/none593=== RUN TestServerTLSConfig/missing_CA_file594=== RUN TestCacheConfigHandler/full_config,_no_issuer5952026/07/19 09:30:11 INFO Starting HTTP server address=127.0.0.1:37401596=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info5972026/07/19 09:30:11 INFO Shutdown signal received, draining in-flight requests timeout=10s598=== PAUSE TestIsValidUploadKey/narinfo599=== PAUSE TestClientErrorHandling/InvalidStorePath600=== RUN TestIsValidCachePath/narinfo601=== PAUSE TestIsValidCachePath/narinfo602=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars603=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars604=== RUN TestProxyWriteTimeout/1_GiB_nar605--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)606=== PAUSE TestParseSingleRange/none607=== PAUSE TestServerTLSConfig/missing_CA_file608=== PAUSE TestCacheConfigHandler/full_config,_no_issuer609=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info6102026/07/19 09:30:11 INFO OIDC provider initialized name=test611=== RUN TestIsValidUploadKey/nar_zst612=== RUN TestClientErrorHandling/InvalidAuthToken613=== PAUSE TestClientErrorHandling/InvalidAuthToken614=== RUN TestIsValidCachePath/nar_zst615=== PAUSE TestProxyWriteTimeout/1_GiB_nar616--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)617=== RUN TestParseSingleRange/unknown_unit618=== PAUSE TestParseSingleRange/unknown_unit619=== RUN TestServerTLSConfig/not_a_PEM_file620=== PAUSE TestServerTLSConfig/not_a_PEM_file621=== RUN TestCacheConfigHandler/no_cache_url_configured622=== PAUSE TestCacheConfigHandler/no_cache_url_configured623=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal624=== PAUSE TestIsValidUploadKey/nar_zst625=== RUN TestIsValidUploadKey/nar_xz626=== PAUSE TestIsValidUploadKey/nar_xz627=== RUN TestClientErrorHandling/ServerNotAvailable628=== PAUSE TestIsValidCachePath/nar_zst629=== RUN TestIsValidCachePath/nar_xz630=== PAUSE TestIsValidCachePath/nar_xz631=== RUN TestProxyWriteTimeout/10_GiB_nar632--- PASS: TestGCTaskStore_StartNew (0.00s)633=== RUN TestParseSingleRange/multi-range_ignored634=== PAUSE TestParseSingleRange/multi-range_ignored635=== CONT TestServerTLSConfig/no_client_CA636=== CONT TestServerTLSConfig/missing_CA_file637=== CONT TestServerTLSConfig/not_a_PEM_file638=== RUN TestCacheConfigHandler/no_signing_keys639=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal640=== RUN TestIsValidUploadKey/nar_plain641=== PAUSE TestIsValidUploadKey/nar_plain642=== PAUSE TestClientErrorHandling/ServerNotAvailable643=== PAUSE TestProxyWriteTimeout/10_GiB_nar644--- PASS: TestGCTaskStore_GetEmpty (0.00s)645--- PASS: TestGenerateLandingPage (0.02s)646=== RUN TestIsValidCachePath/nar_bz2647=== PAUSE TestIsValidCachePath/nar_bz2648=== RUN TestParseSingleRange/malformed_no_dash649=== PAUSE TestParseSingleRange/malformed_no_dash650=== PAUSE TestCacheConfigHandler/no_signing_keys651=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key652=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key653=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key654=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key655=== RUN TestIsValidUploadKey/listing656=== CONT TestClientErrorHandling/ServerNotAvailable657=== CONT TestClientErrorHandling/InvalidAuthToken658=== RUN TestProxyWriteTimeout/unknown_size659=== PAUSE TestProxyWriteTimeout/unknown_size660--- PASS: TestServerTLSConfig (0.02s)661 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)662 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)663 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)664=== RUN TestIsValidCachePath/nar_uncompressed665=== RUN TestParseSingleRange/malformed_both_empty666=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator667=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator668=== CONT TestClientErrorHandling/InvalidStorePath669=== CONT TestCacheConfigHandler/no_signing_keys670=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info671=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key672=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal6732026/07/19 09:30:11 INFO Received complete multipart upload request method=POST path=/674=== PAUSE TestIsValidUploadKey/listing6752026/07/19 09:30:11 INFO Received uploads request method=POST path=/676=== CONT TestProxyWriteTimeout/narinfo6772026/07/19 09:30:11 INFO Received uploads request method=POST path=/678=== CONT TestProxyWriteTimeout/1_GiB_nar679=== CONT TestProxyWriteTimeout/10_GiB_nar680=== CONT TestProxyWriteTimeout/unknown_size681--- PASS: TestProxyWriteTimeout (0.01s)682 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)683 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)684 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)685 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)686=== PAUSE TestIsValidCachePath/nar_uncompressed687=== PAUSE TestParseSingleRange/malformed_both_empty688=== CONT TestCacheConfigHandler/full_config,_no_issuer689=== CONT TestCacheConfigHandler/no_cache_url_configured690=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator691=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key692=== RUN TestIsValidUploadKey/build_log693--- PASS: TestCacheConfigHandler (0.01s)694 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)695 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)696 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)697 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)6982026/07/19 09:30:11 INFO Received request for more parts method=POST path=/699=== RUN TestIsValidCachePath/ls700=== RUN TestParseSingleRange/malformed_end_before_start701=== PAUSE TestIsValidUploadKey/build_log702--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)703 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)704 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)705 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)706 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)707=== PAUSE TestIsValidCachePath/ls708=== PAUSE TestParseSingleRange/malformed_end_before_start709=== RUN TestParseSingleRange/closed710=== PAUSE TestParseSingleRange/closed711=== RUN TestIsValidUploadKey/build_log_home-manager_file712=== RUN TestIsValidCachePath/log713=== PAUSE TestIsValidCachePath/log714=== RUN TestIsValidCachePath/realisation715=== PAUSE TestIsValidCachePath/realisation716=== RUN TestIsValidCachePath/nix-cache-info717=== PAUSE TestIsValidCachePath/nix-cache-info718=== RUN TestIsValidCachePath/index.html719=== PAUSE TestIsValidCachePath/index.html720=== RUN TestParseSingleRange/open-ended721=== PAUSE TestIsValidUploadKey/build_log_home-manager_file722=== RUN TestIsValidCachePath/traversal_parent723=== PAUSE TestIsValidCachePath/traversal_parent724=== RUN TestIsValidCachePath/traversal_in_middle725=== PAUSE TestIsValidCachePath/traversal_in_middle726=== RUN TestIsValidCachePath/invalid_char_e727=== PAUSE TestIsValidCachePath/invalid_char_e728=== RUN TestIsValidCachePath/invalid_char_u729=== PAUSE TestIsValidCachePath/invalid_char_u730=== RUN TestIsValidCachePath/random_path731=== PAUSE TestParseSingleRange/open-ended732=== RUN TestParseSingleRange/end_clamped_to_size733=== PAUSE TestParseSingleRange/end_clamped_to_size734=== RUN TestIsValidUploadKey/build_log_plus_in_name735=== PAUSE TestIsValidUploadKey/build_log_plus_in_name736=== RUN TestIsValidUploadKey/build_log_question_mark737=== PAUSE TestIsValidCachePath/random_path738=== RUN TestIsValidCachePath/empty739=== RUN TestParseSingleRange/suffix740=== PAUSE TestParseSingleRange/suffix741=== PAUSE TestIsValidUploadKey/build_log_question_mark742=== PAUSE TestIsValidCachePath/empty743=== RUN TestParseSingleRange/suffix_exceeds_size744=== PAUSE TestParseSingleRange/suffix_exceeds_size745=== RUN TestParseSingleRange/single_byte746=== PAUSE TestParseSingleRange/single_byte747=== RUN TestParseSingleRange/start_past_EOF748=== PAUSE TestParseSingleRange/start_past_EOF749=== RUN TestIsValidUploadKey/build_log_equals750=== PAUSE TestIsValidUploadKey/build_log_equals751=== RUN TestIsValidCachePath/leading_slash752=== PAUSE TestIsValidCachePath/leading_slash753=== RUN TestIsValidCachePath/wrong_extension754=== RUN TestParseSingleRange/start_far_past_EOF755=== PAUSE TestParseSingleRange/start_far_past_EOF756=== RUN TestIsValidUploadKey/realisation757=== PAUSE TestIsValidUploadKey/realisation758=== RUN TestIsValidUploadKey/realisation_plus_in_output759=== PAUSE TestIsValidUploadKey/realisation_plus_in_output760=== PAUSE TestIsValidCachePath/wrong_extension761=== RUN TestIsValidCachePath/short_hash762=== PAUSE TestIsValidCachePath/short_hash763=== CONT TestParseSingleRange/none764=== CONT TestParseSingleRange/start_far_past_EOF765=== CONT TestParseSingleRange/start_past_EOF766=== CONT TestParseSingleRange/closed767=== CONT TestParseSingleRange/malformed_end_before_start768=== CONT TestParseSingleRange/malformed_both_empty769=== CONT TestParseSingleRange/single_byte770=== CONT TestParseSingleRange/malformed_no_dash771=== CONT TestParseSingleRange/suffix_exceeds_size772=== CONT TestParseSingleRange/suffix773=== CONT TestParseSingleRange/end_clamped_to_size774=== CONT TestParseSingleRange/multi-range_ignored775=== CONT TestParseSingleRange/unknown_unit776=== CONT TestParseSingleRange/open-ended777--- PASS: TestParseSingleRange (0.02s)778 --- PASS: TestParseSingleRange/none (0.00s)779 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)780 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)781 --- PASS: TestParseSingleRange/closed (0.00s)782 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)783 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)784 --- PASS: TestParseSingleRange/single_byte (0.00s)785 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)786 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)787 --- PASS: TestParseSingleRange/suffix (0.00s)788 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)789 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)790 --- PASS: TestParseSingleRange/unknown_unit (0.00s)791 --- PASS: TestParseSingleRange/open-ended (0.00s)792=== RUN TestIsValidUploadKey/nix-cache-info793=== PAUSE TestIsValidUploadKey/nix-cache-info794=== CONT TestIsValidCachePath/narinfo795=== CONT TestIsValidCachePath/short_hash796=== CONT TestIsValidCachePath/wrong_extension797=== CONT TestIsValidCachePath/leading_slash798=== CONT TestIsValidCachePath/empty799=== CONT TestIsValidCachePath/random_path800=== CONT TestIsValidCachePath/invalid_char_u801=== CONT TestIsValidCachePath/ls802=== CONT TestIsValidCachePath/log803=== CONT TestIsValidCachePath/nar_uncompressed804=== CONT TestIsValidCachePath/nar_bz2805=== CONT TestIsValidCachePath/invalid_char_e806=== CONT TestIsValidCachePath/nar_xz807=== CONT TestIsValidCachePath/nix-cache-info808=== CONT TestIsValidCachePath/nar_zst809=== CONT TestIsValidCachePath/index.html810=== CONT TestIsValidCachePath/traversal_in_middle811=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars812=== CONT TestIsValidCachePath/realisation813=== CONT TestIsValidCachePath/traversal_parent814--- PASS: TestIsValidCachePath (0.02s)815 --- PASS: TestIsValidCachePath/narinfo (0.00s)816 --- PASS: TestIsValidCachePath/short_hash (0.00s)817 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)818 --- PASS: TestIsValidCachePath/leading_slash (0.00s)819 --- PASS: TestIsValidCachePath/empty (0.00s)820 --- PASS: TestIsValidCachePath/random_path (0.00s)821 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)822 --- PASS: TestIsValidCachePath/ls (0.00s)823 --- PASS: TestIsValidCachePath/log (0.00s)824 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)825 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)826 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)827 --- PASS: TestIsValidCachePath/nar_xz (0.00s)828 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)829 --- PASS: TestIsValidCachePath/nar_zst (0.00s)830 --- PASS: TestIsValidCachePath/index.html (0.00s)831 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)832 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)833 --- PASS: TestIsValidCachePath/realisation (0.00s)834 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)835=== RUN TestIsValidUploadKey/index.html836=== PAUSE TestIsValidUploadKey/index.html837=== RUN TestIsValidUploadKey/narinfo_key,_nar_type838=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type839=== RUN TestIsValidUploadKey/nar_key,_narinfo_type840=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type841=== RUN TestIsValidUploadKey/listing_key,_narinfo_type842=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type843=== RUN TestIsValidUploadKey/traversal844=== PAUSE TestIsValidUploadKey/traversal845=== RUN TestIsValidUploadKey/traversal_nar846=== PAUSE TestIsValidUploadKey/traversal_nar847=== RUN TestIsValidUploadKey/absolute848=== PAUSE TestIsValidUploadKey/absolute849=== RUN TestIsValidUploadKey/empty_key850=== PAUSE TestIsValidUploadKey/empty_key851=== RUN TestIsValidUploadKey/unknown_type852=== PAUSE TestIsValidUploadKey/unknown_type853=== CONT TestIsValidUploadKey/narinfo854=== CONT TestIsValidUploadKey/nix-cache-info855=== CONT TestIsValidUploadKey/realisation_plus_in_output856=== CONT TestIsValidUploadKey/unknown_type857=== CONT TestIsValidUploadKey/empty_key858=== CONT TestIsValidUploadKey/absolute859=== CONT TestIsValidUploadKey/traversal_nar860=== CONT TestIsValidUploadKey/traversal861=== CONT TestIsValidUploadKey/listing_key,_narinfo_type862=== CONT TestIsValidUploadKey/nar_key,_narinfo_type863=== CONT TestIsValidUploadKey/narinfo_key,_nar_type864=== CONT TestIsValidUploadKey/index.html865=== CONT TestIsValidUploadKey/build_log_home-manager_file866=== CONT TestIsValidUploadKey/realisation867=== CONT TestIsValidUploadKey/build_log_equals868=== CONT TestIsValidUploadKey/build_log_question_mark869=== CONT TestIsValidUploadKey/nar_plain870=== CONT TestIsValidUploadKey/build_log871=== CONT TestIsValidUploadKey/build_log_plus_in_name872=== CONT TestIsValidUploadKey/listing873=== CONT TestIsValidUploadKey/nar_zst874=== CONT TestIsValidUploadKey/nar_xz875--- PASS: TestIsValidUploadKey (0.03s)876 --- PASS: TestIsValidUploadKey/narinfo (0.00s)877 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)878 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)879 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)880 --- PASS: TestIsValidUploadKey/empty_key (0.00s)881 --- PASS: TestIsValidUploadKey/absolute (0.00s)882 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)883 --- PASS: TestIsValidUploadKey/traversal (0.00s)884 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)885 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)886 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)887 --- PASS: TestIsValidUploadKey/index.html (0.00s)888 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)889 --- PASS: TestIsValidUploadKey/realisation (0.00s)890 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)891 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)892 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)893 --- PASS: TestIsValidUploadKey/build_log (0.00s)894 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)895 --- PASS: TestIsValidUploadKey/listing (0.00s)896 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)897 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)898--- PASS: TestGracefulShutdownDrainsInflight (0.08s)8992026/07/19 09:30:12 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_closures900=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure901=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure902=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart903=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart904=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts905=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts906=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure907=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart9082026/07/19 09:30:12 INFO Received uploads request method=POST path=/909=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts9102026/07/19 09:30:12 INFO Received request for more parts method=POST path=/9112026/07/19 09:30:12 INFO Received complete multipart upload request method=POST path=/9122026-07-19 09:30:12.131 UTC [1292] ERROR: relation "goose_db_version" does not exist at character 369132026-07-19 09:30:12.131 UTC [1292] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9142026-07-19 09:30:12.131 UTC [1290] ERROR: relation "goose_db_version" does not exist at character 369152026-07-19 09:30:12.131 UTC [1290] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9162026-07-19 09:30:12.131 UTC [1270] ERROR: relation "goose_db_version" does not exist at character 369172026-07-19 09:30:12.131 UTC [1270] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9182026-07-19 09:30:12.131 UTC [1269] ERROR: relation "goose_db_version" does not exist at character 369192026-07-19 09:30:12.131 UTC [1269] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9202026-07-19 09:30:12.131 UTC [1310] ERROR: relation "goose_db_version" does not exist at character 369212026-07-19 09:30:12.131 UTC [1310] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9222026-07-19 09:30:12.132 UTC [1289] ERROR: relation "goose_db_version" does not exist at character 369232026-07-19 09:30:12.132 UTC [1289] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9242026-07-19 09:30:12.133 UTC [1291] ERROR: relation "goose_db_version" does not exist at character 369252026-07-19 09:30:12.133 UTC [1291] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9262026-07-19 09:30:12.136 UTC [1286] ERROR: relation "goose_db_version" does not exist at character 369272026-07-19 09:30:12.136 UTC [1286] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9282026-07-19 09:30:12.149 UTC [1311] ERROR: relation "goose_db_version" does not exist at character 369292026-07-19 09:30:12.149 UTC [1311] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9302026-07-19 09:30:12.149 UTC [1312] ERROR: relation "goose_db_version" does not exist at character 369312026-07-19 09:30:12.149 UTC [1312] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9322026-07-19 09:30:12.156 UTC [1315] ERROR: relation "goose_db_version" does not exist at character 369332026-07-19 09:30:12.156 UTC [1315] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9342026/07/19 09:30:12 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.697626ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures9352026-07-19 09:30:12.310 UTC [1316] ERROR: relation "goose_db_version" does not exist at character 369362026-07-19 09:30:12.310 UTC [1316] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9372026-07-19 09:30:12.313 UTC [1317] ERROR: relation "goose_db_version" does not exist at character 369382026-07-19 09:30:12.313 UTC [1317] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9392026/07/19 09:30:12 OK 20241026095416_initial_model.sql (159.05ms)9402026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (5.25ms)9412026/07/19 09:30:12 OK 20241026095416_initial_model.sql (165.45ms)9422026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (6.54ms)9432026/07/19 09:30:12 OK 20241026095416_initial_model.sql (165.78ms)9442026/07/19 09:30:12 OK 20251218171726_add_pins.sql (13.02ms)9452026/07/19 09:30:12 OK 20241026095416_initial_model.sql (167.75ms)9462026/07/19 09:30:12 OK 20241026095416_initial_model.sql (166.18ms)9472026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (5.55ms)9482026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (5.1ms)9492026/07/19 09:30:12 OK 20241026095416_initial_model.sql (165.62ms)9502026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (6.98ms)9512026/07/19 09:30:12 OK 20241026095416_initial_model.sql (198.89ms)9522026/07/19 09:30:12 OK 20251218171726_add_pins.sql (31ms)9532026/07/19 09:30:12 OK 20251218171726_add_pins.sql (21.62ms)9542026/07/19 09:30:12 OK 20241026095416_initial_model.sql (188.87ms)9552026/07/19 09:30:12 OK 20251218171726_add_pins.sql (23.06ms)9562026/07/19 09:30:12 OK 20241026095416_initial_model.sql (193.6ms)9572026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (27.17ms)9582026/07/19 09:30:12 goose: successfully migrated database to version: 202606281200009592026/07/19 09:30:12 OK 20251218171726_add_pins.sql (20.01ms)9602026/07/19 09:30:12 OK 20241026095416_initial_model.sql (206.58ms)9612026/07/19 09:30:12 OK 20241026095416_initial_model.sql (190.62ms)9622026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (21.89ms)9632026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (9.92ms)9642026/07/19 09:30:12 OK 1_commit_pending_closure.sql (6.11ms)9652026/07/19 09:30:12 OK 20241026095416_initial_model.sql (31.47ms)9662026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (6.85ms)9672026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (6.75ms)9682026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (5.45ms)9692026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (7.9ms)9702026/07/19 09:30:12 OK 2_object_stats_trigger.sql (4.82ms)9712026/07/19 09:30:12 goose: up to current file version: 29722026/07/19 09:30:12 OK 20241026095416_initial_model.sql (38.2ms)9732026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (5.25ms)9742026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (12.57ms)9752026/07/19 09:30:12 goose: successfully migrated database to version: 202606281200009762026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (13.95ms)9772026/07/19 09:30:12 goose: successfully migrated database to version: 202606281200009782026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (14.49ms)9792026/07/19 09:30:12 goose: successfully migrated database to version: 202606281200009802026/07/19 09:30:12 OK 1_commit_pending_closure.sql (5.75ms)9812026-07-19 09:30:12.386 UTC [1318] ERROR: relation "goose_db_version" does not exist at character 369822026-07-19 09:30:12.386 UTC [1318] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9832026-07-19 09:30:12.386 UTC [1320] ERROR: relation "goose_db_version" does not exist at character 369842026-07-19 09:30:12.386 UTC [1320] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9852026-07-19 09:30:12.386 UTC [1321] ERROR: relation "goose_db_version" does not exist at character 369862026-07-19 09:30:12.386 UTC [1321] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9872026/07/19 09:30:12 OK 1_commit_pending_closure.sql (6.92ms)9882026-07-19 09:30:12.387 UTC [1319] ERROR: relation "goose_db_version" does not exist at character 369892026-07-19 09:30:12.387 UTC [1319] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9902026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (8.82ms)9912026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (20.75ms)9922026/07/19 09:30:12 goose: successfully migrated database to version: 202606281200009932026/07/19 09:30:12 OK 2_object_stats_trigger.sql (4.57ms)9942026/07/19 09:30:12 goose: up to current file version: 29952026/07/19 09:30:12 OK 1_commit_pending_closure.sql (8.7ms)9962026/07/19 09:30:12 OK 2_object_stats_trigger.sql (6.06ms)9972026/07/19 09:30:12 goose: up to current file version: 29982026/07/19 09:30:12 OK 20251218171726_add_pins.sql (25.74ms)9992026/07/19 09:30:12 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"10002026/07/19 09:30:12 WARN mTLS auth: bound subjects configured but subject DN unavailable10012026/07/19 09:30:12 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1002--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.47s)10032026/07/19 09:30:12 OK 20251218171726_add_pins.sql (35.66ms)10042026/07/19 09:30:12 INFO Aborted multipart uploads count=010052026/07/19 09:30:12 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=435.708948ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures10062026/07/19 09:30:12 OK 2_object_stats_trigger.sql (20.41ms)10072026/07/19 09:30:12 goose: up to current file version: 210082026/07/19 09:30:12 OK 20251218171726_add_pins.sql (37.3ms)10092026/07/19 09:30:12 OK 1_commit_pending_closure.sql (22.39ms)10102026/07/19 09:30:12 WARN Force mode enabled - objects will be deleted immediately without grace period10112026/07/19 09:30:12 OK 20251218171726_add_pins.sql (36.95ms)10122026/07/19 09:30:12 OK 20251218171726_add_pins.sql (31.87ms)10132026/07/19 09:30:12 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1014--- PASS: TestService_AuthMiddleware (0.49s)10152026/07/19 09:30:12 OK 2_object_stats_trigger.sql (4.47ms)10162026/07/19 09:30:12 goose: up to current file version: 210172026/07/19 09:30:12 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=010182026/07/19 09:30:12 OK 20251218171726_add_pins.sql (42.36ms)10192026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (10.74ms)10202026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000010212026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures10222026/07/19 09:30:12 INFO Vacuumed table table=pending_closures10232026/07/19 09:30:12 INFO Vacuumed table table=pending_objects1024--- PASS: TestObjectStatsTrigger (0.50s)10252026/07/19 09:30:12 INFO Vacuumed table table=multipart_uploads10262026/07/19 09:30:12 INFO Vacuumed table table=closures10272026/07/19 09:30:12 INFO Vacuumed table table=objects10282026/07/19 09:30:12 OK 1_commit_pending_closure.sql (8.47ms)10292026/07/19 09:30:12 OK 20251218171726_add_pins.sql (50.25ms)10302026/07/19 09:30:12 OK 20251218171726_add_pins.sql (41.59ms)1031--- PASS: TestGCMetrics (0.51s)10322026/07/19 09:30:12 OK 2_object_stats_trigger.sql (12.36ms)10332026/07/19 09:30:12 goose: up to current file version: 210342026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (27.56ms)10352026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000010362026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (44.93ms)10372026/07/19 09:30:12 goose: successfully migrated database to version: 202606281200001038{"timestamp":"2026-07-19T09:30:12.449886702Z","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(646)"}10392026/07/19 09:30:12 INFO Created nix-cache-info in bucket bucket=bucket710402026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (41.63ms)10412026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000010422026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (41.25ms)10432026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000010442026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (39.84ms)10452026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000010462026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (26.45ms)10472026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000010482026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (29.49ms)10492026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000010502026/07/19 09:30:12 OK 1_commit_pending_closure.sql (17.14ms)10512026/07/19 09:30:12 OK 1_commit_pending_closure.sql (5.08ms)10522026/07/19 09:30:12 OK 1_commit_pending_closure.sql (18.59ms)1053--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.53s)10542026/07/19 09:30:12 OK 1_commit_pending_closure.sql (7.49ms)10552026/07/19 09:30:12 OK 1_commit_pending_closure.sql (10.98ms)10562026/07/19 09:30:12 OK 2_object_stats_trigger.sql (7.84ms)10572026/07/19 09:30:12 goose: up to current file version: 210582026/07/19 09:30:12 OK 1_commit_pending_closure.sql (10.09ms)10592026/07/19 09:30:12 OK 2_object_stats_trigger.sql (9.61ms)10602026/07/19 09:30:12 goose: up to current file version: 210612026/07/19 09:30:12 OK 1_commit_pending_closure.sql (9.84ms)10622026/07/19 09:30:12 OK 2_object_stats_trigger.sql (8.27ms)10632026/07/19 09:30:12 goose: up to current file version: 210642026/07/19 09:30:12 OK 2_object_stats_trigger.sql (4.5ms)10652026/07/19 09:30:12 goose: up to current file version: 21066--- PASS: TestService_healthCheckHandler (0.55s)10672026/07/19 09:30:12 OK 2_object_stats_trigger.sql (7.22ms)10682026/07/19 09:30:12 goose: up to current file version: 210692026/07/19 09:30:12 OK 2_object_stats_trigger.sql (6.87ms)10702026/07/19 09:30:12 goose: up to current file version: 210712026/07/19 09:30:12 OK 2_object_stats_trigger.sql (6.46ms)10722026/07/19 09:30:12 goose: up to current file version: 210732026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures10742026/07/19 09:30:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10752026/07/19 09:30:12 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1076--- PASS: TestService_NativeMTLS (0.55s)1077=== NAME TestNARDeduplicationMetadataUploadBug1078 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2510707819/001/store/854bmyvnp2r7r8lbgsm6nwb60v2ygi3s-file1.txt1079--- PASS: TestReadProxyRangeRequest (0.57s)10802026/07/19 09:30:12 OK 20241026095416_initial_model.sql (86.41ms)1081--- PASS: TestReadProxyHead (0.60s)10822026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (8.93ms)10832026/07/19 09:30:12 OK 20241026095416_initial_model.sql (99.76ms)10842026/07/19 09:30:12 OK 20241026095416_initial_model.sql (108.41ms)1085--- PASS: TestMetricsInventory (0.61s)10862026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (9.72ms)10872026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (8.17ms)10882026/07/19 09:30:12 OK 20251218171726_add_pins.sql (9.47ms)10892026/07/19 09:30:12 OK 20251218171726_add_pins.sql (22.29ms)10902026/07/19 09:30:12 OK 20241026095416_initial_model.sql (111.94ms)10912026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (23.83ms)10922026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000010932026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (21.34ms)10942026/07/19 09:30:12 OK 20251218171726_add_pins.sql (26.99ms)10952026/07/19 09:30:12 OK 1_commit_pending_closure.sql (5.94ms)10962026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (29.55ms)10972026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000010982026/07/19 09:30:12 OK 2_object_stats_trigger.sql (3.52ms)10992026/07/19 09:30:12 goose: up to current file version: 211002026/07/19 09:30:12 OK 20251218171726_add_pins.sql (11.31ms)11012026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (12.83ms)11022026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000011032026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures11042026/07/19 09:30:12 OK 1_commit_pending_closure.sql (6.23ms)11052026-07-19 09:30:12.588 UTC [1380] ERROR: relation "goose_db_version" does not exist at character 3611062026-07-19 09:30:12.588 UTC [1380] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11072026-07-19 09:30:12.589 UTC [1379] ERROR: relation "goose_db_version" does not exist at character 3611082026-07-19 09:30:12.589 UTC [1379] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11092026/07/19 09:30:12 OK 1_commit_pending_closure.sql (5.17ms)11102026/07/19 09:30:12 OK 2_object_stats_trigger.sql (3.88ms)11112026/07/19 09:30:12 goose: up to current file version: 211122026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (7.76ms)11132026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000011142026/07/19 09:30:12 OK 2_object_stats_trigger.sql (2.57ms)11152026/07/19 09:30:12 goose: up to current file version: 211162026-07-19 09:30:12.595 UTC [1382] ERROR: relation "goose_db_version" does not exist at character 3611172026-07-19 09:30:12.595 UTC [1382] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11182026-07-19 09:30:12.595 UTC [1381] ERROR: relation "goose_db_version" does not exist at character 3611192026-07-19 09:30:12.595 UTC [1381] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11202026-07-19 09:30:12.596 UTC [1383] ERROR: relation "goose_db_version" does not exist at character 3611212026-07-19 09:30:12.596 UTC [1383] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11222026/07/19 09:30:12 INFO Created nix-cache-info in bucket bucket=bucket1611232026/07/19 09:30:12 OK 1_commit_pending_closure.sql (5.19ms)11242026-07-19 09:30:12.597 UTC [1385] ERROR: relation "goose_db_version" does not exist at character 3611252026-07-19 09:30:12.597 UTC [1385] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11262026-07-19 09:30:12.597 UTC [1384] ERROR: relation "goose_db_version" does not exist at character 3611272026-07-19 09:30:12.597 UTC [1384] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11282026/07/19 09:30:12 INFO Created nix-cache-info in bucket bucket=bucket1711292026/07/19 09:30:12 OK 2_object_stats_trigger.sql (2.01ms)11302026/07/19 09:30:12 goose: up to current file version: 211312026-07-19 09:30:12.599 UTC [1386] ERROR: relation "goose_db_version" does not exist at character 3611322026-07-19 09:30:12.599 UTC [1386] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11332026-07-19 09:30:12.601 UTC [1388] ERROR: relation "goose_db_version" does not exist at character 3611342026-07-19 09:30:12.601 UTC [1388] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11352026-07-19 09:30:12.602 UTC [1395] ERROR: relation "goose_db_version" does not exist at character 3611362026-07-19 09:30:12.602 UTC [1395] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11372026/07/19 09:30:12 INFO Received cleanup request method=DELETE path=/api/pending_closures11382026-07-19 09:30:12.604 UTC [1391] ERROR: relation "goose_db_version" does not exist at character 3611392026-07-19 09:30:12.604 UTC [1391] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11402026-07-19 09:30:12.604 UTC [1389] ERROR: relation "goose_db_version" does not exist at character 3611412026-07-19 09:30:12.604 UTC [1389] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11422026-07-19 09:30:12.604 UTC [1415] ERROR: relation "goose_db_version" does not exist at character 3611432026-07-19 09:30:12.604 UTC [1415] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11442026-07-19 09:30:12.604 UTC [1393] ERROR: relation "goose_db_version" does not exist at character 3611452026-07-19 09:30:12.604 UTC [1393] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11462026-07-19 09:30:12.605 UTC [1401] ERROR: relation "goose_db_version" does not exist at character 3611472026-07-19 09:30:12.605 UTC [1401] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11482026-07-19 09:30:12.605 UTC [1394] ERROR: relation "goose_db_version" does not exist at character 3611492026-07-19 09:30:12.605 UTC [1394] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11502026-07-19 09:30:12.605 UTC [1390] ERROR: relation "goose_db_version" does not exist at character 3611512026-07-19 09:30:12.605 UTC [1390] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11522026-07-19 09:30:12.606 UTC [1387] ERROR: relation "goose_db_version" does not exist at character 3611532026-07-19 09:30:12.606 UTC [1387] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11542026-07-19 09:30:12.606 UTC [1416] ERROR: relation "goose_db_version" does not exist at character 3611552026-07-19 09:30:12.606 UTC [1416] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11562026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures11572026-07-19 09:30:12.606 UTC [1413] ERROR: relation "goose_db_version" does not exist at character 3611582026-07-19 09:30:12.606 UTC [1413] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11592026-07-19 09:30:12.607 UTC [1410] ERROR: relation "goose_db_version" does not exist at character 3611602026-07-19 09:30:12.607 UTC [1410] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11612026/07/19 09:30:12 INFO Aborted multipart uploads count=011622026-07-19 09:30:12.610 UTC [1421] ERROR: relation "goose_db_version" does not exist at character 3611632026-07-19 09:30:12.610 UTC [1421] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11642026-07-19 09:30:12.611 UTC [1420] ERROR: relation "goose_db_version" does not exist at character 3611652026-07-19 09:30:12.611 UTC [1420] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11662026-07-19 09:30:12.611 UTC [1422] ERROR: relation "goose_db_version" does not exist at character 3611672026-07-19 09:30:12.611 UTC [1422] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11682026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures11692026-07-19 09:30:12.611 UTC [1418] ERROR: relation "goose_db_version" does not exist at character 3611702026-07-19 09:30:12.611 UTC [1418] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11712026/07/19 09:30:12 OK 20241026095416_initial_model.sql (11.57ms)11722026/07/19 09:30:12 OK 20241026095416_initial_model.sql (11.82ms)11732026-07-19 09:30:12.613 UTC [1423] ERROR: relation "goose_db_version" does not exist at character 3611742026-07-19 09:30:12.613 UTC [1423] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11752026/07/19 09:30:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11762026/07/19 09:30:12 INFO Uploading 854bmyvnp2r7r8lbgsm6nwb60v2ygi3s-file1.txt (160B)11772026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (2.87ms)11782026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (3.1ms)11792026/07/19 09:30:12 OK 20241026095416_initial_model.sql (11.47ms)11802026/07/19 09:30:12 OK 20251218171726_add_pins.sql (5.78ms)11812026/07/19 09:30:12 INFO Received cleanup request method=DELETE path=/api/pending_closures11822026/07/19 09:30:12 OK 20251218171726_add_pins.sql (5.69ms)11832026/07/19 09:30:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11842026/07/19 09:30:12 INFO Signed narinfos id=1 count=111852026/07/19 09:30:12 INFO Uploading 1 narinfos11862026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)11872026/07/19 09:30:12 OK 20241026095416_initial_model.sql (13.03ms)11882026/07/19 09:30:12 OK 20241026095416_initial_model.sql (13.23ms)11892026/07/19 09:30:12 OK 20241026095416_initial_model.sql (13.36ms)11902026/07/19 09:30:12 INFO Aborted multipart uploads count=111912026/07/19 09:30:12 OK 20241026095416_initial_model.sql (13.74ms)11922026/07/19 09:30:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11932026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (2.71ms)11942026-07-19 09:30:12.627 UTC [1424] ERROR: relation "goose_db_version" does not exist at character 3611952026-07-19 09:30:12.627 UTC [1424] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11962026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)11972026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)11982026/07/19 09:30:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11992026/07/19 09:30:12 INFO Received cleanup request method=DELETE path=/api/pending_closures12002026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (7.22ms)12012026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000012022026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (3.79ms)12032026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (7.93ms)12042026-07-19 09:30:12.630 UTC [1319] ERROR: Closure does not exist: id=112052026-07-19 09:30:12.630 UTC [1319] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE12062026-07-19 09:30:12.630 UTC [1319] STATEMENT: -- name: CommitPendingClosure :exec1207 SELECT commit_pending_closure($1::bigint)1208 12092026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000012102026/07/19 09:30:12 OK 20251218171726_add_pins.sql (6.31ms)1211--- PASS: TestService_cleanupPendingClosuresHandler (0.70s)12122026/07/19 09:30:12 OK 20241026095416_initial_model.sql (15.85ms)12132026/07/19 09:30:12 INFO Completed upload id=112142026/07/19 09:30:12 INFO Upload complete. (100ms)12152026/07/19 09:30:12 INFO Aborted multipart uploads count=112162026/07/19 09:30:12 OK 20251218171726_add_pins.sql (5.83ms)12172026/07/19 09:30:12 OK 20241026095416_initial_model.sql (18.33ms)1218=== NAME TestNARDeduplicationMetadataUploadBug1219 metadata_upload_test.go:54: Retrieved narinfo from S3:1220 StorePath: /build/TestNARDeduplicationMetadataUploadBug2510707819/001/store/854bmyvnp2r7r8lbgsm6nwb60v2ygi3s-file1.txt1221 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst12222026/07/19 09:30:12 OK 1_commit_pending_closure.sql (3.96ms)1223 Compression: zstd12242026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (3.71ms)1225 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1226 NarSize: 16012272026/07/19 09:30:12 OK 20251218171726_add_pins.sql (6.96ms)1228 References: 12292026/07/19 09:30:12 OK 20241026095416_initial_model.sql (16.74ms)1230 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12312026/07/19 09:30:12 OK 20251218171726_add_pins.sql (6.84ms)12322026/07/19 09:30:12 OK 1_commit_pending_closure.sql (4.65ms)12332026/07/19 09:30:12 OK 20241026095416_initial_model.sql (17.36ms)12342026/07/19 09:30:12 OK 20241026095416_initial_model.sql (17.71ms)12352026/07/19 09:30:12 OK 20241026095416_initial_model.sql (16.16ms)12362026/07/19 09:30:12 OK 20241026095416_initial_model.sql (19.01ms)12372026/07/19 09:30:12 OK 20251218171726_add_pins.sql (6.49ms)12382026/07/19 09:30:12 OK 2_object_stats_trigger.sql (2.06ms)12392026/07/19 09:30:12 goose: up to current file version: 212402026/07/19 09:30:12 OK 20241026095416_initial_model.sql (17.83ms)12412026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (3.49ms)12422026/07/19 09:30:12 OK 20241026095416_initial_model.sql (18.64ms)12432026/07/19 09:30:12 OK 20241026095416_initial_model.sql (18.83ms)12442026/07/19 09:30:12 OK 2_object_stats_trigger.sql (2ms)12452026/07/19 09:30:12 goose: up to current file version: 212462026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (6.97ms)12472026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000012482026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)12492026/07/19 09:30:12 OK 20241026095416_initial_model.sql (16.95ms)1250 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)12512026/07/19 09:30:12 OK 20241026095416_initial_model.sql (17.17ms)12522026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)1253 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1254 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12552026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)1256--- PASS: TestMultipartCleanup (0.72s)12572026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)12582026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)12592026/07/19 09:30:12 OK 20241026095416_initial_model.sql (15.41ms)12602026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (5.82ms)12612026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000012622026/07/19 09:30:12 OK 20241026095416_initial_model.sql (16.11ms)12632026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (2.21ms)12642026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)12652026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (5.36ms)12662026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000012672026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (3.08ms)12682026/07/19 09:30:12 OK 20251218171726_add_pins.sql (5.51ms)12692026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures12702026/07/19 09:30:12 OK 1_commit_pending_closure.sql (3.68ms)12712026/07/19 09:30:12 OK 20241026095416_initial_model.sql (17.41ms)12722026/07/19 09:30:12 OK 20241026095416_initial_model.sql (17.67ms)12732026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (3.34ms)12742026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (6.4ms)12752026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000012762026/07/19 09:30:12 OK 20241026095416_initial_model.sql (15.44ms)12772026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (3.71ms)12782026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (2.75ms)12792026/07/19 09:30:12 OK 20251218171726_add_pins.sql (5.13ms)12802026/07/19 09:30:12 OK 20251218171726_add_pins.sql (4.38ms)12812026/07/19 09:30:12 OK 20241026095416_initial_model.sql (26.85ms)12822026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (6.85ms)12832026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000012842026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (4.19ms)12852026/07/19 09:30:12 OK 1_commit_pending_closure.sql (4.46ms)12862026/07/19 09:30:12 OK 20251218171726_add_pins.sql (5.22ms)12872026/07/19 09:30:12 OK 20251218171726_add_pins.sql (5.52ms)12882026/07/19 09:30:12 OK 20251218171726_add_pins.sql (5.07ms)12892026/07/19 09:30:12 OK 20251218171726_add_pins.sql (5.41ms)12902026/07/19 09:30:12 OK 1_commit_pending_closure.sql (4.02ms)12912026/07/19 09:30:12 OK 2_object_stats_trigger.sql (2.96ms)12922026/07/19 09:30:12 goose: up to current file version: 212932026/07/19 09:30:12 OK 20251218171726_add_pins.sql (4.73ms)12942026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (3.08ms)12952026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (2.97ms)12962026/07/19 09:30:12 OK 1_commit_pending_closure.sql (3.73ms)12972026/07/19 09:30:12 OK 20251218171726_add_pins.sql (5.99ms)12982026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (3.25ms)12992026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (3.88ms)13002026/07/19 09:30:12 OK 2_object_stats_trigger.sql (2.84ms)13012026/07/19 09:30:12 OK 20251218171726_add_pins.sql (4.99ms)13022026/07/19 09:30:12 OK 20241026095416_initial_model.sql (15.36ms)13032026/07/19 09:30:12 OK 1_commit_pending_closure.sql (3ms)13042026/07/19 09:30:12 OK 2_object_stats_trigger.sql (2.18ms)13052026/07/19 09:30:12 goose: up to current file version: 213062026/07/19 09:30:12 goose: up to current file version: 213072026/07/19 09:30:12 OK 20251218171726_add_pins.sql (6.2ms)13082026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (6.12ms)13092026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013102026/07/19 09:30:12 OK 20251218171726_add_pins.sql (4.76ms)13112026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.94ms)13122026/07/19 09:30:12 goose: up to current file version: 213132026/07/19 09:30:12 OK 20251218171726_add_pins.sql (4.44ms)13142026/07/19 09:30:12 OK 20251218171726_add_pins.sql (5.59ms)13152026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (4.34ms)13162026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013172026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (4.19ms)13182026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013192026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (5.45ms)13202026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013212026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (5.36ms)13222026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013232026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (5.36ms)13242026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013252026/07/19 09:30:12 OK 2_object_stats_trigger.sql (2.23ms)13262026/07/19 09:30:12 goose: up to current file version: 21327--- PASS: TestReadProxy404 (0.72s)13282026/07/19 09:30:12 OK 20251218171726_add_pins.sql (4.33ms)13292026/07/19 09:30:12 OK 20251218171726_add_pins.sql (4.27ms)13302026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (5.06ms)13312026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013322026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)13332026/07/19 09:30:12 OK 20251218171726_add_pins.sql (4.75ms)13342026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (6.03ms)13352026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013362026/07/19 09:30:12 OK 1_commit_pending_closure.sql (2.87ms)13372026/07/19 09:30:12 OK 20251218171726_add_pins.sql (5.99ms)13382026/07/19 09:30:12 OK 1_commit_pending_closure.sql (3.07ms)13392026/07/19 09:30:12 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1340--- PASS: TestService_ReadAuthMiddleware (0.72s)13412026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (5.03ms)13422026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013432026/07/19 09:30:12 OK 1_commit_pending_closure.sql (3.29ms)13442026/07/19 09:30:12 OK 20241026095416_initial_model.sql (11.94ms)13452026/07/19 09:30:12 OK 1_commit_pending_closure.sql (4.07ms)13462026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (6.09ms)13472026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013482026/07/19 09:30:12 OK 1_commit_pending_closure.sql (3.63ms)13492026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)13502026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013512026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (5.04ms)13522026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013532026/07/19 09:30:12 OK 1_commit_pending_closure.sql (3.06ms)13542026/07/19 09:30:12 OK 1_commit_pending_closure.sql (3.72ms)13552026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (5.05ms)13562026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013572026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.76ms)13582026/07/19 09:30:12 goose: up to current file version: 213592026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (4.95ms)13602026/07/19 09:30:12 OK 2_object_stats_trigger.sql (975.79µs)13612026/07/19 09:30:12 goose: up to current file version: 213622026/07/19 09:30:12 OK 1_commit_pending_closure.sql (2.57ms)13632026/07/19 09:30:12 INFO Created nix-cache-info in bucket bucket=bucket2313642026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.37ms)13652026/07/19 09:30:12 goose: up to current file version: 213662026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.05ms)13672026/07/19 09:30:12 goose: up to current file version: 213682026/07/19 09:30:12 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)13692026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.27ms)13702026/07/19 09:30:12 goose: up to current file version: 213712026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (3.93ms)13722026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013732026/07/19 09:30:12 OK 1_commit_pending_closure.sql (2.08ms)13742026/07/19 09:30:12 OK 1_commit_pending_closure.sql (2.16ms)13752026/07/19 09:30:12 OK 20251218171726_add_pins.sql (3.3ms)13762026/07/19 09:30:12 OK 1_commit_pending_closure.sql (2.3ms)13772026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.05ms)13782026/07/19 09:30:12 goose: up to current file version: 213792026/07/19 09:30:12 OK 1_commit_pending_closure.sql (2.49ms)13802026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)13812026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013822026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)13832026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.09ms)13842026/07/19 09:30:12 OK 2_object_stats_trigger.sql (870.85µs)13852026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013862026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000013872026/07/19 09:30:12 goose: up to current file version: 213882026/07/19 09:30:12 OK 1_commit_pending_closure.sql (2.5ms)13892026/07/19 09:30:12 goose: up to current file version: 213902026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.07ms)13912026/07/19 09:30:12 goose: up to current file version: 213922026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.1ms)13932026/07/19 09:30:12 goose: up to current file version: 213942026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1ms)13952026/07/19 09:30:12 goose: up to current file version: 213962026/07/19 09:30:12 OK 1_commit_pending_closure.sql (2.19ms)13972026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.52ms)13982026/07/19 09:30:12 goose: up to current file version: 213992026/07/19 09:30:12 OK 20251218171726_add_pins.sql (2.95ms)14002026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (5.56ms)14012026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000014022026/07/19 09:30:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1403=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token14042026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.12ms)1405--- PASS: TestService_Rustfstest (0.73s)14062026/07/19 09:30:12 OK 1_commit_pending_closure.sql (2.29ms)1407=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token14082026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (3.33ms)1409--- PASS: TestReadProxyInvalidPath (0.73s)14102026/07/19 09:30:12 goose: successfully migrated database to version: 202606281200001411=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1412=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected14132026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.08ms)1414--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.73s)14152026/07/19 09:30:12 goose: up to current file version: 21416=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected14172026/07/19 09:30:12 OK 1_commit_pending_closure.sql (2.14ms)1418=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected14192026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures1420--- PASS: TestReadProxyDisabled (0.73s)14212026/07/19 09:30:12 OK 1_commit_pending_closure.sql (1.97ms)1422--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.73s)14232026/07/19 09:30:12 goose: up to current file version: 21424=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1425=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured14262026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.04ms)1427=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token14282026/07/19 09:30:12 goose: up to current file version: 21429=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected14302026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures1431=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured14322026/07/19 09:30:12 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]1433=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected14342026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures14352026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures14362026/07/19 09:30:12 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst14372026/07/19 09:30:12 OK 1_commit_pending_closure.sql (3.03ms)1438--- PASS: TestCompleteMultipartUnregistered (0.74s)14392026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.02ms)14402026/07/19 09:30:12 goose: up to current file version: 214412026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.42ms)14422026/07/19 09:30:12 goose: up to current file version: 214432026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures14442026/07/19 09:30:12 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)14452026/07/19 09:30:12 goose: successfully migrated database to version: 2026062812000014462026/07/19 09:30:12 OK 1_commit_pending_closure.sql (2.51ms)14472026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.3ms)14482026/07/19 09:30:12 goose: up to current file version: 214492026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures14502026/07/19 09:30:12 INFO Created nix-cache-info in bucket bucket=bucket3814512026/07/19 09:30:12 OK 2_object_stats_trigger.sql (1.26ms)14522026/07/19 09:30:12 goose: up to current file version: 214532026/07/19 09:30:12 OK 1_commit_pending_closure.sql (1.87ms)14542026/07/19 09:30:12 OK 2_object_stats_trigger.sql (4.75ms)14552026/07/19 09:30:12 goose: up to current file version: 214562026/07/19 09:30:12 INFO Created nix-cache-info in bucket bucket=bucket431457--- PASS: TestCacheStatsHandler (0.75s)1458=== NAME TestNARDeduplicationMetadataUploadBug1459 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2510707819/001/store/vi5y79cwgjljgphai4xwsbs4hx8ba87w-file2.txt14602026/07/19 09:30:12 INFO OIDC auth successful provider=test14612026/07/19 09:30:12 WARN Authentication failed token_preview=eyJhbGciOi...xMQk4eLdgQ 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]1462--- PASS: TestService_AuthMiddleware_OIDC (0.73s)1463 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1464 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1465 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)1466 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)1467--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.75s)14682026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures1469--- PASS: TestReadProxyConditionalGet (0.75s)1470=== NAME TestClientCADerivations1471 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4181418713/001/store/bxc1l786priyk74xxm3kd6d24gxlx206-ca-test1472=== NAME TestClientWithDependencies1473 client_integration_test.go:593: Built derivation: /build/TestClientWithDependencies4257696189/001/store/k72inx7qqz644dg44dgjn7y164ra6ysp-test-script1474--- PASS: TestReadProxyNarStreaming (0.76s)14752026/07/19 09:30:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1476--- PASS: TestResurrectedObjectNotDeleted (0.76s)1477{"timestamp":"2026-07-19T09:30:12.697057461Z","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(763)"}1478{"timestamp":"2026-07-19T09:30:12.697133071Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket37, object=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst"},"target":"rustfs_ecstore::set_disk","filename":"crates/ecstore/src/set_disk.rs","line_number":3534,"threadName":"rustfs-worker","threadId":"ThreadId(763)"}14792026/07/19 09:30:12 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=NzA5MDk1OGQtZTI3Ni00OWM0LWE2YzgtMmJjMDRhMWViOGMzLjE4YzhkNGQ3LTM1NzUtNGZiMC1hNTJkLTE0ZjBhOTdkYmE4YXgxNzg0NDUzNDEyNjc2MzI3MjY214802026/07/19 09:30:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzA5MDk1OGQtZTI3Ni00OWM0LWE2YzgtMmJjMDRhMWViOGMzLjE4YzhkNGQ3LTM1NzUtNGZiMC1hNTJkLTE0ZjBhOTdkYmE4YXgxNzg0NDUzNDEyNjc2MzI3MjY2 parts=11481--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.77s)1482=== NAME TestClientIntegration1483 client_integration_test.go:276: Created store path: /build/TestClientIntegration1766952054/002/store/5xbfaw785vyw5ldg3gw6783qibdy4nka-test-file.txt1484=== NAME TestClientMultipleUploads1485 client_integration_test.go:338: Created store path 0: /build/TestClientMultipleUploads3589163713/001/store/k9fg3jb6ajd2q52m1f6gxl0rjjdxlvmq-test-file-0.txt1486=== NAME TestClientCADerivations1487 client_ca_test.go:139: Found 1 dependencies (including self)1488=== NAME TestClientWithDependencies1489 client_integration_test.go:595: Found 1 dependencies (including self)14902026/07/19 09:30:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1491=== NAME TestPinProtectsFromGC1492 client_integration_test.go:646: Pinned store path: /build/TestPinProtectsFromGC3674883281/001/store/i1vdrksbslmp10nqhpkpsqdzksnnq8cz-pinned-file.txt1493 client_integration_test.go:647: Unpinned store path: /build/TestPinProtectsFromGC3674883281/001/store/vsvlv642sb5wg5hm0md36jfx3ic2m4xm-unpinned-file.txt1494=== NAME TestClientMultipleUploads1495 client_integration_test.go:338: Created store path 1: /build/TestClientMultipleUploads3589163713/001/store/dr5a961k8w93aznp057h81ih9gywypaq-test-file-1.txt14962026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures14972026/07/19 09:30:12 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1498 client_integration_test.go:338: Created store path 2: /build/TestClientMultipleUploads3589163713/001/store/vnd8ja38jmgipwaa6hxx3ynb4kf23yix-test-file-2.txt14992026/07/19 09:30:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15002026/07/19 09:30:12 INFO Signed narinfos id=2 count=115012026/07/19 09:30:12 INFO Uploading 1 narinfos1502--- PASS: TestGCBugBareHashReferences (0.86s)15032026/07/19 09:30:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15042026/07/19 09:30:12 INFO Completed upload id=215052026/07/19 09:30:12 INFO Upload complete. (78ms)1506=== NAME TestNARDeduplicationMetadataUploadBug1507 metadata_upload_test.go:76: Retrieved narinfo from S3:1508 StorePath: /build/TestNARDeduplicationMetadataUploadBug2510707819/001/store/vi5y79cwgjljgphai4xwsbs4hx8ba87w-file2.txt1509 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1510 Compression: zstd1511 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1512 NarSize: 1601513 References: 1514 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf15152026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures1516 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1517 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1518 {"version":1,"root":{"type":"regular","size":44}}1519--- PASS: TestNARDeduplicationMetadataUploadBug (0.87s)15202026/07/19 09:30:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15212026/07/19 09:30:12 INFO Uploading k72inx7qqz644dg44dgjn7y164ra6ysp-test-script (136B)15222026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures15232026/07/19 09:30:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15242026/07/19 09:30:12 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"15252026/07/19 09:30:12 INFO Signed narinfos id=1 count=115262026/07/19 09:30:12 INFO Uploading 1 narinfos15272026/07/19 09:30:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15282026/07/19 09:30:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15292026/07/19 09:30:12 INFO Uploading 5xbfaw785vyw5ldg3gw6783qibdy4nka-test-file.txt (152B)15302026/07/19 09:30:12 INFO Completed upload id=115312026/07/19 09:30:12 INFO Upload complete. (60ms)1532--- PASS: TestReadProxyNarinfo (0.89s)15332026/07/19 09:30:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1534=== NAME TestClientWithDependencies1535 client_integration_test.go:597: Skipping nix copy test - isolated store (/build/TestClientWithDependencies4257696189/001/store) requires matching store prefix15362026/07/19 09:30:12 INFO Signed narinfos id=1 count=115372026/07/19 09:30:12 INFO Uploading 1 narinfos1538--- PASS: TestClientWithDependencies (0.90s)15392026/07/19 09:30:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15402026/07/19 09:30:12 INFO Completed upload id=115412026/07/19 09:30:12 INFO Upload complete. (94ms)1542=== NAME TestClientIntegration1543 client_integration_test.go:292: Retrieved narinfo from S3:1544 StorePath: /build/TestClientIntegration1766952054/002/store/5xbfaw785vyw5ldg3gw6783qibdy4nka-test-file.txt1545 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1546 Compression: zstd1547 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11548 NarSize: 1521549 References: 1550 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11551 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1552 client_integration_test.go:293: Decompressed .ls content (64 bytes):1553 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1554 client_integration_test.go:296: Testing garbage collection...15552026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures15562026/07/19 09:30:12 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=807.943571ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures15572026/07/19 09:30:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15582026/07/19 09:30:12 INFO Uploading i1vdrksbslmp10nqhpkpsqdzksnnq8cz-pinned-file.txt (128B)15592026/07/19 09:30:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15602026/07/19 09:30:12 INFO Signed narinfos id=1 count=115612026/07/19 09:30:12 INFO Uploading 1 narinfos15622026/07/19 09:30:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15632026/07/19 09:30:12 INFO Completed upload id=115642026/07/19 09:30:12 INFO Upload complete. (96ms)15652026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures15662026/07/19 09:30:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures15672026/07/19 09:30:12 INFO Garbage collection started15682026/07/19 09:30:12 INFO Aborted multipart uploads count=015692026/07/19 09:30:12 WARN Force mode enabled - objects will be deleted immediately without grace period15702026/07/19 09:30:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15712026/07/19 09:30:12 INFO Uploading bxc1l786priyk74xxm3kd6d24gxlx206-ca-test (144B)15722026/07/19 09:30:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15732026/07/19 09:30:12 INFO Signed narinfos id=1 count=115742026/07/19 09:30:12 INFO Uploading 1 narinfos15752026/07/19 09:30:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1576--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)1577 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)1578 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1579 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.80s)15802026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures15812026/07/19 09:30:12 INFO Completed upload id=115822026/07/19 09:30:12 INFO Upload complete. (124ms)1583=== NAME TestClientCADerivations15842026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures1585 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4181418713/001/store/bxc1l786priyk74xxm3kd6d24gxlx206-ca-test1586 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1587 Compression: zstd1588 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1589 NarSize: 1441590 References: 1591 Deriver: /build/TestClientCADerivations4181418713/001/store/2biz9v6gwms7d16wfsbybg4yx6spwhpy-ca-test.drv1592 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1593 client_ca_test.go:185: Checking for realisation files in S3...15942026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures1595 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1596 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15972026/07/19 09:30:12 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15982026/07/19 09:30:12 INFO Uploading vnd8ja38jmgipwaa6hxx3ynb4kf23yix-test-file-2.txt (160B)15992026/07/19 09:30:12 INFO Uploading k9fg3jb6ajd2q52m1f6gxl0rjjdxlvmq-test-file-0.txt (160B)16002026/07/19 09:30:12 INFO Uploading dr5a961k8w93aznp057h81ih9gywypaq-test-file-1.txt (160B)16012026/07/19 09:30:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16022026/07/19 09:30:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16032026/07/19 09:30:12 INFO Signed narinfos id=2 count=116042026/07/19 09:30:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16052026/07/19 09:30:12 INFO Signed narinfos id=3 count=116062026/07/19 09:30:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16072026/07/19 09:30:12 INFO Signed narinfos id=1 count=116082026/07/19 09:30:12 INFO Uploading 3 narinfos16092026/07/19 09:30:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16102026/07/19 09:30:12 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NzA5MDk1OGQtZTI3Ni00OWM0LWE2YzgtMmJjMDRhMWViOGMzLjc0ZmViZmYyLWNjNTQtNDllNC05YWE4LWFkNGVlOGJjYzcwM3gxNzg0NDUzNDEyNTk3MzY3MDcy parts=1216112026/07/19 09:30:12 INFO Completed upload id=116122026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures16132026/07/19 09:30:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1614--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.00s)16152026/07/19 09:30:12 INFO Completed upload id=216162026/07/19 09:30:12 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete1617=== NAME TestOrphanedObjectsGC1618 orphaned_objects_gc_test.go:290: GC Test Summary:16192026/07/19 09:30:12 INFO Completed upload id=31620 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1621 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1622 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1623 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)16242026/07/19 09:30:12 INFO Upload complete. (122ms)1625 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1626=== NAME TestClientMultipleUploads1627 client_integration_test.go:349: Uploaded 3 paths in 153.021408ms1628--- PASS: TestOrphanedObjectsGC (1.00s)16292026/07/19 09:30:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16302026/07/19 09:30:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1631--- PASS: TestClientMultipleUploads (1.02s)16322026/07/19 09:30:12 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NzA5MDk1OGQtZTI3Ni00OWM0LWE2YzgtMmJjMDRhMWViOGMzLmI1NTE5NTI2LWQyMDYtNDgyNS1hMGY4LWUwYTEzNjIxZTY3ZngxNzg0NDUzNDEyNjc3NTIyOTc1 parts=1016332026/07/19 09:30:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16342026/07/19 09:30:12 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NzA5MDk1OGQtZTI3Ni00OWM0LWE2YzgtMmJjMDRhMWViOGMzLjc2OTk2ZWI5LTEzZjktNGQyMy1iOTE2LWM3NDlmMzU2ZDQ3OXgxNzg0NDUzNDEyNjc1ODQzNDY2 parts=1016352026/07/19 09:30:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16362026/07/19 09:30:12 INFO Completed upload id=116372026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures16382026/07/19 09:30:12 INFO Completed upload id=116392026/07/19 09:30:12 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016402026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures16412026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures16422026/07/19 09:30:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures16432026/07/19 09:30:12 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16442026/07/19 09:30:12 WARN Found objects in DB but missing from S3, will re-upload count=11645--- PASS: TestService_verifyS3Integrity (1.03s)16462026/07/19 09:30:12 INFO Aborted multipart uploads count=016472026/07/19 09:30:12 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=016482026/07/19 09:30:12 INFO Vacuumed table table=pending_closures16492026/07/19 09:30:12 INFO Vacuumed table table=pending_objects16502026/07/19 09:30:12 INFO Received uploads request method=POST path=/api/pending_closures16512026/07/19 09:30:12 INFO Vacuumed table table=multipart_uploads16522026/07/19 09:30:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16532026/07/19 09:30:12 INFO Uploading vsvlv642sb5wg5hm0md36jfx3ic2m4xm-unpinned-file.txt (128B)16542026/07/19 09:30:12 INFO Vacuumed table table=closures16552026/07/19 09:30:12 INFO Vacuumed table table=objects16562026/07/19 09:30:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16572026/07/19 09:30:12 INFO Signed narinfos id=2 count=116582026/07/19 09:30:12 INFO Uploading 1 narinfos16592026/07/19 09:30:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16602026/07/19 09:30:12 INFO Completed upload id=216612026/07/19 09:30:12 INFO Upload complete. (79ms)16622026/07/19 09:30:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16632026/07/19 09:30:13 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NzA5MDk1OGQtZTI3Ni00OWM0LWE2YzgtMmJjMDRhMWViOGMzLjY5NTI1OGM3LWExNmUtNDFhYi1iYTU5LTg3YjFhNTE4NGY4ZHgxNzg0NDUzNDEyNjc1OTM0NTc2 parts=121664--- PASS: TestRedundantMultipartUpload (1.08s)16652026/07/19 09:30:13 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001666--- PASS: TestService_createPendingClosureHandler (1.08s)16672026/07/19 09:30:13 INFO Received create pin request method=POST path=/api/pins/myapp16682026/07/19 09:30:13 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3674883281/001/store/i1vdrksbslmp10nqhpkpsqdzksnnq8cz-pinned-file.txt narinfo_key=i1vdrksbslmp10nqhpkpsqdzksnnq8cz.narinfo16692026/07/19 09:30:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures16702026/07/19 09:30:13 INFO Garbage collection started1671=== NAME TestClientCADerivations1672 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1673 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1674 error: binary cache 's3://bucket16?endpoint=http://localhost:44903®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4181418713/001/store'1675 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11676--- PASS: TestClientCADerivations (1.10s)16772026/07/19 09:30:13 INFO Aborted multipart uploads count=016782026/07/19 09:30:13 WARN Force mode enabled - objects will be deleted immediately without grace period16792026/07/19 09:30:13 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=016802026/07/19 09:30:13 INFO Vacuumed table table=pending_closures16812026/07/19 09:30:13 INFO Vacuumed table table=pending_objects16822026/07/19 09:30:13 INFO Vacuumed table table=multipart_uploads16832026/07/19 09:30:13 INFO Vacuumed table table=closures16842026/07/19 09:30:13 INFO Vacuumed table table=objects1685=== NAME TestOrphanedObjectsGCStressTest1686 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1687 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1688 orphaned_objects_gc_test.go:509: Stress test completed successfully:1689 orphaned_objects_gc_test.go:510: - Active objects preserved: 201690 orphaned_objects_gc_test.go:511: - Objects deleted: 2101691 orphaned_objects_gc_test.go:512: - Total GC'd: 2101692--- PASS: TestOrphanedObjectsGCStressTest (1.53s)16932026/07/19 09:30:13 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=016942026/07/19 09:30:13 INFO Vacuumed table table=pending_closures16952026/07/19 09:30:13 INFO Vacuumed table table=pending_objects16962026/07/19 09:30:13 INFO Vacuumed table table=multipart_uploads16972026/07/19 09:30:13 INFO Vacuumed table table=closures16982026/07/19 09:30:13 INFO Vacuumed table table=objects16992026/07/19 09:30:13 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.661009476s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17002026/07/19 09:30:14 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01701=== NAME TestClientIntegration1702 client_integration_test.go:303: Objects in database after GC:1703 client_integration_test.go:303: Successfully deleted all objects with GC --force1704--- PASS: TestClientIntegration (2.96s)17052026/07/19 09:30:15 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01706=== NAME TestPinProtectsFromGC1707 client_integration_test.go:709: Pin successfully protected closure from garbage collection1708--- PASS: TestPinProtectsFromGC (3.11s)1709--- PASS: TestClientErrorHandling (0.02s)1710 --- PASS: TestClientErrorHandling/InvalidStorePath (0.76s)1711 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.87s)1712 --- PASS: TestClientErrorHandling/ServerNotAvailable (3.38s)17132026/07/19 09:30:15 WARN Rate limiter enabled after throttle name=s3-test rate=517142026/07/19 09:30:15 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1715=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1716 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101717 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001718--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.05s)1719PASS1720{"timestamp":"2026-07-19T09:30:16.483320327Z","level":"ERROR","fields":{"message":"Unknown connection IO error:Cancelled","peer_addr":"127.0.0.1:37622"},"target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":973,"threadName":"rustfs-worker","threadId":"ThreadId(767)"}17212026-07-19 09:30:16.657 UTC [293] LOG: received smart shutdown request17222026-07-19 09:30:16.661 UTC [293] LOG: background worker "logical replication launcher" (PID 303) exited with exit code 117232026-07-19 09:30:16.666 UTC [298] LOG: shutting down17242026-07-19 09:30:16.667 UTC [298] LOG: checkpoint starting: shutdown immediate17252026-07-19 09:30:18.071 UTC [298] LOG: checkpoint complete: wrote 8673 buffers (52.9%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 12 recycled; write=0.188 s, sync=1.210 s, total=1.405 s; sync files=14838, longest=0.001 s, average=0.001 s; distance=203940 kB, estimate=203940 kB; lsn=0/DE88338, redo lsn=0/DE8833817262026-07-19 09:30:18.147 UTC [293] LOG: database system is shut down1727Running OIDC tests...1728=== RUN TestGlobMatch1729=== PAUSE TestGlobMatch1730=== RUN TestAudienceForIssuer1731=== PAUSE TestAudienceForIssuer1732=== RUN TestValidateToken_ValidToken1733=== PAUSE TestValidateToken_ValidToken1734=== RUN TestValidateToken_WrongAudience1735=== PAUSE TestValidateToken_WrongAudience1736=== RUN TestValidateToken_Expired1737=== PAUSE TestValidateToken_Expired1738=== RUN TestValidateToken_BoundClaimsMismatch1739=== PAUSE TestValidateToken_BoundClaimsMismatch1740=== RUN TestValidateToken_BoundSubjectMismatch1741=== PAUSE TestValidateToken_BoundSubjectMismatch1742=== RUN TestValidateToken_MultipleProviders1743=== PAUSE TestValidateToken_MultipleProviders1744=== RUN TestValidateToken_NoMatchingProvider1745=== PAUSE TestValidateToken_NoMatchingProvider1746=== CONT TestGlobMatch1747=== CONT TestValidateToken_BoundClaimsMismatch1748=== RUN TestGlobMatch/foo_foo1749=== CONT TestValidateToken_WrongAudience1750=== CONT TestAudienceForIssuer1751--- PASS: TestAudienceForIssuer (0.00s)1752=== CONT TestValidateToken_ValidToken1753=== CONT TestValidateToken_MultipleProviders1754=== CONT TestValidateToken_NoMatchingProvider1755=== CONT TestValidateToken_Expired1756=== CONT TestValidateToken_BoundSubjectMismatch1757=== PAUSE TestGlobMatch/foo_foo1758=== RUN TestGlobMatch/foo_bar1759=== PAUSE TestGlobMatch/foo_bar1760=== RUN TestGlobMatch/*_1761=== PAUSE TestGlobMatch/*_1762=== RUN TestGlobMatch/*_anything1763=== PAUSE TestGlobMatch/*_anything1764=== RUN TestGlobMatch/foo*_foo1765=== PAUSE TestGlobMatch/foo*_foo1766=== RUN TestGlobMatch/foo*_foobar1767=== PAUSE TestGlobMatch/foo*_foobar1768=== RUN TestGlobMatch/foo*_bar1769=== PAUSE TestGlobMatch/foo*_bar1770=== RUN TestGlobMatch/*bar_bar1771=== PAUSE TestGlobMatch/*bar_bar1772=== RUN TestGlobMatch/*bar_foobar1773=== PAUSE TestGlobMatch/*bar_foobar1774=== RUN TestGlobMatch/*bar_foo1775=== PAUSE TestGlobMatch/*bar_foo1776=== RUN TestGlobMatch/foo*bar_foobar1777=== PAUSE TestGlobMatch/foo*bar_foobar1778=== RUN TestGlobMatch/foo*bar_foo123bar1779=== PAUSE TestGlobMatch/foo*bar_foo123bar1780=== RUN TestGlobMatch/foo*bar_foobarbaz1781=== PAUSE TestGlobMatch/foo*bar_foobarbaz1782=== RUN TestGlobMatch/*/*_foo/bar1783=== PAUSE TestGlobMatch/*/*_foo/bar1784=== RUN TestGlobMatch/*/*_foo1785=== PAUSE TestGlobMatch/*/*_foo1786=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1787=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1788=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01789=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01790=== RUN TestGlobMatch/refs/*/main_refs/heads/main1791=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1792=== RUN TestGlobMatch/fo?_foo1793=== PAUSE TestGlobMatch/fo?_foo1794=== RUN TestGlobMatch/fo?_fo1795=== PAUSE TestGlobMatch/fo?_fo1796=== RUN TestGlobMatch/fo?_fooo1797=== PAUSE TestGlobMatch/fo?_fooo1798=== RUN TestGlobMatch/?oo_foo1799=== PAUSE TestGlobMatch/?oo_foo1800=== RUN TestGlobMatch/?oo_boo1801=== PAUSE TestGlobMatch/?oo_boo1802=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1803=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1804=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1805=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1806=== CONT TestGlobMatch/foo_foo1807=== CONT TestGlobMatch/*/*_foo1808=== CONT TestGlobMatch/*/*_foo/bar1809=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1810=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1811=== CONT TestGlobMatch/?oo_boo1812=== CONT TestGlobMatch/?oo_foo1813=== CONT TestGlobMatch/fo?_fooo1814=== CONT TestGlobMatch/fo?_fo1815=== CONT TestGlobMatch/fo?_foo1816=== CONT TestGlobMatch/refs/*/main_refs/heads/main1817=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01818=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1819=== CONT TestGlobMatch/foo*bar_foobarbaz1820=== CONT TestGlobMatch/foo*bar_foo123bar1821=== CONT TestGlobMatch/foo*bar_foobar1822=== CONT TestGlobMatch/*bar_foo1823=== CONT TestGlobMatch/*bar_foobar1824=== CONT TestGlobMatch/*bar_bar1825=== CONT TestGlobMatch/foo*_bar1826=== CONT TestGlobMatch/foo*_foobar1827=== CONT TestGlobMatch/foo*_foo1828=== CONT TestGlobMatch/*_anything1829=== CONT TestGlobMatch/*_1830=== CONT TestGlobMatch/foo_bar1831--- PASS: TestGlobMatch (0.00s)1832 --- PASS: TestGlobMatch/foo_foo (0.00s)1833 --- PASS: TestGlobMatch/*/*_foo (0.00s)1834 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1835 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1836 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1837 --- PASS: TestGlobMatch/?oo_boo (0.00s)1838 --- PASS: TestGlobMatch/?oo_foo (0.00s)1839 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1840 --- PASS: TestGlobMatch/fo?_fo (0.00s)1841 --- PASS: TestGlobMatch/fo?_foo (0.00s)1842 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1843 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1844 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1845 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1846 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1847 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1848 --- PASS: TestGlobMatch/*bar_foo (0.00s)1849 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1850 --- PASS: TestGlobMatch/*bar_bar (0.00s)1851 --- PASS: TestGlobMatch/foo*_bar (0.00s)1852 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1853 --- PASS: TestGlobMatch/foo*_foo (0.00s)1854 --- PASS: TestGlobMatch/*_anything (0.00s)1855 --- PASS: TestGlobMatch/*_ (0.00s)1856 --- PASS: TestGlobMatch/foo_bar (0.00s)18572026/07/19 09:30:18 INFO OIDC provider initialized name=test18582026/07/19 09:30:18 INFO OIDC provider initialized name=test18592026/07/19 09:30:18 INFO OIDC provider initialized name=provider118602026/07/19 09:30:18 INFO OIDC provider initialized name=test18612026/07/19 09:30:18 INFO OIDC provider initialized name=test18622026/07/19 09:30:18 INFO OIDC provider initialized name=test18632026/07/19 09:30:18 INFO OIDC provider initialized name=provider118642026/07/19 09:30:18 INFO OIDC provider initialized name=provider21865--- PASS: TestValidateToken_WrongAudience (0.01s)1866--- PASS: TestValidateToken_ValidToken (0.01s)1867--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1868--- PASS: TestValidateToken_Expired (0.01s)1869--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1870--- PASS: TestValidateToken_MultipleProviders (0.01s)1871--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)1872PASS1873Running hook tests...1874=== RUN TestSendPathsEmpty1875=== PAUSE TestSendPathsEmpty1876=== RUN TestQueueEnqueueAndFetch1877=== PAUSE TestQueueEnqueueAndFetch1878=== RUN TestQueueDeduplication1879=== PAUSE TestQueueDeduplication1880=== RUN TestQueueRemove1881=== PAUSE TestQueueRemove1882=== RUN TestQueueFetchBatchLimit1883=== PAUSE TestQueueFetchBatchLimit1884=== RUN TestQueueFetchRemoveLifecycle1885=== PAUSE TestQueueFetchRemoveLifecycle1886=== RUN TestQueueConcurrentWriters1887=== PAUSE TestQueueConcurrentWriters1888=== RUN TestServerClientIntegration1889=== PAUSE TestServerClientIntegration1890=== RUN TestServerQueueError1891=== PAUSE TestServerQueueError1892=== RUN TestGetListenerSocketActivation1893 server_test.go:210: === RUN TestGetListenerSocketActivation1894 --- PASS: TestGetListenerSocketActivation (0.00s)1895 PASS1896 1897--- PASS: TestGetListenerSocketActivation (0.03s)1898=== RUN TestWorkerUploadsAndRemoves1899=== PAUSE TestWorkerUploadsAndRemoves1900=== RUN TestWorkerSkipsGCdPaths1901=== PAUSE TestWorkerSkipsGCdPaths1902=== RUN TestWorkerPrunesClosureDeps1903=== PAUSE TestWorkerPrunesClosureDeps1904=== CONT TestSendPathsEmpty1905=== CONT TestServerClientIntegration1906=== CONT TestQueueConcurrentWriters1907=== CONT TestServerQueueError1908=== CONT TestWorkerUploadsAndRemoves1909=== CONT TestWorkerPrunesClosureDeps1910=== CONT TestQueueRemove1911=== CONT TestWorkerSkipsGCdPaths1912=== CONT TestQueueFetchRemoveLifecycle1913=== CONT TestQueueFetchBatchLimit1914=== CONT TestQueueDeduplication1915--- PASS: TestSendPathsEmpty (0.00s)1916=== CONT TestQueueEnqueueAndFetch19172026/07/19 09:30:19 ERROR Failed to queue paths error="permission denied" count=11918--- PASS: TestServerClientIntegration (0.00s)1919--- PASS: TestServerQueueError (0.00s)19202026/07/19 09:30:19 INFO Upload queue status pending=219212026/07/19 09:30:19 INFO Uploading batch count=219222026/07/19 09:30:19 INFO Upload queue status pending=219232026/07/19 09:30:19 INFO Uploading batch count=119242026/07/19 09:30:19 INFO Upload queue status pending=219252026/07/19 09:30:19 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2087470659/002/nonexistent1926--- PASS: TestQueueEnqueueAndFetch (0.02s)1927--- PASS: TestQueueFetchRemoveLifecycle (0.02s)1928--- PASS: TestQueueFetchBatchLimit (0.02s)19292026/07/19 09:30:19 INFO Uploading batch count=11930--- PASS: TestQueueDeduplication (0.02s)1931--- PASS: TestQueueRemove (0.02s)1932--- PASS: TestWorkerUploadsAndRemoves (0.07s)1933--- PASS: TestWorkerPrunesClosureDeps (0.07s)1934--- PASS: TestWorkerSkipsGCdPaths (0.07s)1935--- PASS: TestQueueConcurrentWriters (0.48s)1936PASS