niks3-go-unit-tests log

succeeded `niks3-go-unit-tests` `x86_64-linux.go-unit-tests` · build #100 · raw

1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestCaseHackSuffix6=== PAUSE TestCaseHackSuffix7=== RUN TestPartSizeForNAR8=== PAUSE TestPartSizeForNAR9=== RUN TestUploadMultipart_SupersededByPeer10=== PAUSE TestUploadMultipart_SupersededByPeer11=== RUN TestDumpPathMatchesNix12=== PAUSE TestDumpPathMatchesNix13=== RUN TestDumpPathSingleFile14=== PAUSE TestDumpPathSingleFile15=== RUN TestDumpPathWriterError16=== PAUSE TestDumpPathWriterError17=== RUN TestEncodeNixBase3218=== PAUSE TestEncodeNixBase3219=== RUN TestEncodeNixBase32WithRealHash20=== PAUSE TestEncodeNixBase32WithRealHash21=== RUN TestConvertHashToNix3222=== PAUSE TestConvertHashToNix3223=== RUN TestGetStorePathHash24=== PAUSE TestGetStorePathHash25=== RUN TestPathInfoHashCompatibility26=== PAUSE TestPathInfoHashCompatibility27=== RUN TestParsePathInfoJSON28=== PAUSE TestParsePathInfoJSON29=== RUN TestParsePathInfoJSONMultiplePaths30=== PAUSE TestParsePathInfoJSONMultiplePaths31=== RUN TestPathInfoCACompatibility32=== PAUSE TestPathInfoCACompatibility33=== RUN TestRateLimiterFeedback34=== PAUSE TestRateLimiterFeedback35=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess36=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess37=== RUN TestResolveStorePath38=== PAUSE TestResolveStorePath39=== RUN TestDoWithRetry_BodyReplayedViaGetBody40=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody41=== RUN TestShellSplit42=== PAUSE TestShellSplit43=== RUN TestShellSplitErrors44=== PAUSE TestShellSplitErrors45=== RUN TestSetClientTLS46=== PAUSE TestSetClientTLS47=== RUN TestSetClientTLSDoesNotMutateDefaultTransport48=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport49=== RUN TestSetClientTLSErrors50=== PAUSE TestSetClientTLSErrors51=== RUN TestStaticToken52=== PAUSE TestStaticToken53=== RUN TestFileTokenReadsAndCaches54=== PAUSE TestFileTokenReadsAndCaches55=== RUN TestFileTokenMissing56=== PAUSE TestFileTokenMissing57=== RUN TestFileTokenEmpty58=== PAUSE TestFileTokenEmpty59=== RUN TestScriptTokenNoExpiryRerunsEveryCall60=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall61=== RUN TestScriptTokenCachesUntilRefresh62=== PAUSE TestScriptTokenCachesUntilRefresh63=== RUN TestScriptTokenEmptyToken64=== PAUSE TestScriptTokenEmptyToken65=== RUN TestScriptTokenBadJSON66=== PAUSE TestScriptTokenBadJSON67=== RUN TestScriptTokenScriptFails68=== PAUSE TestScriptTokenScriptFails69=== RUN TestScriptTokenEmptyCommand70=== PAUSE TestScriptTokenEmptyCommand71=== CONT TestDoServerRequestAttachesToken72=== CONT TestScriptTokenNoExpiryRerunsEveryCall73=== CONT TestFileTokenMissing74=== CONT TestDumpPathWriterError75=== CONT TestSetClientTLS76=== CONT TestStaticToken77=== CONT TestSetClientTLSErrors78--- PASS: TestStaticToken (0.00s)79=== CONT TestSetClientTLSDoesNotMutateDefaultTransport80=== CONT TestPathInfoHashCompatibility81=== CONT TestShellSplitErrors82--- PASS: TestShellSplitErrors (0.00s)83=== CONT TestShellSplit84=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)85=== CONT TestDoWithRetry_BodyReplayedViaGetBody86--- PASS: TestShellSplit (0.00s)87--- PASS: TestFileTokenMissing (0.00s)88=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)89=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess90=== CONT TestRateLimiterFeedback91=== CONT TestPathInfoCACompatibility92=== CONT TestParsePathInfoJSONMultiplePaths93=== RUN TestPathInfoCACompatibility/null_ca_field94=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths95=== CONT TestFileTokenEmpty96=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths97=== CONT TestScriptTokenBadJSON982026/07/18 13:54:30 WARN Rate limiter enabled after throttle name=server-test rate=599=== CONT TestUploadMultipart_SupersededByPeer100=== CONT TestScriptTokenEmptyCommand101=== CONT TestDumpPathSingleFile102=== CONT TestDumpPathMatchesNix103=== CONT TestScriptTokenScriptFails104=== CONT TestCaseHackSuffix105=== CONT TestScriptTokenEmptyToken106=== CONT TestConvertHashToNix32107=== CONT TestFileTokenReadsAndCaches108=== CONT TestGetStorePathHash109=== CONT TestEncodeNixBase32110=== CONT TestPartSizeForNAR111=== CONT TestScriptTokenCachesUntilRefresh112=== CONT TestEncodeNixBase32WithRealHash113=== CONT TestResolveStorePath114=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon115=== RUN TestRateLimiterFeedback/429_enables_limiter116=== CONT TestParsePathInfoJSON117=== PAUSE TestPathInfoCACompatibility/null_ca_field118=== RUN TestPathInfoCACompatibility/old_string_format_-_text119=== RUN TestParsePathInfoJSON/Nix_format120=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths121=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths122=== RUN TestUploadMultipart_SupersededByPeer/exists123=== RUN TestSetClientTLSErrors/missing_cert_file124=== RUN TestConvertHashToNix32/SRI_format_to_Nix32125=== RUN TestPartSizeForNAR/zero_stays_at_minimum126=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths127--- PASS: TestScriptTokenEmptyCommand (0.00s)128=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths129=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text130=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon131=== RUN TestEncodeNixBase32/test_string_hash132--- PASS: TestFileTokenEmpty (0.01s)133--- PASS: TestEncodeNixBase32WithRealHash (0.00s)134--- PASS: TestResolveStorePath (0.01s)135--- PASS: TestScriptTokenScriptFails (0.01s)136=== PAUSE TestParsePathInfoJSON/Nix_format137=== RUN TestParsePathInfoJSON/Lix_format138=== RUN TestGetStorePathHash/valid_store_path139=== PAUSE TestRateLimiterFeedback/429_enables_limiter140=== RUN TestRateLimiterFeedback/503_enables_limiter141=== PAUSE TestParsePathInfoJSON/Lix_format142=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive143=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive144=== PAUSE TestGetStorePathHash/valid_store_path145=== PAUSE TestEncodeNixBase32/test_string_hash146=== PAUSE TestUploadMultipart_SupersededByPeer/exists147=== RUN TestParsePathInfoJSON/empty_input148=== RUN TestUploadMultipart_SupersededByPeer/missing149=== PAUSE TestParsePathInfoJSON/empty_input150=== RUN TestParsePathInfoJSON/whitespace_only151=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI152--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)153 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.01s)154 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)155=== RUN TestEncodeNixBase32/empty_input156=== PAUSE TestEncodeNixBase32/empty_input157=== CONT TestEncodeNixBase32/test_string_hash158--- PASS: TestFileTokenReadsAndCaches (0.01s)1592026/07/18 13:54:30 WARN Rate limiter enabled after throttle name=server-test rate=5160=== RUN TestGetStorePathHash/basename_without_hyphen_should_error161=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error1622026/07/18 13:54:30 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:42391163=== RUN TestPathInfoCACompatibility/new_structured_format_-_text164=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text165=== PAUSE TestUploadMultipart_SupersededByPeer/missing166=== CONT TestUploadMultipart_SupersededByPeer/exists167=== PAUSE TestParsePathInfoJSON/whitespace_only168=== RUN TestParsePathInfoJSON/invalid_JSON169=== PAUSE TestParsePathInfoJSON/invalid_JSON170=== CONT TestParsePathInfoJSON/Nix_format171=== CONT TestParsePathInfoJSON/empty_input172=== CONT TestParsePathInfoJSON/Lix_format173=== CONT TestParsePathInfoJSON/whitespace_only174=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI175=== CONT TestEncodeNixBase32/empty_input176=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512177=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error178=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32179--- PASS: TestScriptTokenBadJSON (0.02s)180=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method181=== CONT TestUploadMultipart_SupersededByPeer/missing182=== PAUSE TestSetClientTLSErrors/missing_cert_file1832026/07/18 13:54:30 WARN Rate limiter backed off name=server-test rate=5184=== CONT TestParsePathInfoJSON/invalid_JSON1852026/07/18 13:54:30 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:42391186=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum187=== PAUSE TestRateLimiterFeedback/503_enables_limiter188=== RUN TestSetClientTLS/rejects_connection_without_client_cert189=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter190=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert191=== RUN TestConvertHashToNix32/already_Nix32_format192=== PAUSE TestConvertHashToNix32/already_Nix32_format193--- PASS: TestDoServerRequestAttachesToken (0.02s)194=== RUN TestSetClientTLSErrors/missing_key_file195--- PASS: TestScriptTokenEmptyToken (0.02s)196=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method197=== CONT TestPathInfoCACompatibility/null_ca_field198=== CONT TestPathInfoCACompatibility/new_structured_format_-_text199=== CONT TestPathInfoCACompatibility/old_string_format_-_text200=== RUN TestPartSizeForNAR/small_stays_at_minimum201=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter202=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error203=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512204=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA205=== RUN TestConvertHashToNix32/invalid_format206=== PAUSE TestConvertHashToNix32/invalid_format207=== PAUSE TestSetClientTLSErrors/missing_key_file208--- PASS: TestEncodeNixBase32 (0.01s)209 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)210 --- PASS: TestEncodeNixBase32/empty_input (0.00s)211=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method212=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive213=== PAUSE TestPartSizeForNAR/small_stays_at_minimum214=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum215=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter216=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error217=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error218=== CONT TestGetStorePathHash/valid_store_path219=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error220=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)221=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512222=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI223=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon224=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA225=== CONT TestConvertHashToNix32/SRI_format_to_Nix32226=== CONT TestConvertHashToNix32/invalid_format227=== CONT TestConvertHashToNix32/already_Nix32_format228=== RUN TestSetClientTLSErrors/missing_ca_file229=== PAUSE TestSetClientTLSErrors/missing_ca_file230--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.02s)231--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)232--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)233=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum234--- PASS: TestPathInfoCACompatibility (0.03s)235 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)236 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)237 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)238 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)239 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)240=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter241--- PASS: TestPathInfoHashCompatibility (0.03s)242 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)243 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)244 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)245 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)246=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error247=== CONT TestGetStorePathHash/basename_without_hyphen_should_error248=== RUN TestSetClientTLS/preserves_debug_logging_transport249=== PAUSE TestSetClientTLS/preserves_debug_logging_transport250=== RUN TestSetClientTLSErrors/invalid_ca_file251=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts252=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts253=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter254=== CONT TestRateLimiterFeedback/429_enables_limiter255=== CONT TestRateLimiterFeedback/503_enables_limiter256=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter257--- PASS: TestUploadMultipart_SupersededByPeer (0.02s)258 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)259 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)260=== CONT TestSetClientTLS/rejects_connection_without_client_cert261=== CONT TestSetClientTLS/preserves_debug_logging_transport262=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA2632026/07/18 13:54:30 WARN Rate limiter enabled after throttle name=server-test rate=5264=== PAUSE TestSetClientTLSErrors/invalid_ca_file2652026/07/18 13:54:30 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:38163266=== RUN TestPartSizeForNAR/1_TiB267=== PAUSE TestPartSizeForNAR/1_TiB268--- PASS: TestParsePathInfoJSON (0.02s)269 --- PASS: TestParsePathInfoJSON/Nix_format (0.01s)270 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)271 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)272 --- PASS: TestParsePathInfoJSON/empty_input (0.01s)273 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)274=== CONT TestSetClientTLSErrors/missing_cert_file2752026/07/18 13:54:30 WARN Rate limiter backed off name=server-test rate=5276=== CONT TestSetClientTLSErrors/missing_key_file2772026/07/18 13:54:30 WARN Rate limiter enabled after throttle name=server-test rate=5278=== CONT TestSetClientTLSErrors/missing_ca_file2792026/07/18 13:54:30 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:33429280=== CONT TestSetClientTLSErrors/invalid_ca_file281=== RUN TestPartSizeForNAR/5_TiB_S3_max_object282=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object283--- PASS: TestGetStorePathHash (0.03s)284 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)285 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)286 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)287 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)288=== RUN TestPartSizeForNAR/capped_at_5_GiB289=== PAUSE TestPartSizeForNAR/capped_at_5_GiB2902026/07/18 13:54:30 WARN Rate limiter backed off name=server-test rate=5291=== CONT TestPartSizeForNAR/zero_stays_at_minimum292=== CONT TestPartSizeForNAR/small_stays_at_minimum293--- PASS: TestConvertHashToNix32 (0.03s)294 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)295 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)296 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)297=== CONT TestPartSizeForNAR/1_TiB298=== CONT TestPartSizeForNAR/capped_at_5_GiB299=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum300=== CONT TestPartSizeForNAR/5_TiB_S3_max_object301=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts302--- PASS: TestRateLimiterFeedback (0.03s)303 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)304 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)305 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)306 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)307--- PASS: TestPartSizeForNAR (0.03s)308 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)309 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)310 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)311 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)312 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)313 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)314 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)315--- PASS: TestSetClientTLSErrors (0.03s)316 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)317 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)318 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)319 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)320--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)3212026/07/18 13:54:30 http: TLS handshake error from 127.0.0.1:34396: remote error: tls: bad certificate322--- PASS: TestSetClientTLS (0.03s)323 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)324 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)325 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)326--- PASS: TestDumpPathSingleFile (0.06s)327--- PASS: TestCaseHackSuffix (0.06s)328--- PASS: TestDumpPathWriterError (0.07s)329--- PASS: TestDumpPathMatchesNix (0.12s)330--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)331PASS332Running server tests...333The files belonging to this database system will be owned by user "nixbld".334This user must also own the server process.335336The database cluster will be initialized with locale "C".337The default database encoding has accordingly been set to "SQL_ASCII".338The default text search configuration will be set to "english".339340Data page checksums are enabled.341342creating directory /build/postgres3290418316/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/postgres3290418316/data -l logfile start359360/build/postgres3290418316:5432 - no response3612026-07-18 13:54:32.125 UTC [309] LOG: starting PostgreSQL 18.4 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit3622026-07-18 13:54:32.126 UTC [309] LOG: listening on Unix socket "/build/postgres3290418316/.s.PGSQL.5432"3632026-07-18 13:54:32.132 UTC [316] LOG: database system was shut down at 2026-07-18 13:54:31 UTC3642026-07-18 13:54:32.136 UTC [309] LOG: database system is ready to accept connections365/build/postgres3290418316:5432 - accepting connections366{"timestamp":"2026-07-18T13:54:32.622448739Z","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(758)"}367368thread 'rustfs-worker' (1081) panicked at /build/rustfs-1.0.0-beta.7-vendor/source-registry-0/reqwest-0.13.4/src/async_impl/client.rs:2507:38:369Client::new(): reqwest::Error { kind: Builder, source: General("No CA certificates were loaded from the system") }370note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace371=== RUN TestService_AuthMiddleware372=== PAUSE TestService_AuthMiddleware373=== RUN TestService_AuthMiddleware_MTLSProxyHeader374=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader375=== RUN TestService_AuthMiddleware_MTLSBoundSubjects376=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects377=== RUN TestService_ReadAuthMiddleware378=== PAUSE TestService_ReadAuthMiddleware379=== RUN TestService_AuthMiddleware_OIDC380=== PAUSE TestService_AuthMiddleware_OIDC381=== RUN TestCacheConfigHandler382=== PAUSE TestCacheConfigHandler383=== RUN TestCacheStatsHandler384=== PAUSE TestCacheStatsHandler385=== RUN TestClientCADerivations386=== PAUSE TestClientCADerivations387=== RUN TestClientErrorHandling388=== PAUSE TestClientErrorHandling389=== RUN TestClientIntegration390=== PAUSE TestClientIntegration391=== RUN TestClientMultipleUploads392=== PAUSE TestClientMultipleUploads393=== RUN TestClientWithDependencies394=== PAUSE TestClientWithDependencies395=== RUN TestPinProtectsFromGC396=== PAUSE TestPinProtectsFromGC397=== RUN TestGCAdvisoryLockBlocksConcurrentRun3982026-07-18 13:54:32.739 UTC [1113] ERROR: relation "goose_db_version" does not exist at character 363992026-07-18 13:54:32.739 UTC [1113] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4002026/07/18 13:54:32 OK 20241026095416_initial_model.sql (9.25ms)4012026/07/18 13:54:32 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)4022026/07/18 13:54:32 OK 20251218171726_add_pins.sql (2.59ms)4032026/07/18 13:54:32 OK 20260628120000_add_object_size_and_stats.sql (2.6ms)4042026/07/18 13:54:32 goose: successfully migrated database to version: 202606281200004052026/07/18 13:54:32 OK 1_commit_pending_closure.sql (1.83ms)4062026/07/18 13:54:32 OK 2_object_stats_trigger.sql (1.36ms)4072026/07/18 13:54:32 goose: up to current file version: 2408--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.17s)409=== RUN TestGCBugBareHashReferences410=== PAUSE TestGCBugBareHashReferences411=== RUN TestGCMetrics412=== PAUSE TestGCMetrics413=== RUN TestGCTaskStore_StartNew414=== PAUSE TestGCTaskStore_StartNew415=== RUN TestGCTaskStore_DeduplicateSameParams416=== PAUSE TestGCTaskStore_DeduplicateSameParams417=== RUN TestGCTaskStore_ConflictDifferentParams418=== PAUSE TestGCTaskStore_ConflictDifferentParams419=== RUN TestGCTaskStore_GetEmpty420=== PAUSE TestGCTaskStore_GetEmpty421=== RUN TestGCTaskStore_GetReturnsLatest422=== PAUSE TestGCTaskStore_GetReturnsLatest423=== RUN TestGCTaskStore_CompletedAllowsNewTask424=== PAUSE TestGCTaskStore_CompletedAllowsNewTask425=== RUN TestGCTaskStore_PhaseUpdates426=== PAUSE TestGCTaskStore_PhaseUpdates427=== RUN TestGCTaskStore_Fail428=== PAUSE TestGCTaskStore_Fail429=== RUN TestGracefulShutdownDrainsInflight430=== PAUSE TestGracefulShutdownDrainsInflight431=== RUN TestService_healthCheckHandler432=== PAUSE TestService_healthCheckHandler433=== RUN TestGenerateLandingPage434=== PAUSE TestGenerateLandingPage435=== RUN TestNARDeduplicationMetadataUploadBug436=== PAUSE TestNARDeduplicationMetadataUploadBug437=== RUN TestMetricsInventory438=== PAUSE TestMetricsInventory439=== RUN TestService_NativeMTLS440=== PAUSE TestService_NativeMTLS441=== RUN TestServerTLSConfig442=== PAUSE TestServerTLSConfig443=== RUN TestMultipartCleanup444=== PAUSE TestMultipartCleanup445=== RUN TestObjectStatsTrigger446=== PAUSE TestObjectStatsTrigger447=== RUN TestOrphanedObjectsGC448=== PAUSE TestOrphanedObjectsGC449=== RUN TestOrphanedObjectsGCStressTest450=== PAUSE TestOrphanedObjectsGCStressTest451=== RUN TestResurrectedObjectNotDeleted452=== PAUSE TestResurrectedObjectNotDeleted453=== RUN TestParseSingleRange454=== PAUSE TestParseSingleRange455=== RUN TestIsValidCachePath456=== PAUSE TestIsValidCachePath457=== RUN TestReadProxyNarinfo458=== PAUSE TestReadProxyNarinfo459=== RUN TestReadProxyNarinfoAlreadyDecompressed460=== PAUSE TestReadProxyNarinfoAlreadyDecompressed461=== RUN TestReadProxyNarStreaming462=== PAUSE TestReadProxyNarStreaming463=== RUN TestReadProxy404464=== PAUSE TestReadProxy404465=== RUN TestReadProxyInvalidPath466=== PAUSE TestReadProxyInvalidPath467=== RUN TestReadProxyHead468=== PAUSE TestReadProxyHead469=== RUN TestReadProxyConditionalGet470=== PAUSE TestReadProxyConditionalGet471=== RUN TestReadProxyRootRedirectsToIndexHTML472=== PAUSE TestReadProxyRootRedirectsToIndexHTML473=== RUN TestReadProxyDisabled474=== PAUSE TestReadProxyDisabled475=== RUN TestReadProxyRangeRequest476=== PAUSE TestReadProxyRangeRequest477=== RUN TestRedundantMultipartUpload478=== PAUSE TestRedundantMultipartUpload479=== RUN TestCompleteMultipartUpload_ErrorButObjectExists480=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists481=== RUN TestCompletedNarNotReofferedAcrossClosures482=== PAUSE TestCompletedNarNotReofferedAcrossClosures483=== RUN TestService_Rustfstest484=== PAUSE TestService_Rustfstest485=== RUN TestSystemdListenerNotActivated486--- PASS: TestSystemdListenerNotActivated (0.00s)487=== RUN TestWatchdogBeatsWhenHealthy488--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)489=== RUN TestWatchdogSkipsWhenUnhealthy4902026/07/18 13:54:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4912026/07/18 13:54:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4922026/07/18 13:54:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4932026/07/18 13:54:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4942026/07/18 13:54:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4952026/07/18 13:54:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4962026/07/18 13:54:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4972026/07/18 13:54:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4982026/07/18 13:54:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4992026/07/18 13:54:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"500--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)501=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle502=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle503=== RUN TestProxyWriteTimeout504=== PAUSE TestProxyWriteTimeout505=== RUN TestIsValidUploadKey506=== PAUSE TestIsValidUploadKey507=== RUN TestUploadHandlersRejectInvalidKeys508=== PAUSE TestUploadHandlersRejectInvalidKeys509=== RUN TestUploadHandlersRejectOversizedBody510=== PAUSE TestUploadHandlersRejectOversizedBody511=== RUN TestService_cleanupPendingClosuresHandler512=== PAUSE TestService_cleanupPendingClosuresHandler513=== RUN TestService_createPendingClosureHandler514=== PAUSE TestService_createPendingClosureHandler515=== RUN TestService_verifyS3Integrity516=== PAUSE TestService_verifyS3Integrity517=== RUN TestCompleteMultipartUnregistered518=== PAUSE TestCompleteMultipartUnregistered519=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT520=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT521=== CONT TestService_AuthMiddleware522=== CONT TestReadProxyHead523=== CONT TestReadProxyRootRedirectsToIndexHTML524=== CONT TestGCTaskStore_PhaseUpdates525--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)526=== CONT TestReadProxyInvalidPath527=== CONT TestReadProxy404528=== CONT TestReadProxyNarStreaming529=== CONT TestReadProxyNarinfoAlreadyDecompressed530=== CONT TestReadProxyNarinfo531=== CONT TestIsValidCachePath532=== CONT TestParseSingleRange533=== CONT TestResurrectedObjectNotDeleted534=== CONT TestOrphanedObjectsGCStressTest535=== CONT TestOrphanedObjectsGC536=== CONT TestObjectStatsTrigger537=== CONT TestMultipartCleanup538=== CONT TestServerTLSConfig539=== CONT TestService_NativeMTLS540=== CONT TestMetricsInventory541=== CONT TestNARDeduplicationMetadataUploadBug542=== CONT TestGenerateLandingPage543=== CONT TestService_healthCheckHandler544=== CONT TestGracefulShutdownDrainsInflight545=== CONT TestGCTaskStore_Fail546=== CONT TestProxyWriteTimeout547=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT548=== CONT TestCompleteMultipartUnregistered549=== CONT TestService_verifyS3Integrity550=== CONT TestClientWithDependencies551=== CONT TestService_createPendingClosureHandler552=== CONT TestService_cleanupPendingClosuresHandler553=== CONT TestUploadHandlersRejectOversizedBody554=== CONT TestGCTaskStore_CompletedAllowsNewTask555=== CONT TestUploadHandlersRejectInvalidKeys556=== CONT TestGCTaskStore_GetReturnsLatest557=== CONT TestGCTaskStore_GetEmpty558=== CONT TestGCTaskStore_ConflictDifferentParams559=== CONT TestIsValidUploadKey560=== CONT TestGCTaskStore_DeduplicateSameParams561=== CONT TestGCTaskStore_StartNew562=== CONT TestGCBugBareHashReferences563=== CONT TestPinProtectsFromGC564=== CONT TestGCMetrics565=== CONT TestRedundantMultipartUpload566=== CONT TestService_Rustfstest567=== CONT TestCompletedNarNotReofferedAcrossClosures568=== CONT TestCompleteMultipartUpload_ErrorButObjectExists569=== CONT TestCacheStatsHandler570=== CONT TestClientMultipleUploads571=== CONT TestService_ReadAuthMiddleware572=== CONT TestClientIntegration573=== CONT TestCacheConfigHandler574=== CONT TestClientErrorHandling575=== CONT TestService_AuthMiddleware_OIDC576=== CONT TestReadProxyDisabled577=== CONT TestClientCADerivations578=== CONT TestReadProxyRangeRequest579=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle580=== CONT TestService_AuthMiddleware_MTLSBoundSubjects581=== CONT TestService_AuthMiddleware_MTLSProxyHeader582=== CONT TestReadProxyConditionalGet583=== RUN TestParseSingleRange/none584=== PAUSE TestParseSingleRange/none585=== RUN TestProxyWriteTimeout/narinfo586=== RUN TestIsValidCachePath/narinfo587--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)588=== RUN TestServerTLSConfig/no_client_CA589=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info590=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info591=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal592=== PAUSE TestIsValidCachePath/narinfo593=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars594=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars595=== RUN TestIsValidCachePath/nar_zst596=== PAUSE TestIsValidCachePath/nar_zst597=== RUN TestIsValidCachePath/nar_xz598=== PAUSE TestIsValidCachePath/nar_xz599=== RUN TestIsValidCachePath/nar_bz2600=== PAUSE TestIsValidCachePath/nar_bz2601=== RUN TestIsValidCachePath/nar_uncompressed602=== PAUSE TestIsValidCachePath/nar_uncompressed603=== RUN TestIsValidCachePath/ls604=== PAUSE TestIsValidCachePath/ls605=== RUN TestIsValidCachePath/log606=== PAUSE TestIsValidCachePath/log607=== RUN TestIsValidCachePath/realisation608=== PAUSE TestIsValidCachePath/realisation609=== RUN TestIsValidCachePath/nix-cache-info610=== PAUSE TestIsValidCachePath/nix-cache-info611=== RUN TestIsValidCachePath/index.html612--- PASS: TestGCTaskStore_GetEmpty (0.00s)613--- PASS: TestGCTaskStore_Fail (0.00s)614--- PASS: TestGCTaskStore_StartNew (0.00s)615--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)616--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)617=== PAUSE TestIsValidCachePath/index.html618=== PAUSE TestServerTLSConfig/no_client_CA619=== RUN TestServerTLSConfig/missing_CA_file620=== PAUSE TestServerTLSConfig/missing_CA_file621=== RUN TestServerTLSConfig/not_a_PEM_file622=== PAUSE TestServerTLSConfig/not_a_PEM_file623--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)624=== RUN TestCacheConfigHandler/full_config,_no_issuer625=== RUN TestIsValidUploadKey/narinfo626=== RUN TestIsValidCachePath/traversal_parent627=== RUN TestClientErrorHandling/InvalidStorePath628=== PAUSE TestCacheConfigHandler/full_config,_no_issuer629=== CONT TestServerTLSConfig/not_a_PEM_file6302026/07/18 13:54:33 INFO Starting HTTP server address=127.0.0.1:33813631=== PAUSE TestClientErrorHandling/InvalidStorePath632=== CONT TestServerTLSConfig/missing_CA_file633=== PAUSE TestIsValidUploadKey/narinfo634=== RUN TestParseSingleRange/unknown_unit635=== CONT TestServerTLSConfig/no_client_CA636=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal637=== RUN TestCacheConfigHandler/no_cache_url_configured638=== PAUSE TestProxyWriteTimeout/narinfo639=== PAUSE TestIsValidCachePath/traversal_parent640=== RUN TestClientErrorHandling/InvalidAuthToken641=== RUN TestIsValidUploadKey/nar_zst642=== PAUSE TestParseSingleRange/unknown_unit643=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key6442026/07/18 13:54:33 INFO Shutdown signal received, draining in-flight requests timeout=10s645=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key646=== PAUSE TestCacheConfigHandler/no_cache_url_configured647=== RUN TestProxyWriteTimeout/1_GiB_nar648=== RUN TestIsValidCachePath/traversal_in_middle649=== PAUSE TestClientErrorHandling/InvalidAuthToken650--- PASS: TestServerTLSConfig (0.01s)651 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)652 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)653 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)654=== PAUSE TestIsValidUploadKey/nar_zst655=== RUN TestParseSingleRange/multi-range_ignored656=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key657=== RUN TestCacheConfigHandler/no_signing_keys658=== PAUSE TestProxyWriteTimeout/1_GiB_nar659=== RUN TestProxyWriteTimeout/10_GiB_nar660=== PAUSE TestIsValidCachePath/traversal_in_middle661=== RUN TestClientErrorHandling/ServerNotAvailable662=== RUN TestIsValidUploadKey/nar_xz663=== PAUSE TestParseSingleRange/multi-range_ignored664=== RUN TestParseSingleRange/malformed_no_dash665=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key666=== PAUSE TestCacheConfigHandler/no_signing_keys667=== PAUSE TestProxyWriteTimeout/10_GiB_nar6682026/07/18 13:54:33 INFO OIDC provider initialized name=test669=== RUN TestIsValidCachePath/invalid_char_e670=== PAUSE TestIsValidCachePath/invalid_char_e671=== PAUSE TestClientErrorHandling/ServerNotAvailable672=== CONT TestClientErrorHandling/InvalidStorePath673=== CONT TestClientErrorHandling/ServerNotAvailable674=== PAUSE TestParseSingleRange/malformed_no_dash675=== RUN TestParseSingleRange/malformed_both_empty676=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info677=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal678=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key679=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key6802026/07/18 13:54:33 INFO Received uploads request method=POST path=/6812026/07/18 13:54:33 INFO Received complete multipart upload request method=POST path=/682=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator6832026/07/18 13:54:33 INFO Received request for more parts method=POST path=/684=== RUN TestProxyWriteTimeout/unknown_size6852026/07/18 13:54:33 INFO Received uploads request method=POST path=/686=== RUN TestIsValidCachePath/invalid_char_u687=== PAUSE TestIsValidCachePath/invalid_char_u688=== PAUSE TestIsValidUploadKey/nar_xz689=== CONT TestClientErrorHandling/InvalidAuthToken690=== PAUSE TestParseSingleRange/malformed_both_empty691--- PASS: TestGenerateLandingPage (0.01s)692=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator693=== PAUSE TestProxyWriteTimeout/unknown_size694=== CONT TestProxyWriteTimeout/narinfo695=== CONT TestProxyWriteTimeout/unknown_size696=== RUN TestIsValidUploadKey/nar_plain697=== PAUSE TestIsValidUploadKey/nar_plain698=== RUN TestIsValidUploadKey/listing699=== PAUSE TestIsValidUploadKey/listing700=== RUN TestIsValidUploadKey/build_log701=== RUN TestParseSingleRange/malformed_end_before_start702=== PAUSE TestParseSingleRange/malformed_end_before_start703=== RUN TestParseSingleRange/closed704=== PAUSE TestParseSingleRange/closed705=== RUN TestParseSingleRange/open-ended706=== CONT TestCacheConfigHandler/full_config,_no_issuer707=== CONT TestCacheConfigHandler/no_cache_url_configured708=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator709=== CONT TestCacheConfigHandler/no_signing_keys710--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)711 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)712 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)713 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)714 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)715=== RUN TestIsValidCachePath/random_path716=== PAUSE TestIsValidCachePath/random_path717=== CONT TestProxyWriteTimeout/10_GiB_nar718=== CONT TestProxyWriteTimeout/1_GiB_nar719=== PAUSE TestIsValidUploadKey/build_log720=== PAUSE TestParseSingleRange/open-ended721--- PASS: TestCacheConfigHandler (0.01s)722 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)723 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)724 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)725 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)726=== RUN TestIsValidCachePath/empty727=== RUN TestIsValidUploadKey/build_log_home-manager_file728=== PAUSE TestIsValidUploadKey/build_log_home-manager_file729=== RUN TestParseSingleRange/end_clamped_to_size730=== PAUSE TestParseSingleRange/end_clamped_to_size731--- PASS: TestProxyWriteTimeout (0.02s)732 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)733 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)734 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)735 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)736=== PAUSE TestIsValidCachePath/empty737=== RUN TestIsValidUploadKey/build_log_plus_in_name738=== PAUSE TestIsValidUploadKey/build_log_plus_in_name739=== RUN TestIsValidUploadKey/build_log_question_mark740=== PAUSE TestIsValidUploadKey/build_log_question_mark741=== RUN TestParseSingleRange/suffix742=== PAUSE TestParseSingleRange/suffix743=== RUN TestIsValidCachePath/leading_slash744=== PAUSE TestIsValidCachePath/leading_slash745=== RUN TestIsValidUploadKey/build_log_equals746=== RUN TestParseSingleRange/suffix_exceeds_size747=== PAUSE TestParseSingleRange/suffix_exceeds_size748=== RUN TestIsValidCachePath/wrong_extension749=== PAUSE TestIsValidCachePath/wrong_extension750=== PAUSE TestIsValidUploadKey/build_log_equals751=== RUN TestParseSingleRange/single_byte752=== PAUSE TestParseSingleRange/single_byte753=== RUN TestParseSingleRange/start_past_EOF754=== PAUSE TestParseSingleRange/start_past_EOF755=== RUN TestParseSingleRange/start_far_past_EOF756=== PAUSE TestParseSingleRange/start_far_past_EOF757=== RUN TestIsValidCachePath/short_hash758=== PAUSE TestIsValidCachePath/short_hash759=== RUN TestIsValidUploadKey/realisation760=== PAUSE TestIsValidUploadKey/realisation761=== RUN TestIsValidUploadKey/realisation_plus_in_output762=== PAUSE TestIsValidUploadKey/realisation_plus_in_output763=== RUN TestIsValidUploadKey/nix-cache-info764=== PAUSE TestIsValidUploadKey/nix-cache-info765=== RUN TestIsValidUploadKey/index.html766=== PAUSE TestIsValidUploadKey/index.html767=== RUN TestIsValidUploadKey/narinfo_key,_nar_type768=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type769=== CONT TestParseSingleRange/none770=== CONT TestParseSingleRange/start_far_past_EOF771=== CONT TestParseSingleRange/start_past_EOF772=== CONT TestParseSingleRange/malformed_end_before_start773=== CONT TestParseSingleRange/malformed_both_empty774=== CONT TestParseSingleRange/closed775=== CONT TestParseSingleRange/malformed_no_dash776=== CONT TestParseSingleRange/single_byte777=== CONT TestParseSingleRange/suffix_exceeds_size778=== CONT TestParseSingleRange/multi-range_ignored779=== CONT TestParseSingleRange/suffix780=== CONT TestParseSingleRange/end_clamped_to_size781=== CONT TestParseSingleRange/open-ended782=== CONT TestParseSingleRange/unknown_unit783=== CONT TestIsValidCachePath/narinfo784=== CONT TestIsValidCachePath/leading_slash785=== CONT TestIsValidCachePath/empty786=== CONT TestIsValidCachePath/short_hash787=== CONT TestIsValidCachePath/random_path788=== CONT TestIsValidCachePath/wrong_extension789=== CONT TestIsValidCachePath/log790=== CONT TestIsValidCachePath/realisation791=== CONT TestIsValidCachePath/traversal_in_middle792=== CONT TestIsValidCachePath/ls793=== CONT TestIsValidCachePath/invalid_char_u794=== CONT TestIsValidCachePath/traversal_parent795=== CONT TestIsValidCachePath/nar_uncompressed796=== CONT TestIsValidCachePath/index.html797=== CONT TestIsValidCachePath/nar_bz2798=== CONT TestIsValidCachePath/invalid_char_e799=== CONT TestIsValidCachePath/nar_xz800=== CONT TestIsValidCachePath/nar_zst801=== CONT TestIsValidCachePath/nix-cache-info802=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars803=== RUN TestIsValidUploadKey/nar_key,_narinfo_type804=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type805--- PASS: TestParseSingleRange (0.02s)806 --- PASS: TestParseSingleRange/none (0.00s)807 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)808 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)809 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)810 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)811 --- PASS: TestParseSingleRange/closed (0.00s)812 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)813 --- PASS: TestParseSingleRange/single_byte (0.00s)814 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)815 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)816 --- PASS: TestParseSingleRange/suffix (0.00s)817 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)818 --- PASS: TestParseSingleRange/open-ended (0.00s)819 --- PASS: TestParseSingleRange/unknown_unit (0.00s)820=== RUN TestIsValidUploadKey/listing_key,_narinfo_type821=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type822--- PASS: TestIsValidCachePath (0.02s)823 --- PASS: TestIsValidCachePath/narinfo (0.00s)824 --- PASS: TestIsValidCachePath/leading_slash (0.00s)825 --- PASS: TestIsValidCachePath/empty (0.00s)826 --- PASS: TestIsValidCachePath/short_hash (0.00s)827 --- PASS: TestIsValidCachePath/random_path (0.00s)828 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)829 --- PASS: TestIsValidCachePath/log (0.00s)830 --- PASS: TestIsValidCachePath/realisation (0.00s)831 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)832 --- PASS: TestIsValidCachePath/ls (0.00s)833 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)834 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)835 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)836 --- PASS: TestIsValidCachePath/index.html (0.00s)837 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)838 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)839 --- PASS: TestIsValidCachePath/nar_xz (0.00s)840 --- PASS: TestIsValidCachePath/nar_zst (0.00s)841 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)842 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)843=== RUN TestIsValidUploadKey/traversal844=== PAUSE TestIsValidUploadKey/traversal845=== RUN TestIsValidUploadKey/traversal_nar846=== PAUSE TestIsValidUploadKey/traversal_nar847=== RUN TestIsValidUploadKey/absolute848=== PAUSE TestIsValidUploadKey/absolute849=== RUN TestIsValidUploadKey/empty_key850=== PAUSE TestIsValidUploadKey/empty_key851=== RUN TestIsValidUploadKey/unknown_type852=== PAUSE TestIsValidUploadKey/unknown_type853=== CONT TestIsValidUploadKey/narinfo854=== CONT TestIsValidUploadKey/nar_plain855=== CONT TestIsValidUploadKey/nix-cache-info856=== CONT TestIsValidUploadKey/unknown_type857=== CONT TestIsValidUploadKey/empty_key858=== CONT TestIsValidUploadKey/absolute859=== CONT TestIsValidUploadKey/traversal_nar860=== CONT TestIsValidUploadKey/traversal861=== CONT TestIsValidUploadKey/build_log_question_mark862=== CONT TestIsValidUploadKey/listing863=== CONT TestIsValidUploadKey/build_log_plus_in_name864=== CONT TestIsValidUploadKey/nar_key,_narinfo_type865=== CONT TestIsValidUploadKey/build_log_home-manager_file866=== CONT TestIsValidUploadKey/narinfo_key,_nar_type867=== CONT TestIsValidUploadKey/index.html868=== CONT TestIsValidUploadKey/build_log869=== CONT TestIsValidUploadKey/nar_xz870=== CONT TestIsValidUploadKey/realisation871=== CONT TestIsValidUploadKey/realisation_plus_in_output872=== CONT TestIsValidUploadKey/build_log_equals873=== CONT TestIsValidUploadKey/nar_zst874=== CONT TestIsValidUploadKey/listing_key,_narinfo_type875--- PASS: TestIsValidUploadKey (0.02s)876 --- PASS: TestIsValidUploadKey/narinfo (0.00s)877 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)878 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)879 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)880 --- PASS: TestIsValidUploadKey/empty_key (0.00s)881 --- PASS: TestIsValidUploadKey/absolute (0.00s)882 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)883 --- PASS: TestIsValidUploadKey/traversal (0.00s)884 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)885 --- PASS: TestIsValidUploadKey/listing (0.00s)886 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)887 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)888 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)889 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)890 --- PASS: TestIsValidUploadKey/index.html (0.00s)891 --- PASS: TestIsValidUploadKey/build_log (0.00s)892 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)893 --- PASS: TestIsValidUploadKey/realisation (0.00s)894 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)895 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)896 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)897 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)898--- PASS: TestGracefulShutdownDrainsInflight (0.08s)899=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure900=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure901=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart902=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart903=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts904=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts905=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure9062026/07/18 13:54:33 INFO Received uploads request method=POST path=/907=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts908=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart9092026/07/18 13:54:33 INFO Received request for more parts method=POST path=/9102026/07/18 13:54:33 INFO Received complete multipart upload request method=POST path=/9112026-07-18 13:54:33.244 UTC [1277] ERROR: relation "goose_db_version" does not exist at character 369122026-07-18 13:54:33.244 UTC [1277] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9132026-07-18 13:54:33.244 UTC [1279] ERROR: relation "goose_db_version" does not exist at character 369142026-07-18 13:54:33.244 UTC [1279] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9152026-07-18 13:54:33.245 UTC [1281] ERROR: relation "goose_db_version" does not exist at character 369162026-07-18 13:54:33.245 UTC [1281] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9172026-07-18 13:54:33.246 UTC [1280] ERROR: relation "goose_db_version" does not exist at character 369182026-07-18 13:54:33.246 UTC [1280] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9192026-07-18 13:54:33.246 UTC [1278] ERROR: relation "goose_db_version" does not exist at character 369202026-07-18 13:54:33.246 UTC [1278] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9212026/07/18 13:54:33 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_closures9222026-07-18 13:54:33.278 UTC [1323] ERROR: relation "goose_db_version" does not exist at character 369232026-07-18 13:54:33.278 UTC [1323] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9242026-07-18 13:54:33.278 UTC [1299] ERROR: relation "goose_db_version" does not exist at character 369252026-07-18 13:54:33.278 UTC [1299] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9262026-07-18 13:54:33.279 UTC [1301] ERROR: relation "goose_db_version" does not exist at character 369272026-07-18 13:54:33.279 UTC [1301] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9282026-07-18 13:54:33.293 UTC [1325] ERROR: relation "goose_db_version" does not exist at character 369292026-07-18 13:54:33.293 UTC [1325] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9302026-07-18 13:54:33.293 UTC [1324] ERROR: relation "goose_db_version" does not exist at character 369312026-07-18 13:54:33.293 UTC [1324] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9322026/07/18 13:54:33 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.022213ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures9332026/07/18 13:54:33 OK 20241026095416_initial_model.sql (99.79ms)9342026-07-18 13:54:33.372 UTC [1328] ERROR: relation "goose_db_version" does not exist at character 369352026-07-18 13:54:33.372 UTC [1328] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9362026-07-18 13:54:33.376 UTC [1329] ERROR: relation "goose_db_version" does not exist at character 369372026-07-18 13:54:33.376 UTC [1329] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9382026-07-18 13:54:33.383 UTC [1330] ERROR: relation "goose_db_version" does not exist at character 369392026-07-18 13:54:33.383 UTC [1330] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9402026/07/18 13:54:33 OK 20241026095416_initial_model.sql (110.7ms)9412026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (21.89ms)9422026/07/18 13:54:33 OK 20241026095416_initial_model.sql (122.08ms)9432026/07/18 13:54:33 OK 20241026095416_initial_model.sql (125.09ms)9442026/07/18 13:54:33 OK 20241026095416_initial_model.sql (122.32ms)9452026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (9.79ms)9462026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (7.46ms)9472026/07/18 13:54:33 OK 20241026095416_initial_model.sql (103.55ms)9482026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (7.69ms)9492026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (9.34ms)9502026/07/18 13:54:33 OK 20241026095416_initial_model.sql (90.13ms)9512026/07/18 13:54:33 OK 20241026095416_initial_model.sql (102.47ms)9522026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (5.5ms)9532026/07/18 13:54:33 OK 20251218171726_add_pins.sql (12.26ms)9542026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (4.86ms)9552026/07/18 13:54:33 OK 20251218171726_add_pins.sql (20.05ms)9562026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (6.65ms)9572026/07/18 13:54:33 OK 20241026095416_initial_model.sql (106.84ms)9582026/07/18 13:54:33 OK 20241026095416_initial_model.sql (104.89ms)9592026/07/18 13:54:33 OK 20251218171726_add_pins.sql (16.44ms)9602026/07/18 13:54:33 OK 20251218171726_add_pins.sql (13.65ms)9612026/07/18 13:54:33 OK 20251218171726_add_pins.sql (13.86ms)9622026/07/18 13:54:33 OK 20251218171726_add_pins.sql (10.28ms)9632026/07/18 13:54:33 OK 20251218171726_add_pins.sql (13.62ms)9642026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (12.21ms)9652026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (6.48ms)9662026/07/18 13:54:33 goose: successfully migrated database to version: 202606281200009672026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (6.28ms)9682026/07/18 13:54:33 OK 20251218171726_add_pins.sql (11.55ms)9692026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (12.17ms)9702026/07/18 13:54:33 goose: successfully migrated database to version: 202606281200009712026-07-18 13:54:33.443 UTC [1331] ERROR: relation "goose_db_version" does not exist at character 369722026-07-18 13:54:33.443 UTC [1331] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9732026-07-18 13:54:33.444 UTC [1332] ERROR: relation "goose_db_version" does not exist at character 369742026-07-18 13:54:33.444 UTC [1332] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9752026/07/18 13:54:33 OK 1_commit_pending_closure.sql (21.42ms)9762026/07/18 13:54:33 OK 1_commit_pending_closure.sql (21.77ms)9772026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (31.67ms)9782026/07/18 13:54:33 goose: successfully migrated database to version: 202606281200009792026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (34.09ms)9802026/07/18 13:54:33 goose: successfully migrated database to version: 202606281200009812026/07/18 13:54:33 OK 2_object_stats_trigger.sql (9.21ms)9822026/07/18 13:54:33 goose: up to current file version: 29832026/07/18 13:54:33 OK 2_object_stats_trigger.sql (7.49ms)9842026/07/18 13:54:33 goose: up to current file version: 29852026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (36.19ms)9862026/07/18 13:54:33 goose: successfully migrated database to version: 202606281200009872026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (35.52ms)9882026/07/18 13:54:33 goose: successfully migrated database to version: 202606281200009892026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (33.9ms)9902026/07/18 13:54:33 goose: successfully migrated database to version: 202606281200009912026/07/18 13:54:33 OK 1_commit_pending_closure.sql (9.22ms)9922026/07/18 13:54:33 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"993--- PASS: TestService_AuthMiddleware (0.43s)9942026/07/18 13:54:33 OK 1_commit_pending_closure.sql (9.27ms)9952026/07/18 13:54:33 OK 1_commit_pending_closure.sql (8.32ms)996{"timestamp":"2026-07-18T13:54:33.466391108Z","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(759)"}9972026/07/18 13:54:33 OK 2_object_stats_trigger.sql (6.35ms)998--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.43s)9992026/07/18 13:54:33 goose: up to current file version: 210002026/07/18 13:54:33 OK 20251218171726_add_pins.sql (42.08ms)10012026/07/18 13:54:33 OK 1_commit_pending_closure.sql (8.62ms)10022026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (41.33ms)10032026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000010042026/07/18 13:54:33 OK 1_commit_pending_closure.sql (8.35ms)10052026/07/18 13:54:33 OK 2_object_stats_trigger.sql (5.77ms)10062026/07/18 13:54:33 goose: up to current file version: 210072026/07/18 13:54:33 OK 20251218171726_add_pins.sql (44.93ms)10082026/07/18 13:54:33 OK 2_object_stats_trigger.sql (7.62ms)10092026/07/18 13:54:33 goose: up to current file version: 210102026/07/18 13:54:33 INFO Created nix-cache-info in bucket bucket=bucket61011--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.45s)10122026/07/18 13:54:33 OK 2_object_stats_trigger.sql (17.4ms)10132026/07/18 13:54:33 goose: up to current file version: 210142026/07/18 13:54:33 OK 2_object_stats_trigger.sql (17.16ms)10152026/07/18 13:54:33 goose: up to current file version: 21016=== NAME TestNARDeduplicationMetadataUploadBug1017 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3243253882/001/store/3pvbl54iqibxv3sfw095m8dv7mr8xa5q-file1.txt10182026/07/18 13:54:33 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.911493ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures10192026/07/18 13:54:33 OK 1_commit_pending_closure.sql (98.62ms)10202026-07-18 13:54:33.569 UTC [1334] ERROR: relation "goose_db_version" does not exist at character 3610212026-07-18 13:54:33.569 UTC [1334] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10222026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (101.91ms)10232026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000010242026/07/18 13:54:33 OK 20241026095416_initial_model.sql (153.73ms)10252026/07/18 13:54:33 OK 20241026095416_initial_model.sql (158.73ms)10262026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (106.74ms)10272026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000010282026/07/18 13:54:33 OK 20241026095416_initial_model.sql (160.79ms)1029--- PASS: TestReadProxy404 (0.58s)1030--- PASS: TestReadProxyHead (0.58s)1031--- PASS: TestReadProxyNarStreaming (0.58s)10322026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (27.95ms)10332026/07/18 13:54:33 OK 1_commit_pending_closure.sql (32.29ms)10342026/07/18 13:54:33 OK 2_object_stats_trigger.sql (36.54ms)10352026/07/18 13:54:33 goose: up to current file version: 210362026/07/18 13:54:33 OK 1_commit_pending_closure.sql (35.96ms)10372026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (36.14ms)10382026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (38.99ms)10392026/07/18 13:54:33 OK 2_object_stats_trigger.sql (10.04ms)10402026/07/18 13:54:33 goose: up to current file version: 210412026/07/18 13:54:33 OK 2_object_stats_trigger.sql (9.39ms)10422026/07/18 13:54:33 goose: up to current file version: 210432026/07/18 13:54:33 INFO Received uploads request method=POST path=/api/pending_closures10442026/07/18 13:54:33 INFO Received uploads request method=POST path=/api/pending_closures10452026/07/18 13:54:33 INFO Received uploads request method=POST path=/api/pending_closures1046--- PASS: TestService_healthCheckHandler (0.62s)10472026/07/18 13:54:33 INFO Received uploads request method=POST path=/api/pending_closures10482026/07/18 13:54:33 OK 20251218171726_add_pins.sql (34.36ms)10492026/07/18 13:54:33 OK 20251218171726_add_pins.sql (32.63ms)10502026/07/18 13:54:33 OK 20251218171726_add_pins.sql (38.31ms)10512026/07/18 13:54:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10522026/07/18 13:54:33 INFO Uploading 3pvbl54iqibxv3sfw095m8dv7mr8xa5q-file1.txt (160B)10532026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (18.57ms)10542026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000010552026/07/18 13:54:33 OK 20241026095416_initial_model.sql (83.78ms)10562026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (11.53ms)10572026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000010582026/07/18 13:54:33 OK 1_commit_pending_closure.sql (6.92ms)10592026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (13.95ms)10602026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000010612026/07/18 13:54:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10622026/07/18 13:54:33 INFO Signed narinfos id=1 count=110632026/07/18 13:54:33 INFO Uploading 1 narinfos10642026/07/18 13:54:33 OK 20241026095416_initial_model.sql (91.31ms)10652026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (5.43ms)10662026/07/18 13:54:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10672026/07/18 13:54:33 OK 2_object_stats_trigger.sql (4.43ms)10682026/07/18 13:54:33 goose: up to current file version: 210692026/07/18 13:54:33 OK 1_commit_pending_closure.sql (6.59ms)10702026/07/18 13:54:33 OK 1_commit_pending_closure.sql (6.4ms)10712026/07/18 13:54:33 INFO Received uploads request method=POST path=/api/pending_closures10722026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (4.48ms)10732026/07/18 13:54:33 OK 2_object_stats_trigger.sql (4.12ms)10742026/07/18 13:54:33 goose: up to current file version: 210752026/07/18 13:54:33 OK 2_object_stats_trigger.sql (5.14ms)10762026/07/18 13:54:33 goose: up to current file version: 210772026/07/18 13:54:33 INFO Received uploads request method=POST path=/api/pending_closures10782026/07/18 13:54:33 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10792026/07/18 13:54:33 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1080--- PASS: TestService_NativeMTLS (0.68s)10812026-07-18 13:54:33.726 UTC [1406] ERROR: relation "goose_db_version" does not exist at character 3610822026-07-18 13:54:33.726 UTC [1406] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10832026-07-18 13:54:33.726 UTC [1408] ERROR: relation "goose_db_version" does not exist at character 3610842026-07-18 13:54:33.726 UTC [1408] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10852026-07-18 13:54:33.727 UTC [1409] ERROR: relation "goose_db_version" does not exist at character 3610862026-07-18 13:54:33.727 UTC [1409] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10872026-07-18 13:54:33.727 UTC [1407] ERROR: relation "goose_db_version" does not exist at character 3610882026-07-18 13:54:33.727 UTC [1407] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10892026-07-18 13:54:33.727 UTC [1411] ERROR: relation "goose_db_version" does not exist at character 3610902026-07-18 13:54:33.727 UTC [1411] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10912026-07-18 13:54:33.728 UTC [1410] ERROR: relation "goose_db_version" does not exist at character 3610922026-07-18 13:54:33.728 UTC [1410] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10932026/07/18 13:54:33 INFO Completed upload id=110942026/07/18 13:54:33 INFO Upload complete. (153ms)10952026-07-18 13:54:33.731 UTC [1414] ERROR: relation "goose_db_version" does not exist at character 3610962026-07-18 13:54:33.731 UTC [1414] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10972026-07-18 13:54:33.731 UTC [1415] ERROR: relation "goose_db_version" does not exist at character 3610982026-07-18 13:54:33.731 UTC [1415] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10992026-07-18 13:54:33.731 UTC [1413] ERROR: relation "goose_db_version" does not exist at character 3611002026-07-18 13:54:33.731 UTC [1413] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11012026-07-18 13:54:33.731 UTC [1412] ERROR: relation "goose_db_version" does not exist at character 3611022026-07-18 13:54:33.731 UTC [1412] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1103=== NAME TestNARDeduplicationMetadataUploadBug1104 metadata_upload_test.go:54: Retrieved narinfo from S3:1105 StorePath: /build/TestNARDeduplicationMetadataUploadBug3243253882/001/store/3pvbl54iqibxv3sfw095m8dv7mr8xa5q-file1.txt1106 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1107 Compression: zstd1108 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1109 NarSize: 1601110 References: 1111 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf11122026/07/18 13:54:33 OK 20251218171726_add_pins.sql (25.71ms)1113 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1114 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):11152026/07/18 13:54:33 OK 20241026095416_initial_model.sql (52.07ms)1116 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11172026/07/18 13:54:33 OK 20251218171726_add_pins.sql (38.89ms)11182026-07-18 13:54:33.752 UTC [1416] ERROR: relation "goose_db_version" does not exist at character 3611192026-07-18 13:54:33.752 UTC [1416] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11202026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (16.27ms)11212026/07/18 13:54:33 goose: successfully migrated database to version: 202606281200001122--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.72s)11232026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (5.97ms)11242026-07-18 13:54:33.760 UTC [1419] ERROR: relation "goose_db_version" does not exist at character 3611252026-07-18 13:54:33.760 UTC [1419] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11262026-07-18 13:54:33.760 UTC [1418] ERROR: relation "goose_db_version" does not exist at character 3611272026-07-18 13:54:33.760 UTC [1418] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11282026-07-18 13:54:33.760 UTC [1417] ERROR: relation "goose_db_version" does not exist at character 3611292026-07-18 13:54:33.760 UTC [1417] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11302026/07/18 13:54:33 OK 1_commit_pending_closure.sql (4.82ms)11312026-07-18 13:54:33.762 UTC [1421] ERROR: relation "goose_db_version" does not exist at character 3611322026-07-18 13:54:33.762 UTC [1421] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11332026/07/18 13:54:33 OK 2_object_stats_trigger.sql (2.75ms)11342026/07/18 13:54:33 goose: up to current file version: 211352026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (9.34ms)11362026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000011372026/07/18 13:54:33 OK 20241026095416_initial_model.sql (12.6ms)11382026/07/18 13:54:33 OK 20241026095416_initial_model.sql (12.85ms)11392026/07/18 13:54:33 OK 1_commit_pending_closure.sql (6.5ms)11402026/07/18 13:54:33 OK 20241026095416_initial_model.sql (14.4ms)11412026/07/18 13:54:33 OK 20251218171726_add_pins.sql (9.35ms)11422026-07-18 13:54:33.774 UTC [1423] ERROR: relation "goose_db_version" does not exist at character 3611432026-07-18 13:54:33.774 UTC [1423] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11442026-07-18 13:54:33.774 UTC [1422] ERROR: relation "goose_db_version" does not exist at character 3611452026-07-18 13:54:33.774 UTC [1422] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11462026-07-18 13:54:33.775 UTC [1425] ERROR: relation "goose_db_version" does not exist at character 3611472026-07-18 13:54:33.775 UTC [1425] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11482026-07-18 13:54:33.775 UTC [1424] ERROR: relation "goose_db_version" does not exist at character 3611492026-07-18 13:54:33.775 UTC [1424] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11502026-07-18 13:54:33.775 UTC [1426] ERROR: relation "goose_db_version" does not exist at character 3611512026-07-18 13:54:33.775 UTC [1426] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11522026/07/18 13:54:33 OK 20241026095416_initial_model.sql (13.25ms)11532026-07-18 13:54:33.777 UTC [1428] ERROR: relation "goose_db_version" does not exist at character 3611542026-07-18 13:54:33.777 UTC [1428] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11552026-07-18 13:54:33.777 UTC [1427] ERROR: relation "goose_db_version" does not exist at character 3611562026-07-18 13:54:33.777 UTC [1427] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11572026/07/18 13:54:33 OK 2_object_stats_trigger.sql (3.65ms)11582026-07-18 13:54:33.778 UTC [1429] ERROR: relation "goose_db_version" does not exist at character 3611592026-07-18 13:54:33.778 UTC [1429] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11602026/07/18 13:54:33 goose: up to current file version: 211612026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (3.77ms)11622026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (3.85ms)11632026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (4.29ms)11642026/07/18 13:54:33 OK 20241026095416_initial_model.sql (13.71ms)11652026/07/18 13:54:33 OK 20241026095416_initial_model.sql (14.63ms)11662026/07/18 13:54:33 OK 20241026095416_initial_model.sql (15.24ms)11672026/07/18 13:54:33 OK 20241026095416_initial_model.sql (15.36ms)11682026-07-18 13:54:33.780 UTC [1430] ERROR: relation "goose_db_version" does not exist at character 3611692026-07-18 13:54:33.780 UTC [1430] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11702026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (3.23ms)11712026/07/18 13:54:33 OK 20241026095416_initial_model.sql (14.77ms)11722026/07/18 13:54:33 OK 20241026095416_initial_model.sql (16.3ms)11732026/07/18 13:54:33 OK 20241026095416_initial_model.sql (13.15ms)11742026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (2.85ms)11752026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (3.33ms)11762026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (2.99ms)11772026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (3.31ms)11782026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (9.2ms)11792026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000011802026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (3.23ms)11812026/07/18 13:54:33 OK 20251218171726_add_pins.sql (6.43ms)11822026/07/18 13:54:33 OK 20251218171726_add_pins.sql (6.08ms)11832026/07/18 13:54:33 OK 20251218171726_add_pins.sql (6.18ms)11842026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (4.14ms)11852026/07/18 13:54:33 OK 20251218171726_add_pins.sql (5.57ms)11862026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (3.72ms)11872026-07-18 13:54:33.787 UTC [1431] ERROR: relation "goose_db_version" does not exist at character 3611882026-07-18 13:54:33.787 UTC [1431] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11892026/07/18 13:54:33 OK 20251218171726_add_pins.sql (5.24ms)11902026-07-18 13:54:33.788 UTC [1432] ERROR: relation "goose_db_version" does not exist at character 3611912026-07-18 13:54:33.788 UTC [1432] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11922026/07/18 13:54:33 OK 20251218171726_add_pins.sql (5.6ms)11932026/07/18 13:54:33 OK 1_commit_pending_closure.sql (4.96ms)11942026/07/18 13:54:33 OK 20251218171726_add_pins.sql (6.14ms)11952026-07-18 13:54:33.789 UTC [1433] ERROR: relation "goose_db_version" does not exist at character 3611962026-07-18 13:54:33.789 UTC [1433] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11972026-07-18 13:54:33.789 UTC [1434] ERROR: relation "goose_db_version" does not exist at character 3611982026-07-18 13:54:33.789 UTC [1434] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11992026/07/18 13:54:33 OK 20251218171726_add_pins.sql (5.84ms)12002026/07/18 13:54:33 OK 20251218171726_add_pins.sql (6.49ms)12012026/07/18 13:54:33 OK 20251218171726_add_pins.sql (5.64ms)12022026/07/18 13:54:33 OK 2_object_stats_trigger.sql (2.58ms)12032026/07/18 13:54:33 goose: up to current file version: 212042026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (7.03ms)12052026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000012062026/07/18 13:54:33 OK 20251218171726_add_pins.sql (6.02ms)12072026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (6.91ms)12082026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000012092026/07/18 13:54:33 OK 20241026095416_initial_model.sql (12.91ms)12102026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (7.65ms)12112026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000012122026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (6.79ms)12132026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000012142026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (6.96ms)12152026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000012162026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (7.04ms)12172026/07/18 13:54:33 goose: successfully migrated database to version: 202606281200001218--- PASS: TestService_Rustfstest (0.76s)12192026/07/18 13:54:33 OK 1_commit_pending_closure.sql (4.3ms)12202026/07/18 13:54:33 OK 20241026095416_initial_model.sql (17.48ms)12212026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (8.16ms)12222026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000012232026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (4.31ms)12242026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (7.43ms)12252026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000012262026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (7.6ms)12272026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000012282026/07/18 13:54:33 OK 1_commit_pending_closure.sql (4.83ms)12292026/07/18 13:54:33 OK 1_commit_pending_closure.sql (4.55ms)12302026/07/18 13:54:33 OK 1_commit_pending_closure.sql (4.41ms)12312026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (6.62ms)12322026/07/18 13:54:33 goose: successfully migrated database to version: 202606281200001233=== NAME TestNARDeduplicationMetadataUploadBug12342026/07/18 13:54:33 OK 2_object_stats_trigger.sql (2.34ms)1235 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3243253882/001/store/l8spk21nq4akvgnfqi3cccdmsn0q4rag-file2.txt12362026/07/18 13:54:33 goose: up to current file version: 212372026/07/18 13:54:33 OK 20241026095416_initial_model.sql (19.36ms)12382026/07/18 13:54:33 OK 2_object_stats_trigger.sql (2ms)12392026/07/18 13:54:33 goose: up to current file version: 212402026/07/18 13:54:33 OK 2_object_stats_trigger.sql (1.81ms)12412026/07/18 13:54:33 goose: up to current file version: 212422026/07/18 13:54:33 OK 1_commit_pending_closure.sql (5.52ms)12432026/07/18 13:54:33 OK 1_commit_pending_closure.sql (4.38ms)12442026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (7.84ms)12452026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000012462026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (3.38ms)12472026/07/18 13:54:33 OK 2_object_stats_trigger.sql (2.42ms)12482026/07/18 13:54:33 goose: up to current file version: 212492026/07/18 13:54:33 OK 1_commit_pending_closure.sql (3.7ms)12502026/07/18 13:54:33 OK 1_commit_pending_closure.sql (4.19ms)12512026/07/18 13:54:33 OK 20241026095416_initial_model.sql (19.55ms)12522026/07/18 13:54:33 OK 1_commit_pending_closure.sql (3.77ms)12532026/07/18 13:54:33 OK 1_commit_pending_closure.sql (4.63ms)12542026/07/18 13:54:33 OK 2_object_stats_trigger.sql (2.31ms)12552026/07/18 13:54:33 goose: up to current file version: 212562026/07/18 13:54:33 OK 20251218171726_add_pins.sql (5.69ms)12572026/07/18 13:54:33 OK 2_object_stats_trigger.sql (2.43ms)12582026/07/18 13:54:33 goose: up to current file version: 212592026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (3.17ms)12602026/07/18 13:54:33 OK 2_object_stats_trigger.sql (2.41ms)12612026/07/18 13:54:33 goose: up to current file version: 212622026/07/18 13:54:33 OK 2_object_stats_trigger.sql (2.17ms)12632026/07/18 13:54:33 goose: up to current file version: 212642026/07/18 13:54:33 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"12652026/07/18 13:54:33 OK 2_object_stats_trigger.sql (2.15ms)12662026/07/18 13:54:33 goose: up to current file version: 212672026/07/18 13:54:33 OK 20241026095416_initial_model.sql (14.07ms)12682026/07/18 13:54:33 WARN mTLS auth: bound subjects configured but subject DN unavailable12692026/07/18 13:54:33 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1270--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.76s)12712026/07/18 13:54:33 OK 20241026095416_initial_model.sql (14.16ms)12722026/07/18 13:54:33 OK 2_object_stats_trigger.sql (2.46ms)12732026/07/18 13:54:33 goose: up to current file version: 212742026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (4.22ms)12752026/07/18 13:54:33 OK 20241026095416_initial_model.sql (13.31ms)12762026/07/18 13:54:33 OK 1_commit_pending_closure.sql (4.71ms)12772026/07/18 13:54:33 OK 20241026095416_initial_model.sql (12.4ms)12782026/07/18 13:54:33 OK 20241026095416_initial_model.sql (12.98ms)12792026/07/18 13:54:33 OK 20241026095416_initial_model.sql (13.88ms)12802026/07/18 13:54:33 OK 20251218171726_add_pins.sql (5.45ms)12812026/07/18 13:54:33 INFO Received uploads request method=POST path=/api/pending_closures12822026/07/18 13:54:33 INFO Created nix-cache-info in bucket bucket=bucket1812832026/07/18 13:54:33 OK 2_object_stats_trigger.sql (1.98ms)12842026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (3.45ms)12852026/07/18 13:54:33 goose: up to current file version: 212862026/07/18 13:54:33 OK 20241026095416_initial_model.sql (13.69ms)12872026/07/18 13:54:33 OK 20241026095416_initial_model.sql (16.51ms)1288=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token12892026/07/18 13:54:33 OK 20251218171726_add_pins.sql (5.03ms)1290=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token12912026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (6.16ms)1292=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected12932026/07/18 13:54:33 goose: successfully migrated database to version: 202606281200001294=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected12952026/07/18 13:54:33 INFO Created nix-cache-info in bucket bucket=bucket221296=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1297=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected12982026/07/18 13:54:33 INFO Created nix-cache-info in bucket bucket=bucket251299=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1300=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1301=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1302=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected13032026/07/18 13:54:33 OK 20241026095416_initial_model.sql (13.83ms)1304=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured13052026/07/18 13:54:33 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]13062026/07/18 13:54:33 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1307=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected13082026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)1309--- PASS: TestService_ReadAuthMiddleware (0.77s)13102026/07/18 13:54:33 OK 20251218171726_add_pins.sql (6.47ms)13112026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (3.23ms)13122026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (2.87ms)13132026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (6.5ms)13142026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000013152026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (3.91ms)13162026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (4.25ms)13172026/07/18 13:54:33 OK 1_commit_pending_closure.sql (3.86ms)13182026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (2.77ms)13192026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (2.88ms)13202026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (3.12ms)13212026/07/18 13:54:33 INFO OIDC auth successful provider=test13222026/07/18 13:54:33 WARN Authentication failed token_preview=eyJhbGciOi...-D4RbXkXeg 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]13232026/07/18 13:54:33 OK 2_object_stats_trigger.sql (2.11ms)13242026/07/18 13:54:33 goose: up to current file version: 213252026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (6.6ms)13262026/07/18 13:54:33 goose: successfully migrated database to version: 202606281200001327--- PASS: TestService_AuthMiddleware_OIDC (0.77s)1328 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1329 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1330 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)1331 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)13322026/07/18 13:54:33 OK 20241026095416_initial_model.sql (12.5ms)13332026/07/18 13:54:33 OK 20251218171726_add_pins.sql (7.73ms)13342026/07/18 13:54:33 OK 20251218171726_add_pins.sql (4.6ms)13352026/07/18 13:54:33 OK 1_commit_pending_closure.sql (5.21ms)13362026/07/18 13:54:33 OK 20251218171726_add_pins.sql (6.43ms)13372026/07/18 13:54:33 OK 20241026095416_initial_model.sql (13.6ms)13382026/07/18 13:54:33 OK 20241026095416_initial_model.sql (13.67ms)13392026/07/18 13:54:33 OK 20251218171726_add_pins.sql (5.47ms)13402026/07/18 13:54:33 OK 20251218171726_add_pins.sql (6.74ms)13412026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (8.27ms)13422026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000013432026/07/18 13:54:33 OK 20251218171726_add_pins.sql (8.79ms)13442026/07/18 13:54:33 OK 20251218171726_add_pins.sql (6.41ms)13452026/07/18 13:54:33 OK 20251218171726_add_pins.sql (6.75ms)13462026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (1.95ms)13472026/07/18 13:54:33 OK 1_commit_pending_closure.sql (4ms)13482026/07/18 13:54:33 OK 20251218171726_add_pins.sql (6.48ms)13492026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (4.01ms)13502026/07/18 13:54:33 OK 2_object_stats_trigger.sql (2.38ms)13512026/07/18 13:54:33 goose: up to current file version: 213522026/07/18 13:54:33 INFO Created nix-cache-info in bucket bucket=bucket2913532026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)13542026/07/18 13:54:33 OK 2_object_stats_trigger.sql (4.46ms)13552026/07/18 13:54:33 goose: up to current file version: 213562026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (5.79ms)13572026/07/18 13:54:33 OK 1_commit_pending_closure.sql (5.77ms)13582026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000013592026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (7.95ms)13602026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000013612026/07/18 13:54:33 OK 20251218171726_add_pins.sql (6.02ms)13622026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (10.15ms)13632026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (6.97ms)13642026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000013652026/07/18 13:54:33 OK 20251218171726_add_pins.sql (5.72ms)13662026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (5.9ms)13672026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000013682026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000013692026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (7.41ms)13702026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000013712026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (7.54ms)13722026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (12.34ms)13732026/07/18 13:54:33 OK 2_object_stats_trigger.sql (2.09ms)13742026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (8.63ms)13752026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000013762026/07/18 13:54:33 goose: successfully migrated database to version: 202606281200001377--- PASS: TestObjectStatsTrigger (0.79s)13782026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000013792026/07/18 13:54:33 goose: up to current file version: 213802026/07/18 13:54:33 OK 20241026095416_initial_model.sql (22.2ms)13812026/07/18 13:54:33 OK 1_commit_pending_closure.sql (6.77ms)13822026/07/18 13:54:33 OK 1_commit_pending_closure.sql (6.29ms)13832026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (6.5ms)13842026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000013852026/07/18 13:54:33 OK 20251218171726_add_pins.sql (7.62ms)1386--- PASS: TestReadProxyInvalidPath (0.80s)13872026/07/18 13:54:33 OK 1_commit_pending_closure.sql (5.93ms)13882026/07/18 13:54:33 OK 2_object_stats_trigger.sql (1.65ms)13892026/07/18 13:54:33 goose: up to current file version: 213902026/07/18 13:54:33 OK 1_commit_pending_closure.sql (3.58ms)13912026/07/18 13:54:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13922026/07/18 13:54:33 OK 1_commit_pending_closure.sql (3.42ms)13932026/07/18 13:54:33 OK 1_commit_pending_closure.sql (3.52ms)13942026/07/18 13:54:33 OK 2_object_stats_trigger.sql (1.33ms)13952026/07/18 13:54:33 OK 1_commit_pending_closure.sql (2.98ms)1396--- PASS: TestMetricsInventory (0.79s)13972026/07/18 13:54:33 OK 1_commit_pending_closure.sql (3.52ms)13982026/07/18 13:54:33 goose: up to current file version: 213992026/07/18 13:54:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14002026/07/18 13:54:33 OK 1_commit_pending_closure.sql (3.09ms)14012026/07/18 13:54:33 OK 2_object_stats_trigger.sql (1.34ms)14022026/07/18 13:54:33 goose: up to current file version: 214032026/07/18 13:54:33 OK 2_object_stats_trigger.sql (1.48ms)14042026/07/18 13:54:33 goose: up to current file version: 214052026/07/18 13:54:33 OK 2_object_stats_trigger.sql (1.5ms)14062026/07/18 13:54:33 goose: up to current file version: 214072026/07/18 13:54:33 OK 2_object_stats_trigger.sql (1.57ms)14082026/07/18 13:54:33 goose: up to current file version: 214092026/07/18 13:54:33 OK 2_object_stats_trigger.sql (1.27ms)14102026/07/18 13:54:33 goose: up to current file version: 214112026/07/18 13:54:33 OK 2_object_stats_trigger.sql (1.44ms)14122026/07/18 13:54:33 goose: up to current file version: 214132026/07/18 13:54:33 INFO Received uploads request method=POST path=/api/pending_closures14142026/07/18 13:54:33 OK 2_object_stats_trigger.sql (1.37ms)14152026/07/18 13:54:33 goose: up to current file version: 214162026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (5.15ms)14172026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000014182026/07/18 13:54:33 OK 1_commit_pending_closure.sql (3.04ms)1419{"timestamp":"2026-07-18T13:54:33.84217821Z","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(757)"}14202026/07/18 13:54:33 OK 20251210153512_drop_unused_gin_index.sql (3.18ms)1421{"timestamp":"2026-07-18T13:54:33.84224555Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket24, 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(757)"}14222026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (6.29ms)14232026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000014242026/07/18 13:54:33 OK 2_object_stats_trigger.sql (1.15ms)14252026/07/18 13:54:33 goose: up to current file version: 21426--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.80s)14272026/07/18 13:54:33 INFO Received uploads request method=POST path=/api/pending_closures14282026/07/18 13:54:33 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst14292026/07/18 13:54:33 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=NDA4MDNjMjAtZmQwZi00MWUwLWFjMWMtMGVmMjFhOWY3MDZhLmNmYTdhZGI5LTY3MWYtNDcxYy04ZWM5LTIyY2I5ZjFkNjgyNHgxNzg0MzgyODczODE3NjkwNzkx1430--- PASS: TestCompleteMultipartUnregistered (0.80s)14312026/07/18 13:54:33 INFO Received uploads request method=POST path=/api/pending_closures1432--- PASS: TestReadProxyDisabled (0.80s)14332026/07/18 13:54:33 OK 1_commit_pending_closure.sql (2.51ms)14342026/07/18 13:54:33 INFO Received uploads request method=POST path=/api/pending_closures14352026/07/18 13:54:33 OK 1_commit_pending_closure.sql (3.27ms)1436--- PASS: TestCacheStatsHandler (0.80s)14372026/07/18 13:54:33 OK 2_object_stats_trigger.sql (1.32ms)14382026/07/18 13:54:33 goose: up to current file version: 214392026/07/18 13:54:33 INFO Created nix-cache-info in bucket bucket=bucket3914402026/07/18 13:54:33 OK 20251218171726_add_pins.sql (5.68ms)14412026/07/18 13:54:33 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDA4MDNjMjAtZmQwZi00MWUwLWFjMWMtMGVmMjFhOWY3MDZhLmNmYTdhZGI5LTY3MWYtNDcxYy04ZWM5LTIyY2I5ZjFkNjgyNHgxNzg0MzgyODczODE3NjkwNzkx parts=11442--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.80s)14432026/07/18 13:54:33 OK 2_object_stats_trigger.sql (1.22ms)14442026/07/18 13:54:33 goose: up to current file version: 214452026/07/18 13:54:33 OK 20260628120000_add_object_size_and_stats.sql (6.03ms)14462026/07/18 13:54:33 goose: successfully migrated database to version: 2026062812000014472026/07/18 13:54:33 INFO Received cleanup request method=DELETE path=/api/pending_closures14482026/07/18 13:54:33 INFO Received uploads request method=POST path=/api/pending_closures1449--- PASS: TestReadProxyRangeRequest (0.81s)1450--- PASS: TestReadProxyNarinfo (0.82s)14512026/07/18 13:54:33 INFO Aborted multipart uploads count=014522026/07/18 13:54:33 OK 1_commit_pending_closure.sql (3.32ms)14532026/07/18 13:54:33 INFO Received uploads request method=POST path=/api/pending_closures1454=== NAME TestClientMultipleUploads14552026/07/18 13:54:33 OK 2_object_stats_trigger.sql (1.25ms)1456 client_integration_test.go:338: Created store path 0: /build/TestClientMultipleUploads1353804234/001/store/i7bvccp4g5mfn2rqlb6gs0z63s1gcn02-test-file-0.txt14572026/07/18 13:54:33 goose: up to current file version: 214582026/07/18 13:54:33 INFO Aborted multipart uploads count=01459--- PASS: TestReadProxyConditionalGet (0.82s)14602026/07/18 13:54:33 WARN Force mode enabled - objects will be deleted immediately without grace period14612026/07/18 13:54:33 INFO Received cleanup request method=DELETE path=/api/pending_closures14622026/07/18 13:54:33 INFO Received cleanup request method=DELETE path=/api/pending_closures14632026/07/18 13:54:33 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=014642026/07/18 13:54:33 INFO Vacuumed table table=pending_closures14652026/07/18 13:54:33 INFO Aborted multipart uploads count=114662026/07/18 13:54:33 INFO Vacuumed table table=pending_objects14672026/07/18 13:54:33 INFO Vacuumed table table=multipart_uploads14682026/07/18 13:54:33 INFO Vacuumed table table=closures14692026/07/18 13:54:33 INFO Vacuumed table table=objects14702026/07/18 13:54:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14712026/07/18 13:54:33 INFO Aborted multipart uploads count=114722026-07-18 13:54:33.871 UTC [1432] ERROR: Closure does not exist: id=114732026-07-18 13:54:33.871 UTC [1432] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE14742026-07-18 13:54:33.871 UTC [1432] STATEMENT: -- name: CommitPendingClosure :exec1475 SELECT commit_pending_closure($1::bigint)1476 1477--- PASS: TestService_cleanupPendingClosuresHandler (0.83s)1478--- PASS: TestMultipartCleanup (0.84s)1479--- PASS: TestGCMetrics (0.83s)1480=== NAME TestClientIntegration1481 client_integration_test.go:276: Created store path: /build/TestClientIntegration1745119953/002/store/21a2zw64xrvkgf4war5c4mhbsnnsqgb6-test-file.txt1482--- PASS: TestResurrectedObjectNotDeleted (0.86s)1483=== NAME TestClientMultipleUploads1484 client_integration_test.go:338: Created store path 1: /build/TestClientMultipleUploads1353804234/001/store/cxwh2dcw5i050gwfn9jfsi9pab334fyj-test-file-1.txt1485=== NAME TestPinProtectsFromGC1486 client_integration_test.go:646: Pinned store path: /build/TestPinProtectsFromGC1339669489/001/store/8q1dp38a3jgjwqb7mkiyjjg0sxm92jyj-pinned-file.txt1487 client_integration_test.go:647: Unpinned store path: /build/TestPinProtectsFromGC1339669489/001/store/kisnp8vyvh21qy41pcrmdbpbbg10ikfq-unpinned-file.txt14882026/07/18 13:54:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1489=== NAME TestClientWithDependencies1490 client_integration_test.go:593: Built derivation: /build/TestClientWithDependencies2857166424/001/store/k2j48kmybm97vsqcjnfm5in8x0p40asm-test-script14912026/07/18 13:54:33 INFO Received uploads request method=POST path=/api/pending_closures14922026/07/18 13:54:33 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14932026/07/18 13:54:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14942026/07/18 13:54:33 INFO Signed narinfos id=2 count=114952026/07/18 13:54:33 INFO Uploading 1 narinfos14962026/07/18 13:54:33 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=753.957174ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures14972026/07/18 13:54:33 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14982026/07/18 13:54:33 INFO Completed upload id=21499=== NAME TestClientCADerivations1500 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2503571063/001/store/a86qyqcqwsjfk662q3hanqzwdnnkpk43-ca-test15012026/07/18 13:54:33 INFO Upload complete. (97ms)1502=== NAME TestNARDeduplicationMetadataUploadBug1503 metadata_upload_test.go:76: Retrieved narinfo from S3:1504 StorePath: /build/TestNARDeduplicationMetadataUploadBug3243253882/001/store/l8spk21nq4akvgnfqi3cccdmsn0q4rag-file2.txt1505 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1506 Compression: zstd1507 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1508 NarSize: 1601509 References: 1510 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1511 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1512 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1513 {"version":1,"root":{"type":"regular","size":44}}1514--- PASS: TestNARDeduplicationMetadataUploadBug (0.91s)1515=== NAME TestClientMultipleUploads1516 client_integration_test.go:338: Created store path 2: /build/TestClientMultipleUploads1353804234/001/store/9rz4awi203h1zmc54mr43q6ky97gcf5r-test-file-2.txt15172026/07/18 13:54:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1518=== NAME TestClientWithDependencies1519 client_integration_test.go:595: Found 1 dependencies (including self)15202026/07/18 13:54:33 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NDA4MDNjMjAtZmQwZi00MWUwLWFjMWMtMGVmMjFhOWY3MDZhLmE5ZjQ3MmViLWM5MzMtNGUwZi04NjEzLTgwYTdkNmUxZjc4NngxNzg0MzgyODczNjkxMTU5NzY4 parts=1015212026/07/18 13:54:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15222026/07/18 13:54:33 INFO Completed upload id=115232026/07/18 13:54:33 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015242026/07/18 13:54:33 INFO Received uploads request method=POST path=/api/pending_closures1525=== NAME TestClientCADerivations1526 client_ca_test.go:139: Found 1 dependencies (including self)15272026/07/18 13:54:33 INFO Starting cleanup of old closures method=DELETE path=/api/closures15282026/07/18 13:54:33 INFO Aborted multipart uploads count=015292026/07/18 13:54:34 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=015302026/07/18 13:54:34 INFO Vacuumed table table=pending_closures15312026/07/18 13:54:34 INFO Vacuumed table table=pending_objects15322026/07/18 13:54:34 INFO Vacuumed table table=multipart_uploads15332026/07/18 13:54:34 INFO Vacuumed table table=closures15342026/07/18 13:54:34 INFO Vacuumed table table=objects1535--- PASS: TestUploadHandlersRejectOversizedBody (0.18s)1536 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)1537 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1538 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.80s)15392026/07/18 13:54:34 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"15402026/07/18 13:54:34 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001541--- PASS: TestService_createPendingClosureHandler (1.00s)15422026/07/18 13:54:34 INFO Received uploads request method=POST path=/api/pending_closures15432026/07/18 13:54:34 INFO Received uploads request method=POST path=/api/pending_closures15442026/07/18 13:54:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15452026/07/18 13:54:34 INFO Uploading 21a2zw64xrvkgf4war5c4mhbsnnsqgb6-test-file.txt (152B)15462026/07/18 13:54:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15472026/07/18 13:54:34 INFO Uploading 8q1dp38a3jgjwqb7mkiyjjg0sxm92jyj-pinned-file.txt (128B)15482026/07/18 13:54:34 INFO Received uploads request method=POST path=/api/pending_closures15492026/07/18 13:54:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15502026/07/18 13:54:34 INFO Signed narinfos id=1 count=115512026/07/18 13:54:34 INFO Uploading 1 narinfos15522026/07/18 13:54:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15532026/07/18 13:54:34 INFO Signed narinfos id=1 count=115542026/07/18 13:54:34 INFO Uploading 1 narinfos15552026/07/18 13:54:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15562026/07/18 13:54:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15572026/07/18 13:54:34 INFO Uploading k2j48kmybm97vsqcjnfm5in8x0p40asm-test-script (136B)15582026/07/18 13:54:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1559=== NAME TestOrphanedObjectsGC1560 orphaned_objects_gc_test.go:290: GC Test Summary:1561 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1562 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1563 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1564 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1565 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1566--- PASS: TestOrphanedObjectsGC (1.03s)15672026/07/18 13:54:34 INFO Completed upload id=115682026/07/18 13:54:34 INFO Upload complete. (123ms)1569--- PASS: TestGCBugBareHashReferences (1.03s)15702026/07/18 13:54:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1571=== NAME TestClientIntegration1572 client_integration_test.go:292: Retrieved narinfo from S3:1573 StorePath: /build/TestClientIntegration1745119953/002/store/21a2zw64xrvkgf4war5c4mhbsnnsqgb6-test-file.txt1574 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1575 Compression: zstd1576 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11577 NarSize: 1521578 References: 1579 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk115802026/07/18 13:54:34 INFO Signed narinfos id=1 count=115812026/07/18 13:54:34 INFO Uploading 1 narinfos15822026/07/18 13:54:34 INFO Completed upload id=115832026/07/18 13:54:34 INFO Upload complete. (126ms)1584 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1585 client_integration_test.go:293: Decompressed .ls content (64 bytes):1586 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1587 client_integration_test.go:296: Testing garbage collection...15882026/07/18 13:54:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15892026/07/18 13:54:34 INFO Completed upload id=115902026/07/18 13:54:34 INFO Upload complete. (77ms)1591=== NAME TestClientWithDependencies1592 client_integration_test.go:597: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2857166424/001/store) requires matching store prefix1593--- PASS: TestClientWithDependencies (1.05s)15942026/07/18 13:54:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15952026/07/18 13:54:34 INFO Received uploads request method=POST path=/api/pending_closures15962026/07/18 13:54:34 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NDA4MDNjMjAtZmQwZi00MWUwLWFjMWMtMGVmMjFhOWY3MDZhLjU1MmY5N2QxLWE3MjMtNGZkYi1hOWM0LTI1MTUyMzM1YWM2NXgxNzg0MzgyODczODUzNDY3ODUz parts=1015972026/07/18 13:54:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15982026/07/18 13:54:34 INFO Received uploads request method=POST path=/api/pending_closures15992026/07/18 13:54:34 INFO Received uploads request method=POST path=/api/pending_closures16002026/07/18 13:54:34 INFO Received uploads request method=POST path=/api/pending_closures16012026/07/18 13:54:34 INFO Completed upload id=116022026/07/18 13:54:34 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16032026/07/18 13:54:34 INFO Uploading i7bvccp4g5mfn2rqlb6gs0z63s1gcn02-test-file-0.txt (160B)16042026/07/18 13:54:34 INFO Uploading 9rz4awi203h1zmc54mr43q6ky97gcf5r-test-file-2.txt (160B)16052026/07/18 13:54:34 INFO Uploading cxwh2dcw5i050gwfn9jfsi9pab334fyj-test-file-1.txt (160B)16062026/07/18 13:54:34 INFO Received uploads request method=POST path=/api/pending_closures16072026/07/18 13:54:34 INFO Received uploads request method=POST path=/api/pending_closures16082026/07/18 13:54:34 INFO Starting cleanup of old closures method=DELETE path=/api/closures16092026/07/18 13:54:34 INFO Garbage collection started16102026/07/18 13:54:34 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16112026/07/18 13:54:34 WARN Found objects in DB but missing from S3, will re-upload count=116122026/07/18 13:54:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16132026/07/18 13:54:34 INFO Uploading a86qyqcqwsjfk662q3hanqzwdnnkpk43-ca-test (144B)1614--- PASS: TestService_verifyS3Integrity (1.08s)16152026/07/18 13:54:34 INFO Aborted multipart uploads count=016162026/07/18 13:54:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16172026/07/18 13:54:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16182026/07/18 13:54:34 INFO Signed narinfos id=1 count=116192026/07/18 13:54:34 INFO Signed narinfos id=1 count=116202026/07/18 13:54:34 INFO Uploading 1 narinfos16212026/07/18 13:54:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16222026/07/18 13:54:34 WARN Force mode enabled - objects will be deleted immediately without grace period16232026/07/18 13:54:34 INFO Signed narinfos id=2 count=116242026/07/18 13:54:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16252026/07/18 13:54:34 INFO Signed narinfos id=3 count=116262026/07/18 13:54:34 INFO Uploading 3 narinfos16272026/07/18 13:54:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16282026/07/18 13:54:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16292026/07/18 13:54:34 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16302026/07/18 13:54:34 INFO Completed upload id=116312026/07/18 13:54:34 INFO Upload complete. (123ms)16322026/07/18 13:54:34 INFO Completed upload id=216332026/07/18 13:54:34 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16342026/07/18 13:54:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16352026/07/18 13:54:34 INFO Completed upload id=316362026/07/18 13:54:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16372026/07/18 13:54:34 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NDA4MDNjMjAtZmQwZi00MWUwLWFjMWMtMGVmMjFhOWY3MDZhLjJiN2E1OGE2LTBjZjgtNDI5My1iZGFmLTgzMjkwYTI2ODZkNHgxNzg0MzgyODczODUxMDgzMDM4 parts=1216382026/07/18 13:54:34 INFO Completed upload id=11639=== NAME TestClientCADerivations16402026/07/18 13:54:34 INFO Upload complete. (159ms)1641 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2503571063/001/store/a86qyqcqwsjfk662q3hanqzwdnnkpk43-ca-test16422026/07/18 13:54:34 INFO Received uploads request method=POST path=/api/pending_closures1643 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1644 Compression: zstd1645 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1646 NarSize: 1441647 References: 1648 Deriver: /build/TestClientCADerivations2503571063/001/store/jr5cqdq4jln6n8xr3spai0ybpwjv3dpc-ca-test.drv1649 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1650 client_ca_test.go:185: Checking for realisation files in S3...1651=== NAME TestClientMultipleUploads1652 client_integration_test.go:349: Uploaded 3 paths in 202.211325ms1653--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.11s)1654=== NAME TestClientCADerivations1655 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1656 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16572026/07/18 13:54:34 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NDA4MDNjMjAtZmQwZi00MWUwLWFjMWMtMGVmMjFhOWY3MDZhLjEzZmE3NjBjLWQ4NGYtNDUzNy1hZGE5LTI2M2VhY2RlZWM5MXgxNzg0MzgyODczODUyNjg0ODkx parts=121658--- PASS: TestRedundantMultipartUpload (1.12s)1659--- PASS: TestClientMultipleUploads (1.13s)16602026/07/18 13:54:34 INFO Received uploads request method=POST path=/api/pending_closures16612026/07/18 13:54:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16622026/07/18 13:54:34 INFO Uploading kisnp8vyvh21qy41pcrmdbpbbg10ikfq-unpinned-file.txt (128B)16632026/07/18 13:54:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16642026/07/18 13:54:34 INFO Signed narinfos id=2 count=116652026/07/18 13:54:34 INFO Uploading 1 narinfos16662026/07/18 13:54:34 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16672026/07/18 13:54:34 INFO Completed upload id=216682026/07/18 13:54:34 INFO Upload complete. (103ms)16692026/07/18 13:54:34 INFO Received create pin request method=POST path=/api/pins/myapp16702026/07/18 13:54:34 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1339669489/001/store/8q1dp38a3jgjwqb7mkiyjjg0sxm92jyj-pinned-file.txt narinfo_key=8q1dp38a3jgjwqb7mkiyjjg0sxm92jyj.narinfo16712026/07/18 13:54:34 INFO Starting cleanup of old closures method=DELETE path=/api/closures16722026/07/18 13:54:34 INFO Garbage collection started16732026/07/18 13:54:34 INFO Aborted multipart uploads count=016742026/07/18 13:54:34 WARN Force mode enabled - objects will be deleted immediately without grace period1675=== NAME TestClientCADerivations1676 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1677 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1678 error: binary cache 's3://bucket29?endpoint=http://localhost:43997&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2503571063/001/store'1679 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11680--- PASS: TestClientCADerivations (1.25s)1681=== NAME TestOrphanedObjectsGCStressTest1682 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1683 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion16842026/07/18 13:54:34 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=016852026/07/18 13:54:34 INFO Vacuumed table table=pending_closures16862026/07/18 13:54:34 INFO Vacuumed table table=pending_objects16872026/07/18 13:54:34 INFO Vacuumed table table=multipart_uploads16882026/07/18 13:54:34 INFO Vacuumed table table=closures16892026/07/18 13:54:34 INFO Vacuumed table table=objects1690 orphaned_objects_gc_test.go:509: Stress test completed successfully:1691 orphaned_objects_gc_test.go:510: - Active objects preserved: 201692 orphaned_objects_gc_test.go:511: - Objects deleted: 2101693 orphaned_objects_gc_test.go:512: - Total GC'd: 2101694--- PASS: TestOrphanedObjectsGCStressTest (1.57s)16952026/07/18 13:54:34 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.44177576s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16962026/07/18 13:54:34 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=016972026/07/18 13:54:34 INFO Vacuumed table table=pending_closures16982026/07/18 13:54:34 INFO Vacuumed table table=pending_objects16992026/07/18 13:54:34 INFO Vacuumed table table=multipart_uploads17002026/07/18 13:54:34 INFO Vacuumed table table=closures17012026/07/18 13:54:34 INFO Vacuumed table table=objects17022026/07/18 13:54:36 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01703=== NAME TestClientIntegration1704 client_integration_test.go:303: Objects in database after GC:1705 client_integration_test.go:303: Successfully deleted all objects with GC --force1706--- PASS: TestClientIntegration (3.09s)1707--- PASS: TestClientErrorHandling (0.01s)1708 --- PASS: TestClientErrorHandling/InvalidStorePath (0.80s)1709 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.97s)1710 --- PASS: TestClientErrorHandling/ServerNotAvailable (3.09s)17112026/07/18 13:54:36 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01712=== NAME TestPinProtectsFromGC1713 client_integration_test.go:709: Pin successfully protected closure from garbage collection1714--- PASS: TestPinProtectsFromGC (3.24s)17152026/07/18 13:54:39 WARN Rate limiter enabled after throttle name=s3-test rate=517162026/07/18 13:54:39 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1717=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1718 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101719 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001720--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.76s)1721PASS17222026-07-18 13:54:40.498 UTC [309] LOG: received smart shutdown request17232026-07-18 13:54:40.502 UTC [309] LOG: background worker "logical replication launcher" (PID 319) exited with exit code 117242026-07-18 13:54:40.512 UTC [314] LOG: shutting down17252026-07-18 13:54:40.513 UTC [314] LOG: checkpoint starting: shutdown immediate17262026-07-18 13:54:41.905 UTC [314] LOG: checkpoint complete: wrote 8034 buffers (49.0%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 12 recycled; write=0.284 s, sync=1.095 s, total=1.393 s; sync files=14838, longest=0.002 s, average=0.001 s; distance=203939 kB, estimate=203939 kB; lsn=0/DE87F80, redo lsn=0/DE87F8017272026-07-18 13:54:41.992 UTC [309] LOG: database system is shut down1728Running OIDC tests...1729=== RUN TestGlobMatch1730=== PAUSE TestGlobMatch1731=== RUN TestAudienceForIssuer1732=== PAUSE TestAudienceForIssuer1733=== RUN TestValidateToken_ValidToken1734=== PAUSE TestValidateToken_ValidToken1735=== RUN TestValidateToken_WrongAudience1736=== PAUSE TestValidateToken_WrongAudience1737=== RUN TestValidateToken_Expired1738=== PAUSE TestValidateToken_Expired1739=== RUN TestValidateToken_BoundClaimsMismatch1740=== PAUSE TestValidateToken_BoundClaimsMismatch1741=== RUN TestValidateToken_BoundSubjectMismatch1742=== PAUSE TestValidateToken_BoundSubjectMismatch1743=== RUN TestValidateToken_MultipleProviders1744=== PAUSE TestValidateToken_MultipleProviders1745=== RUN TestValidateToken_NoMatchingProvider1746=== PAUSE TestValidateToken_NoMatchingProvider1747=== CONT TestGlobMatch1748=== RUN TestGlobMatch/foo_foo1749=== CONT TestValidateToken_NoMatchingProvider1750=== CONT TestValidateToken_Expired1751=== PAUSE TestGlobMatch/foo_foo1752=== CONT TestValidateToken_BoundClaimsMismatch1753=== CONT TestValidateToken_WrongAudience1754=== CONT TestValidateToken_ValidToken1755=== CONT TestAudienceForIssuer1756=== CONT TestValidateToken_BoundSubjectMismatch1757=== CONT TestValidateToken_MultipleProviders1758=== RUN TestGlobMatch/foo_bar1759=== PAUSE TestGlobMatch/foo_bar1760=== RUN TestGlobMatch/*_1761=== PAUSE TestGlobMatch/*_1762=== RUN TestGlobMatch/*_anything1763=== PAUSE TestGlobMatch/*_anything1764=== RUN TestGlobMatch/foo*_foo1765=== PAUSE TestGlobMatch/foo*_foo1766=== RUN TestGlobMatch/foo*_foobar1767=== PAUSE TestGlobMatch/foo*_foobar1768--- PASS: TestAudienceForIssuer (0.00s)1769=== RUN TestGlobMatch/foo*_bar1770=== PAUSE TestGlobMatch/foo*_bar1771=== RUN TestGlobMatch/*bar_bar1772=== PAUSE TestGlobMatch/*bar_bar1773=== RUN TestGlobMatch/*bar_foobar1774=== PAUSE TestGlobMatch/*bar_foobar1775=== RUN TestGlobMatch/*bar_foo1776=== PAUSE TestGlobMatch/*bar_foo1777=== RUN TestGlobMatch/foo*bar_foobar1778=== PAUSE TestGlobMatch/foo*bar_foobar1779=== RUN TestGlobMatch/foo*bar_foo123bar1780=== PAUSE TestGlobMatch/foo*bar_foo123bar1781=== RUN TestGlobMatch/foo*bar_foobarbaz1782=== PAUSE TestGlobMatch/foo*bar_foobarbaz1783=== RUN TestGlobMatch/*/*_foo/bar1784=== PAUSE TestGlobMatch/*/*_foo/bar1785=== RUN TestGlobMatch/*/*_foo1786=== PAUSE TestGlobMatch/*/*_foo1787=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1788=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1789=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01790=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01791=== RUN TestGlobMatch/refs/*/main_refs/heads/main1792=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1793=== RUN TestGlobMatch/fo?_foo1794=== PAUSE TestGlobMatch/fo?_foo1795=== RUN TestGlobMatch/fo?_fo1796=== PAUSE TestGlobMatch/fo?_fo1797=== RUN TestGlobMatch/fo?_fooo1798=== PAUSE TestGlobMatch/fo?_fooo1799=== RUN TestGlobMatch/?oo_foo1800=== PAUSE TestGlobMatch/?oo_foo1801=== RUN TestGlobMatch/?oo_boo1802=== PAUSE TestGlobMatch/?oo_boo1803=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1804=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1805=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1806=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1807=== CONT TestGlobMatch/foo_foo1808=== CONT TestGlobMatch/*bar_foo1809=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1810=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1811=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1812=== CONT TestGlobMatch/?oo_boo1813=== CONT TestGlobMatch/?oo_foo1814=== CONT TestGlobMatch/fo?_fooo1815=== CONT TestGlobMatch/fo?_fo1816=== CONT TestGlobMatch/fo?_foo1817=== CONT TestGlobMatch/refs/*/main_refs/heads/main1818=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01819=== CONT TestGlobMatch/*bar_foobar1820=== CONT TestGlobMatch/*/*_foo1821=== CONT TestGlobMatch/*/*_foo/bar1822=== CONT TestGlobMatch/foo*bar_foobarbaz1823=== CONT TestGlobMatch/foo*bar_foo123bar1824=== CONT TestGlobMatch/foo*bar_foobar1825=== CONT TestGlobMatch/foo*_foo1826=== CONT TestGlobMatch/*bar_bar1827=== CONT TestGlobMatch/foo*_bar1828=== CONT TestGlobMatch/foo*_foobar1829=== CONT TestGlobMatch/*_1830=== CONT TestGlobMatch/*_anything1831=== CONT TestGlobMatch/foo_bar1832--- PASS: TestGlobMatch (0.00s)1833 --- PASS: TestGlobMatch/foo_foo (0.00s)1834 --- PASS: TestGlobMatch/*bar_foo (0.00s)1835 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1836 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1837 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1838 --- PASS: TestGlobMatch/?oo_boo (0.00s)1839 --- PASS: TestGlobMatch/?oo_foo (0.00s)1840 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1841 --- PASS: TestGlobMatch/fo?_fo (0.00s)1842 --- PASS: TestGlobMatch/fo?_foo (0.00s)1843 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1844 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1845 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1846 --- PASS: TestGlobMatch/*/*_foo (0.00s)1847 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1848 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1849 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1850 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1851 --- PASS: TestGlobMatch/foo*_foo (0.00s)1852 --- PASS: TestGlobMatch/*bar_bar (0.00s)1853 --- PASS: TestGlobMatch/foo*_bar (0.00s)1854 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1855 --- PASS: TestGlobMatch/*_ (0.00s)1856 --- PASS: TestGlobMatch/*_anything (0.00s)1857 --- PASS: TestGlobMatch/foo_bar (0.00s)18582026/07/18 13:54:42 INFO OIDC provider initialized name=provider218592026/07/18 13:54:42 INFO OIDC provider initialized name=test18602026/07/18 13:54:42 INFO OIDC provider initialized name=test18612026/07/18 13:54:42 INFO OIDC provider initialized name=test18622026/07/18 13:54:42 INFO OIDC provider initialized name=test18632026/07/18 13:54:42 INFO OIDC provider initialized name=test18642026/07/18 13:54:42 INFO OIDC provider initialized name=provider118652026/07/18 13:54:42 INFO OIDC provider initialized name=provider11866--- PASS: TestValidateToken_ValidToken (0.01s)1867--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1868--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1869--- PASS: TestValidateToken_WrongAudience (0.01s)1870--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1871--- PASS: TestValidateToken_MultipleProviders (0.01s)1872--- PASS: TestValidateToken_Expired (0.01s)1873PASS1874Running hook tests...1875=== RUN TestSendPathsEmpty1876=== PAUSE TestSendPathsEmpty1877=== RUN TestQueueEnqueueAndFetch1878=== PAUSE TestQueueEnqueueAndFetch1879=== RUN TestQueueDeduplication1880=== PAUSE TestQueueDeduplication1881=== RUN TestQueueRemove1882=== PAUSE TestQueueRemove1883=== RUN TestQueueFetchBatchLimit1884=== PAUSE TestQueueFetchBatchLimit1885=== RUN TestQueueFetchRemoveLifecycle1886=== PAUSE TestQueueFetchRemoveLifecycle1887=== RUN TestQueueConcurrentWriters1888=== PAUSE TestQueueConcurrentWriters1889=== RUN TestServerClientIntegration1890=== PAUSE TestServerClientIntegration1891=== RUN TestServerQueueError1892=== PAUSE TestServerQueueError1893=== RUN TestGetListenerSocketActivation1894 server_test.go:210: === RUN TestGetListenerSocketActivation1895 --- PASS: TestGetListenerSocketActivation (0.00s)1896 PASS1897 1898--- PASS: TestGetListenerSocketActivation (0.03s)1899=== RUN TestWorkerUploadsAndRemoves1900=== PAUSE TestWorkerUploadsAndRemoves1901=== RUN TestWorkerSkipsGCdPaths1902=== PAUSE TestWorkerSkipsGCdPaths1903=== RUN TestWorkerPrunesClosureDeps1904=== PAUSE TestWorkerPrunesClosureDeps1905=== CONT TestSendPathsEmpty1906=== CONT TestServerQueueError1907=== CONT TestQueueFetchBatchLimit1908--- PASS: TestSendPathsEmpty (0.00s)1909=== CONT TestQueueRemove1910=== CONT TestQueueDeduplication1911=== CONT TestQueueEnqueueAndFetch1912=== CONT TestWorkerSkipsGCdPaths1913=== CONT TestWorkerPrunesClosureDeps19142026/07/18 13:54:43 ERROR Failed to queue paths error="permission denied" count=11915=== CONT TestQueueFetchRemoveLifecycle1916=== CONT TestWorkerUploadsAndRemoves1917=== CONT TestServerClientIntegration1918=== CONT TestQueueConcurrentWriters1919--- PASS: TestServerQueueError (0.00s)1920--- PASS: TestServerClientIntegration (0.00s)19212026/07/18 13:54:43 INFO Upload queue status pending=219222026/07/18 13:54:43 INFO Uploading batch count=11923--- PASS: TestQueueFetchBatchLimit (0.02s)19242026/07/18 13:54:43 INFO Upload queue status pending=21925--- PASS: TestQueueDeduplication (0.02s)19262026/07/18 13:54:43 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1600877950/002/nonexistent19272026/07/18 13:54:43 INFO Upload queue status pending=219282026/07/18 13:54:43 INFO Uploading batch count=21929--- PASS: TestQueueEnqueueAndFetch (0.02s)1930--- PASS: TestQueueFetchRemoveLifecycle (0.02s)19312026/07/18 13:54:43 INFO Uploading batch count=11932--- PASS: TestQueueRemove (0.02s)1933--- PASS: TestWorkerSkipsGCdPaths (0.07s)1934--- PASS: TestWorkerUploadsAndRemoves (0.07s)1935--- PASS: TestWorkerPrunesClosureDeps (0.07s)1936--- PASS: TestQueueConcurrentWriters (0.28s)1937PASS

succeeded niks3-go-unit-tests x86_64-linux.go-unit-tests · build #100 · raw

succeeded `niks3-go-unit-tests` `x86_64-linux.go-unit-tests` · build #100 · raw