niks3-go-unit-tests
aarch64-linux.go-unit-tests
· build #92
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestCaseHackSuffix6=== PAUSE TestCaseHackSuffix7=== RUN TestPartSizeForNAR8=== PAUSE TestPartSizeForNAR9=== RUN TestUploadMultipart_SupersededByPeer10=== PAUSE TestUploadMultipart_SupersededByPeer11=== RUN TestDumpPathMatchesNix12=== PAUSE TestDumpPathMatchesNix13=== RUN TestDumpPathSingleFile14=== PAUSE TestDumpPathSingleFile15=== RUN TestDumpPathWriterError16=== PAUSE TestDumpPathWriterError17=== RUN TestEncodeNixBase3218=== PAUSE TestEncodeNixBase3219=== RUN TestEncodeNixBase32WithRealHash20=== PAUSE TestEncodeNixBase32WithRealHash21=== RUN TestConvertHashToNix3222=== PAUSE TestConvertHashToNix3223=== RUN TestGetStorePathHash24=== PAUSE TestGetStorePathHash25=== RUN TestPathInfoHashCompatibility26=== PAUSE TestPathInfoHashCompatibility27=== RUN TestParsePathInfoJSON28=== PAUSE TestParsePathInfoJSON29=== RUN TestParsePathInfoJSONMultiplePaths30=== PAUSE TestParsePathInfoJSONMultiplePaths31=== RUN TestPathInfoCACompatibility32=== PAUSE TestPathInfoCACompatibility33=== RUN TestRateLimiterFeedback34=== PAUSE TestRateLimiterFeedback35=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess36=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess37=== RUN TestResolveStorePath38=== PAUSE TestResolveStorePath39=== RUN TestDoWithRetry_BodyReplayedViaGetBody40=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody41=== RUN TestShellSplit42=== PAUSE TestShellSplit43=== RUN TestShellSplitErrors44=== PAUSE TestShellSplitErrors45=== RUN TestSetClientTLS46=== PAUSE TestSetClientTLS47=== RUN TestSetClientTLSDoesNotMutateDefaultTransport48=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport49=== RUN TestSetClientTLSErrors50=== PAUSE TestSetClientTLSErrors51=== RUN TestStaticToken52=== PAUSE TestStaticToken53=== RUN TestFileTokenReadsAndCaches54=== PAUSE TestFileTokenReadsAndCaches55=== RUN TestFileTokenMissing56=== PAUSE TestFileTokenMissing57=== RUN TestFileTokenEmpty58=== PAUSE TestFileTokenEmpty59=== RUN TestScriptTokenNoExpiryRerunsEveryCall60=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall61=== RUN TestScriptTokenCachesUntilRefresh62=== PAUSE TestScriptTokenCachesUntilRefresh63=== RUN TestScriptTokenEmptyToken64=== PAUSE TestScriptTokenEmptyToken65=== RUN TestScriptTokenBadJSON66=== PAUSE TestScriptTokenBadJSON67=== RUN TestScriptTokenScriptFails68=== PAUSE TestScriptTokenScriptFails69=== RUN TestScriptTokenEmptyCommand70=== PAUSE TestScriptTokenEmptyCommand71=== CONT TestDoServerRequestAttachesToken72=== CONT TestShellSplitErrors73=== CONT TestGetStorePathHash74=== RUN TestGetStorePathHash/valid_store_path75=== CONT TestScriptTokenEmptyCommand76--- PASS: TestShellSplitErrors (0.00s)77--- PASS: TestScriptTokenEmptyCommand (0.00s)78=== CONT TestRateLimiterFeedback79=== RUN TestRateLimiterFeedback/429_enables_limiter80=== CONT TestShellSplit81=== CONT TestDoWithRetry_BodyReplayedViaGetBody82=== CONT TestResolveStorePath83=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess84=== CONT TestFileTokenEmpty85=== CONT TestScriptTokenScriptFails86--- PASS: TestShellSplit (0.00s)87=== PAUSE TestGetStorePathHash/valid_store_path88=== CONT TestScriptTokenBadJSON89=== CONT TestScriptTokenEmptyToken90=== CONT TestPathInfoCACompatibility91=== CONT TestScriptTokenCachesUntilRefresh92=== CONT TestParsePathInfoJSONMultiplePaths93=== CONT TestScriptTokenNoExpiryRerunsEveryCall94=== CONT TestParsePathInfoJSON95=== CONT TestUploadMultipart_SupersededByPeer96=== CONT TestPathInfoHashCompatibility97=== CONT TestDumpPathMatchesNix98=== CONT TestPartSizeForNAR99=== CONT TestEncodeNixBase32WithRealHash100=== CONT TestConvertHashToNix32101=== CONT TestCaseHackSuffix1022026/07/09 07:20:06 WARN Rate limiter enabled after throttle name=server-test rate=5103=== CONT TestStaticToken104=== CONT TestEncodeNixBase32105=== CONT TestFileTokenMissing106=== CONT TestDumpPathWriterError107=== CONT TestFileTokenReadsAndCaches108=== CONT TestSetClientTLSDoesNotMutateDefaultTransport109=== CONT TestSetClientTLS110=== CONT TestSetClientTLSErrors111=== PAUSE TestRateLimiterFeedback/429_enables_limiter112=== CONT TestDumpPathSingleFile113=== RUN TestGetStorePathHash/basename_without_hyphen_should_error114=== RUN TestRateLimiterFeedback/503_enables_limiter115=== RUN TestConvertHashToNix32/SRI_format_to_Nix32116=== PAUSE TestRateLimiterFeedback/503_enables_limiter117=== RUN TestPathInfoCACompatibility/null_ca_field118=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32119=== RUN TestUploadMultipart_SupersededByPeer/exists120=== PAUSE TestUploadMultipart_SupersededByPeer/exists121=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter122=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter123=== RUN TestEncodeNixBase32/test_string_hash124=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths125=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error126=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter127=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths128=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error129=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths130=== RUN TestParsePathInfoJSON/Nix_format131=== PAUSE TestParsePathInfoJSON/Nix_format132=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)133=== PAUSE TestPathInfoCACompatibility/null_ca_field134=== RUN TestParsePathInfoJSON/Lix_format135=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)136=== RUN TestConvertHashToNix32/already_Nix32_format137=== PAUSE TestEncodeNixBase32/test_string_hash138=== RUN TestEncodeNixBase32/empty_input139=== PAUSE TestEncodeNixBase32/empty_input140--- PASS: TestStaticToken (0.00s)141=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter142=== RUN TestPartSizeForNAR/zero_stays_at_minimum143=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error144=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths145=== RUN TestUploadMultipart_SupersededByPeer/missing1462026/07/09 07:20:06 WARN Rate limiter enabled after throttle name=server-test rate=5147=== RUN TestPathInfoCACompatibility/old_string_format_-_text148=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon1492026/07/09 07:20:06 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45139150=== PAUSE TestParsePathInfoJSON/Lix_format151=== PAUSE TestConvertHashToNix32/already_Nix32_format152=== RUN TestConvertHashToNix32/invalid_format153=== CONT TestEncodeNixBase32/test_string_hash154=== CONT TestEncodeNixBase32/empty_input1552026/07/09 07:20:06 WARN Rate limiter backed off name=server-test rate=5156--- PASS: TestResolveStorePath (0.00s)1572026/07/09 07:20:06 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45139158=== CONT TestRateLimiterFeedback/429_enables_limiter159=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter160=== CONT TestRateLimiterFeedback/503_enables_limiter161=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter162=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum163=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error164=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths165=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths166=== PAUSE TestUploadMultipart_SupersededByPeer/missing167=== RUN TestSetClientTLSErrors/missing_cert_file168=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text169=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive170=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon171=== RUN TestParsePathInfoJSON/empty_input172=== PAUSE TestConvertHashToNix32/invalid_format173--- PASS: TestEncodeNixBase32WithRealHash (0.00s)174=== RUN TestPartSizeForNAR/small_stays_at_minimum175=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error176=== CONT TestUploadMultipart_SupersededByPeer/exists1772026/07/09 07:20:06 WARN Rate limiter enabled after throttle name=server-test rate=5178--- PASS: TestFileTokenEmpty (0.00s)1792026/07/09 07:20:06 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:33855180=== PAUSE TestSetClientTLSErrors/missing_cert_file1812026/07/09 07:20:06 WARN Rate limiter enabled after throttle name=server-test rate=5182=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1832026/07/09 07:20:06 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:33191184=== CONT TestConvertHashToNix32/SRI_format_to_Nix32185=== CONT TestConvertHashToNix32/already_Nix32_format186=== CONT TestConvertHashToNix32/invalid_format187=== PAUSE TestParsePathInfoJSON/empty_input188=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI189=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error1902026/07/09 07:20:06 WARN Rate limiter backed off name=server-test rate=5191=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error1922026/07/09 07:20:06 WARN Rate limiter backed off name=server-test rate=5193=== CONT TestGetStorePathHash/basename_without_hyphen_should_error194=== CONT TestGetStorePathHash/valid_store_path195=== PAUSE TestPartSizeForNAR/small_stays_at_minimum196=== CONT TestUploadMultipart_SupersededByPeer/missing197=== RUN TestSetClientTLS/rejects_connection_without_client_cert198--- PASS: TestScriptTokenScriptFails (0.01s)199=== RUN TestSetClientTLSErrors/missing_key_file200=== RUN TestPathInfoCACompatibility/new_structured_format_-_text201=== RUN TestParsePathInfoJSON/whitespace_only202=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI203=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum204=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert205=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512206--- PASS: TestFileTokenMissing (0.01s)207--- PASS: TestFileTokenReadsAndCaches (0.01s)208--- PASS: TestScriptTokenBadJSON (0.01s)209--- PASS: TestScriptTokenEmptyToken (0.01s)210--- PASS: TestDoServerRequestAttachesToken (0.02s)211=== PAUSE TestSetClientTLSErrors/missing_key_file212=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text213=== RUN TestSetClientTLSErrors/missing_ca_file214=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method215=== PAUSE TestParsePathInfoJSON/whitespace_only216=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum217=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA218=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA219=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512220--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)221=== PAUSE TestSetClientTLSErrors/missing_ca_file222=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method223=== RUN TestParsePathInfoJSON/invalid_JSON224=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive225=== RUN TestSetClientTLS/preserves_debug_logging_transport226=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)227=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512228=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI229--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.02s)230--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)231=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon232=== CONT TestPathInfoCACompatibility/null_ca_field233=== CONT TestPathInfoCACompatibility/new_structured_format_-_text234=== RUN TestSetClientTLSErrors/invalid_ca_file235=== CONT TestPathInfoCACompatibility/old_string_format_-_text236=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method237=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts238=== PAUSE TestParsePathInfoJSON/invalid_JSON239=== PAUSE TestSetClientTLS/preserves_debug_logging_transport240--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)241 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)242 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)243=== CONT TestParsePathInfoJSON/empty_input244=== CONT TestSetClientTLS/rejects_connection_without_client_cert245=== CONT TestParsePathInfoJSON/Nix_format246=== CONT TestParsePathInfoJSON/whitespace_only247=== CONT TestParsePathInfoJSON/invalid_JSON248--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)249--- PASS: TestEncodeNixBase32 (0.01s)250 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)251 --- PASS: TestEncodeNixBase32/empty_input (0.00s)252=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA253=== PAUSE TestSetClientTLSErrors/invalid_ca_file254=== CONT TestSetClientTLS/preserves_debug_logging_transport255=== CONT TestParsePathInfoJSON/Lix_format256=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts257--- PASS: TestGetStorePathHash (0.03s)258 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)259 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)260 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)261 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)262=== CONT TestSetClientTLSErrors/missing_cert_file263=== CONT TestSetClientTLSErrors/invalid_ca_file264=== CONT TestSetClientTLSErrors/missing_ca_file265=== CONT TestSetClientTLSErrors/missing_key_file266=== RUN TestPartSizeForNAR/1_TiB267--- PASS: TestRateLimiterFeedback (0.02s)268 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)269 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)270 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)271 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)272=== PAUSE TestPartSizeForNAR/1_TiB273--- PASS: TestUploadMultipart_SupersededByPeer (0.02s)274 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)275 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)276=== RUN TestPartSizeForNAR/5_TiB_S3_max_object277--- PASS: TestPathInfoCACompatibility (0.03s)278 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)279 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)280 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)281 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)282 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)283=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object284--- PASS: TestConvertHashToNix32 (0.02s)285 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)286 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)287 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)288=== RUN TestPartSizeForNAR/capped_at_5_GiB289--- PASS: TestPathInfoHashCompatibility (0.03s)290 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)291 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)292 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)293 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)294--- PASS: TestParsePathInfoJSON (0.03s)295 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)296 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)297 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)298 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)299 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)300=== PAUSE TestPartSizeForNAR/capped_at_5_GiB301=== CONT TestPartSizeForNAR/zero_stays_at_minimum302=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts303=== CONT TestPartSizeForNAR/5_TiB_S3_max_object304=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum305=== CONT TestPartSizeForNAR/capped_at_5_GiB306=== CONT TestPartSizeForNAR/small_stays_at_minimum307=== CONT TestPartSizeForNAR/1_TiB308--- PASS: TestPartSizeForNAR (0.03s)309 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)310 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)311 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)312 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)313 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)314 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)315 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)316--- PASS: TestSetClientTLSErrors (0.03s)317 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)318 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)319 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)320 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)3212026/07/09 07:20:06 http: TLS handshake error from 127.0.0.1:36642: remote error: tls: bad certificate322--- PASS: TestSetClientTLS (0.03s)323 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.00s)324 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)325 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)326--- PASS: TestDumpPathSingleFile (0.04s)327--- PASS: TestCaseHackSuffix (0.05s)328--- PASS: TestDumpPathWriterError (0.07s)329--- PASS: TestDumpPathMatchesNix (0.11s)330--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)331PASS332Running server tests...333The files belonging to this database system will be owned by user "nixbld".334This user must also own the server process.335336The database cluster will be initialized with locale "C".337The default database encoding has accordingly been set to "SQL_ASCII".338The default text search configuration will be set to "english".339340Data page checksums are disabled.341342creating directory /build/postgres3620625510/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/postgres3620625510/data -l logfile start359360/build/postgres3620625510:5432 - no response3612026-07-09 07:20:08.588 UTC [211] LOG: starting PostgreSQL 17.10 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit3622026-07-09 07:20:08.588 UTC [211] LOG: listening on Unix socket "/build/postgres3620625510/.s.PGSQL.5432"3632026-07-09 07:20:08.592 UTC [215] LOG: database system was shut down at 2026-07-09 07:20:08 UTC3642026-07-09 07:20:08.597 UTC [211] LOG: database system is ready to accept connections365/build/postgres3620625510:5432 - accepting connections366=== RUN TestService_AuthMiddleware367=== PAUSE TestService_AuthMiddleware368=== RUN TestService_AuthMiddleware_MTLSProxyHeader369=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader370=== RUN TestService_AuthMiddleware_MTLSBoundSubjects371=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects372=== RUN TestService_ReadAuthMiddleware373=== PAUSE TestService_ReadAuthMiddleware374=== RUN TestService_AuthMiddleware_OIDC375=== PAUSE TestService_AuthMiddleware_OIDC376=== RUN TestCacheConfigHandler377=== PAUSE TestCacheConfigHandler378=== RUN TestCacheStatsHandler379=== PAUSE TestCacheStatsHandler380=== RUN TestClientCADerivations381=== PAUSE TestClientCADerivations382=== RUN TestClientErrorHandling383=== PAUSE TestClientErrorHandling384=== RUN TestClientIntegration385=== PAUSE TestClientIntegration386=== RUN TestClientMultipleUploads387=== PAUSE TestClientMultipleUploads388=== RUN TestClientWithDependencies389=== PAUSE TestClientWithDependencies390=== RUN TestPinProtectsFromGC391=== PAUSE TestPinProtectsFromGC392=== RUN TestGCAdvisoryLockBlocksConcurrentRun393{"timestamp":"2026-07-09T07:20:08.799255661Z","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(382)"}394395thread 'rustfs-worker' (418) panicked at /build/rustfs-1.0.0-beta.7-vendor/source-registry-0/reqwest-0.13.4/src/async_impl/client.rs:2507:38:396Client::new(): reqwest::Error { kind: Builder, source: General("No CA certificates were loaded from the system") }397note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace3982026-07-09 07:20:08.884 UTC [626] ERROR: relation "goose_db_version" does not exist at character 363992026-07-09 07:20:08.884 UTC [626] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4002026/07/09 07:20:08 OK 20241026095416_initial_model.sql (12.36ms)4012026/07/09 07:20:08 OK 20251210153512_drop_unused_gin_index.sql (2.96ms)4022026/07/09 07:20:08 OK 20251218171726_add_pins.sql (3.42ms)4032026/07/09 07:20:08 OK 20260628120000_add_object_size_and_stats.sql (3.11ms)4042026/07/09 07:20:08 goose: successfully migrated database to version: 202606281200004052026/07/09 07:20:08 OK 1_commit_pending_closure.sql (2.13ms)4062026/07/09 07:20:08 OK 2_object_stats_trigger.sql (925.53µs)4072026/07/09 07:20:08 goose: up to current file version: 2408--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.14s)409=== RUN TestGCBugBareHashReferences410=== PAUSE TestGCBugBareHashReferences411=== RUN TestGCMetrics412=== PAUSE TestGCMetrics413=== RUN TestGCTaskStore_StartNew414=== PAUSE TestGCTaskStore_StartNew415=== RUN TestGCTaskStore_DeduplicateSameParams416=== PAUSE TestGCTaskStore_DeduplicateSameParams417=== RUN TestGCTaskStore_ConflictDifferentParams418=== PAUSE TestGCTaskStore_ConflictDifferentParams419=== RUN TestGCTaskStore_GetEmpty420=== PAUSE TestGCTaskStore_GetEmpty421=== RUN TestGCTaskStore_GetReturnsLatest422=== PAUSE TestGCTaskStore_GetReturnsLatest423=== RUN TestGCTaskStore_CompletedAllowsNewTask424=== PAUSE TestGCTaskStore_CompletedAllowsNewTask425=== RUN TestGCTaskStore_PhaseUpdates426=== PAUSE TestGCTaskStore_PhaseUpdates427=== RUN TestGCTaskStore_Fail428=== PAUSE TestGCTaskStore_Fail429=== RUN TestGracefulShutdownDrainsInflight430=== PAUSE TestGracefulShutdownDrainsInflight431=== RUN TestService_healthCheckHandler432=== PAUSE TestService_healthCheckHandler433=== RUN TestGenerateLandingPage434=== PAUSE TestGenerateLandingPage435=== RUN TestNARDeduplicationMetadataUploadBug436=== PAUSE TestNARDeduplicationMetadataUploadBug437=== RUN TestMetricsInventory438=== PAUSE TestMetricsInventory439=== RUN TestService_NativeMTLS440=== PAUSE TestService_NativeMTLS441=== RUN TestServerTLSConfig442=== PAUSE TestServerTLSConfig443=== RUN TestMultipartCleanup444=== PAUSE TestMultipartCleanup445=== RUN TestObjectStatsTrigger446=== PAUSE TestObjectStatsTrigger447=== RUN TestOrphanedObjectsGC448=== PAUSE TestOrphanedObjectsGC449=== RUN TestOrphanedObjectsGCStressTest450=== PAUSE TestOrphanedObjectsGCStressTest451=== RUN TestResurrectedObjectNotDeleted452=== PAUSE TestResurrectedObjectNotDeleted453=== RUN TestParseSingleRange454=== PAUSE TestParseSingleRange455=== RUN TestIsValidCachePath456=== PAUSE TestIsValidCachePath457=== RUN TestReadProxyNarinfo458=== PAUSE TestReadProxyNarinfo459=== RUN TestReadProxyNarinfoAlreadyDecompressed460=== PAUSE TestReadProxyNarinfoAlreadyDecompressed461=== RUN TestReadProxyNarStreaming462=== PAUSE TestReadProxyNarStreaming463=== RUN TestReadProxy404464=== PAUSE TestReadProxy404465=== RUN TestReadProxyInvalidPath466=== PAUSE TestReadProxyInvalidPath467=== RUN TestReadProxyHead468=== PAUSE TestReadProxyHead469=== RUN TestReadProxyConditionalGet470=== PAUSE TestReadProxyConditionalGet471=== RUN TestReadProxyRootRedirectsToIndexHTML472=== PAUSE TestReadProxyRootRedirectsToIndexHTML473=== RUN TestReadProxyDisabled474=== PAUSE TestReadProxyDisabled475=== RUN TestReadProxyRangeRequest476=== PAUSE TestReadProxyRangeRequest477=== RUN TestRedundantMultipartUpload478=== PAUSE TestRedundantMultipartUpload479=== RUN TestCompleteMultipartUpload_ErrorButObjectExists480=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists481=== RUN TestService_Rustfstest482=== PAUSE TestService_Rustfstest483=== RUN TestSystemdListenerNotActivated484--- PASS: TestSystemdListenerNotActivated (0.00s)485=== RUN TestWatchdogBeatsWhenHealthy486--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)487=== RUN TestWatchdogSkipsWhenUnhealthy4882026/07/09 07:20:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4892026/07/09 07:20:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4902026/07/09 07:20:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4912026/07/09 07:20:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4922026/07/09 07:20:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4932026/07/09 07:20:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4942026/07/09 07:20:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4952026/07/09 07:20:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4962026/07/09 07:20:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4972026/07/09 07:20:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"498--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)499=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle500=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle501=== RUN TestProxyWriteTimeout502=== PAUSE TestProxyWriteTimeout503=== RUN TestIsValidUploadKey504=== PAUSE TestIsValidUploadKey505=== RUN TestUploadHandlersRejectInvalidKeys506=== PAUSE TestUploadHandlersRejectInvalidKeys507=== RUN TestUploadHandlersRejectOversizedBody508=== PAUSE TestUploadHandlersRejectOversizedBody509=== RUN TestService_cleanupPendingClosuresHandler510=== PAUSE TestService_cleanupPendingClosuresHandler511=== RUN TestService_createPendingClosureHandler512=== PAUSE TestService_createPendingClosureHandler513=== RUN TestService_verifyS3Integrity514=== PAUSE TestService_verifyS3Integrity515=== RUN TestCompleteMultipartUnregistered516=== PAUSE TestCompleteMultipartUnregistered517=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT518=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT519=== CONT TestUploadHandlersRejectInvalidKeys520=== CONT TestReadProxyNarinfoAlreadyDecompressed521=== CONT TestService_verifyS3Integrity522=== CONT TestService_createPendingClosureHandler523=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT524=== CONT TestService_AuthMiddleware525=== CONT TestCompleteMultipartUnregistered526=== CONT TestIsValidUploadKey527=== CONT TestProxyWriteTimeout528=== RUN TestProxyWriteTimeout/narinfo529=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle530=== CONT TestService_Rustfstest531=== CONT TestGenerateLandingPage532=== CONT TestService_healthCheckHandler533=== CONT TestCompleteMultipartUpload_ErrorButObjectExists534=== CONT TestGracefulShutdownDrainsInflight535=== CONT TestIsValidCachePath536=== CONT TestGCTaskStore_Fail537=== CONT TestParseSingleRange538=== CONT TestGCTaskStore_PhaseUpdates539=== CONT TestResurrectedObjectNotDeleted540=== CONT TestGCTaskStore_CompletedAllowsNewTask541=== CONT TestOrphanedObjectsGCStressTest542=== CONT TestGCTaskStore_GetReturnsLatest543=== CONT TestOrphanedObjectsGC544=== CONT TestGCTaskStore_GetEmpty545=== CONT TestObjectStatsTrigger546=== CONT TestGCTaskStore_ConflictDifferentParams547=== CONT TestMultipartCleanup548=== CONT TestReadProxyNarinfo549=== CONT TestGCTaskStore_DeduplicateSameParams550=== CONT TestServerTLSConfig551=== CONT TestGCTaskStore_StartNew552=== CONT TestService_NativeMTLS553=== CONT TestGCMetrics554=== CONT TestMetricsInventory555=== CONT TestRedundantMultipartUpload556=== CONT TestGCBugBareHashReferences557=== CONT TestNARDeduplicationMetadataUploadBug558=== CONT TestReadProxyRangeRequest559=== CONT TestPinProtectsFromGC560=== CONT TestReadProxyDisabled561=== CONT TestCacheStatsHandler562=== CONT TestCacheConfigHandler563=== CONT TestReadProxyRootRedirectsToIndexHTML564=== CONT TestClientWithDependencies565=== RUN TestServerTLSConfig/no_client_CA566=== PAUSE TestServerTLSConfig/no_client_CA567=== RUN TestServerTLSConfig/missing_CA_file568=== PAUSE TestServerTLSConfig/missing_CA_file569=== CONT TestReadProxyConditionalGet570=== CONT TestClientMultipleUploads571=== CONT TestService_ReadAuthMiddleware572=== CONT TestReadProxyHead573=== CONT TestClientIntegration574=== CONT TestService_AuthMiddleware_MTLSBoundSubjects575=== CONT TestReadProxyInvalidPath576=== CONT TestClientErrorHandling577=== CONT TestReadProxy404578=== CONT TestService_AuthMiddleware_MTLSProxyHeader579=== CONT TestClientCADerivations580=== CONT TestReadProxyNarStreaming581=== CONT TestService_cleanupPendingClosuresHandler582=== CONT TestUploadHandlersRejectOversizedBody583=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info584=== RUN TestIsValidUploadKey/narinfo585=== PAUSE TestProxyWriteTimeout/narinfo586=== RUN TestIsValidCachePath/narinfo587=== PAUSE TestIsValidCachePath/narinfo588=== RUN TestCacheConfigHandler/full_config,_no_issuer589=== PAUSE TestCacheConfigHandler/full_config,_no_issuer590=== RUN TestCacheConfigHandler/no_cache_url_configured591=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars592=== RUN TestClientErrorHandling/InvalidStorePath593=== CONT TestService_AuthMiddleware_OIDC594--- PASS: TestGCTaskStore_Fail (0.00s)5952026/07/09 07:20:09 INFO Starting HTTP server address=127.0.0.1:33633596=== RUN TestParseSingleRange/none597=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars598=== RUN TestServerTLSConfig/not_a_PEM_file599=== PAUSE TestCacheConfigHandler/no_cache_url_configured600=== PAUSE TestIsValidUploadKey/narinfo601=== RUN TestProxyWriteTimeout/1_GiB_nar602=== RUN TestIsValidUploadKey/nar_zst603=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info604=== PAUSE TestClientErrorHandling/InvalidStorePath605--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)606=== PAUSE TestParseSingleRange/none607--- PASS: TestGCTaskStore_GetEmpty (0.00s)608--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)609--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)610--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)611--- PASS: TestGCTaskStore_StartNew (0.00s)612--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)613=== PAUSE TestServerTLSConfig/not_a_PEM_file614=== RUN TestIsValidCachePath/nar_zst615=== RUN TestCacheConfigHandler/no_signing_keys616=== PAUSE TestProxyWriteTimeout/1_GiB_nar6172026/07/09 07:20:09 INFO Shutdown signal received, draining in-flight requests timeout=10s618=== PAUSE TestIsValidUploadKey/nar_zst619=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal620=== RUN TestParseSingleRange/unknown_unit621=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal622=== RUN TestIsValidUploadKey/nar_xz623=== PAUSE TestIsValidUploadKey/nar_xz624=== RUN TestClientErrorHandling/InvalidAuthToken625=== PAUSE TestParseSingleRange/unknown_unit626=== CONT TestServerTLSConfig/no_client_CA627=== CONT TestServerTLSConfig/missing_CA_file628=== CONT TestServerTLSConfig/not_a_PEM_file629=== PAUSE TestIsValidCachePath/nar_zst630=== RUN TestIsValidCachePath/nar_xz631=== PAUSE TestCacheConfigHandler/no_signing_keys632=== RUN TestProxyWriteTimeout/10_GiB_nar633=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key634=== RUN TestIsValidUploadKey/nar_plain635=== PAUSE TestIsValidUploadKey/nar_plain636=== RUN TestIsValidUploadKey/listing637=== PAUSE TestClientErrorHandling/InvalidAuthToken638=== RUN TestParseSingleRange/multi-range_ignored639=== PAUSE TestParseSingleRange/multi-range_ignored640=== PAUSE TestIsValidCachePath/nar_xz641=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator642=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator643=== PAUSE TestProxyWriteTimeout/10_GiB_nar644=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key645=== PAUSE TestIsValidUploadKey/listing646=== RUN TestClientErrorHandling/ServerNotAvailable647=== RUN TestParseSingleRange/malformed_no_dash648=== RUN TestIsValidCachePath/nar_bz2649=== PAUSE TestParseSingleRange/malformed_no_dash650=== CONT TestCacheConfigHandler/full_config,_no_issuer651=== RUN TestParseSingleRange/malformed_both_empty652=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator653=== CONT TestCacheConfigHandler/no_signing_keys654=== CONT TestCacheConfigHandler/no_cache_url_configured655--- PASS: TestServerTLSConfig (0.01s)656 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)657 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)658 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)659=== RUN TestProxyWriteTimeout/unknown_size660=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key661=== RUN TestIsValidUploadKey/build_log662=== PAUSE TestIsValidUploadKey/build_log663=== RUN TestIsValidUploadKey/build_log_home-manager_file664=== PAUSE TestIsValidUploadKey/build_log_home-manager_file665--- PASS: TestCacheConfigHandler (0.01s)666 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)667 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)668 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)669 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)670=== RUN TestIsValidUploadKey/build_log_plus_in_name671=== PAUSE TestProxyWriteTimeout/unknown_size672=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key673=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info674=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key675=== PAUSE TestIsValidUploadKey/build_log_plus_in_name676=== RUN TestIsValidUploadKey/build_log_question_mark677=== PAUSE TestIsValidUploadKey/build_log_question_mark678=== RUN TestIsValidUploadKey/build_log_equals679=== PAUSE TestIsValidUploadKey/build_log_equals680=== RUN TestIsValidUploadKey/realisation681=== CONT TestProxyWriteTimeout/narinfo682=== CONT TestProxyWriteTimeout/unknown_size683=== CONT TestProxyWriteTimeout/10_GiB_nar684=== CONT TestProxyWriteTimeout/1_GiB_nar685--- PASS: TestProxyWriteTimeout (0.01s)686 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)687 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)688 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)689 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)690=== PAUSE TestClientErrorHandling/ServerNotAvailable691=== CONT TestClientErrorHandling/InvalidStorePath6922026/07/09 07:20:09 INFO Received uploads request method=POST path=/693=== CONT TestClientErrorHandling/ServerNotAvailable6942026/07/09 07:20:09 INFO Received request for more parts method=POST path=/695=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key696=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal6972026/07/09 07:20:09 INFO Received uploads request method=POST path=/698=== CONT TestClientErrorHandling/InvalidAuthToken6992026/07/09 07:20:09 INFO Received complete multipart upload request method=POST path=/700--- PASS: TestGenerateLandingPage (0.01s)701--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)702 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)703 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)704 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)705 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)706=== PAUSE TestIsValidCachePath/nar_bz2707=== RUN TestIsValidCachePath/nar_uncompressed708=== PAUSE TestIsValidCachePath/nar_uncompressed709=== PAUSE TestParseSingleRange/malformed_both_empty710=== RUN TestIsValidCachePath/ls711=== PAUSE TestIsValidCachePath/ls712=== PAUSE TestIsValidUploadKey/realisation713=== RUN TestIsValidCachePath/log714=== RUN TestParseSingleRange/malformed_end_before_start715=== PAUSE TestParseSingleRange/malformed_end_before_start716=== RUN TestParseSingleRange/closed717=== RUN TestIsValidUploadKey/realisation_plus_in_output718=== PAUSE TestIsValidCachePath/log719=== RUN TestIsValidCachePath/realisation720=== PAUSE TestParseSingleRange/closed721=== PAUSE TestIsValidUploadKey/realisation_plus_in_output722=== RUN TestParseSingleRange/open-ended723=== PAUSE TestParseSingleRange/open-ended724=== RUN TestIsValidUploadKey/nix-cache-info725=== PAUSE TestIsValidUploadKey/nix-cache-info726=== RUN TestIsValidUploadKey/index.html727=== PAUSE TestIsValidUploadKey/index.html728=== PAUSE TestIsValidCachePath/realisation729=== RUN TestIsValidCachePath/nix-cache-info730=== RUN TestParseSingleRange/end_clamped_to_size731=== RUN TestIsValidUploadKey/narinfo_key,_nar_type732=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type733=== RUN TestIsValidUploadKey/nar_key,_narinfo_type734=== PAUSE TestIsValidCachePath/nix-cache-info735=== PAUSE TestParseSingleRange/end_clamped_to_size736=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type737=== RUN TestIsValidCachePath/index.html738=== RUN TestParseSingleRange/suffix739=== PAUSE TestParseSingleRange/suffix740=== RUN TestIsValidUploadKey/listing_key,_narinfo_type741=== PAUSE TestIsValidCachePath/index.html742=== RUN TestParseSingleRange/suffix_exceeds_size743=== PAUSE TestParseSingleRange/suffix_exceeds_size744=== RUN TestParseSingleRange/single_byte745=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type746=== RUN TestIsValidCachePath/traversal_parent7472026/07/09 07:20:09 INFO OIDC provider initialized name=test748=== PAUSE TestIsValidCachePath/traversal_parent749=== RUN TestIsValidCachePath/traversal_in_middle750=== PAUSE TestParseSingleRange/single_byte751=== RUN TestParseSingleRange/start_past_EOF752=== PAUSE TestParseSingleRange/start_past_EOF753=== RUN TestParseSingleRange/start_far_past_EOF754=== RUN TestIsValidUploadKey/traversal755=== PAUSE TestParseSingleRange/start_far_past_EOF756=== PAUSE TestIsValidUploadKey/traversal757=== CONT TestParseSingleRange/end_clamped_to_size758=== CONT TestParseSingleRange/multi-range_ignored759=== CONT TestParseSingleRange/start_far_past_EOF760=== CONT TestParseSingleRange/none761=== CONT TestParseSingleRange/closed762=== CONT TestParseSingleRange/suffix_exceeds_size763=== CONT TestParseSingleRange/malformed_end_before_start764=== CONT TestParseSingleRange/open-ended765=== CONT TestParseSingleRange/start_past_EOF766=== CONT TestParseSingleRange/malformed_both_empty767=== CONT TestParseSingleRange/suffix768=== CONT TestParseSingleRange/single_byte769=== CONT TestParseSingleRange/malformed_no_dash770=== CONT TestParseSingleRange/unknown_unit771--- PASS: TestParseSingleRange (0.08s)772 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)773 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)774 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)775 --- PASS: TestParseSingleRange/none (0.00s)776 --- PASS: TestParseSingleRange/closed (0.00s)777 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)778 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)779 --- PASS: TestParseSingleRange/open-ended (0.00s)780 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)781 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)782 --- PASS: TestParseSingleRange/suffix (0.00s)783 --- PASS: TestParseSingleRange/single_byte (0.00s)784 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)785 --- PASS: TestParseSingleRange/unknown_unit (0.00s)786=== PAUSE TestIsValidCachePath/traversal_in_middle787=== RUN TestIsValidUploadKey/traversal_nar788=== PAUSE TestIsValidUploadKey/traversal_nar789=== RUN TestIsValidUploadKey/absolute790=== PAUSE TestIsValidUploadKey/absolute791=== RUN TestIsValidCachePath/invalid_char_e792=== RUN TestIsValidUploadKey/empty_key793=== PAUSE TestIsValidCachePath/invalid_char_e794=== PAUSE TestIsValidUploadKey/empty_key795=== RUN TestIsValidUploadKey/unknown_type796=== RUN TestIsValidCachePath/invalid_char_u797=== PAUSE TestIsValidUploadKey/unknown_type798=== CONT TestIsValidUploadKey/traversal799=== CONT TestIsValidUploadKey/listing800=== CONT TestIsValidUploadKey/narinfo801=== CONT TestIsValidUploadKey/traversal_nar802=== CONT TestIsValidUploadKey/listing_key,_narinfo_type803=== CONT TestIsValidUploadKey/nar_key,_narinfo_type804=== CONT TestIsValidUploadKey/narinfo_key,_nar_type805=== CONT TestIsValidUploadKey/index.html806=== CONT TestIsValidUploadKey/nix-cache-info807=== CONT TestIsValidUploadKey/realisation_plus_in_output808=== CONT TestIsValidUploadKey/realisation809=== CONT TestIsValidUploadKey/build_log_equals810=== CONT TestIsValidUploadKey/build_log_question_mark811=== CONT TestIsValidUploadKey/build_log_plus_in_name812=== CONT TestIsValidUploadKey/build_log_home-manager_file813=== CONT TestIsValidUploadKey/build_log814=== CONT TestIsValidUploadKey/nar_xz815=== CONT TestIsValidUploadKey/nar_plain816=== CONT TestIsValidUploadKey/empty_key817=== PAUSE TestIsValidCachePath/invalid_char_u818=== CONT TestIsValidUploadKey/unknown_type819=== CONT TestIsValidUploadKey/absolute820=== CONT TestIsValidUploadKey/nar_zst821--- PASS: TestIsValidUploadKey (0.08s)822 --- PASS: TestIsValidUploadKey/traversal (0.00s)823 --- PASS: TestIsValidUploadKey/listing (0.00s)824 --- PASS: TestIsValidUploadKey/narinfo (0.00s)825 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)826 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)827 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)828 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)829 --- PASS: TestIsValidUploadKey/index.html (0.00s)830 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)831 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)832 --- PASS: TestIsValidUploadKey/realisation (0.00s)833 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)834 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)835 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)836 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)837 --- PASS: TestIsValidUploadKey/build_log (0.00s)838 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)839 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)840 --- PASS: TestIsValidUploadKey/empty_key (0.00s)841 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)842 --- PASS: TestIsValidUploadKey/absolute (0.00s)843 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)844=== RUN TestIsValidCachePath/random_path845=== PAUSE TestIsValidCachePath/random_path846=== RUN TestIsValidCachePath/empty847=== PAUSE TestIsValidCachePath/empty848=== RUN TestIsValidCachePath/leading_slash849=== PAUSE TestIsValidCachePath/leading_slash850=== RUN TestIsValidCachePath/wrong_extension851=== PAUSE TestIsValidCachePath/wrong_extension852--- PASS: TestGracefulShutdownDrainsInflight (0.08s)853=== RUN TestIsValidCachePath/short_hash854=== PAUSE TestIsValidCachePath/short_hash855=== CONT TestIsValidCachePath/narinfo856=== CONT TestIsValidCachePath/realisation857=== CONT TestIsValidCachePath/ls858=== CONT TestIsValidCachePath/wrong_extension859=== CONT TestIsValidCachePath/traversal_parent860=== CONT TestIsValidCachePath/short_hash861=== CONT TestIsValidCachePath/empty862=== CONT TestIsValidCachePath/traversal_in_middle863=== CONT TestIsValidCachePath/invalid_char_u864=== CONT TestIsValidCachePath/invalid_char_e865=== CONT TestIsValidCachePath/nar_bz2866=== CONT TestIsValidCachePath/index.html867=== CONT TestIsValidCachePath/log868=== CONT TestIsValidCachePath/nar_xz869=== CONT TestIsValidCachePath/nix-cache-info870=== CONT TestIsValidCachePath/random_path871=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars872=== CONT TestIsValidCachePath/nar_uncompressed873=== CONT TestIsValidCachePath/nar_zst874=== CONT TestIsValidCachePath/leading_slash875--- PASS: TestIsValidCachePath (0.08s)876 --- PASS: TestIsValidCachePath/narinfo (0.00s)877 --- PASS: TestIsValidCachePath/realisation (0.00s)878 --- PASS: TestIsValidCachePath/ls (0.00s)879 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)880 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)881 --- PASS: TestIsValidCachePath/short_hash (0.00s)882 --- PASS: TestIsValidCachePath/empty (0.00s)883 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)884 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)885 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)886 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)887 --- PASS: TestIsValidCachePath/index.html (0.00s)888 --- PASS: TestIsValidCachePath/log (0.00s)889 --- PASS: TestIsValidCachePath/nar_xz (0.00s)890 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)891 --- PASS: TestIsValidCachePath/random_path (0.00s)892 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)893 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)894 --- PASS: TestIsValidCachePath/nar_zst (0.00s)895 --- PASS: TestIsValidCachePath/leading_slash (0.00s)8962026-07-09 07:20:09.318 UTC [769] ERROR: relation "goose_db_version" does not exist at character 368972026-07-09 07:20:09.318 UTC [769] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8982026-07-09 07:20:09.320 UTC [770] ERROR: relation "goose_db_version" does not exist at character 368992026-07-09 07:20:09.320 UTC [770] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9002026-07-09 07:20:09.320 UTC [768] ERROR: relation "goose_db_version" does not exist at character 369012026-07-09 07:20:09.320 UTC [768] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC902=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure903=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure904=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart905=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart906=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts907=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts908=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure909=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts910=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart9112026/07/09 07:20:09 INFO Received uploads request method=POST path=/9122026/07/09 07:20:09 INFO Received request for more parts method=POST path=/9132026/07/09 07:20:09 INFO Received complete multipart upload request method=POST path=/9142026-07-09 07:20:09.355 UTC [791] ERROR: relation "goose_db_version" does not exist at character 369152026-07-09 07:20:09.355 UTC [791] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9162026-07-09 07:20:09.356 UTC [771] ERROR: relation "goose_db_version" does not exist at character 369172026-07-09 07:20:09.356 UTC [771] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9182026-07-09 07:20:09.356 UTC [773] ERROR: relation "goose_db_version" does not exist at character 369192026-07-09 07:20:09.356 UTC [773] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9202026/07/09 07:20:09 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_closures9212026-07-09 07:20:09.365 UTC [811] ERROR: relation "goose_db_version" does not exist at character 369222026-07-09 07:20:09.365 UTC [811] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9232026-07-09 07:20:09.366 UTC [810] ERROR: relation "goose_db_version" does not exist at character 369242026-07-09 07:20:09.366 UTC [810] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9252026-07-09 07:20:09.387 UTC [832] ERROR: relation "goose_db_version" does not exist at character 369262026-07-09 07:20:09.387 UTC [832] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9272026-07-09 07:20:09.387 UTC [833] ERROR: relation "goose_db_version" does not exist at character 369282026-07-09 07:20:09.387 UTC [833] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9292026-07-09 07:20:09.396 UTC [834] ERROR: relation "goose_db_version" does not exist at character 369302026-07-09 07:20:09.396 UTC [834] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9312026/07/09 07:20:09 OK 20241026095416_initial_model.sql (71.59ms)9322026/07/09 07:20:09 OK 20241026095416_initial_model.sql (65.95ms)9332026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (5.69ms)9342026/07/09 07:20:09 OK 20241026095416_initial_model.sql (67.93ms)9352026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (5.91ms)9362026-07-09 07:20:09.431 UTC [835] ERROR: relation "goose_db_version" does not exist at character 369372026-07-09 07:20:09.431 UTC [835] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9382026-07-09 07:20:09.435 UTC [836] ERROR: relation "goose_db_version" does not exist at character 369392026-07-09 07:20:09.435 UTC [836] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9402026-07-09 07:20:09.435 UTC [837] ERROR: relation "goose_db_version" does not exist at character 369412026-07-09 07:20:09.435 UTC [837] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9422026-07-09 07:20:09.437 UTC [838] ERROR: relation "goose_db_version" does not exist at character 369432026-07-09 07:20:09.437 UTC [838] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9442026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (11.09ms)9452026-07-09 07:20:09.440 UTC [839] ERROR: relation "goose_db_version" does not exist at character 369462026-07-09 07:20:09.440 UTC [839] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9472026/07/09 07:20:09 OK 20241026095416_initial_model.sql (48.51ms)9482026/07/09 07:20:09 OK 20241026095416_initial_model.sql (31.84ms)9492026/07/09 07:20:09 OK 20251218171726_add_pins.sql (22.32ms)9502026/07/09 07:20:09 OK 20251218171726_add_pins.sql (31.82ms)9512026/07/09 07:20:09 OK 20251218171726_add_pins.sql (22.98ms)9522026/07/09 07:20:09 OK 20241026095416_initial_model.sql (62.46ms)9532026/07/09 07:20:09 OK 20241026095416_initial_model.sql (61.05ms)9542026/07/09 07:20:09 OK 20241026095416_initial_model.sql (59.13ms)9552026/07/09 07:20:09 OK 20241026095416_initial_model.sql (42.45ms)9562026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (17.24ms)9572026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (19.59ms)9582026/07/09 07:20:09 OK 20241026095416_initial_model.sql (61.47ms)9592026/07/09 07:20:09 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.649792ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures9602026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (18.89ms)9612026/07/09 07:20:09 goose: successfully migrated database to version: 202606281200009622026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (5.18ms)9632026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (5.15ms)9642026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (5.11ms)9652026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (4.87ms)9662026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (5ms)9672026/07/09 07:20:09 OK 20241026095416_initial_model.sql (48.88ms)9682026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (9.66ms)9692026/07/09 07:20:09 goose: successfully migrated database to version: 202606281200009702026/07/09 07:20:09 OK 1_commit_pending_closure.sql (6.45ms)9712026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (12.35ms)9722026/07/09 07:20:09 goose: successfully migrated database to version: 202606281200009732026/07/09 07:20:09 OK 20251218171726_add_pins.sql (12.83ms)9742026/07/09 07:20:09 OK 20251218171726_add_pins.sql (12.77ms)9752026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (6.19ms)9762026/07/09 07:20:09 OK 1_commit_pending_closure.sql (5.3ms)9772026/07/09 07:20:09 OK 2_object_stats_trigger.sql (7.05ms)9782026/07/09 07:20:09 OK 1_commit_pending_closure.sql (7.16ms)9792026/07/09 07:20:09 goose: up to current file version: 29802026-07-09 07:20:09.484 UTC [840] ERROR: relation "goose_db_version" does not exist at character 369812026-07-09 07:20:09.484 UTC [840] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC982{"timestamp":"2026-07-09T07:20:09.487253607Z","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(296)"}9832026-07-09 07:20:09.487 UTC [842] ERROR: relation "goose_db_version" does not exist at character 369842026-07-09 07:20:09.487 UTC [842] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9852026-07-09 07:20:09.488 UTC [841] ERROR: relation "goose_db_version" does not exist at character 369862026-07-09 07:20:09.488 UTC [841] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9872026-07-09 07:20:09.490 UTC [844] ERROR: relation "goose_db_version" does not exist at character 369882026-07-09 07:20:09.490 UTC [844] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9892026-07-09 07:20:09.492 UTC [843] ERROR: relation "goose_db_version" does not exist at character 369902026-07-09 07:20:09.492 UTC [843] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC991--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.33s)9922026/07/09 07:20:09 OK 2_object_stats_trigger.sql (15.55ms)9932026/07/09 07:20:09 goose: up to current file version: 29942026/07/09 07:20:09 OK 2_object_stats_trigger.sql (15.56ms)9952026/07/09 07:20:09 goose: up to current file version: 29962026/07/09 07:20:09 OK 20251218171726_add_pins.sql (27.36ms)9972026/07/09 07:20:09 OK 20251218171726_add_pins.sql (26.1ms)9982026/07/09 07:20:09 OK 20251218171726_add_pins.sql (29.55ms)9992026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures10002026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures10012026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures10022026/07/09 07:20:09 OK 20251218171726_add_pins.sql (29.86ms)1003--- PASS: TestService_healthCheckHandler (0.34s)10042026/07/09 07:20:09 OK 20251218171726_add_pins.sql (29.51ms)10052026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (25.7ms)10062026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000010072026/07/09 07:20:09 OK 20251218171726_add_pins.sql (26.83ms)10082026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (27.27ms)10092026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000010102026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (10.56ms)10112026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000010122026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (12.24ms)10132026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000010142026/07/09 07:20:09 OK 1_commit_pending_closure.sql (5.63ms)10152026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (9.64ms)10162026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000010172026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (11.39ms)10182026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000010192026/07/09 07:20:09 OK 1_commit_pending_closure.sql (6.2ms)10202026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (11.66ms)10212026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000010222026/07/09 07:20:09 OK 20241026095416_initial_model.sql (46.34ms)10232026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (8.11ms)10242026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000010252026/07/09 07:20:09 OK 20241026095416_initial_model.sql (47.54ms)10262026/07/09 07:20:09 OK 20241026095416_initial_model.sql (47.46ms)10272026/07/09 07:20:09 OK 2_object_stats_trigger.sql (4.88ms)10282026/07/09 07:20:09 goose: up to current file version: 210292026/07/09 07:20:09 OK 20241026095416_initial_model.sql (49.96ms)10302026/07/09 07:20:09 OK 1_commit_pending_closure.sql (8.09ms)10312026/07/09 07:20:09 OK 1_commit_pending_closure.sql (4.85ms)10322026/07/09 07:20:09 OK 1_commit_pending_closure.sql (5.78ms)10332026/07/09 07:20:09 OK 2_object_stats_trigger.sql (14.19ms)10342026/07/09 07:20:09 goose: up to current file version: 210352026/07/09 07:20:09 OK 1_commit_pending_closure.sql (15.87ms)10362026/07/09 07:20:09 OK 1_commit_pending_closure.sql (41.18ms)10372026/07/09 07:20:09 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1038--- PASS: TestService_AuthMiddleware (0.40s)10392026/07/09 07:20:09 OK 20241026095416_initial_model.sql (104.17ms)10402026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (10.78ms)10412026/07/09 07:20:09 OK 2_object_stats_trigger.sql (11.94ms)10422026/07/09 07:20:09 goose: up to current file version: 210432026/07/09 07:20:09 OK 2_object_stats_trigger.sql (11.9ms)10442026/07/09 07:20:09 goose: up to current file version: 210452026/07/09 07:20:09 OK 2_object_stats_trigger.sql (11.83ms)10462026/07/09 07:20:09 goose: up to current file version: 210472026/07/09 07:20:09 OK 2_object_stats_trigger.sql (12.14ms)10482026/07/09 07:20:09 goose: up to current file version: 210492026/07/09 07:20:09 OK 2_object_stats_trigger.sql (12.16ms)10502026/07/09 07:20:09 goose: up to current file version: 210512026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures10522026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures10532026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures10542026/07/09 07:20:09 INFO Created nix-cache-info in bucket bucket=bucket1010552026/07/09 07:20:09 OK 1_commit_pending_closure.sql (24.02ms)10562026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (24.36ms)10572026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (15.29ms)10582026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (24.13ms)10592026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (24.25ms)10602026/07/09 07:20:09 OK 20251218171726_add_pins.sql (15.84ms)10612026/07/09 07:20:09 OK 2_object_stats_trigger.sql (7.89ms)10622026/07/09 07:20:09 goose: up to current file version: 210632026/07/09 07:20:09 OK 20241026095416_initial_model.sql (84.96ms)10642026/07/09 07:20:09 OK 20251218171726_add_pins.sql (12.34ms)10652026/07/09 07:20:09 OK 20251218171726_add_pins.sql (12.33ms)10662026/07/09 07:20:09 OK 20251218171726_add_pins.sql (12.16ms)10672026/07/09 07:20:09 OK 20241026095416_initial_model.sql (87ms)10682026/07/09 07:20:09 OK 20241026095416_initial_model.sql (86.32ms)10692026/07/09 07:20:09 OK 20241026095416_initial_model.sql (87.42ms)10702026/07/09 07:20:09 OK 20241026095416_initial_model.sql (87.54ms)10712026/07/09 07:20:09 OK 20251218171726_add_pins.sql (12.39ms)10722026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures10732026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (11.98ms)10742026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000010752026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (4.86ms)10762026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (6.04ms)10772026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (5.92ms)10782026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (7.63ms)10792026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (7.81ms)10802026/07/09 07:20:09 OK 1_commit_pending_closure.sql (7.14ms)10812026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (9.39ms)10822026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000010832026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (9.4ms)10842026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000010852026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (9.49ms)10862026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000010872026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (8.68ms)10882026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000010892026/07/09 07:20:09 OK 20251218171726_add_pins.sql (6.93ms)1090--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.44s)10912026/07/09 07:20:09 OK 2_object_stats_trigger.sql (3.18ms)10922026/07/09 07:20:09 goose: up to current file version: 210932026/07/09 07:20:09 OK 20251218171726_add_pins.sql (7.13ms)10942026/07/09 07:20:09 OK 20251218171726_add_pins.sql (7.33ms)10952026/07/09 07:20:09 OK 1_commit_pending_closure.sql (3.71ms)10962026/07/09 07:20:09 OK 1_commit_pending_closure.sql (5.19ms)10972026/07/09 07:20:09 OK 1_commit_pending_closure.sql (5.85ms)10982026/07/09 07:20:09 OK 20251218171726_add_pins.sql (6.34ms)10992026/07/09 07:20:09 OK 1_commit_pending_closure.sql (6.19ms)11002026-07-09 07:20:09.613 UTC [853] ERROR: relation "goose_db_version" does not exist at character 3611012026-07-09 07:20:09.613 UTC [853] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11022026-07-09 07:20:09.613 UTC [852] ERROR: relation "goose_db_version" does not exist at character 3611032026-07-09 07:20:09.613 UTC [852] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11042026-07-09 07:20:09.613 UTC [851] ERROR: relation "goose_db_version" does not exist at character 3611052026-07-09 07:20:09.613 UTC [851] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11062026/07/09 07:20:09 OK 2_object_stats_trigger.sql (3.71ms)11072026/07/09 07:20:09 goose: up to current file version: 211082026/07/09 07:20:09 OK 20251218171726_add_pins.sql (10.43ms)11092026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (9.2ms)11102026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000011112026-07-09 07:20:09.616 UTC [854] ERROR: relation "goose_db_version" does not exist at character 3611122026-07-09 07:20:09.616 UTC [854] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11132026-07-09 07:20:09.616 UTC [856] ERROR: relation "goose_db_version" does not exist at character 3611142026-07-09 07:20:09.616 UTC [856] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11152026-07-09 07:20:09.616 UTC [855] ERROR: relation "goose_db_version" does not exist at character 3611162026-07-09 07:20:09.616 UTC [855] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11172026/07/09 07:20:09 OK 2_object_stats_trigger.sql (4.51ms)11182026/07/09 07:20:09 goose: up to current file version: 211192026/07/09 07:20:09 OK 2_object_stats_trigger.sql (4.23ms)11202026/07/09 07:20:09 goose: up to current file version: 211212026-07-09 07:20:09.618 UTC [857] ERROR: relation "goose_db_version" does not exist at character 3611222026-07-09 07:20:09.618 UTC [857] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11232026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (8.52ms)11242026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000011252026-07-09 07:20:09.618 UTC [858] ERROR: relation "goose_db_version" does not exist at character 3611262026-07-09 07:20:09.618 UTC [858] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11272026-07-09 07:20:09.619 UTC [863] ERROR: relation "goose_db_version" does not exist at character 3611282026-07-09 07:20:09.619 UTC [863] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11292026/07/09 07:20:09 OK 1_commit_pending_closure.sql (3.57ms)11302026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (7.38ms)11312026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000011322026-07-09 07:20:09.619 UTC [860] ERROR: relation "goose_db_version" does not exist at character 3611332026-07-09 07:20:09.619 UTC [860] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11342026/07/09 07:20:09 INFO Created nix-cache-info in bucket bucket=bucket1311352026-07-09 07:20:09.620 UTC [861] ERROR: relation "goose_db_version" does not exist at character 3611362026-07-09 07:20:09.620 UTC [861] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11372026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (7.93ms)11382026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000011392026/07/09 07:20:09 OK 2_object_stats_trigger.sql (2.86ms)11402026/07/09 07:20:09 goose: up to current file version: 211412026/07/09 07:20:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11422026/07/09 07:20:09 OK 2_object_stats_trigger.sql (2.4ms)11432026/07/09 07:20:09 goose: up to current file version: 211442026/07/09 07:20:09 OK 1_commit_pending_closure.sql (4.17ms)11452026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (8.42ms)11462026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000011472026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures11482026/07/09 07:20:09 OK 1_commit_pending_closure.sql (5.29ms)11492026/07/09 07:20:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11502026/07/09 07:20:09 OK 1_commit_pending_closure.sql (4.33ms)11512026/07/09 07:20:09 OK 2_object_stats_trigger.sql (1.94ms)11522026/07/09 07:20:09 goose: up to current file version: 211532026/07/09 07:20:09 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11542026/07/09 07:20:09 WARN mTLS auth: subject not in bound subjects subject="CN=writer"11552026/07/09 07:20:09 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1156--- PASS: TestService_NativeMTLS (0.46s)1157--- PASS: TestCompleteMultipartUnregistered (0.46s)11582026/07/09 07:20:09 OK 2_object_stats_trigger.sql (1.46ms)11592026/07/09 07:20:09 goose: up to current file version: 211602026-07-09 07:20:09.628 UTC [879] ERROR: relation "goose_db_version" does not exist at character 3611612026-07-09 07:20:09.628 UTC [879] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11622026/07/09 07:20:09 OK 2_object_stats_trigger.sql (1.81ms)11632026/07/09 07:20:09 goose: up to current file version: 211642026-07-09 07:20:09.629 UTC [880] ERROR: relation "goose_db_version" does not exist at character 3611652026-07-09 07:20:09.629 UTC [880] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11662026/07/09 07:20:09 OK 1_commit_pending_closure.sql (5.04ms)1167--- PASS: TestResurrectedObjectNotDeleted (0.47s)11682026-07-09 07:20:09.630 UTC [887] ERROR: relation "goose_db_version" does not exist at character 3611692026-07-09 07:20:09.630 UTC [887] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11702026/07/09 07:20:09 INFO Aborted multipart uploads count=01171{"timestamp":"2026-07-09T07:20:09.633134104Z","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(379)"}1172{"timestamp":"2026-07-09T07:20:09.633198984Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket11, 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(379)"}11732026-07-09 07:20:09.633 UTC [881] ERROR: relation "goose_db_version" does not exist at character 3611742026-07-09 07:20:09.633 UTC [881] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11752026-07-09 07:20:09.633 UTC [883] ERROR: relation "goose_db_version" does not exist at character 3611762026-07-09 07:20:09.633 UTC [883] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11772026-07-09 07:20:09.633 UTC [890] ERROR: relation "goose_db_version" does not exist at character 3611782026-07-09 07:20:09.633 UTC [890] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11792026-07-09 07:20:09.633 UTC [893] ERROR: relation "goose_db_version" does not exist at character 3611802026-07-09 07:20:09.633 UTC [893] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11812026-07-09 07:20:09.633 UTC [884] ERROR: relation "goose_db_version" does not exist at character 3611822026-07-09 07:20:09.633 UTC [884] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11832026-07-09 07:20:09.633 UTC [888] ERROR: relation "goose_db_version" does not exist at character 3611842026-07-09 07:20:09.633 UTC [888] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1185--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.47s)11862026-07-09 07:20:09.633 UTC [889] ERROR: relation "goose_db_version" does not exist at character 3611872026-07-09 07:20:09.633 UTC [889] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11882026-07-09 07:20:09.633 UTC [891] ERROR: relation "goose_db_version" does not exist at character 3611892026-07-09 07:20:09.633 UTC [891] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11902026/07/09 07:20:09 OK 2_object_stats_trigger.sql (6.03ms)11912026/07/09 07:20:09 goose: up to current file version: 211922026/07/09 07:20:09 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=NjMzYTY1YTItMWZmNC00YWQ3LThmNjEtNjFlYzRlZWZjNTBjLjE5MDNkNDUwLTM0YmItNDQxNi04NDM4LWU4MWE5YmVkMTE0N3gxNzgzNTgxNjA5NTk5OTU1MjMy11932026/07/09 07:20:09 WARN Force mode enabled - objects will be deleted immediately without grace period11942026/07/09 07:20:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjMzYTY1YTItMWZmNC00YWQ3LThmNjEtNjFlYzRlZWZjNTBjLjE5MDNkNDUwLTM0YmItNDQxNi04NDM4LWU4MWE5YmVkMTE0N3gxNzgzNTgxNjA5NTk5OTU1MjMy parts=11195--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.48s)1196--- PASS: TestService_Rustfstest (0.48s)11972026/07/09 07:20:09 OK 20241026095416_initial_model.sql (14.34ms)11982026/07/09 07:20:09 OK 20241026095416_initial_model.sql (14.62ms)11992026/07/09 07:20:09 OK 20241026095416_initial_model.sql (15.08ms)12002026/07/09 07:20:09 OK 20241026095416_initial_model.sql (14.14ms)12012026/07/09 07:20:09 OK 20241026095416_initial_model.sql (14ms)12022026/07/09 07:20:09 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=012032026/07/09 07:20:09 INFO Vacuumed table table=pending_closures12042026/07/09 07:20:09 INFO Vacuumed table table=pending_objects12052026/07/09 07:20:09 INFO Vacuumed table table=multipart_uploads12062026/07/09 07:20:09 INFO Vacuumed table table=closures12072026/07/09 07:20:09 INFO Vacuumed table table=objects1208--- PASS: TestGCMetrics (0.49s)12092026/07/09 07:20:09 OK 20241026095416_initial_model.sql (22.27ms)12102026/07/09 07:20:09 OK 20241026095416_initial_model.sql (15.64ms)1211--- PASS: TestObjectStatsTrigger (0.49s)12122026/07/09 07:20:09 OK 20241026095416_initial_model.sql (13.71ms)12132026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (8.99ms)12142026/07/09 07:20:09 OK 20241026095416_initial_model.sql (11.86ms)12152026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (7.89ms)12162026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (9.37ms)12172026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (9.37ms)12182026/07/09 07:20:09 OK 20241026095416_initial_model.sql (23.7ms)12192026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (9.92ms)12202026/07/09 07:20:09 OK 20241026095416_initial_model.sql (24.58ms)12212026/07/09 07:20:09 OK 20241026095416_initial_model.sql (16.99ms)12222026/07/09 07:20:09 OK 20241026095416_initial_model.sql (16.97ms)12232026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (3.09ms)12242026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (3.22ms)12252026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (3.89ms)12262026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (3.03ms)12272026/07/09 07:20:09 OK 20241026095416_initial_model.sql (10.73ms)12282026/07/09 07:20:09 OK 20251218171726_add_pins.sql (5.92ms)12292026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (6.09ms)1230--- PASS: TestCacheStatsHandler (0.50s)12312026/07/09 07:20:09 OK 20251218171726_add_pins.sql (6.79ms)12322026/07/09 07:20:09 OK 20251218171726_add_pins.sql (7.11ms)12332026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (5.99ms)12342026/07/09 07:20:09 OK 20251218171726_add_pins.sql (7.52ms)12352026/07/09 07:20:09 OK 20251218171726_add_pins.sql (7.29ms)12362026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (6.26ms)12372026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (7.25ms)12382026/07/09 07:20:09 OK 20251218171726_add_pins.sql (4.73ms)12392026/07/09 07:20:09 OK 20251218171726_add_pins.sql (5.65ms)12402026/07/09 07:20:09 OK 20251218171726_add_pins.sql (5.08ms)12412026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (5.12ms)12422026/07/09 07:20:09 OK 20251218171726_add_pins.sql (6.69ms)1243=== NAME TestNARDeduplicationMetadataUploadBug1244 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug729751299/001/store/wl3198s2znrkrcbzfgrldjx7c1hqmqv5-file1.txt12452026/07/09 07:20:09 OK 20251218171726_add_pins.sql (4.57ms)12462026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (6.52ms)12472026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000012482026/07/09 07:20:09 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=393.684729ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures12492026/07/09 07:20:09 OK 20241026095416_initial_model.sql (13.48ms)12502026/07/09 07:20:09 OK 20251218171726_add_pins.sql (6.43ms)12512026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (6.68ms)12522026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000012532026/07/09 07:20:09 OK 20251218171726_add_pins.sql (6.69ms)12542026/07/09 07:20:09 OK 20251218171726_add_pins.sql (6.18ms)12552026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (6.08ms)12562026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000012572026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (6.65ms)12582026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000012592026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (8.01ms)12602026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000012612026/07/09 07:20:09 OK 20241026095416_initial_model.sql (17.36ms)12622026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (8.89ms)12632026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000012642026/07/09 07:20:09 OK 20251218171726_add_pins.sql (7.73ms)12652026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (7.89ms)12662026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000012672026/07/09 07:20:09 OK 20241026095416_initial_model.sql (14.97ms)12682026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (8.61ms)12692026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000012702026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (7.07ms)12712026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000012722026/07/09 07:20:09 OK 1_commit_pending_closure.sql (4.2ms)12732026/07/09 07:20:09 OK 20241026095416_initial_model.sql (16.44ms)1274=== NAME TestClientWithDependencies1275 client_integration_test.go:593: Built derivation: /build/TestClientWithDependencies1071890434/001/store/yfx0zdhr6p3ihycnz1kfkgss7rsl2gvg-test-script12762026/07/09 07:20:09 OK 20241026095416_initial_model.sql (16.71ms)12772026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (4.35ms)12782026/07/09 07:20:09 OK 1_commit_pending_closure.sql (5.09ms)12792026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (8.61ms)12802026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000012812026/07/09 07:20:09 OK 20241026095416_initial_model.sql (19.25ms)12822026/07/09 07:20:09 OK 1_commit_pending_closure.sql (5.65ms)12832026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (3.72ms)12842026/07/09 07:20:09 OK 1_commit_pending_closure.sql (5.42ms)12852026/07/09 07:20:09 OK 20241026095416_initial_model.sql (18.54ms)12862026/07/09 07:20:09 OK 2_object_stats_trigger.sql (3.89ms)12872026/07/09 07:20:09 goose: up to current file version: 212882026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (6.83ms)12892026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000012902026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (6.8ms)12912026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000012922026/07/09 07:20:09 OK 1_commit_pending_closure.sql (4.75ms)12932026/07/09 07:20:09 OK 1_commit_pending_closure.sql (4.63ms)12942026/07/09 07:20:09 OK 1_commit_pending_closure.sql (4.92ms)12952026/07/09 07:20:09 OK 20241026095416_initial_model.sql (18.27ms)12962026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (4.9ms)12972026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (4.24ms)12982026/07/09 07:20:09 OK 2_object_stats_trigger.sql (2.69ms)12992026/07/09 07:20:09 goose: up to current file version: 213002026/07/09 07:20:09 OK 1_commit_pending_closure.sql (5.87ms)13012026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (6.02ms)13022026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000013032026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (8.32ms)13042026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000013052026/07/09 07:20:09 OK 1_commit_pending_closure.sql (5.46ms)13062026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (4.77ms)13072026/07/09 07:20:09 OK 2_object_stats_trigger.sql (3.13ms)13082026/07/09 07:20:09 goose: up to current file version: 213092026/07/09 07:20:09 OK 1_commit_pending_closure.sql (3.73ms)13102026/07/09 07:20:09 OK 2_object_stats_trigger.sql (3.52ms)13112026/07/09 07:20:09 goose: up to current file version: 213122026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (3.84ms)13132026/07/09 07:20:09 OK 20251218171726_add_pins.sql (4.98ms)13142026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (3.16ms)13152026/07/09 07:20:09 OK 2_object_stats_trigger.sql (3.19ms)13162026/07/09 07:20:09 goose: up to current file version: 213172026/07/09 07:20:09 OK 2_object_stats_trigger.sql (3.25ms)13182026/07/09 07:20:09 goose: up to current file version: 213192026/07/09 07:20:09 OK 2_object_stats_trigger.sql (2.56ms)13202026/07/09 07:20:09 goose: up to current file version: 213212026/07/09 07:20:09 OK 1_commit_pending_closure.sql (3.92ms)13222026/07/09 07:20:09 OK 20251218171726_add_pins.sql (4.56ms)13232026/07/09 07:20:09 OK 20251210153512_drop_unused_gin_index.sql (4.48ms)13242026/07/09 07:20:09 OK 2_object_stats_trigger.sql (3.63ms)13252026/07/09 07:20:09 goose: up to current file version: 213262026/07/09 07:20:09 OK 2_object_stats_trigger.sql (2.09ms)13272026/07/09 07:20:09 goose: up to current file version: 213282026/07/09 07:20:09 OK 1_commit_pending_closure.sql (2.97ms)13292026/07/09 07:20:09 OK 1_commit_pending_closure.sql (4.15ms)13302026/07/09 07:20:09 OK 20251218171726_add_pins.sql (4.1ms)13312026/07/09 07:20:09 OK 2_object_stats_trigger.sql (1.99ms)13322026/07/09 07:20:09 goose: up to current file version: 213332026/07/09 07:20:09 WARN mTLS auth: subject not in bound subjects subject="CN=writer"13342026/07/09 07:20:09 OK 20251218171726_add_pins.sql (4.25ms)1335--- PASS: TestService_ReadAuthMiddleware (0.51s)13362026/07/09 07:20:09 OK 1_commit_pending_closure.sql (2.86ms)13372026/07/09 07:20:09 OK 20251218171726_add_pins.sql (4.59ms)13382026/07/09 07:20:09 OK 2_object_stats_trigger.sql (3.73ms)13392026/07/09 07:20:09 goose: up to current file version: 213402026/07/09 07:20:09 OK 2_object_stats_trigger.sql (3.09ms)13412026/07/09 07:20:09 goose: up to current file version: 213422026/07/09 07:20:09 OK 2_object_stats_trigger.sql (2.63ms)13432026/07/09 07:20:09 goose: up to current file version: 213442026/07/09 07:20:09 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13452026/07/09 07:20:09 WARN mTLS auth: bound subjects configured but subject DN unavailable1346--- PASS: TestReadProxyDisabled (0.52s)13472026/07/09 07:20:09 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1348--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.52s)13492026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (6.61ms)13502026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000013512026/07/09 07:20:09 OK 20251218171726_add_pins.sql (5.1ms)13522026/07/09 07:20:09 OK 2_object_stats_trigger.sql (4.72ms)13532026/07/09 07:20:09 goose: up to current file version: 213542026/07/09 07:20:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13552026/07/09 07:20:09 OK 20251218171726_add_pins.sql (5.76ms)13562026/07/09 07:20:09 OK 20251218171726_add_pins.sql (6.69ms)13572026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (6.12ms)13582026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000013592026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (5.2ms)13602026/07/09 07:20:09 goose: successfully migrated database to version: 202606281200001361--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.52s)13622026/07/09 07:20:09 INFO Created nix-cache-info in bucket bucket=bucket2713632026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (7.43ms)13642026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000013652026/07/09 07:20:09 INFO Received cleanup request method=DELETE path=/api/pending_closures13662026/07/09 07:20:09 OK 1_commit_pending_closure.sql (3.9ms)13672026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (7.15ms)13682026/07/09 07:20:09 goose: successfully migrated database to version: 202606281200001369--- PASS: TestReadProxy404 (0.52s)13702026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (5.12ms)13712026/07/09 07:20:09 OK 1_commit_pending_closure.sql (4.52ms)13722026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000013732026/07/09 07:20:09 OK 1_commit_pending_closure.sql (4.44ms)13742026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (5.8ms)13752026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000013762026/07/09 07:20:09 OK 20260628120000_add_object_size_and_stats.sql (6.21ms)13772026/07/09 07:20:09 goose: successfully migrated database to version: 2026062812000013782026/07/09 07:20:09 OK 2_object_stats_trigger.sql (2.22ms)13792026/07/09 07:20:09 OK 1_commit_pending_closure.sql (3.45ms)13802026/07/09 07:20:09 goose: up to current file version: 213812026/07/09 07:20:09 INFO Aborted multipart uploads count=013822026/07/09 07:20:09 OK 1_commit_pending_closure.sql (3.33ms)13832026/07/09 07:20:09 OK 2_object_stats_trigger.sql (2.5ms)13842026/07/09 07:20:09 goose: up to current file version: 213852026/07/09 07:20:09 OK 2_object_stats_trigger.sql (2.79ms)13862026/07/09 07:20:09 goose: up to current file version: 213872026/07/09 07:20:09 OK 2_object_stats_trigger.sql (2.13ms)13882026/07/09 07:20:09 goose: up to current file version: 213892026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures13902026/07/09 07:20:09 OK 1_commit_pending_closure.sql (2.62ms)13912026/07/09 07:20:09 OK 2_object_stats_trigger.sql (1.7ms)13922026/07/09 07:20:09 goose: up to current file version: 213932026/07/09 07:20:09 OK 1_commit_pending_closure.sql (3.62ms)13942026/07/09 07:20:09 OK 1_commit_pending_closure.sql (3.32ms)13952026/07/09 07:20:09 OK 2_object_stats_trigger.sql (1.82ms)13962026/07/09 07:20:09 goose: up to current file version: 213972026/07/09 07:20:09 OK 2_object_stats_trigger.sql (1.4ms)13982026/07/09 07:20:09 goose: up to current file version: 213992026/07/09 07:20:09 OK 2_object_stats_trigger.sql (1.8ms)14002026/07/09 07:20:09 goose: up to current file version: 214012026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures1402--- PASS: TestReadProxyNarStreaming (0.53s)1403=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1404=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1405=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1406=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1407=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1408=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1409=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1410=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1411=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1412=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1413=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1414=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured14152026/07/09 07:20:09 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]1416--- PASS: TestReadProxyInvalidPath (0.53s)1417--- PASS: TestReadProxyNarinfo (0.54s)14182026/07/09 07:20:09 INFO Created nix-cache-info in bucket bucket=bucket391419--- PASS: TestReadProxyRangeRequest (0.54s)14202026/07/09 07:20:09 INFO Received cleanup request method=DELETE path=/api/pending_closures14212026/07/09 07:20:09 INFO Created nix-cache-info in bucket bucket=bucket4314222026/07/09 07:20:09 INFO Created nix-cache-info in bucket bucket=bucket441423=== NAME TestClientWithDependencies1424 client_integration_test.go:595: Found 1 dependencies (including self)14252026/07/09 07:20:09 WARN Authentication failed token_preview=eyJhbGciOi...wngRu8XCDg token_length=702 oidc_error="bound claims validation failed: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]14262026/07/09 07:20:09 INFO Aborted multipart uploads count=114272026/07/09 07:20:09 INFO OIDC auth successful provider=test14282026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures1429--- PASS: TestService_AuthMiddleware_OIDC (0.53s)1430 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1431 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1432 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)1433 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.02s)14342026/07/09 07:20:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14352026-07-09 07:20:09.715 UTC [860] ERROR: Closure does not exist: id=114362026-07-09 07:20:09.715 UTC [860] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE14372026-07-09 07:20:09.715 UTC [860] STATEMENT: -- name: CommitPendingClosure :exec1438 SELECT commit_pending_closure($1::bigint)1439 1440--- PASS: TestService_cleanupPendingClosuresHandler (0.55s)1441--- PASS: TestReadProxyConditionalGet (0.55s)1442--- PASS: TestMetricsInventory (0.56s)1443=== NAME TestClientMultipleUploads1444 client_integration_test.go:338: Created store path 0: /build/TestClientMultipleUploads901830334/001/store/h2zrh9yzcy0q9f6bk3shkyf66a7avgkg-test-file-0.txt1445--- PASS: TestReadProxyHead (0.56s)1446=== NAME TestClientIntegration1447 client_integration_test.go:276: Created store path: /build/TestClientIntegration2536303115/002/store/17ndlvnz6fdc3p64s48l4rh5jqz6hk10-test-file.txt14482026/07/09 07:20:09 INFO Received cleanup request method=DELETE path=/api/pending_closures1449=== NAME TestClientMultipleUploads1450 client_integration_test.go:338: Created store path 1: /build/TestClientMultipleUploads901830334/001/store/c71dcj9c4av04b31hlnhl25br7pxnkzq-test-file-1.txt14512026/07/09 07:20:09 INFO Aborted multipart uploads count=114522026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures1453--- PASS: TestMultipartCleanup (0.61s)14542026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures1455=== NAME TestPinProtectsFromGC1456 client_integration_test.go:646: Pinned store path: /build/TestPinProtectsFromGC3479033521/001/store/4v9ypcbzl83d4pxcf9m7p4z56mr0hbs6-pinned-file.txt1457 client_integration_test.go:647: Unpinned store path: /build/TestPinProtectsFromGC3479033521/001/store/dswx8van3qd2cw2i5h3l0nry917jzpbv-unpinned-file.txt14582026/07/09 07:20:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14592026/07/09 07:20:09 INFO Uploading yfx0zdhr6p3ihycnz1kfkgss7rsl2gvg-test-script (136B)14602026/07/09 07:20:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14612026/07/09 07:20:09 INFO Uploading wl3198s2znrkrcbzfgrldjx7c1hqmqv5-file1.txt (160B)1462=== NAME TestClientCADerivations1463 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1157895421/001/store/9xj20y2kkn0mdxd16nsc0w64f8hnyyw3-ca-test14642026/07/09 07:20:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14652026/07/09 07:20:09 INFO Signed narinfos id=1 count=114662026/07/09 07:20:09 INFO Uploading 1 narinfos14672026/07/09 07:20:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14682026/07/09 07:20:09 INFO Signed narinfos id=1 count=114692026/07/09 07:20:09 INFO Uploading 1 narinfos14702026/07/09 07:20:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14712026/07/09 07:20:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1472=== NAME TestClientMultipleUploads1473 client_integration_test.go:338: Created store path 2: /build/TestClientMultipleUploads901830334/001/store/54gnvvxrqzj8kgw1h2p17xwv5978b4h5-test-file-2.txt14742026/07/09 07:20:09 INFO Completed upload id=114752026/07/09 07:20:09 INFO Upload complete. (64ms)14762026/07/09 07:20:09 INFO Completed upload id=114772026/07/09 07:20:09 INFO Upload complete. (97ms)1478=== NAME TestClientWithDependencies1479 client_integration_test.go:597: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1071890434/001/store) requires matching store prefix1480=== NAME TestNARDeduplicationMetadataUploadBug1481 metadata_upload_test.go:54: Retrieved narinfo from S3:1482 StorePath: /build/TestNARDeduplicationMetadataUploadBug729751299/001/store/wl3198s2znrkrcbzfgrldjx7c1hqmqv5-file1.txt1483 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1484 Compression: zstd1485 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1486 NarSize: 1601487 References: 1488 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1489--- PASS: TestClientWithDependencies (0.64s)1490=== NAME TestNARDeduplicationMetadataUploadBug1491 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1492 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1493 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1494=== NAME TestClientCADerivations1495 client_ca_test.go:139: Found 1 dependencies (including self)14962026/07/09 07:20:09 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"14972026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures14982026/07/09 07:20:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14992026/07/09 07:20:09 INFO Uploading 17ndlvnz6fdc3p64s48l4rh5jqz6hk10-test-file.txt (152B)1500=== NAME TestNARDeduplicationMetadataUploadBug1501 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug729751299/001/store/7gkxaf7vyb4ys3sjcy21lvh1bs981axy-file2.txt15022026/07/09 07:20:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15032026/07/09 07:20:09 INFO Signed narinfos id=1 count=115042026/07/09 07:20:09 INFO Uploading 1 narinfos15052026/07/09 07:20:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15062026/07/09 07:20:09 INFO Completed upload id=115072026/07/09 07:20:09 INFO Upload complete. (95ms)1508=== NAME TestClientIntegration1509 client_integration_test.go:292: Retrieved narinfo from S3:1510 StorePath: /build/TestClientIntegration2536303115/002/store/17ndlvnz6fdc3p64s48l4rh5jqz6hk10-test-file.txt1511 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1512 Compression: zstd1513 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11514 NarSize: 1521515 References: 1516 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11517 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1518 client_integration_test.go:293: Decompressed .ls content (64 bytes):1519 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1520 client_integration_test.go:296: Testing garbage collection...15212026/07/09 07:20:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15222026/07/09 07:20:09 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NjMzYTY1YTItMWZmNC00YWQ3LThmNjEtNjFlYzRlZWZjNTBjLjAzODZjNGNmLTViODQtNGVmYy1iNTBlLTY2ZTNmZGIzNTQwMXgxNzgzNTgxNjA5NTEwNjg0NDM5 parts=1015232026/07/09 07:20:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15242026/07/09 07:20:09 INFO Completed upload id=115252026/07/09 07:20:09 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015262026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures15272026/07/09 07:20:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures1528=== NAME TestOrphanedObjectsGC1529 orphaned_objects_gc_test.go:290: GC Test Summary:1530 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1531 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1532 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1533 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1534 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1535--- PASS: TestOrphanedObjectsGC (0.74s)15362026/07/09 07:20:09 INFO Aborted multipart uploads count=015372026/07/09 07:20:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures15382026/07/09 07:20:09 INFO Garbage collection started15392026/07/09 07:20:09 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=015402026/07/09 07:20:09 INFO Aborted multipart uploads count=015412026/07/09 07:20:09 INFO Vacuumed table table=pending_closures15422026/07/09 07:20:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15432026/07/09 07:20:09 INFO Vacuumed table table=pending_objects1544--- PASS: TestGCBugBareHashReferences (0.76s)15452026/07/09 07:20:09 WARN Force mode enabled - objects will be deleted immediately without grace period15462026/07/09 07:20:09 INFO Vacuumed table table=multipart_uploads15472026/07/09 07:20:09 INFO Vacuumed table table=closures15482026/07/09 07:20:09 INFO Vacuumed table table=objects15492026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures15502026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures15512026/07/09 07:20:09 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NjMzYTY1YTItMWZmNC00YWQ3LThmNjEtNjFlYzRlZWZjNTBjLmM1ZTkwMWViLWEwNDctNDIzYy05M2U1LTZmOGM2N2Y1ZjEyZngxNzgzNTgxNjA5NTk3OTI1NDU1 parts=1015522026/07/09 07:20:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15532026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures15542026/07/09 07:20:09 INFO Completed upload id=115552026/07/09 07:20:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15562026/07/09 07:20:09 INFO Uploading 4v9ypcbzl83d4pxcf9m7p4z56mr0hbs6-pinned-file.txt (128B)15572026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures15582026/07/09 07:20:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15592026/07/09 07:20:09 INFO Uploading 9xj20y2kkn0mdxd16nsc0w64f8hnyyw3-ca-test (144B)15602026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures15612026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures15622026/07/09 07:20:09 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo15632026/07/09 07:20:09 WARN Found objects in DB but missing from S3, will re-upload count=11564--- PASS: TestService_verifyS3Integrity (0.78s)15652026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures15662026/07/09 07:20:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15672026/07/09 07:20:09 INFO Signed narinfos id=1 count=115682026/07/09 07:20:09 INFO Uploading 1 narinfos15692026/07/09 07:20:09 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001570--- PASS: TestService_createPendingClosureHandler (0.78s)15712026/07/09 07:20:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15722026/07/09 07:20:09 INFO Signed narinfos id=1 count=115732026/07/09 07:20:09 INFO Uploading 1 narinfos15742026/07/09 07:20:09 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15752026/07/09 07:20:09 INFO Uploading 54gnvvxrqzj8kgw1h2p17xwv5978b4h5-test-file-2.txt (160B)15762026/07/09 07:20:09 INFO Uploading h2zrh9yzcy0q9f6bk3shkyf66a7avgkg-test-file-0.txt (160B)15772026/07/09 07:20:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15782026/07/09 07:20:09 INFO Uploading c71dcj9c4av04b31hlnhl25br7pxnkzq-test-file-1.txt (160B)15792026/07/09 07:20:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15802026/07/09 07:20:09 INFO Received uploads request method=POST path=/api/pending_closures15812026/07/09 07:20:09 INFO Completed upload id=115822026/07/09 07:20:09 INFO Upload complete. (146ms)15832026/07/09 07:20:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15842026/07/09 07:20:09 INFO Signed narinfos id=2 count=115852026/07/09 07:20:09 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15862026/07/09 07:20:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15872026/07/09 07:20:09 INFO Signed narinfos id=3 count=115882026/07/09 07:20:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15892026/07/09 07:20:09 INFO Completed upload id=115902026/07/09 07:20:09 INFO Upload complete. (102ms)15912026/07/09 07:20:09 INFO Signed narinfos id=1 count=115922026/07/09 07:20:09 INFO Uploading 3 narinfos15932026/07/09 07:20:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15942026/07/09 07:20:09 INFO Signed narinfos id=2 count=115952026/07/09 07:20:09 INFO Uploading 1 narinfos15962026/07/09 07:20:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15972026/07/09 07:20:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1598=== NAME TestClientCADerivations1599 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1157895421/001/store/9xj20y2kkn0mdxd16nsc0w64f8hnyyw3-ca-test1600 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1601 Compression: zstd1602 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1603 NarSize: 1441604 References: 1605 Deriver: /build/TestClientCADerivations1157895421/001/store/0drsbkzgmsqrcbgsbp5b7a88rc4v2d5l-ca-test.drv1606 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1607 client_ca_test.go:185: Checking for realisation files in S3...16082026/07/09 07:20:09 INFO Completed upload id=216092026/07/09 07:20:09 INFO Upload complete. (80ms)1610 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1611 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16122026/07/09 07:20:09 INFO Completed upload id=11613=== NAME TestNARDeduplicationMetadataUploadBug1614 metadata_upload_test.go:76: Retrieved narinfo from S3:1615 StorePath: /build/TestNARDeduplicationMetadataUploadBug729751299/001/store/7gkxaf7vyb4ys3sjcy21lvh1bs981axy-file2.txt1616 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1617 Compression: zstd1618 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1619 NarSize: 1601620 References: 1621 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf16222026/07/09 07:20:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16232026/07/09 07:20:09 INFO Completed upload id=216242026/07/09 07:20:09 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16252026/07/09 07:20:09 INFO Completed upload id=316262026/07/09 07:20:09 INFO Upload complete. (135ms)1627=== NAME TestClientMultipleUploads1628 client_integration_test.go:349: Uploaded 3 paths in 171.84349ms1629=== NAME TestNARDeduplicationMetadataUploadBug1630 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1631 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1632 {"version":1,"root":{"type":"regular","size":44}}1633--- PASS: TestNARDeduplicationMetadataUploadBug (0.81s)1634--- PASS: TestClientMultipleUploads (0.81s)16352026/07/09 07:20:10 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=771.76748ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16362026/07/09 07:20:10 INFO Received uploads request method=POST path=/api/pending_closures16372026/07/09 07:20:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16382026/07/09 07:20:10 INFO Uploading dswx8van3qd2cw2i5h3l0nry917jzpbv-unpinned-file.txt (128B)16392026/07/09 07:20:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16402026/07/09 07:20:10 INFO Signed narinfos id=2 count=116412026/07/09 07:20:10 INFO Uploading 1 narinfos16422026/07/09 07:20:10 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16432026/07/09 07:20:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16442026/07/09 07:20:10 INFO Completed upload id=216452026/07/09 07:20:10 INFO Upload complete. (95ms)16462026/07/09 07:20:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NjMzYTY1YTItMWZmNC00YWQ3LThmNjEtNjFlYzRlZWZjNTBjLmRjNGFiNDU1LTc0ZGYtNGU3Yy1hNjYzLWRlYTRkNjYyNWM1ZXgxNzgzNTgxNjA5NzAyMTY5ODUw parts=121647--- PASS: TestRedundantMultipartUpload (0.93s)1648=== NAME TestClientCADerivations1649 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1650 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1651 error: binary cache 's3://bucket44?endpoint=http://localhost:41133®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1157895421/001/store'1652 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11653--- PASS: TestClientCADerivations (0.94s)16542026/07/09 07:20:10 INFO Received create pin request method=POST path=/api/pins/myapp16552026/07/09 07:20:10 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3479033521/001/store/4v9ypcbzl83d4pxcf9m7p4z56mr0hbs6-pinned-file.txt narinfo_key=4v9ypcbzl83d4pxcf9m7p4z56mr0hbs6.narinfo16562026/07/09 07:20:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures16572026/07/09 07:20:10 INFO Garbage collection started16582026/07/09 07:20:10 INFO Aborted multipart uploads count=016592026/07/09 07:20:10 WARN Force mode enabled - objects will be deleted immediately without grace period1660=== NAME TestOrphanedObjectsGCStressTest1661 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1662 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion16632026/07/09 07:20:10 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=016642026/07/09 07:20:10 INFO Vacuumed table table=pending_closures16652026/07/09 07:20:10 INFO Vacuumed table table=pending_objects16662026/07/09 07:20:10 INFO Vacuumed table table=multipart_uploads16672026/07/09 07:20:10 INFO Vacuumed table table=closures16682026/07/09 07:20:10 INFO Vacuumed table table=objects1669--- PASS: TestUploadHandlersRejectOversizedBody (0.19s)1670 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.09s)1671 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.09s)1672 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.41s)1673=== NAME TestOrphanedObjectsGCStressTest1674 orphaned_objects_gc_test.go:509: Stress test completed successfully:1675 orphaned_objects_gc_test.go:510: - Active objects preserved: 201676 orphaned_objects_gc_test.go:511: - Objects deleted: 2101677 orphaned_objects_gc_test.go:512: - Total GC'd: 2101678--- PASS: TestOrphanedObjectsGCStressTest (1.63s)16792026/07/09 07:20:10 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.528802217s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16802026/07/09 07:20:10 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=016812026/07/09 07:20:10 INFO Vacuumed table table=pending_closures16822026/07/09 07:20:10 INFO Vacuumed table table=pending_objects16832026/07/09 07:20:10 INFO Vacuumed table table=multipart_uploads16842026/07/09 07:20:10 INFO Vacuumed table table=closures16852026/07/09 07:20:10 INFO Vacuumed table table=objects16862026/07/09 07:20:11 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01687=== NAME TestClientIntegration1688 client_integration_test.go:303: Objects in database after GC:1689 client_integration_test.go:303: Successfully deleted all objects with GC --force1690--- PASS: TestClientIntegration (2.75s)16912026/07/09 07:20:12 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01692=== NAME TestPinProtectsFromGC1693 client_integration_test.go:709: Pin successfully protected closure from garbage collection1694--- PASS: TestPinProtectsFromGC (2.97s)1695--- PASS: TestClientErrorHandling (0.01s)1696 --- PASS: TestClientErrorHandling/InvalidStorePath (0.55s)1697 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.66s)1698 --- PASS: TestClientErrorHandling/ServerNotAvailable (3.20s)16992026/07/09 07:20:12 WARN Rate limiter enabled after throttle name=s3-test rate=517002026/07/09 07:20:12 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1701=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1702 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101703 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001704--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.67s)1705PASS17062026-07-09 07:20:13.494 UTC [211] LOG: received smart shutdown request17072026-07-09 07:20:13.498 UTC [211] LOG: background worker "logical replication launcher" (PID 218) exited with exit code 117082026-07-09 07:20:13.503 UTC [213] LOG: shutting down17092026-07-09 07:20:13.503 UTC [213] LOG: checkpoint starting: shutdown immediate17102026-07-09 07:20:14.124 UTC [213] LOG: checkpoint complete: wrote 9784 buffers (59.7%); 0 WAL file(s) added, 0 removed, 12 recycled; write=0.208 s, sync=0.404 s, total=0.621 s; sync files=14421, longest=0.007 s, average=0.001 s; distance=194060 kB, estimate=194060 kB; lsn=0/D26FAE8, redo lsn=0/D26FAE817112026-07-09 07:20:14.217 UTC [211] LOG: database system is shut down1712Running OIDC tests...1713=== RUN TestGlobMatch1714=== PAUSE TestGlobMatch1715=== RUN TestAudienceForIssuer1716=== PAUSE TestAudienceForIssuer1717=== RUN TestValidateToken_ValidToken1718=== PAUSE TestValidateToken_ValidToken1719=== RUN TestValidateToken_WrongAudience1720=== PAUSE TestValidateToken_WrongAudience1721=== RUN TestValidateToken_Expired1722=== PAUSE TestValidateToken_Expired1723=== RUN TestValidateToken_BoundClaimsMismatch1724=== PAUSE TestValidateToken_BoundClaimsMismatch1725=== RUN TestValidateToken_BoundSubjectMismatch1726=== PAUSE TestValidateToken_BoundSubjectMismatch1727=== RUN TestValidateToken_MultipleProviders1728=== PAUSE TestValidateToken_MultipleProviders1729=== RUN TestValidateToken_NoMatchingProvider1730=== PAUSE TestValidateToken_NoMatchingProvider1731=== CONT TestGlobMatch1732=== CONT TestValidateToken_BoundClaimsMismatch1733=== CONT TestValidateToken_MultipleProviders1734=== RUN TestGlobMatch/foo_foo1735=== PAUSE TestGlobMatch/foo_foo1736=== RUN TestGlobMatch/foo_bar1737=== PAUSE TestGlobMatch/foo_bar1738=== RUN TestGlobMatch/*_1739=== CONT TestValidateToken_ValidToken1740=== CONT TestAudienceForIssuer1741--- PASS: TestAudienceForIssuer (0.00s)1742=== CONT TestValidateToken_BoundSubjectMismatch1743=== CONT TestValidateToken_NoMatchingProvider1744=== CONT TestValidateToken_Expired1745=== CONT TestValidateToken_WrongAudience1746=== PAUSE TestGlobMatch/*_1747=== RUN TestGlobMatch/*_anything1748=== PAUSE TestGlobMatch/*_anything1749=== RUN TestGlobMatch/foo*_foo1750=== PAUSE TestGlobMatch/foo*_foo1751=== RUN TestGlobMatch/foo*_foobar1752=== PAUSE TestGlobMatch/foo*_foobar1753=== RUN TestGlobMatch/foo*_bar1754=== PAUSE TestGlobMatch/foo*_bar1755=== RUN TestGlobMatch/*bar_bar1756=== PAUSE TestGlobMatch/*bar_bar1757=== RUN TestGlobMatch/*bar_foobar1758=== PAUSE TestGlobMatch/*bar_foobar1759=== RUN TestGlobMatch/*bar_foo1760=== PAUSE TestGlobMatch/*bar_foo1761=== RUN TestGlobMatch/foo*bar_foobar1762=== PAUSE TestGlobMatch/foo*bar_foobar1763=== RUN TestGlobMatch/foo*bar_foo123bar1764=== PAUSE TestGlobMatch/foo*bar_foo123bar1765=== RUN TestGlobMatch/foo*bar_foobarbaz1766=== PAUSE TestGlobMatch/foo*bar_foobarbaz1767=== RUN TestGlobMatch/*/*_foo/bar1768=== PAUSE TestGlobMatch/*/*_foo/bar1769=== RUN TestGlobMatch/*/*_foo1770=== PAUSE TestGlobMatch/*/*_foo1771=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1772=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1773=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01774=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01775=== RUN TestGlobMatch/refs/*/main_refs/heads/main1776=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1777=== RUN TestGlobMatch/fo?_foo1778=== PAUSE TestGlobMatch/fo?_foo1779=== RUN TestGlobMatch/fo?_fo1780=== PAUSE TestGlobMatch/fo?_fo1781=== RUN TestGlobMatch/fo?_fooo1782=== PAUSE TestGlobMatch/fo?_fooo1783=== RUN TestGlobMatch/?oo_foo1784=== PAUSE TestGlobMatch/?oo_foo1785=== RUN TestGlobMatch/?oo_boo1786=== PAUSE TestGlobMatch/?oo_boo1787=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1788=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1789=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1790=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1791=== CONT TestGlobMatch/foo_foo1792=== CONT TestGlobMatch/*bar_bar1793=== CONT TestGlobMatch/*bar_foo1794=== CONT TestGlobMatch/fo?_fo1795=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1796=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1797=== CONT TestGlobMatch/?oo_boo1798=== CONT TestGlobMatch/?oo_foo1799=== CONT TestGlobMatch/fo?_fooo1800=== CONT TestGlobMatch/foo*_bar1801=== CONT TestGlobMatch/*/*_foo/bar1802=== CONT TestGlobMatch/foo*_foobar1803=== CONT TestGlobMatch/fo?_foo1804=== CONT TestGlobMatch/*_1805=== CONT TestGlobMatch/refs/*/main_refs/heads/main1806=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01807=== CONT TestGlobMatch/*_anything1808=== CONT TestGlobMatch/foo_bar1809=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1810=== CONT TestGlobMatch/foo*_foo1811=== CONT TestGlobMatch/*/*_foo1812=== CONT TestGlobMatch/*bar_foobar1813=== CONT TestGlobMatch/foo*bar_foo123bar1814=== CONT TestGlobMatch/foo*bar_foobarbaz1815=== CONT TestGlobMatch/foo*bar_foobar1816--- PASS: TestGlobMatch (0.01s)1817 --- PASS: TestGlobMatch/foo_foo (0.00s)1818 --- PASS: TestGlobMatch/*bar_bar (0.00s)1819 --- PASS: TestGlobMatch/*bar_foo (0.00s)1820 --- PASS: TestGlobMatch/fo?_fo (0.00s)1821 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1822 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1823 --- PASS: TestGlobMatch/?oo_boo (0.00s)1824 --- PASS: TestGlobMatch/?oo_foo (0.00s)1825 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1826 --- PASS: TestGlobMatch/foo*_bar (0.00s)1827 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1828 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1829 --- PASS: TestGlobMatch/fo?_foo (0.00s)1830 --- PASS: TestGlobMatch/*_ (0.00s)1831 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1832 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1833 --- PASS: TestGlobMatch/*_anything (0.00s)1834 --- PASS: TestGlobMatch/foo_bar (0.00s)1835 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1836 --- PASS: TestGlobMatch/foo*_foo (0.00s)1837 --- PASS: TestGlobMatch/*/*_foo (0.00s)1838 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1839 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1840 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1841 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)18422026/07/09 07:20:15 INFO OIDC provider initialized name=test18432026/07/09 07:20:15 INFO OIDC provider initialized name=provider118442026/07/09 07:20:15 INFO OIDC provider initialized name=test18452026/07/09 07:20:15 INFO OIDC provider initialized name=test18462026/07/09 07:20:15 INFO OIDC provider initialized name=provider118472026/07/09 07:20:15 INFO OIDC provider initialized name=provider218482026/07/09 07:20:15 INFO OIDC provider initialized name=test18492026/07/09 07:20:15 INFO OIDC provider initialized name=test1850--- PASS: TestValidateToken_Expired (0.01s)1851--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)1852--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)1853--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1854--- PASS: TestValidateToken_MultipleProviders (0.02s)1855--- PASS: TestValidateToken_ValidToken (0.02s)1856--- PASS: TestValidateToken_WrongAudience (0.01s)1857PASS1858Running hook tests...1859=== RUN TestSendPathsEmpty1860=== PAUSE TestSendPathsEmpty1861=== RUN TestQueueEnqueueAndFetch1862=== PAUSE TestQueueEnqueueAndFetch1863=== RUN TestQueueDeduplication1864=== PAUSE TestQueueDeduplication1865=== RUN TestQueueRemove1866=== PAUSE TestQueueRemove1867=== RUN TestQueueFetchBatchLimit1868=== PAUSE TestQueueFetchBatchLimit1869=== RUN TestQueueFetchRemoveLifecycle1870=== PAUSE TestQueueFetchRemoveLifecycle1871=== RUN TestQueueConcurrentWriters1872=== PAUSE TestQueueConcurrentWriters1873=== RUN TestServerClientIntegration1874=== PAUSE TestServerClientIntegration1875=== RUN TestServerQueueError1876=== PAUSE TestServerQueueError1877=== RUN TestGetListenerSocketActivation1878 server_test.go:210: === RUN TestGetListenerSocketActivation1879 --- PASS: TestGetListenerSocketActivation (0.00s)1880 PASS1881 1882--- PASS: TestGetListenerSocketActivation (0.01s)1883=== RUN TestWorkerUploadsAndRemoves1884=== PAUSE TestWorkerUploadsAndRemoves1885=== RUN TestWorkerSkipsGCdPaths1886=== PAUSE TestWorkerSkipsGCdPaths1887=== RUN TestWorkerPrunesClosureDeps1888=== PAUSE TestWorkerPrunesClosureDeps1889=== CONT TestSendPathsEmpty1890=== CONT TestQueueConcurrentWriters1891--- PASS: TestSendPathsEmpty (0.00s)1892=== CONT TestWorkerUploadsAndRemoves1893=== CONT TestQueueFetchRemoveLifecycle1894=== CONT TestWorkerPrunesClosureDeps1895=== CONT TestQueueFetchBatchLimit1896=== CONT TestWorkerSkipsGCdPaths1897=== CONT TestQueueRemove1898=== CONT TestQueueDeduplication1899=== CONT TestQueueEnqueueAndFetch1900=== CONT TestServerQueueError1901=== CONT TestServerClientIntegration19022026/07/09 07:20:15 ERROR Failed to queue paths error="permission denied" count=11903--- PASS: TestServerClientIntegration (0.00s)1904--- PASS: TestServerQueueError (0.00s)19052026/07/09 07:20:15 INFO Upload queue status pending=219062026/07/09 07:20:15 INFO Uploading batch count=119072026/07/09 07:20:15 INFO Upload queue status pending=219082026/07/09 07:20:15 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2430368000/002/nonexistent1909--- PASS: TestQueueFetchBatchLimit (0.02s)1910--- PASS: TestQueueFetchRemoveLifecycle (0.02s)19112026/07/09 07:20:15 INFO Upload queue status pending=21912--- PASS: TestQueueEnqueueAndFetch (0.02s)19132026/07/09 07:20:15 INFO Uploading batch count=21914--- PASS: TestQueueRemove (0.02s)1915--- PASS: TestQueueDeduplication (0.02s)19162026/07/09 07:20:15 INFO Uploading batch count=11917--- PASS: TestWorkerSkipsGCdPaths (0.06s)1918--- PASS: TestWorkerPrunesClosureDeps (0.07s)1919--- PASS: TestWorkerUploadsAndRemoves (0.07s)1920--- PASS: TestQueueConcurrentWriters (0.20s)1921PASS