niks3-go-unit-tests
aarch64-darwin.go-unit-tests
· build #104
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestCaseHackSuffix5=== PAUSE TestCaseHackSuffix6=== RUN TestPartSizeForNAR7=== PAUSE TestPartSizeForNAR8=== RUN TestUploadMultipart_SupersededByPeer9=== PAUSE TestUploadMultipart_SupersededByPeer10=== RUN TestDumpPathMatchesNix11=== PAUSE TestDumpPathMatchesNix12=== RUN TestDumpPathSingleFile13=== PAUSE TestDumpPathSingleFile14=== RUN TestDumpPathWriterError15=== PAUSE TestDumpPathWriterError16=== RUN TestEncodeNixBase3217=== PAUSE TestEncodeNixBase3218=== RUN TestEncodeNixBase32WithRealHash19=== PAUSE TestEncodeNixBase32WithRealHash20=== RUN TestConvertHashToNix3221=== PAUSE TestConvertHashToNix3222=== RUN TestGetStorePathHash23=== PAUSE TestGetStorePathHash24=== RUN TestPathInfoHashCompatibility25=== PAUSE TestPathInfoHashCompatibility26=== RUN TestParsePathInfoJSON27=== PAUSE TestParsePathInfoJSON28=== RUN TestParsePathInfoJSONMultiplePaths29=== PAUSE TestParsePathInfoJSONMultiplePaths30=== RUN TestPathInfoCACompatibility31=== PAUSE TestPathInfoCACompatibility32=== RUN TestRateLimiterFeedback33=== PAUSE TestRateLimiterFeedback34=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess35=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess36=== RUN TestResolveStorePath37=== PAUSE TestResolveStorePath38=== RUN TestDoWithRetry_BodyReplayedViaGetBody39=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody40=== RUN TestShellSplit41=== PAUSE TestShellSplit42=== RUN TestShellSplitErrors43=== PAUSE TestShellSplitErrors44=== RUN TestSetClientTLS45=== PAUSE TestSetClientTLS46=== RUN TestSetClientTLSDoesNotMutateDefaultTransport47=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport48=== RUN TestSetClientTLSErrors49=== PAUSE TestSetClientTLSErrors50=== RUN TestStaticToken51=== PAUSE TestStaticToken52=== RUN TestFileTokenReadsAndCaches53=== PAUSE TestFileTokenReadsAndCaches54=== RUN TestFileTokenMissing55=== PAUSE TestFileTokenMissing56=== RUN TestFileTokenEmpty57=== PAUSE TestFileTokenEmpty58=== RUN TestScriptTokenNoExpiryRerunsEveryCall59=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall60=== RUN TestScriptTokenCachesUntilRefresh61=== PAUSE TestScriptTokenCachesUntilRefresh62=== RUN TestScriptTokenEmptyToken63=== PAUSE TestScriptTokenEmptyToken64=== RUN TestScriptTokenBadJSON65=== PAUSE TestScriptTokenBadJSON66=== RUN TestScriptTokenScriptFails67=== PAUSE TestScriptTokenScriptFails68=== RUN TestScriptTokenEmptyCommand69=== PAUSE TestScriptTokenEmptyCommand70=== CONT TestDoServerRequestAttachesToken71=== CONT TestSetClientTLS72=== CONT TestPathInfoHashCompatibility73=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)74=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess75=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)76=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon77=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon78=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI79=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI80=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha51281=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha51282=== CONT TestFileTokenMissing83=== CONT TestRateLimiterFeedback84=== RUN TestRateLimiterFeedback/429_enables_limiter85=== PAUSE TestRateLimiterFeedback/429_enables_limiter86=== RUN TestRateLimiterFeedback/503_enables_limiter87=== PAUSE TestRateLimiterFeedback/503_enables_limiter88=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter89=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter90=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter91=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter92=== CONT TestPathInfoCACompatibility93=== RUN TestPathInfoCACompatibility/null_ca_field94=== PAUSE TestPathInfoCACompatibility/null_ca_field95=== RUN TestPathInfoCACompatibility/old_string_format_-_text96=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text97=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive98=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive99=== RUN TestPathInfoCACompatibility/new_structured_format_-_text100=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text101=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method102=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method103=== CONT TestParsePathInfoJSONMultiplePaths104=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths105=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths106=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths107=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths108=== CONT TestScriptTokenEmptyCommand109--- PASS: TestScriptTokenEmptyCommand (0.00s)110=== CONT TestScriptTokenEmptyToken1112026/07/19 09:52:19 WARN Rate limiter enabled after throttle name=server-test rate=5112=== CONT TestScriptTokenScriptFails113=== CONT TestParsePathInfoJSON114=== RUN TestParsePathInfoJSON/Nix_format115=== PAUSE TestParsePathInfoJSON/Nix_format116=== RUN TestParsePathInfoJSON/Lix_format117=== PAUSE TestParsePathInfoJSON/Lix_format118=== RUN TestParsePathInfoJSON/empty_input119=== PAUSE TestParsePathInfoJSON/empty_input120=== RUN TestParsePathInfoJSON/whitespace_only121=== PAUSE TestParsePathInfoJSON/whitespace_only122--- PASS: TestFileTokenMissing (0.00s)123=== RUN TestParsePathInfoJSON/invalid_JSON124=== CONT TestShellSplit125=== PAUSE TestParsePathInfoJSON/invalid_JSON126=== CONT TestFileTokenReadsAndCaches127=== CONT TestShellSplitErrors128--- PASS: TestShellSplitErrors (0.00s)129=== CONT TestScriptTokenCachesUntilRefresh130--- PASS: TestShellSplit (0.00s)131=== CONT TestDoWithRetry_BodyReplayedViaGetBody132=== CONT TestFileTokenEmpty133=== CONT TestScriptTokenBadJSON134--- PASS: TestFileTokenReadsAndCaches (0.00s)135=== CONT TestResolveStorePath136--- PASS: TestFileTokenEmpty (0.00s)137=== CONT TestDumpPathWriterError1382026/07/19 09:52:19 WARN Rate limiter enabled after throttle name=server-test rate=51392026/07/19 09:52:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:590061402026/07/19 09:52:19 WARN Rate limiter backed off name=server-test rate=51412026/07/19 09:52:19 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:59006142--- PASS: TestDoServerRequestAttachesToken (0.01s)143=== CONT TestGetStorePathHash144=== RUN TestGetStorePathHash/valid_store_path145=== PAUSE TestGetStorePathHash/valid_store_path146=== RUN TestGetStorePathHash/basename_without_hyphen_should_error147=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error148=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error149=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error150--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)151=== CONT TestConvertHashToNix32152=== RUN TestConvertHashToNix32/SRI_format_to_Nix32153=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32154=== RUN TestConvertHashToNix32/already_Nix32_format155=== PAUSE TestConvertHashToNix32/already_Nix32_format156=== RUN TestConvertHashToNix32/invalid_format157=== PAUSE TestConvertHashToNix32/invalid_format158=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error159=== CONT TestEncodeNixBase32WithRealHash160--- PASS: TestEncodeNixBase32WithRealHash (0.00s)161=== CONT TestEncodeNixBase32162=== RUN TestEncodeNixBase32/test_string_hash163=== PAUSE TestEncodeNixBase32/test_string_hash164=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error165=== CONT TestSetClientTLSErrors166--- PASS: TestResolveStorePath (0.00s)167=== CONT TestStaticToken168--- PASS: TestStaticToken (0.00s)169=== CONT TestUploadMultipart_SupersededByPeer170=== RUN TestEncodeNixBase32/empty_input171=== PAUSE TestEncodeNixBase32/empty_input172=== RUN TestUploadMultipart_SupersededByPeer/exists173=== CONT TestDumpPathSingleFile174=== PAUSE TestUploadMultipart_SupersededByPeer/exists175=== RUN TestUploadMultipart_SupersededByPeer/missing176=== PAUSE TestUploadMultipart_SupersededByPeer/missing177=== CONT TestDumpPathMatchesNix178=== RUN TestSetClientTLS/rejects_connection_without_client_cert179=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert180=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA181=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA182=== RUN TestSetClientTLS/preserves_debug_logging_transport183=== PAUSE TestSetClientTLS/preserves_debug_logging_transport184=== CONT TestSetClientTLSDoesNotMutateDefaultTransport185=== RUN TestSetClientTLSErrors/missing_cert_file186=== PAUSE TestSetClientTLSErrors/missing_cert_file187=== RUN TestSetClientTLSErrors/missing_key_file188=== PAUSE TestSetClientTLSErrors/missing_key_file189=== RUN TestSetClientTLSErrors/missing_ca_file190=== PAUSE TestSetClientTLSErrors/missing_ca_file191=== RUN TestSetClientTLSErrors/invalid_ca_file192=== PAUSE TestSetClientTLSErrors/invalid_ca_file193=== CONT TestPartSizeForNAR194=== RUN TestPartSizeForNAR/zero_stays_at_minimum195=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum196=== RUN TestPartSizeForNAR/small_stays_at_minimum197=== PAUSE TestPartSizeForNAR/small_stays_at_minimum198=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum199=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum200=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts201=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts202=== RUN TestPartSizeForNAR/1_TiB203=== PAUSE TestPartSizeForNAR/1_TiB204=== RUN TestPartSizeForNAR/5_TiB_S3_max_object205=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object206=== RUN TestPartSizeForNAR/capped_at_5_GiB207=== PAUSE TestPartSizeForNAR/capped_at_5_GiB208=== CONT TestCaseHackSuffix209--- PASS: TestScriptTokenScriptFails (0.01s)210=== CONT TestScriptTokenNoExpiryRerunsEveryCall211--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)212=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)213=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI214=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512215=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon216--- PASS: TestPathInfoHashCompatibility (0.00s)217 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)218 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)219 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)220 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)221=== CONT TestRateLimiterFeedback/429_enables_limiter2222026/07/19 09:52:19 WARN Rate limiter enabled after throttle name=server-test rate=52232026/07/19 09:52:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:590112242026/07/19 09:52:19 WARN Rate limiter backed off name=server-test rate=5225=== CONT TestPathInfoCACompatibility/null_ca_field226=== CONT TestRateLimiterFeedback/503_enables_limiter2272026/07/19 09:52:19 WARN Rate limiter enabled after throttle name=server-test rate=52282026/07/19 09:52:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:590132292026/07/19 09:52:19 WARN Rate limiter backed off name=server-test rate=5230=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths231=== CONT TestPathInfoCACompatibility/old_string_format_-_text232=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method233=== CONT TestPathInfoCACompatibility/new_structured_format_-_text234=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive235--- PASS: TestPathInfoCACompatibility (0.00s)236 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)237 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)238 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)239 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)240 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)241=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter242=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths243--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)244 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)245 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)246=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter247--- PASS: TestRateLimiterFeedback (0.00s)248 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)249 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)250 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)251 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)252=== CONT TestParsePathInfoJSON/Nix_format253=== CONT TestParsePathInfoJSON/whitespace_only254=== CONT TestParsePathInfoJSON/invalid_JSON255=== CONT TestParsePathInfoJSON/empty_input256=== CONT TestParsePathInfoJSON/Lix_format257--- PASS: TestParsePathInfoJSON (0.00s)258 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)259 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)260 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)261 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)262 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)263=== CONT TestConvertHashToNix32/SRI_format_to_Nix32264=== CONT TestConvertHashToNix32/invalid_format265=== CONT TestConvertHashToNix32/already_Nix32_format266--- PASS: TestConvertHashToNix32 (0.00s)267 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)268 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)269 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)270=== CONT TestGetStorePathHash/valid_store_path271=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error272=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error273=== CONT TestGetStorePathHash/basename_without_hyphen_should_error274--- PASS: TestGetStorePathHash (0.00s)275 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)276 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)277 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)278 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)279=== CONT TestEncodeNixBase32/test_string_hash280=== CONT TestEncodeNixBase32/empty_input281--- PASS: TestEncodeNixBase32 (0.00s)282 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)283 --- PASS: TestEncodeNixBase32/empty_input (0.00s)284=== CONT TestUploadMultipart_SupersededByPeer/exists285--- PASS: TestScriptTokenEmptyToken (0.02s)286=== CONT TestUploadMultipart_SupersededByPeer/missing287--- PASS: TestScriptTokenBadJSON (0.02s)288=== CONT TestSetClientTLS/rejects_connection_without_client_cert289=== CONT TestSetClientTLS/preserves_debug_logging_transport290--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)291 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)292 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)293=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA294=== CONT TestSetClientTLSErrors/missing_cert_file295=== CONT TestSetClientTLSErrors/invalid_ca_file296=== CONT TestSetClientTLSErrors/missing_ca_file297=== CONT TestSetClientTLSErrors/missing_key_file298=== CONT TestPartSizeForNAR/1_TiB299=== CONT TestPartSizeForNAR/capped_at_5_GiB300=== CONT TestPartSizeForNAR/5_TiB_S3_max_object301=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum302=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts303=== CONT TestPartSizeForNAR/small_stays_at_minimum304=== CONT TestPartSizeForNAR/zero_stays_at_minimum305--- PASS: TestPartSizeForNAR (0.00s)306 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)307 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)308 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)309 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)310 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)311 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)312 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)313--- PASS: TestSetClientTLSErrors (0.00s)314 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)315 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)316 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)317 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3182026/07/19 09:52:19 http: TLS handshake error from 127.0.0.1:59022: remote error: tls: bad certificate319--- PASS: TestSetClientTLS (0.01s)320 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)321 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)322 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)323--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)324--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)325--- PASS: TestDumpPathWriterError (0.05s)326--- PASS: TestDumpPathSingleFile (0.05s)327--- PASS: TestCaseHackSuffix (0.05s)328--- PASS: TestDumpPathMatchesNix (0.07s)329--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)330PASS331Running server tests...332The files belonging to this database system will be owned by user "_nixbld1".333This user must also own the server process.334335The database cluster will be initialized with locale "C".336The default database encoding has accordingly been set to "SQL_ASCII".337The default text search configuration will be set to "english".338339Data page checksums are enabled.340341creating directory /nix/var/nix/builds/nix-91752-1574309481/postgres1462467122/data ... ok342creating subdirectories ... ok343selecting dynamic shared memory implementation ... posix344selecting default "max_connections" ... 100345selecting default "shared_buffers" ... 128MB346selecting default time zone ... UTC347creating configuration files ... ok348running bootstrap script ... ok349performing post-bootstrap initialization ... ok350syncing data to disk ... ok351352initdb: warning: enabling "trust" authentication for local connections353initdb: 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.354355Success. You can now start the database server using:356357 pg_ctl -D /nix/var/nix/builds/nix-91752-1574309481/postgres1462467122/data -l logfile start358359/nix/var/nix/builds/nix-91752-1574309481/postgres1462467122:5432 - no response3602026-07-19 09:52:21.146 UTC [91787] LOG: starting PostgreSQL 18.4 on aarch64-apple-darwin25.3.0, compiled by clang version 21.1.8, 64-bit3612026-07-19 09:52:21.146 UTC [91787] LOG: listening on Unix socket "/nix/var/nix/builds/nix-91752-1574309481/postgres1462467122/.s.PGSQL.5432"3622026-07-19 09:52:21.148 UTC [91794] LOG: database system was shut down at 2026-07-19 09:52:21 UTC3632026-07-19 09:52:21.149 UTC [91787] LOG: database system is ready to accept connections364/nix/var/nix/builds/nix-91752-1574309481/postgres1462467122:5432 - accepting connections365<jemalloc>: option background_thread currently supports pthread only366{"timestamp":"2026-07-19T09:52:21.270445Z","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(4)"}367=== RUN TestService_AuthMiddleware368=== PAUSE TestService_AuthMiddleware369=== RUN TestService_AuthMiddleware_MTLSProxyHeader370=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader371=== RUN TestService_AuthMiddleware_MTLSBoundSubjects372=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects373=== RUN TestService_ReadAuthMiddleware374=== PAUSE TestService_ReadAuthMiddleware375=== RUN TestService_AuthMiddleware_OIDC376=== PAUSE TestService_AuthMiddleware_OIDC377=== RUN TestCacheConfigHandler378=== PAUSE TestCacheConfigHandler379=== RUN TestCacheStatsHandler380=== PAUSE TestCacheStatsHandler381=== RUN TestClientCADerivations382=== PAUSE TestClientCADerivations383=== RUN TestClientErrorHandling384=== PAUSE TestClientErrorHandling385=== RUN TestClientIntegration386=== PAUSE TestClientIntegration387=== RUN TestClientMultipleUploads388=== PAUSE TestClientMultipleUploads389=== RUN TestClientWithDependencies390=== PAUSE TestClientWithDependencies391=== RUN TestPinProtectsFromGC392=== PAUSE TestPinProtectsFromGC393=== RUN TestGCAdvisoryLockBlocksConcurrentRun3942026-07-19 09:52:21.407 UTC [91845] ERROR: relation "goose_db_version" does not exist at character 363952026-07-19 09:52:21.407 UTC [91845] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC3962026/07/19 09:52:21 OK 20241026095416_initial_model.sql (3.19ms)3972026/07/19 09:52:21 OK 20251210153512_drop_unused_gin_index.sql (366.88µs)3982026/07/19 09:52:21 OK 20251218171726_add_pins.sql (776.21µs)3992026/07/19 09:52:21 OK 20260628120000_add_object_size_and_stats.sql (799.75µs)4002026/07/19 09:52:21 goose: successfully migrated database to version: 202606281200004012026/07/19 09:52:21 OK 1_commit_pending_closure.sql (794.5µs)4022026/07/19 09:52:21 OK 2_object_stats_trigger.sql (203.71µs)4032026/07/19 09:52:21 goose: up to current file version: 2404--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.06s)405=== RUN TestGCBugBareHashReferences406=== PAUSE TestGCBugBareHashReferences407=== RUN TestGCMetrics408=== PAUSE TestGCMetrics409=== RUN TestGCTaskStore_StartNew410=== PAUSE TestGCTaskStore_StartNew411=== RUN TestGCTaskStore_DeduplicateSameParams412=== PAUSE TestGCTaskStore_DeduplicateSameParams413=== RUN TestGCTaskStore_ConflictDifferentParams414=== PAUSE TestGCTaskStore_ConflictDifferentParams415=== RUN TestGCTaskStore_GetEmpty416=== PAUSE TestGCTaskStore_GetEmpty417=== RUN TestGCTaskStore_GetReturnsLatest418=== PAUSE TestGCTaskStore_GetReturnsLatest419=== RUN TestGCTaskStore_CompletedAllowsNewTask420=== PAUSE TestGCTaskStore_CompletedAllowsNewTask421=== RUN TestGCTaskStore_PhaseUpdates422=== PAUSE TestGCTaskStore_PhaseUpdates423=== RUN TestGCTaskStore_Fail424=== PAUSE TestGCTaskStore_Fail425=== RUN TestGracefulShutdownDrainsInflight426=== PAUSE TestGracefulShutdownDrainsInflight427=== RUN TestService_healthCheckHandler428=== PAUSE TestService_healthCheckHandler429=== RUN TestGenerateLandingPage430=== PAUSE TestGenerateLandingPage431=== RUN TestNARDeduplicationMetadataUploadBug432=== PAUSE TestNARDeduplicationMetadataUploadBug433=== RUN TestMetricsInventory434=== PAUSE TestMetricsInventory435=== RUN TestService_NativeMTLS436=== PAUSE TestService_NativeMTLS437=== RUN TestServerTLSConfig438=== PAUSE TestServerTLSConfig439=== RUN TestMultipartCleanup440=== PAUSE TestMultipartCleanup441=== RUN TestObjectStatsTrigger442=== PAUSE TestObjectStatsTrigger443=== RUN TestOrphanedObjectsGC444=== PAUSE TestOrphanedObjectsGC445=== RUN TestOrphanedObjectsGCStressTest446=== PAUSE TestOrphanedObjectsGCStressTest447=== RUN TestResurrectedObjectNotDeleted448=== PAUSE TestResurrectedObjectNotDeleted449=== RUN TestParseSingleRange450=== PAUSE TestParseSingleRange451=== RUN TestIsValidCachePath452=== PAUSE TestIsValidCachePath453=== RUN TestReadProxyNarinfo454=== PAUSE TestReadProxyNarinfo455=== RUN TestReadProxyNarinfoAlreadyDecompressed456=== PAUSE TestReadProxyNarinfoAlreadyDecompressed457=== RUN TestReadProxyNarStreaming458=== PAUSE TestReadProxyNarStreaming459=== RUN TestReadProxy404460=== PAUSE TestReadProxy404461=== RUN TestReadProxyInvalidPath462=== PAUSE TestReadProxyInvalidPath463=== RUN TestReadProxyHead464=== PAUSE TestReadProxyHead465=== RUN TestReadProxyConditionalGet466=== PAUSE TestReadProxyConditionalGet467=== RUN TestReadProxyRootRedirectsToIndexHTML468=== PAUSE TestReadProxyRootRedirectsToIndexHTML469=== RUN TestReadProxyDisabled470=== PAUSE TestReadProxyDisabled471=== RUN TestReadProxyRangeRequest472=== PAUSE TestReadProxyRangeRequest473=== RUN TestRedundantMultipartUpload474=== PAUSE TestRedundantMultipartUpload475=== RUN TestCompleteMultipartUpload_ErrorButObjectExists476=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists477=== RUN TestCompletedNarNotReofferedAcrossClosures478=== PAUSE TestCompletedNarNotReofferedAcrossClosures479=== RUN TestPresignedUploadRegisteredBeforeCommit480=== PAUSE TestPresignedUploadRegisteredBeforeCommit481=== RUN TestService_Rustfstest482=== PAUSE TestService_Rustfstest483=== RUN TestSystemdListenerNotActivated484--- PASS: TestSystemdListenerNotActivated (0.00s)485=== RUN TestWatchdogBeatsWhenHealthy486--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)487=== RUN TestWatchdogSkipsWhenUnhealthy4882026/07/19 09:52:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4892026/07/19 09:52:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4902026/07/19 09:52:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4912026/07/19 09:52:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4922026/07/19 09:52:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4932026/07/19 09:52:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4942026/07/19 09:52:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4952026/07/19 09:52:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4962026/07/19 09:52:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4972026/07/19 09:52:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"498--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)499=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle500=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle501=== RUN TestProxyWriteTimeout502=== PAUSE TestProxyWriteTimeout503=== RUN TestIsValidUploadKey504=== PAUSE TestIsValidUploadKey505=== RUN TestUploadHandlersRejectInvalidKeys506=== PAUSE TestUploadHandlersRejectInvalidKeys507=== RUN TestUploadHandlersRejectOversizedBody508=== PAUSE TestUploadHandlersRejectOversizedBody509=== RUN TestService_cleanupPendingClosuresHandler510=== PAUSE TestService_cleanupPendingClosuresHandler511=== RUN TestService_createPendingClosureHandler512=== PAUSE TestService_createPendingClosureHandler513=== RUN TestService_verifyS3Integrity514=== PAUSE TestService_verifyS3Integrity515=== RUN TestCompleteMultipartUnregistered516=== PAUSE TestCompleteMultipartUnregistered517=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT518=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT519=== CONT TestService_AuthMiddleware520=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT521=== CONT TestObjectStatsTrigger522=== CONT TestReadProxyRangeRequest523=== CONT TestCompleteMultipartUnregistered524=== CONT TestService_verifyS3Integrity525=== CONT TestService_createPendingClosureHandler526=== CONT TestService_cleanupPendingClosuresHandler527=== CONT TestUploadHandlersRejectOversizedBody528=== CONT TestUploadHandlersRejectInvalidKeys529=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info530=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info531=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal532=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal533=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key534=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key535=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key536=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key537=== CONT TestIsValidUploadKey538=== RUN TestIsValidUploadKey/narinfo539=== PAUSE TestIsValidUploadKey/narinfo540=== RUN TestIsValidUploadKey/nar_zst541=== PAUSE TestIsValidUploadKey/nar_zst542=== RUN TestIsValidUploadKey/nar_xz543=== PAUSE TestIsValidUploadKey/nar_xz544=== RUN TestIsValidUploadKey/nar_plain545=== PAUSE TestIsValidUploadKey/nar_plain546=== RUN TestIsValidUploadKey/listing547=== PAUSE TestIsValidUploadKey/listing548=== RUN TestIsValidUploadKey/build_log549=== PAUSE TestIsValidUploadKey/build_log550=== RUN TestIsValidUploadKey/build_log_home-manager_file551=== PAUSE TestIsValidUploadKey/build_log_home-manager_file552=== RUN TestIsValidUploadKey/build_log_plus_in_name553=== PAUSE TestIsValidUploadKey/build_log_plus_in_name554=== RUN TestIsValidUploadKey/build_log_question_mark555=== PAUSE TestIsValidUploadKey/build_log_question_mark556=== RUN TestIsValidUploadKey/build_log_equals557=== PAUSE TestIsValidUploadKey/build_log_equals558=== RUN TestIsValidUploadKey/realisation559=== PAUSE TestIsValidUploadKey/realisation560=== RUN TestIsValidUploadKey/realisation_plus_in_output561=== PAUSE TestIsValidUploadKey/realisation_plus_in_output562=== RUN TestIsValidUploadKey/nix-cache-info563=== PAUSE TestIsValidUploadKey/nix-cache-info564=== RUN TestIsValidUploadKey/index.html565=== PAUSE TestIsValidUploadKey/index.html566=== RUN TestIsValidUploadKey/narinfo_key,_nar_type567=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type568=== RUN TestIsValidUploadKey/nar_key,_narinfo_type569=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type570=== RUN TestIsValidUploadKey/listing_key,_narinfo_type571=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type572=== RUN TestIsValidUploadKey/traversal573=== PAUSE TestIsValidUploadKey/traversal574=== RUN TestIsValidUploadKey/traversal_nar575=== PAUSE TestIsValidUploadKey/traversal_nar576=== RUN TestIsValidUploadKey/absolute577=== PAUSE TestIsValidUploadKey/absolute578=== RUN TestIsValidUploadKey/empty_key579=== PAUSE TestIsValidUploadKey/empty_key580=== RUN TestIsValidUploadKey/unknown_type581=== PAUSE TestIsValidUploadKey/unknown_type582=== CONT TestProxyWriteTimeout583=== RUN TestProxyWriteTimeout/narinfo584=== PAUSE TestProxyWriteTimeout/narinfo585=== RUN TestProxyWriteTimeout/1_GiB_nar586=== PAUSE TestProxyWriteTimeout/1_GiB_nar587=== RUN TestProxyWriteTimeout/10_GiB_nar588=== PAUSE TestProxyWriteTimeout/10_GiB_nar589=== RUN TestProxyWriteTimeout/unknown_size590=== PAUSE TestProxyWriteTimeout/unknown_size591=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle592=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure593=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure594=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart595=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart596=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts597=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts598=== CONT TestService_Rustfstest5992026-07-19 09:52:21.942 UTC [91867] ERROR: relation "goose_db_version" does not exist at character 366002026-07-19 09:52:21.942 UTC [91867] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6012026-07-19 09:52:21.944 UTC [91868] ERROR: relation "goose_db_version" does not exist at character 366022026-07-19 09:52:21.944 UTC [91868] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6032026-07-19 09:52:21.945 UTC [91872] ERROR: relation "goose_db_version" does not exist at character 366042026-07-19 09:52:21.945 UTC [91872] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6052026-07-19 09:52:21.946 UTC [91870] ERROR: relation "goose_db_version" does not exist at character 366062026-07-19 09:52:21.946 UTC [91870] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6072026-07-19 09:52:21.946 UTC [91871] ERROR: relation "goose_db_version" does not exist at character 366082026-07-19 09:52:21.946 UTC [91871] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6092026-07-19 09:52:21.946 UTC [91869] ERROR: relation "goose_db_version" does not exist at character 366102026-07-19 09:52:21.946 UTC [91869] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6112026-07-19 09:52:21.946 UTC [91873] ERROR: relation "goose_db_version" does not exist at character 366122026-07-19 09:52:21.946 UTC [91873] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6132026-07-19 09:52:21.947 UTC [91874] ERROR: relation "goose_db_version" does not exist at character 366142026-07-19 09:52:21.947 UTC [91874] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6152026-07-19 09:52:21.948 UTC [91875] ERROR: relation "goose_db_version" does not exist at character 366162026-07-19 09:52:21.948 UTC [91875] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6172026-07-19 09:52:21.950 UTC [91876] ERROR: relation "goose_db_version" does not exist at character 366182026-07-19 09:52:21.950 UTC [91876] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6192026/07/19 09:52:21 OK 20241026095416_initial_model.sql (6.83ms)6202026/07/19 09:52:21 OK 20241026095416_initial_model.sql (8.8ms)6212026/07/19 09:52:21 OK 20241026095416_initial_model.sql (6.82ms)6222026/07/19 09:52:21 OK 20251210153512_drop_unused_gin_index.sql (1.13ms)6232026/07/19 09:52:21 OK 20241026095416_initial_model.sql (6.91ms)6242026/07/19 09:52:21 OK 20251210153512_drop_unused_gin_index.sql (767µs)6252026/07/19 09:52:21 OK 20251210153512_drop_unused_gin_index.sql (716.13µs)6262026/07/19 09:52:21 OK 20241026095416_initial_model.sql (7.83ms)6272026/07/19 09:52:21 OK 20251210153512_drop_unused_gin_index.sql (763.79µs)6282026/07/19 09:52:21 OK 20251210153512_drop_unused_gin_index.sql (743.04µs)6292026/07/19 09:52:21 OK 20251218171726_add_pins.sql (1.35ms)6302026/07/19 09:52:21 OK 20241026095416_initial_model.sql (8.15ms)6312026/07/19 09:52:21 OK 20251218171726_add_pins.sql (1.36ms)6322026/07/19 09:52:21 OK 20241026095416_initial_model.sql (6.08ms)6332026/07/19 09:52:21 OK 20251210153512_drop_unused_gin_index.sql (638.92µs)6342026/07/19 09:52:21 OK 20251218171726_add_pins.sql (1.38ms)6352026/07/19 09:52:21 OK 20251210153512_drop_unused_gin_index.sql (465.96µs)6362026/07/19 09:52:21 OK 20251218171726_add_pins.sql (1.55ms)6372026/07/19 09:52:21 OK 20251218171726_add_pins.sql (2.5ms)6382026/07/19 09:52:21 OK 20260628120000_add_object_size_and_stats.sql (1.35ms)6392026/07/19 09:52:21 goose: successfully migrated database to version: 202606281200006402026/07/19 09:52:21 OK 20260628120000_add_object_size_and_stats.sql (1.15ms)6412026/07/19 09:52:21 goose: successfully migrated database to version: 202606281200006422026/07/19 09:52:21 OK 20251218171726_add_pins.sql (1.35ms)6432026/07/19 09:52:21 OK 20241026095416_initial_model.sql (9.75ms)6442026/07/19 09:52:21 OK 20251218171726_add_pins.sql (1.45ms)6452026/07/19 09:52:21 OK 20260628120000_add_object_size_and_stats.sql (2.5ms)6462026/07/19 09:52:21 goose: successfully migrated database to version: 202606281200006472026/07/19 09:52:21 OK 20260628120000_add_object_size_and_stats.sql (1.29ms)6482026/07/19 09:52:21 goose: successfully migrated database to version: 202606281200006492026/07/19 09:52:21 OK 20251210153512_drop_unused_gin_index.sql (571.79µs)6502026/07/19 09:52:21 OK 20241026095416_initial_model.sql (9.24ms)6512026/07/19 09:52:21 OK 1_commit_pending_closure.sql (1.03ms)6522026/07/19 09:52:21 OK 20260628120000_add_object_size_and_stats.sql (974.21µs)6532026/07/19 09:52:21 goose: successfully migrated database to version: 202606281200006542026/07/19 09:52:21 OK 20260628120000_add_object_size_and_stats.sql (1.76ms)6552026/07/19 09:52:21 goose: successfully migrated database to version: 202606281200006562026/07/19 09:52:21 OK 20251210153512_drop_unused_gin_index.sql (511.79µs)6572026/07/19 09:52:21 OK 2_object_stats_trigger.sql (558.54µs)6582026/07/19 09:52:21 goose: up to current file version: 26592026/07/19 09:52:21 OK 1_commit_pending_closure.sql (1.07ms)6602026/07/19 09:52:21 OK 20260628120000_add_object_size_and_stats.sql (1.2ms)6612026/07/19 09:52:21 goose: successfully migrated database to version: 202606281200006622026/07/19 09:52:21 OK 2_object_stats_trigger.sql (489.42µs)6632026/07/19 09:52:21 goose: up to current file version: 26642026/07/19 09:52:21 OK 1_commit_pending_closure.sql (2.12ms)6652026/07/19 09:52:21 OK 1_commit_pending_closure.sql (1.13ms)6662026/07/19 09:52:21 OK 1_commit_pending_closure.sql (1.5ms)6672026/07/19 09:52:21 OK 1_commit_pending_closure.sql (1.13ms)6682026/07/19 09:52:21 OK 20241026095416_initial_model.sql (6.53ms)6692026/07/19 09:52:21 OK 20251218171726_add_pins.sql (1.08ms)6702026/07/19 09:52:21 OK 2_object_stats_trigger.sql (578.75µs)6712026/07/19 09:52:21 goose: up to current file version: 26722026/07/19 09:52:21 OK 2_object_stats_trigger.sql (547.75µs)6732026/07/19 09:52:21 goose: up to current file version: 26742026/07/19 09:52:21 OK 2_object_stats_trigger.sql (541.79µs)6752026/07/19 09:52:21 goose: up to current file version: 26762026/07/19 09:52:21 OK 2_object_stats_trigger.sql (555.33µs)6772026/07/19 09:52:21 goose: up to current file version: 26782026/07/19 09:52:21 OK 1_commit_pending_closure.sql (1.21ms)6792026/07/19 09:52:21 OK 20251218171726_add_pins.sql (2.16ms)6802026/07/19 09:52:21 OK 20251210153512_drop_unused_gin_index.sql (499.58µs)6812026/07/19 09:52:21 OK 2_object_stats_trigger.sql (382.88µs)6822026/07/19 09:52:21 goose: up to current file version: 26832026/07/19 09:52:21 OK 20260628120000_add_object_size_and_stats.sql (1.1ms)6842026/07/19 09:52:21 goose: successfully migrated database to version: 202606281200006852026/07/19 09:52:21 INFO Received uploads request method=POST path=/api/pending_closures6862026/07/19 09:52:21 INFO Received uploads request method=POST path=/api/pending_closures6872026/07/19 09:52:21 OK 20260628120000_add_object_size_and_stats.sql (1.39ms)6882026/07/19 09:52:21 goose: successfully migrated database to version: 202606281200006892026/07/19 09:52:21 INFO Received uploads request method=POST path=/api/pending_closures6902026/07/19 09:52:21 INFO Received uploads request method=POST path=/api/pending_closures6912026/07/19 09:52:21 OK 20251218171726_add_pins.sql (1.22ms)6922026/07/19 09:52:21 INFO Received uploads request method=POST path=/api/pending_closures6932026/07/19 09:52:21 INFO Received uploads request method=POST path=/api/pending_closures694{"timestamp":"2026-07-19T09:52:21.965538Z","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(7)"}6952026/07/19 09:52:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete6962026/07/19 09:52:21 OK 1_commit_pending_closure.sql (1.97ms)6972026/07/19 09:52:21 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst698--- PASS: TestCompleteMultipartUnregistered (0.32s)699=== CONT TestPresignedUploadRegisteredBeforeCommit7002026/07/19 09:52:21 OK 20260628120000_add_object_size_and_stats.sql (1.74ms)7012026/07/19 09:52:21 goose: successfully migrated database to version: 202606281200007022026/07/19 09:52:21 OK 1_commit_pending_closure.sql (1.9ms)7032026/07/19 09:52:21 OK 2_object_stats_trigger.sql (404.38µs)7042026/07/19 09:52:21 goose: up to current file version: 27052026/07/19 09:52:21 OK 2_object_stats_trigger.sql (1.44ms)7062026/07/19 09:52:21 goose: up to current file version: 27072026/07/19 09:52:21 OK 1_commit_pending_closure.sql (2.36ms)708--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.32s)709=== CONT TestCompletedNarNotReofferedAcrossClosures7102026/07/19 09:52:21 INFO Received cleanup request method=DELETE path=/api/pending_closures7112026/07/19 09:52:21 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"712--- PASS: TestService_AuthMiddleware (0.32s)713=== CONT TestCompleteMultipartUpload_ErrorButObjectExists7142026/07/19 09:52:21 OK 2_object_stats_trigger.sql (1.22ms)7152026/07/19 09:52:21 goose: up to current file version: 27162026/07/19 09:52:21 INFO Aborted multipart uploads count=07172026/07/19 09:52:21 INFO Received uploads request method=POST path=/api/pending_closures718--- PASS: TestObjectStatsTrigger (0.33s)719=== CONT TestRedundantMultipartUpload720--- PASS: TestReadProxyRangeRequest (0.33s)721=== CONT TestGCTaskStore_DeduplicateSameParams722--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)723=== CONT TestMultipartCleanup724--- PASS: TestService_Rustfstest (0.28s)725=== CONT TestServerTLSConfig726=== RUN TestServerTLSConfig/no_client_CA727=== PAUSE TestServerTLSConfig/no_client_CA728=== RUN TestServerTLSConfig/missing_CA_file729=== PAUSE TestServerTLSConfig/missing_CA_file730=== RUN TestServerTLSConfig/not_a_PEM_file731=== PAUSE TestServerTLSConfig/not_a_PEM_file732=== CONT TestService_NativeMTLS7332026/07/19 09:52:21 INFO Received cleanup request method=DELETE path=/api/pending_closures7342026/07/19 09:52:21 INFO Aborted multipart uploads count=17352026/07/19 09:52:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7362026-07-19 09:52:21.984 UTC [91874] ERROR: Closure does not exist: id=17372026-07-19 09:52:21.984 UTC [91874] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE7382026-07-19 09:52:21.984 UTC [91874] STATEMENT: -- name: CommitPendingClosure :exec739 SELECT commit_pending_closure($1::bigint)740 741--- PASS: TestService_cleanupPendingClosuresHandler (0.34s)742=== CONT TestMetricsInventory7432026/07/19 09:52:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7442026/07/19 09:52:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7452026/07/19 09:52:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7462026/07/19 09:52:22 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZTY4MThmMzQtNjcxNy00MzY4LWIwM2YtMDZjOThiYTM1Y2VmLmFkZTA3ZjVkLTM2MzQtNDdiYy05NWUyLTMyMGQyZGQyZDVkOXgxNzg0NDU0NzQxOTY4MTM0MDAw parts=107472026/07/19 09:52:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7482026/07/19 09:52:22 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZTY4MThmMzQtNjcxNy00MzY4LWIwM2YtMDZjOThiYTM1Y2VmLmJjYjFhZjhlLWYxZmMtNDJlOS1iZDBlLTk0NWE3ZmE1NGQ5NngxNzg0NDU0NzQxOTY2NDA4MDAw parts=107492026/07/19 09:52:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7502026/07/19 09:52:22 INFO Completed upload id=17512026/07/19 09:52:22 INFO Received uploads request method=POST path=/api/pending_closures7522026/07/19 09:52:22 INFO Received uploads request method=POST path=/api/pending_closures7532026/07/19 09:52:22 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo7542026/07/19 09:52:22 WARN Found objects in DB but missing from S3, will re-upload count=1755--- PASS: TestService_verifyS3Integrity (0.47s)756=== CONT TestNARDeduplicationMetadataUploadBug7572026/07/19 09:52:22 INFO Completed upload id=17582026/07/19 09:52:22 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000007592026/07/19 09:52:22 INFO Received uploads request method=POST path=/api/pending_closures7602026/07/19 09:52:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures7612026/07/19 09:52:22 INFO Aborted multipart uploads count=07622026/07/19 09:52:22 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=07632026-07-19 09:52:22.133 UTC [91915] ERROR: relation "goose_db_version" does not exist at character 367642026-07-19 09:52:22.133 UTC [91915] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7652026/07/19 09:52:22 INFO Vacuumed table table=pending_closures7662026/07/19 09:52:22 INFO Vacuumed table table=pending_objects7672026/07/19 09:52:22 INFO Vacuumed table table=multipart_uploads7682026/07/19 09:52:22 INFO Vacuumed table table=closures7692026/07/19 09:52:22 INFO Vacuumed table table=objects7702026/07/19 09:52:22 OK 20241026095416_initial_model.sql (26.61ms)7712026/07/19 09:52:22 OK 20251210153512_drop_unused_gin_index.sql (341.33µs)7722026/07/19 09:52:22 OK 20251218171726_add_pins.sql (698.5µs)7732026/07/19 09:52:22 OK 20260628120000_add_object_size_and_stats.sql (6.2ms)7742026/07/19 09:52:22 goose: successfully migrated database to version: 202606281200007752026/07/19 09:52:22 OK 1_commit_pending_closure.sql (1.4ms)7762026/07/19 09:52:22 OK 2_object_stats_trigger.sql (247.25µs)7772026/07/19 09:52:22 goose: up to current file version: 27782026/07/19 09:52:22 INFO Received uploads request method=POST path=/api/pending_closures7792026/07/19 09:52:22 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7802026/07/19 09:52:22 INFO Received uploads request method=POST path=/api/pending_closures781--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.22s)782=== CONT TestGenerateLandingPage783--- PASS: TestGenerateLandingPage (0.00s)784=== CONT TestService_healthCheckHandler7852026-07-19 09:52:22.198 UTC [91919] ERROR: relation "goose_db_version" does not exist at character 367862026-07-19 09:52:22.198 UTC [91919] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7872026-07-19 09:52:22.212 UTC [91921] ERROR: relation "goose_db_version" does not exist at character 367882026-07-19 09:52:22.212 UTC [91921] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7892026-07-19 09:52:22.213 UTC [91922] ERROR: relation "goose_db_version" does not exist at character 367902026-07-19 09:52:22.213 UTC [91922] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7912026/07/19 09:52:22 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000792--- PASS: TestService_createPendingClosureHandler (0.57s)793=== CONT TestGracefulShutdownDrainsInflight7942026/07/19 09:52:22 INFO Starting HTTP server address=127.0.0.1:590737952026/07/19 09:52:22 INFO Shutdown signal received, draining in-flight requests timeout=10s7962026/07/19 09:52:22 OK 20241026095416_initial_model.sql (22.43ms)7972026/07/19 09:52:22 OK 20251210153512_drop_unused_gin_index.sql (447.42µs)7982026/07/19 09:52:22 OK 20251218171726_add_pins.sql (1.22ms)7992026/07/19 09:52:22 OK 20260628120000_add_object_size_and_stats.sql (3.51ms)8002026/07/19 09:52:22 goose: successfully migrated database to version: 202606281200008012026/07/19 09:52:22 OK 1_commit_pending_closure.sql (1.22ms)8022026/07/19 09:52:22 OK 2_object_stats_trigger.sql (312.5µs)8032026/07/19 09:52:22 goose: up to current file version: 28042026/07/19 09:52:22 OK 20241026095416_initial_model.sql (5.68ms)8052026/07/19 09:52:22 OK 20241026095416_initial_model.sql (5.73ms)8062026/07/19 09:52:22 OK 20251210153512_drop_unused_gin_index.sql (385.33µs)8072026/07/19 09:52:22 OK 20251210153512_drop_unused_gin_index.sql (355.17µs)8082026/07/19 09:52:22 INFO Received uploads request method=POST path=/api/pending_closures8092026/07/19 09:52:22 OK 20251218171726_add_pins.sql (1.32ms)8102026/07/19 09:52:22 OK 20251218171726_add_pins.sql (1.34ms)8112026/07/19 09:52:22 OK 20260628120000_add_object_size_and_stats.sql (1.75ms)8122026/07/19 09:52:22 goose: successfully migrated database to version: 202606281200008132026/07/19 09:52:22 OK 1_commit_pending_closure.sql (1.06ms)8142026/07/19 09:52:22 OK 2_object_stats_trigger.sql (215.83µs)8152026/07/19 09:52:22 goose: up to current file version: 28162026/07/19 09:52:22 INFO Received uploads request method=POST path=/api/pending_closures8172026/07/19 09:52:22 OK 20260628120000_add_object_size_and_stats.sql (6.17ms)8182026/07/19 09:52:22 goose: successfully migrated database to version: 202606281200008192026/07/19 09:52:22 INFO Received uploads request method=POST path=/api/pending_closures8202026/07/19 09:52:22 OK 1_commit_pending_closure.sql (1.08ms)8212026/07/19 09:52:22 OK 2_object_stats_trigger.sql (337.08µs)8222026/07/19 09:52:22 goose: up to current file version: 28232026/07/19 09:52:22 INFO Received uploads request method=POST path=/api/pending_closures8242026/07/19 09:52:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete825{"timestamp":"2026-07-19T09:52:22.250894Z","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(8)"}826{"timestamp":"2026-07-19T09:52:22.250918Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket14, 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(8)"}8272026/07/19 09:52:22 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=ZTY4MThmMzQtNjcxNy00MzY4LWIwM2YtMDZjOThiYTM1Y2VmLjMwMzhiZTM3LWIwNjgtNGE4Mi1hMjk0LWE5OGMzMWFjOWJmZngxNzg0NDU0NzQyMjQ0NzI3MDAw8282026/07/19 09:52:22 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTY4MThmMzQtNjcxNy00MzY4LWIwM2YtMDZjOThiYTM1Y2VmLjMwMzhiZTM3LWIwNjgtNGE4Mi1hMjk0LWE5OGMzMWFjOWJmZngxNzg0NDU0NzQyMjQ0NzI3MDAw parts=1829--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.28s)830=== CONT TestGCTaskStore_Fail831--- PASS: TestGCTaskStore_Fail (0.00s)832=== CONT TestGCTaskStore_PhaseUpdates833--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)834=== CONT TestGCTaskStore_CompletedAllowsNewTask835--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)836=== CONT TestGCTaskStore_GetReturnsLatest837--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)838=== CONT TestGCTaskStore_GetEmpty839--- PASS: TestGCTaskStore_GetEmpty (0.00s)840=== CONT TestReadProxyNarStreaming841--- PASS: TestGracefulShutdownDrainsInflight (0.07s)842=== CONT TestGCTaskStore_ConflictDifferentParams843--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)844=== CONT TestReadProxyHead8452026/07/19 09:52:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8462026/07/19 09:52:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8472026/07/19 09:52:22 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZTY4MThmMzQtNjcxNy00MzY4LWIwM2YtMDZjOThiYTM1Y2VmLmUyYWQ0ZWJhLTU2MWQtNDc3Ny1iMjc2LTk0ODQ1OGYzN2NmYngxNzg0NDU0NzQyMjM2NTc1MDAw parts=12848--- PASS: TestRedundantMultipartUpload (0.40s)849=== CONT TestClientErrorHandling850=== RUN TestClientErrorHandling/InvalidStorePath851=== PAUSE TestClientErrorHandling/InvalidStorePath852=== RUN TestClientErrorHandling/InvalidAuthToken853=== PAUSE TestClientErrorHandling/InvalidAuthToken854=== RUN TestClientErrorHandling/ServerNotAvailable855=== PAUSE TestClientErrorHandling/ServerNotAvailable856=== CONT TestReadProxyInvalidPath8572026/07/19 09:52:22 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZTY4MThmMzQtNjcxNy00MzY4LWIwM2YtMDZjOThiYTM1Y2VmLjczZTk4ODZmLWI5MTQtNDVmOS04ZjY1LTk2YTNkOWM1MDU5MXgxNzg0NDU0NzQyMjQ2NTMyMDAw parts=128582026/07/19 09:52:22 INFO Received uploads request method=POST path=/api/pending_closures859--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.41s)860=== CONT TestGCTaskStore_StartNew861--- PASS: TestGCTaskStore_StartNew (0.00s)862=== CONT TestReadProxy4048632026-07-19 09:52:22.414 UTC [91931] ERROR: relation "goose_db_version" does not exist at character 368642026-07-19 09:52:22.414 UTC [91931] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8652026-07-19 09:52:22.432 UTC [91932] ERROR: relation "goose_db_version" does not exist at character 368662026-07-19 09:52:22.432 UTC [91932] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8672026/07/19 09:52:22 OK 20241026095416_initial_model.sql (14.67ms)8682026/07/19 09:52:22 OK 20251210153512_drop_unused_gin_index.sql (861.63µs)8692026/07/19 09:52:22 OK 20251218171726_add_pins.sql (1.32ms)8702026-07-19 09:52:22.449 UTC [91933] ERROR: relation "goose_db_version" does not exist at character 368712026-07-19 09:52:22.449 UTC [91933] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8722026/07/19 09:52:22 OK 20260628120000_add_object_size_and_stats.sql (10.75ms)8732026/07/19 09:52:22 goose: successfully migrated database to version: 202606281200008742026/07/19 09:52:22 OK 1_commit_pending_closure.sql (856.13µs)8752026/07/19 09:52:22 OK 2_object_stats_trigger.sql (235.08µs)8762026/07/19 09:52:22 goose: up to current file version: 28772026/07/19 09:52:22 INFO Received uploads request method=POST path=/api/pending_closures8782026/07/19 09:52:22 OK 20241026095416_initial_model.sql (18.89ms)8792026/07/19 09:52:22 OK 20251210153512_drop_unused_gin_index.sql (461.88µs)8802026/07/19 09:52:22 OK 20251218171726_add_pins.sql (1.13ms)8812026/07/19 09:52:22 OK 20241026095416_initial_model.sql (8.72ms)8822026/07/19 09:52:22 OK 20260628120000_add_object_size_and_stats.sql (6.19ms)8832026/07/19 09:52:22 goose: successfully migrated database to version: 202606281200008842026/07/19 09:52:22 OK 20251210153512_drop_unused_gin_index.sql (348.83µs)8852026/07/19 09:52:22 OK 1_commit_pending_closure.sql (912.96µs)8862026/07/19 09:52:22 OK 20251218171726_add_pins.sql (693.13µs)8872026/07/19 09:52:22 OK 2_object_stats_trigger.sql (216.75µs)8882026/07/19 09:52:22 goose: up to current file version: 28892026/07/19 09:52:22 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8902026/07/19 09:52:22 WARN mTLS auth: subject not in bound subjects subject="CN=writer"891--- PASS: TestService_NativeMTLS (0.49s)892=== CONT TestGCMetrics8932026/07/19 09:52:22 OK 20260628120000_add_object_size_and_stats.sql (13.24ms)8942026/07/19 09:52:22 goose: successfully migrated database to version: 202606281200008952026/07/19 09:52:22 OK 1_commit_pending_closure.sql (990.75µs)8962026/07/19 09:52:22 OK 2_object_stats_trigger.sql (323.96µs)8972026/07/19 09:52:22 goose: up to current file version: 2898--- PASS: TestMetricsInventory (0.50s)899=== CONT TestReadProxyConditionalGet9002026/07/19 09:52:22 INFO Received cleanup request method=DELETE path=/api/pending_closures9012026/07/19 09:52:22 INFO Aborted multipart uploads count=1902--- PASS: TestMultipartCleanup (0.60s)903=== CONT TestGCBugBareHashReferences9042026-07-19 09:52:22.715 UTC [91940] ERROR: relation "goose_db_version" does not exist at character 369052026-07-19 09:52:22.715 UTC [91940] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9062026-07-19 09:52:22.729 UTC [91941] ERROR: relation "goose_db_version" does not exist at character 369072026-07-19 09:52:22.729 UTC [91941] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9082026/07/19 09:52:22 OK 20241026095416_initial_model.sql (12.45ms)9092026/07/19 09:52:22 OK 20241026095416_initial_model.sql (8.68ms)9102026/07/19 09:52:22 OK 20251210153512_drop_unused_gin_index.sql (382.71µs)9112026/07/19 09:52:22 OK 20251210153512_drop_unused_gin_index.sql (326.13µs)9122026/07/19 09:52:22 OK 20251218171726_add_pins.sql (725.13µs)9132026/07/19 09:52:22 OK 20251218171726_add_pins.sql (750.71µs)9142026/07/19 09:52:22 OK 20260628120000_add_object_size_and_stats.sql (5.11ms)9152026/07/19 09:52:22 goose: successfully migrated database to version: 202606281200009162026/07/19 09:52:22 OK 20260628120000_add_object_size_and_stats.sql (5.76ms)9172026/07/19 09:52:22 goose: successfully migrated database to version: 202606281200009182026/07/19 09:52:22 OK 1_commit_pending_closure.sql (1.53ms)9192026/07/19 09:52:22 OK 1_commit_pending_closure.sql (901.04µs)9202026/07/19 09:52:22 OK 2_object_stats_trigger.sql (211.75µs)9212026/07/19 09:52:22 goose: up to current file version: 29222026/07/19 09:52:22 OK 2_object_stats_trigger.sql (199.79µs)9232026/07/19 09:52:22 goose: up to current file version: 2924--- PASS: TestService_healthCheckHandler (0.57s)925=== CONT TestReadProxyDisabled9262026/07/19 09:52:22 INFO Created nix-cache-info in bucket bucket=bucket209272026-07-19 09:52:22.776 UTC [91945] ERROR: relation "goose_db_version" does not exist at character 369282026-07-19 09:52:22.776 UTC [91945] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9292026-07-19 09:52:22.796 UTC [91947] ERROR: relation "goose_db_version" does not exist at character 369302026-07-19 09:52:22.796 UTC [91947] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC931=== NAME TestNARDeduplicationMetadataUploadBug932 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-91752-1574309481/TestNARDeduplicationMetadataUploadBug3063334065/001/store/svx3ka162dbf1gd78ss7fha6nazn6zav-file1.txt9332026/07/19 09:52:22 OK 20241026095416_initial_model.sql (32.88ms)9342026/07/19 09:52:22 OK 20251210153512_drop_unused_gin_index.sql (647µs)9352026/07/19 09:52:22 OK 20251218171726_add_pins.sql (913.17µs)9362026-07-19 09:52:22.826 UTC [91949] ERROR: relation "goose_db_version" does not exist at character 369372026-07-19 09:52:22.826 UTC [91949] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9382026/07/19 09:52:22 OK 20260628120000_add_object_size_and_stats.sql (11.57ms)9392026/07/19 09:52:22 goose: successfully migrated database to version: 202606281200009402026/07/19 09:52:22 OK 20241026095416_initial_model.sql (15.34ms)9412026/07/19 09:52:22 OK 1_commit_pending_closure.sql (1.25ms)9422026/07/19 09:52:22 OK 2_object_stats_trigger.sql (322.88µs)9432026/07/19 09:52:22 goose: up to current file version: 29442026/07/19 09:52:22 OK 20251210153512_drop_unused_gin_index.sql (446.5µs)9452026/07/19 09:52:22 OK 20251218171726_add_pins.sql (974.58µs)946--- PASS: TestReadProxyHead (0.55s)947=== CONT TestReadProxyRootRedirectsToIndexHTML9482026-07-19 09:52:22.840 UTC [91950] ERROR: relation "goose_db_version" does not exist at character 369492026-07-19 09:52:22.840 UTC [91950] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9502026/07/19 09:52:22 OK 20241026095416_initial_model.sql (13.55ms)9512026/07/19 09:52:22 OK 20251210153512_drop_unused_gin_index.sql (476.92µs)9522026/07/19 09:52:22 OK 20260628120000_add_object_size_and_stats.sql (16.63ms)9532026/07/19 09:52:22 goose: successfully migrated database to version: 202606281200009542026/07/19 09:52:22 OK 20251218171726_add_pins.sql (2.82ms)9552026/07/19 09:52:22 OK 1_commit_pending_closure.sql (937.67µs)9562026/07/19 09:52:22 OK 2_object_stats_trigger.sql (227.71µs)9572026/07/19 09:52:22 goose: up to current file version: 29582026/07/19 09:52:22 OK 20241026095416_initial_model.sql (7.07ms)959--- PASS: TestReadProxy404 (0.48s)960=== CONT TestCacheStatsHandler9612026/07/19 09:52:22 OK 20251210153512_drop_unused_gin_index.sql (835.63µs)9622026/07/19 09:52:22 OK 20260628120000_add_object_size_and_stats.sql (4.04ms)9632026/07/19 09:52:22 goose: successfully migrated database to version: 202606281200009642026/07/19 09:52:22 OK 20251218171726_add_pins.sql (2.27ms)9652026/07/19 09:52:22 OK 1_commit_pending_closure.sql (1.9ms)9662026/07/19 09:52:22 OK 2_object_stats_trigger.sql (343.88µs)9672026/07/19 09:52:22 goose: up to current file version: 29682026/07/19 09:52:22 OK 20260628120000_add_object_size_and_stats.sql (2.96ms)9692026/07/19 09:52:22 goose: successfully migrated database to version: 20260628120000970--- PASS: TestReadProxyInvalidPath (0.49s)971=== CONT TestClientCADerivations9722026/07/19 09:52:22 OK 1_commit_pending_closure.sql (961.46µs)9732026/07/19 09:52:22 OK 2_object_stats_trigger.sql (281.54µs)9742026/07/19 09:52:22 goose: up to current file version: 2975--- PASS: TestReadProxyNarStreaming (0.61s)976=== CONT TestClientMultipleUploads9772026-07-19 09:52:22.911 UTC [91963] ERROR: relation "goose_db_version" does not exist at character 369782026-07-19 09:52:22.911 UTC [91963] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9792026/07/19 09:52:22 INFO Received uploads request method=POST path=/api/pending_closures9802026/07/19 09:52:22 OK 20241026095416_initial_model.sql (9.8ms)9812026/07/19 09:52:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9822026/07/19 09:52:22 INFO Uploading svx3ka162dbf1gd78ss7fha6nazn6zav-file1.txt (160B)9832026/07/19 09:52:22 OK 20251210153512_drop_unused_gin_index.sql (525.71µs)9842026/07/19 09:52:22 OK 20251218171726_add_pins.sql (777.88µs)9852026/07/19 09:52:22 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9862026/07/19 09:52:22 WARN Failed to register uploaded object key=svx3ka162dbf1gd78ss7fha6nazn6zav.ls error="server returned 404: 404 page not found\n"9872026/07/19 09:52:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9882026/07/19 09:52:22 INFO Signed narinfos id=1 count=19892026/07/19 09:52:22 INFO Uploading 1 narinfos9902026/07/19 09:52:22 WARN Failed to register uploaded object key=svx3ka162dbf1gd78ss7fha6nazn6zav.narinfo error="server returned 404: 404 page not found\n"9912026/07/19 09:52:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9922026-07-19 09:52:22.941 UTC [91965] ERROR: relation "goose_db_version" does not exist at character 369932026-07-19 09:52:22.941 UTC [91965] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9942026/07/19 09:52:22 INFO Completed upload id=19952026/07/19 09:52:22 INFO Upload complete. (95ms)996=== NAME TestNARDeduplicationMetadataUploadBug997 metadata_upload_test.go:54: Retrieved narinfo from S3:998 StorePath: /nix/var/nix/builds/nix-91752-1574309481/TestNARDeduplicationMetadataUploadBug3063334065/001/store/svx3ka162dbf1gd78ss7fha6nazn6zav-file1.txt999 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1000 Compression: zstd1001 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1002 NarSize: 1601003 References: 1004 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1005 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1006 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1007 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}10082026/07/19 09:52:22 OK 20260628120000_add_object_size_and_stats.sql (15.01ms)10092026/07/19 09:52:22 goose: successfully migrated database to version: 2026062812000010102026/07/19 09:52:22 OK 1_commit_pending_closure.sql (1.45ms)10112026/07/19 09:52:22 OK 2_object_stats_trigger.sql (283.67µs)10122026/07/19 09:52:22 goose: up to current file version: 210132026/07/19 09:52:22 INFO Aborted multipart uploads count=010142026/07/19 09:52:22 WARN Force mode enabled - objects will be deleted immediately without grace period10152026/07/19 09:52:22 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=010162026/07/19 09:52:22 INFO Vacuumed table table=pending_closures10172026/07/19 09:52:22 INFO Vacuumed table table=pending_objects10182026/07/19 09:52:22 INFO Vacuumed table table=multipart_uploads10192026/07/19 09:52:22 INFO Vacuumed table table=closures10202026/07/19 09:52:22 OK 20241026095416_initial_model.sql (9.74ms)10212026/07/19 09:52:22 OK 20251210153512_drop_unused_gin_index.sql (364.04µs)10222026/07/19 09:52:22 OK 20251218171726_add_pins.sql (719.46µs)10232026/07/19 09:52:22 INFO Vacuumed table table=objects1024--- PASS: TestGCMetrics (0.50s)1025=== CONT TestClientWithDependencies10262026/07/19 09:52:22 OK 20260628120000_add_object_size_and_stats.sql (3.65ms)10272026/07/19 09:52:22 goose: successfully migrated database to version: 2026062812000010282026/07/19 09:52:22 OK 1_commit_pending_closure.sql (1.01ms)10292026/07/19 09:52:22 OK 2_object_stats_trigger.sql (277.04µs)10302026/07/19 09:52:22 goose: up to current file version: 21031--- PASS: TestReadProxyConditionalGet (0.49s)1032=== CONT TestService_AuthMiddleware_OIDC10332026/07/19 09:52:22 INFO OIDC provider initialized name=test1034=== NAME TestNARDeduplicationMetadataUploadBug1035 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-91752-1574309481/TestNARDeduplicationMetadataUploadBug3063334065/001/store/r43i09hfniw9qfb8kz6vrfdcx3yx2m65-file2.txt10362026-07-19 09:52:22.995 UTC [91974] ERROR: relation "goose_db_version" does not exist at character 3610372026-07-19 09:52:22.995 UTC [91974] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10382026/07/19 09:52:23 OK 20241026095416_initial_model.sql (6.32ms)10392026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (531.38µs)10402026/07/19 09:52:23 OK 20251218171726_add_pins.sql (1.84ms)10412026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (2.47ms)10422026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000010432026/07/19 09:52:23 OK 1_commit_pending_closure.sql (889.79µs)10442026/07/19 09:52:23 OK 2_object_stats_trigger.sql (227.5µs)10452026/07/19 09:52:23 goose: up to current file version: 210462026/07/19 09:52:23 INFO Received uploads request method=POST path=/api/pending_closures10472026/07/19 09:52:23 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)10482026/07/19 09:52:23 WARN Failed to register uploaded object key=r43i09hfniw9qfb8kz6vrfdcx3yx2m65.ls error="server returned 404: 404 page not found\n"10492026/07/19 09:52:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10502026/07/19 09:52:23 INFO Signed narinfos id=2 count=110512026/07/19 09:52:23 INFO Uploading 1 narinfos10522026/07/19 09:52:23 WARN Failed to register uploaded object key=r43i09hfniw9qfb8kz6vrfdcx3yx2m65.narinfo error="server returned 404: 404 page not found\n"10532026/07/19 09:52:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10542026/07/19 09:52:23 INFO Completed upload id=210552026/07/19 09:52:23 INFO Upload complete. (71ms)1056 metadata_upload_test.go:76: Retrieved narinfo from S3:1057 StorePath: /nix/var/nix/builds/nix-91752-1574309481/TestNARDeduplicationMetadataUploadBug3063334065/001/store/r43i09hfniw9qfb8kz6vrfdcx3yx2m65-file2.txt1058 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1059 Compression: zstd1060 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1061 NarSize: 1601062 References: 1063 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1064 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1065 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1066 {"version":1,"root":{"type":"regular","size":44}}1067--- PASS: TestNARDeduplicationMetadataUploadBug (0.98s)1068=== CONT TestService_AuthMiddleware_MTLSBoundSubjects10692026-07-19 09:52:23.134 UTC [91982] ERROR: relation "goose_db_version" does not exist at character 3610702026-07-19 09:52:23.134 UTC [91982] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10712026-07-19 09:52:23.147 UTC [91983] ERROR: relation "goose_db_version" does not exist at character 3610722026-07-19 09:52:23.147 UTC [91983] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10732026/07/19 09:52:23 OK 20241026095416_initial_model.sql (13.69ms)10742026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (426.38µs)10752026/07/19 09:52:23 OK 20251218171726_add_pins.sql (1.18ms)10762026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (6.32ms)10772026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000010782026/07/19 09:52:23 OK 20241026095416_initial_model.sql (8.61ms)10792026/07/19 09:52:23 OK 1_commit_pending_closure.sql (911.13µs)10802026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (345.13µs)10812026/07/19 09:52:23 OK 2_object_stats_trigger.sql (264.04µs)10822026/07/19 09:52:23 goose: up to current file version: 210832026/07/19 09:52:23 OK 20251218171726_add_pins.sql (1.2ms)1084--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.33s)1085=== CONT TestCacheConfigHandler1086=== RUN TestCacheConfigHandler/full_config,_no_issuer1087=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1088=== RUN TestCacheConfigHandler/no_cache_url_configured1089=== PAUSE TestCacheConfigHandler/no_cache_url_configured1090=== RUN TestCacheConfigHandler/no_signing_keys1091=== PAUSE TestCacheConfigHandler/no_signing_keys1092=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1093=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1094=== CONT TestService_ReadAuthMiddleware10952026-07-19 09:52:23.171 UTC [91985] ERROR: relation "goose_db_version" does not exist at character 3610962026-07-19 09:52:23.171 UTC [91985] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10972026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (13.5ms)10982026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000010992026/07/19 09:52:23 OK 1_commit_pending_closure.sql (1.1ms)11002026/07/19 09:52:23 OK 2_object_stats_trigger.sql (399.13µs)11012026/07/19 09:52:23 goose: up to current file version: 21102--- PASS: TestReadProxyDisabled (0.42s)1103=== CONT TestPinProtectsFromGC11042026-07-19 09:52:23.190 UTC [91988] ERROR: relation "goose_db_version" does not exist at character 3611052026-07-19 09:52:23.190 UTC [91988] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11062026/07/19 09:52:23 OK 20241026095416_initial_model.sql (17.72ms)11072026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (545.75µs)11082026/07/19 09:52:23 OK 20251218171726_add_pins.sql (796.46µs)11092026-07-19 09:52:23.205 UTC [91990] ERROR: relation "goose_db_version" does not exist at character 3611102026-07-19 09:52:23.205 UTC [91990] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11112026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (8.41ms)11122026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000011132026/07/19 09:52:23 OK 1_commit_pending_closure.sql (886.46µs)11142026/07/19 09:52:23 OK 2_object_stats_trigger.sql (210.58µs)11152026/07/19 09:52:23 goose: up to current file version: 211162026/07/19 09:52:23 OK 20241026095416_initial_model.sql (19.59ms)11172026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (754.42µs)11182026/07/19 09:52:23 OK 20251218171726_add_pins.sql (4.14ms)11192026/07/19 09:52:23 OK 20241026095416_initial_model.sql (14.18ms)1120--- PASS: TestCacheStatsHandler (0.37s)1121=== CONT TestService_AuthMiddleware_MTLSProxyHeader11222026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (941.5µs)11232026/07/19 09:52:23 OK 20251218171726_add_pins.sql (811.46µs)1124--- PASS: TestGCBugBareHashReferences (0.66s)1125=== CONT TestClientIntegration11262026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (9.92ms)11272026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000011282026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (12.67ms)11292026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000011302026/07/19 09:52:23 OK 1_commit_pending_closure.sql (1.86ms)11312026/07/19 09:52:23 OK 1_commit_pending_closure.sql (1.15ms)11322026/07/19 09:52:23 OK 2_object_stats_trigger.sql (215.42µs)11332026/07/19 09:52:23 goose: up to current file version: 211342026/07/19 09:52:23 OK 2_object_stats_trigger.sql (304.21µs)11352026/07/19 09:52:23 goose: up to current file version: 211362026/07/19 09:52:23 INFO Created nix-cache-info in bucket bucket=bucket3211372026/07/19 09:52:23 INFO Created nix-cache-info in bucket bucket=bucket311138=== NAME TestClientMultipleUploads1139 client_integration_test.go:338: Created store path 0: /nix/var/nix/builds/nix-91752-1574309481/TestClientMultipleUploads2302634143/001/store/cdz2sgixgbc6iynk29dl4z39f8zx77hl-test-file-0.txt11402026-07-19 09:52:23.322 UTC [91999] ERROR: relation "goose_db_version" does not exist at character 3611412026-07-19 09:52:23.322 UTC [91999] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11422026-07-19 09:52:23.336 UTC [92002] ERROR: relation "goose_db_version" does not exist at character 3611432026-07-19 09:52:23.336 UTC [92002] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11442026/07/19 09:52:23 OK 20241026095416_initial_model.sql (22.45ms)11452026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (591.71µs)11462026/07/19 09:52:23 OK 20251218171726_add_pins.sql (797.96µs)11472026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (2.81ms)11482026/07/19 09:52:23 goose: successfully migrated database to version: 202606281200001149 client_integration_test.go:338: Created store path 1: /nix/var/nix/builds/nix-91752-1574309481/TestClientMultipleUploads2302634143/001/store/h8zrscza0b4zcm4j8zg6l0md4ms04dmj-test-file-1.txt11502026/07/19 09:52:23 OK 1_commit_pending_closure.sql (2.44ms)11512026/07/19 09:52:23 OK 2_object_stats_trigger.sql (495.5µs)11522026/07/19 09:52:23 goose: up to current file version: 211532026/07/19 09:52:23 OK 20241026095416_initial_model.sql (9.33ms)11542026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (811.42µs)11552026/07/19 09:52:23 INFO Created nix-cache-info in bucket bucket=bucket3311562026/07/19 09:52:23 OK 20251218171726_add_pins.sql (1.29ms)11572026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (2.33ms)11582026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000011592026/07/19 09:52:23 OK 1_commit_pending_closure.sql (1.94ms)11602026/07/19 09:52:23 OK 2_object_stats_trigger.sql (276.13µs)11612026/07/19 09:52:23 goose: up to current file version: 21162=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1163=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1164=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1165=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1166=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1167=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1168=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1169=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1170=== CONT TestParseSingleRange1171=== RUN TestParseSingleRange/none1172=== PAUSE TestParseSingleRange/none1173=== RUN TestParseSingleRange/unknown_unit1174=== PAUSE TestParseSingleRange/unknown_unit1175=== RUN TestParseSingleRange/multi-range_ignored1176=== PAUSE TestParseSingleRange/multi-range_ignored1177=== RUN TestParseSingleRange/malformed_no_dash1178=== PAUSE TestParseSingleRange/malformed_no_dash1179=== RUN TestParseSingleRange/malformed_both_empty1180=== PAUSE TestParseSingleRange/malformed_both_empty1181=== RUN TestParseSingleRange/malformed_end_before_start1182=== PAUSE TestParseSingleRange/malformed_end_before_start1183=== RUN TestParseSingleRange/closed1184=== PAUSE TestParseSingleRange/closed1185=== RUN TestParseSingleRange/open-ended1186=== PAUSE TestParseSingleRange/open-ended1187=== RUN TestParseSingleRange/end_clamped_to_size1188=== PAUSE TestParseSingleRange/end_clamped_to_size1189=== RUN TestParseSingleRange/suffix1190=== PAUSE TestParseSingleRange/suffix1191=== RUN TestParseSingleRange/suffix_exceeds_size1192=== PAUSE TestParseSingleRange/suffix_exceeds_size1193=== RUN TestParseSingleRange/single_byte1194=== PAUSE TestParseSingleRange/single_byte1195=== RUN TestParseSingleRange/start_past_EOF1196=== PAUSE TestParseSingleRange/start_past_EOF1197=== RUN TestParseSingleRange/start_far_past_EOF1198=== PAUSE TestParseSingleRange/start_far_past_EOF1199=== CONT TestOrphanedObjectsGCStressTest1200=== NAME TestClientMultipleUploads1201 client_integration_test.go:338: Created store path 2: /nix/var/nix/builds/nix-91752-1574309481/TestClientMultipleUploads2302634143/001/store/yrx0jab6s78d0fiipjfs3y9hhsxw3r23-test-file-2.txt12022026-07-19 09:52:23.473 UTC [92020] ERROR: relation "goose_db_version" does not exist at character 3612032026-07-19 09:52:23.473 UTC [92020] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1204=== NAME TestClientCADerivations1205 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-91752-1574309481/TestClientCADerivations702849114/001/store/l6kw2w295jzzdjf9adjj0xc5fbw0i6i4-ca-test12062026/07/19 09:52:23 OK 20241026095416_initial_model.sql (10.39ms)12072026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (704.04µs)12082026/07/19 09:52:23 OK 20251218171726_add_pins.sql (1.27ms)12092026/07/19 09:52:23 INFO Received uploads request method=POST path=/api/pending_closures12102026-07-19 09:52:23.502 UTC [92023] ERROR: relation "goose_db_version" does not exist at character 3612112026-07-19 09:52:23.502 UTC [92023] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12122026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (11.52ms)12132026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000012142026/07/19 09:52:23 OK 1_commit_pending_closure.sql (2.03ms)12152026/07/19 09:52:23 OK 2_object_stats_trigger.sql (437.21µs)12162026/07/19 09:52:23 goose: up to current file version: 212172026/07/19 09:52:23 INFO Received uploads request method=POST path=/api/pending_closures12182026/07/19 09:52:23 INFO Received uploads request method=POST path=/api/pending_closures12192026/07/19 09:52:23 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"12202026/07/19 09:52:23 WARN mTLS auth: bound subjects configured but subject DN unavailable12212026/07/19 09:52:23 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1222--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.42s)1223=== CONT TestResurrectedObjectNotDeleted12242026/07/19 09:52:23 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12252026/07/19 09:52:23 INFO Uploading yrx0jab6s78d0fiipjfs3y9hhsxw3r23-test-file-2.txt (160B)12262026/07/19 09:52:23 INFO Uploading cdz2sgixgbc6iynk29dl4z39f8zx77hl-test-file-0.txt (160B)12272026/07/19 09:52:23 INFO Uploading h8zrscza0b4zcm4j8zg6l0md4ms04dmj-test-file-1.txt (160B)12282026/07/19 09:52:23 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12292026/07/19 09:52:23 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12302026/07/19 09:52:23 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12312026/07/19 09:52:23 WARN Failed to register uploaded object key=cdz2sgixgbc6iynk29dl4z39f8zx77hl.ls error="server returned 404: 404 page not found\n"12322026/07/19 09:52:23 WARN Failed to register uploaded object key=yrx0jab6s78d0fiipjfs3y9hhsxw3r23.ls error="server returned 404: 404 page not found\n"12332026/07/19 09:52:23 WARN Failed to register uploaded object key=h8zrscza0b4zcm4j8zg6l0md4ms04dmj.ls error="server returned 404: 404 page not found\n"12342026/07/19 09:52:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign12352026/07/19 09:52:23 INFO Signed narinfos id=3 count=112362026/07/19 09:52:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12372026/07/19 09:52:23 INFO Signed narinfos id=1 count=112382026/07/19 09:52:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12392026/07/19 09:52:23 INFO Signed narinfos id=2 count=112402026/07/19 09:52:23 INFO Uploading 3 narinfos1241=== NAME TestClientCADerivations1242 client_ca_test.go:139: Found 1 dependencies (including self)12432026/07/19 09:52:23 OK 20241026095416_initial_model.sql (11.73ms)12442026/07/19 09:52:23 WARN Failed to register uploaded object key=yrx0jab6s78d0fiipjfs3y9hhsxw3r23.narinfo error="server returned 404: 404 page not found\n"12452026/07/19 09:52:23 WARN Failed to register uploaded object key=h8zrscza0b4zcm4j8zg6l0md4ms04dmj.narinfo error="server returned 404: 404 page not found\n"12462026/07/19 09:52:23 WARN Failed to register uploaded object key=cdz2sgixgbc6iynk29dl4z39f8zx77hl.narinfo error="server returned 404: 404 page not found\n"12472026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)12482026/07/19 09:52:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12492026-07-19 09:52:23.532 UTC [92028] ERROR: relation "goose_db_version" does not exist at character 3612502026-07-19 09:52:23.532 UTC [92028] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12512026/07/19 09:52:23 OK 20251218171726_add_pins.sql (10.75ms)12522026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (6.44ms)12532026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000012542026/07/19 09:52:23 INFO Completed upload id=112552026/07/19 09:52:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12562026/07/19 09:52:23 OK 1_commit_pending_closure.sql (1.58ms)12572026/07/19 09:52:23 OK 2_object_stats_trigger.sql (462.33µs)12582026/07/19 09:52:23 goose: up to current file version: 212592026/07/19 09:52:23 INFO Completed upload id=212602026/07/19 09:52:23 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete12612026/07/19 09:52:23 INFO Completed upload id=312622026/07/19 09:52:23 INFO Upload complete. (115ms)1263=== NAME TestClientMultipleUploads1264 client_integration_test.go:349: Uploaded 3 paths in 145.669958ms12652026/07/19 09:52:23 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1266--- PASS: TestService_ReadAuthMiddleware (0.38s)1267=== CONT TestReadProxyNarinfo1268--- PASS: TestClientMultipleUploads (0.69s)1269=== CONT TestIsValidCachePath1270=== RUN TestIsValidCachePath/narinfo1271=== PAUSE TestIsValidCachePath/narinfo1272=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1273=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1274=== RUN TestIsValidCachePath/nar_zst1275=== PAUSE TestIsValidCachePath/nar_zst1276=== RUN TestIsValidCachePath/nar_xz1277=== PAUSE TestIsValidCachePath/nar_xz1278=== RUN TestIsValidCachePath/nar_bz21279=== PAUSE TestIsValidCachePath/nar_bz21280=== RUN TestIsValidCachePath/nar_uncompressed1281=== PAUSE TestIsValidCachePath/nar_uncompressed1282=== RUN TestIsValidCachePath/ls1283=== PAUSE TestIsValidCachePath/ls1284=== RUN TestIsValidCachePath/log1285=== PAUSE TestIsValidCachePath/log1286=== RUN TestIsValidCachePath/realisation1287=== PAUSE TestIsValidCachePath/realisation1288=== RUN TestIsValidCachePath/nix-cache-info1289=== PAUSE TestIsValidCachePath/nix-cache-info1290=== RUN TestIsValidCachePath/index.html1291=== PAUSE TestIsValidCachePath/index.html1292=== RUN TestIsValidCachePath/traversal_parent1293=== PAUSE TestIsValidCachePath/traversal_parent1294=== RUN TestIsValidCachePath/traversal_in_middle1295=== PAUSE TestIsValidCachePath/traversal_in_middle1296=== RUN TestIsValidCachePath/invalid_char_e1297=== PAUSE TestIsValidCachePath/invalid_char_e1298=== RUN TestIsValidCachePath/invalid_char_u1299=== PAUSE TestIsValidCachePath/invalid_char_u1300=== RUN TestIsValidCachePath/random_path1301=== PAUSE TestIsValidCachePath/random_path1302=== RUN TestIsValidCachePath/empty1303=== PAUSE TestIsValidCachePath/empty1304=== RUN TestIsValidCachePath/leading_slash1305=== PAUSE TestIsValidCachePath/leading_slash1306=== RUN TestIsValidCachePath/wrong_extension1307=== PAUSE TestIsValidCachePath/wrong_extension1308=== RUN TestIsValidCachePath/short_hash1309=== PAUSE TestIsValidCachePath/short_hash1310=== CONT TestReadProxyNarinfoAlreadyDecompressed13112026/07/19 09:52:23 OK 20241026095416_initial_model.sql (12.24ms)13122026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (957.13µs)13132026/07/19 09:52:23 OK 20251218171726_add_pins.sql (1.3ms)13142026-07-19 09:52:23.560 UTC [92033] ERROR: relation "goose_db_version" does not exist at character 3613152026-07-19 09:52:23.560 UTC [92033] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13162026-07-19 09:52:23.567 UTC [92036] ERROR: relation "goose_db_version" does not exist at character 3613172026-07-19 09:52:23.567 UTC [92036] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13182026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (11.1ms)13192026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000013202026/07/19 09:52:23 OK 1_commit_pending_closure.sql (900.5µs)13212026/07/19 09:52:23 OK 2_object_stats_trigger.sql (207.17µs)13222026/07/19 09:52:23 goose: up to current file version: 213232026/07/19 09:52:23 INFO Created nix-cache-info in bucket bucket=bucket371324=== NAME TestClientWithDependencies1325 client_integration_test.go:593: Built derivation: /nix/var/nix/builds/nix-91752-1574309481/TestClientWithDependencies1402331035/001/store/57wvd97sfvlk3j5b9n2vh8nh2qlg1h6h-test-script13262026/07/19 09:52:23 OK 20241026095416_initial_model.sql (21.85ms)13272026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (1.44ms)13282026/07/19 09:52:23 OK 20251218171726_add_pins.sql (1.45ms)13292026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (2.59ms)13302026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000013312026/07/19 09:52:23 OK 1_commit_pending_closure.sql (1.04ms)13322026/07/19 09:52:23 OK 2_object_stats_trigger.sql (371.67µs)13332026/07/19 09:52:23 goose: up to current file version: 21334--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.38s)1335=== CONT TestOrphanedObjectsGC13362026/07/19 09:52:23 OK 20241026095416_initial_model.sql (13.24ms)13372026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)13382026/07/19 09:52:23 OK 20251218171726_add_pins.sql (2.49ms)1339=== NAME TestClientWithDependencies1340 client_integration_test.go:595: Found 1 dependencies (including self)13412026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (22.01ms)13422026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000013432026/07/19 09:52:23 OK 1_commit_pending_closure.sql (1.66ms)13442026/07/19 09:52:23 INFO Received uploads request method=POST path=/api/pending_closures13452026/07/19 09:52:23 OK 2_object_stats_trigger.sql (932.08µs)13462026/07/19 09:52:23 goose: up to current file version: 213472026/07/19 09:52:23 INFO Created nix-cache-info in bucket bucket=bucket3913482026/07/19 09:52:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13492026/07/19 09:52:23 INFO Uploading l6kw2w295jzzdjf9adjj0xc5fbw0i6i4-ca-test (144B)13502026/07/19 09:52:23 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13512026/07/19 09:52:23 WARN Failed to register uploaded object key=log/wd8h2b23m8z2i3gfq5jww6mfgb3c0wp7-ca-test.drv error="server returned 404: 404 page not found\n"13522026/07/19 09:52:23 WARN Failed to register uploaded object key=l6kw2w295jzzdjf9adjj0xc5fbw0i6i4.ls error="server returned 404: 404 page not found\n"13532026/07/19 09:52:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13542026/07/19 09:52:23 INFO Signed narinfos id=1 count=113552026/07/19 09:52:23 INFO Uploading 1 narinfos13562026/07/19 09:52:23 WARN Failed to register uploaded object key=l6kw2w295jzzdjf9adjj0xc5fbw0i6i4.narinfo error="server returned 404: 404 page not found\n"13572026/07/19 09:52:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13582026/07/19 09:52:23 INFO Completed upload id=113592026/07/19 09:52:23 INFO Upload complete. (97ms)1360=== NAME TestClientCADerivations1361 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-91752-1574309481/TestClientCADerivations702849114/001/store/l6kw2w295jzzdjf9adjj0xc5fbw0i6i4-ca-test1362 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1363 Compression: zstd1364 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1365 NarSize: 1441366 References: 1367 Deriver: /nix/var/nix/builds/nix-91752-1574309481/TestClientCADerivations702849114/001/store/wd8h2b23m8z2i3gfq5jww6mfgb3c0wp7-ca-test.drv1368 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1369 client_ca_test.go:185: Checking for realisation files in S3...1370 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1371 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1372=== NAME TestPinProtectsFromGC1373 client_integration_test.go:646: Pinned store path: /nix/var/nix/builds/nix-91752-1574309481/TestPinProtectsFromGC3647456582/001/store/92pq38vy03whg2dx42zmsmlldbx844pj-pinned-file.txt1374 client_integration_test.go:647: Unpinned store path: /nix/var/nix/builds/nix-91752-1574309481/TestPinProtectsFromGC3647456582/001/store/mdvphry8kyhw4fgckli43akf8mhnnnfj-unpinned-file.txt13752026/07/19 09:52:23 INFO Received uploads request method=POST path=/api/pending_closures1376=== NAME TestClientIntegration1377 client_integration_test.go:276: Created store path: /nix/var/nix/builds/nix-91752-1574309481/TestClientIntegration2423191205/002/store/nychk8g1ph0lq6z9j8gx8bzrha1lzpzp-test-file.txt1378=== NAME TestClientCADerivations1379 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket32?endpoint=http://localhost:59027®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-91752-1574309481/TestClientCADerivations702849114/001/store'1380 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11381--- PASS: TestClientCADerivations (0.84s)1382=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info13832026/07/19 09:52:23 INFO Received uploads request method=POST path=/1384=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key13852026/07/19 09:52:23 INFO Received complete multipart upload request method=POST path=/1386=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key13872026/07/19 09:52:23 INFO Received request for more parts method=POST path=/1388=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal13892026/07/19 09:52:23 INFO Received uploads request method=POST path=/1390--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1391 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1392 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1393 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1394 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1395=== CONT TestIsValidUploadKey/narinfo1396=== CONT TestIsValidUploadKey/realisation_plus_in_output1397=== CONT TestIsValidUploadKey/unknown_type1398=== CONT TestIsValidUploadKey/empty_key1399=== CONT TestIsValidUploadKey/absolute1400=== CONT TestIsValidUploadKey/traversal_nar1401=== CONT TestIsValidUploadKey/traversal1402=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1403=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1404=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1405=== CONT TestIsValidUploadKey/index.html1406=== CONT TestIsValidUploadKey/nix-cache-info1407=== CONT TestIsValidUploadKey/build_log_home-manager_file1408=== CONT TestIsValidUploadKey/realisation1409=== CONT TestIsValidUploadKey/build_log_equals1410=== CONT TestIsValidUploadKey/build_log_question_mark1411=== CONT TestIsValidUploadKey/build_log_plus_in_name1412=== CONT TestIsValidUploadKey/nar_plain1413=== CONT TestIsValidUploadKey/build_log1414=== CONT TestIsValidUploadKey/listing1415=== CONT TestIsValidUploadKey/nar_xz1416=== CONT TestIsValidUploadKey/nar_zst1417--- PASS: TestIsValidUploadKey (0.03s)1418 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1419 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1420 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1421 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1422 --- PASS: TestIsValidUploadKey/absolute (0.00s)1423 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1424 --- PASS: TestIsValidUploadKey/traversal (0.00s)1425 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1426 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1427 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1428 --- PASS: TestIsValidUploadKey/index.html (0.00s)1429 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1430 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1431 --- PASS: TestIsValidUploadKey/realisation (0.00s)1432 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1433 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1434 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1435 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1436 --- PASS: TestIsValidUploadKey/build_log (0.00s)1437 --- PASS: TestIsValidUploadKey/listing (0.00s)1438 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1439 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)14402026/07/19 09:52:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1441=== CONT TestProxyWriteTimeout/narinfo14422026/07/19 09:52:23 INFO Uploading 57wvd97sfvlk3j5b9n2vh8nh2qlg1h6h-test-script (136B)1443=== CONT TestProxyWriteTimeout/10_GiB_nar1444=== CONT TestProxyWriteTimeout/unknown_size1445=== CONT TestProxyWriteTimeout/1_GiB_nar1446=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14472026/07/19 09:52:23 INFO Received uploads request method=POST path=/1448--- PASS: TestProxyWriteTimeout (0.00s)1449 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1450 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1451 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1452 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)14532026/07/19 09:52:23 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14542026/07/19 09:52:23 WARN Failed to register uploaded object key=57wvd97sfvlk3j5b9n2vh8nh2qlg1h6h.ls error="server returned 404: 404 page not found\n"14552026/07/19 09:52:23 WARN Failed to register uploaded object key=log/7zx4hdfvc2m0qxd9n6lm06awiljw44wz-test-script.drv error="server returned 404: 404 page not found\n"14562026/07/19 09:52:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14572026/07/19 09:52:23 INFO Signed narinfos id=1 count=114582026/07/19 09:52:23 INFO Uploading 1 narinfos14592026/07/19 09:52:23 WARN Failed to register uploaded object key=57wvd97sfvlk3j5b9n2vh8nh2qlg1h6h.narinfo error="server returned 404: 404 page not found\n"14602026/07/19 09:52:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14612026/07/19 09:52:23 INFO Completed upload id=114622026/07/19 09:52:23 INFO Upload complete. (62ms)1463=== NAME TestClientWithDependencies1464 client_integration_test.go:597: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-91752-1574309481/TestClientWithDependencies1402331035/001/store) requires matching store prefix1465--- PASS: TestClientWithDependencies (0.75s)1466=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14672026/07/19 09:52:23 INFO Received request for more parts method=POST path=/14682026-07-19 09:52:23.723 UTC [92060] ERROR: relation "goose_db_version" does not exist at character 3614692026-07-19 09:52:23.723 UTC [92060] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1470=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14712026/07/19 09:52:23 INFO Received complete multipart upload request method=POST path=/14722026/07/19 09:52:23 OK 20241026095416_initial_model.sql (8.41ms)14732026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (549.75µs)14742026/07/19 09:52:23 OK 20251218171726_add_pins.sql (860.42µs)14752026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)14762026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000014772026/07/19 09:52:23 OK 1_commit_pending_closure.sql (1.91ms)14782026/07/19 09:52:23 OK 2_object_stats_trigger.sql (503.54µs)14792026/07/19 09:52:23 goose: up to current file version: 21480=== CONT TestServerTLSConfig/no_client_CA1481=== CONT TestServerTLSConfig/not_a_PEM_file1482=== CONT TestServerTLSConfig/missing_CA_file1483--- PASS: TestServerTLSConfig (0.00s)1484 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1485 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1486 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1487=== CONT TestClientErrorHandling/InvalidStorePath14882026-07-19 09:52:23.787 UTC [92070] ERROR: relation "goose_db_version" does not exist at character 3614892026-07-19 09:52:23.787 UTC [92070] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14902026/07/19 09:52:23 INFO Received uploads request method=POST path=/api/pending_closures14912026/07/19 09:52:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14922026/07/19 09:52:23 INFO Uploading 92pq38vy03whg2dx42zmsmlldbx844pj-pinned-file.txt (128B)14932026/07/19 09:52:23 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14942026/07/19 09:52:23 OK 20241026095416_initial_model.sql (4.71ms)14952026/07/19 09:52:23 WARN Failed to register uploaded object key=92pq38vy03whg2dx42zmsmlldbx844pj.ls error="server returned 404: 404 page not found\n"14962026/07/19 09:52:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14972026/07/19 09:52:23 INFO Signed narinfos id=1 count=114982026/07/19 09:52:23 INFO Uploading 1 narinfos14992026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (718.83µs)15002026/07/19 09:52:23 WARN Failed to register uploaded object key=92pq38vy03whg2dx42zmsmlldbx844pj.narinfo error="server returned 404: 404 page not found\n"15012026/07/19 09:52:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15022026/07/19 09:52:23 OK 20251218171726_add_pins.sql (1.55ms)15032026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (1.49ms)15042026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000015052026/07/19 09:52:23 OK 1_commit_pending_closure.sql (878.92µs)15062026/07/19 09:52:23 INFO Completed upload id=115072026/07/19 09:52:23 INFO Upload complete. (96ms)15082026/07/19 09:52:23 OK 2_object_stats_trigger.sql (350.29µs)15092026/07/19 09:52:23 goose: up to current file version: 215102026-07-19 09:52:23.809 UTC [92072] ERROR: relation "goose_db_version" does not exist at character 3615112026-07-19 09:52:23.809 UTC [92072] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15122026/07/19 09:52:23 INFO Received uploads request method=POST path=/api/pending_closures15132026-07-19 09:52:23.822 UTC [92074] ERROR: relation "goose_db_version" does not exist at character 3615142026-07-19 09:52:23.822 UTC [92074] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15152026/07/19 09:52:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15162026/07/19 09:52:23 INFO Uploading nychk8g1ph0lq6z9j8gx8bzrha1lzpzp-test-file.txt (152B)15172026/07/19 09:52:23 OK 20241026095416_initial_model.sql (5.4ms)15182026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (449.42µs)15192026/07/19 09:52:23 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15202026/07/19 09:52:23 OK 20251218171726_add_pins.sql (839.79µs)15212026/07/19 09:52:23 WARN Failed to register uploaded object key=nychk8g1ph0lq6z9j8gx8bzrha1lzpzp.ls error="server returned 404: 404 page not found\n"15222026/07/19 09:52:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15232026/07/19 09:52:23 INFO Signed narinfos id=1 count=115242026/07/19 09:52:23 INFO Uploading 1 narinfos15252026/07/19 09:52:23 WARN Failed to register uploaded object key=nychk8g1ph0lq6z9j8gx8bzrha1lzpzp.narinfo error="server returned 404: 404 page not found\n"15262026/07/19 09:52:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15272026/07/19 09:52:23 OK 20241026095416_initial_model.sql (5.8ms)15282026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (349.29µs)15292026/07/19 09:52:23 OK 20251218171726_add_pins.sql (764.92µs)15302026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (5.14ms)15312026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000015322026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (1.75ms)15332026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000015342026/07/19 09:52:23 INFO Completed upload id=115352026/07/19 09:52:23 INFO Upload complete. (105ms)15362026/07/19 09:52:23 OK 1_commit_pending_closure.sql (1.5ms)15372026/07/19 09:52:23 OK 1_commit_pending_closure.sql (1.45ms)1538=== NAME TestClientIntegration1539 client_integration_test.go:292: Retrieved narinfo from S3:1540 StorePath: /nix/var/nix/builds/nix-91752-1574309481/TestClientIntegration2423191205/002/store/nychk8g1ph0lq6z9j8gx8bzrha1lzpzp-test-file.txt1541 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1542 Compression: zstd1543 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11544 NarSize: 1521545 References: 1546 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk115472026/07/19 09:52:23 OK 2_object_stats_trigger.sql (433.67µs)15482026/07/19 09:52:23 goose: up to current file version: 215492026/07/19 09:52:23 OK 2_object_stats_trigger.sql (1.2ms)15502026/07/19 09:52:23 goose: up to current file version: 21551 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1552 client_integration_test.go:293: Decompressed .ls content (64 bytes):1553 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1554 client_integration_test.go:296: Testing garbage collection...1555--- PASS: TestResurrectedObjectNotDeleted (0.33s)1556=== CONT TestClientErrorHandling/ServerNotAvailable1557--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.30s)1558=== CONT TestClientErrorHandling/InvalidAuthToken1559--- PASS: TestReadProxyNarinfo (0.31s)1560=== CONT TestCacheConfigHandler/full_config,_no_issuer1561=== CONT TestCacheConfigHandler/no_signing_keys1562=== CONT TestCacheConfigHandler/no_cache_url_configured1563=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1564--- PASS: TestCacheConfigHandler (0.00s)1565 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1566 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1567 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1568 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1569=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token15702026/07/19 09:52:23 INFO OIDC auth successful provider=test1571=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected15722026/07/19 09:52:23 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1573=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1574=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected15752026/07/19 09:52:23 WARN Authentication failed token_preview=eyJhbGciOi...ijHwU09R0Q 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]1576=== CONT TestParseSingleRange/none1577=== CONT TestParseSingleRange/open-ended1578=== CONT TestParseSingleRange/start_far_past_EOF1579=== CONT TestParseSingleRange/start_past_EOF1580=== CONT TestParseSingleRange/single_byte1581=== CONT TestParseSingleRange/suffix_exceeds_size1582=== CONT TestParseSingleRange/suffix1583=== CONT TestParseSingleRange/end_clamped_to_size1584=== CONT TestParseSingleRange/malformed_both_empty1585=== CONT TestParseSingleRange/closed1586=== CONT TestParseSingleRange/malformed_end_before_start1587=== CONT TestParseSingleRange/multi-range_ignored1588=== CONT TestParseSingleRange/malformed_no_dash1589=== CONT TestParseSingleRange/unknown_unit1590--- PASS: TestParseSingleRange (0.00s)1591 --- PASS: TestParseSingleRange/none (0.00s)1592 --- PASS: TestParseSingleRange/open-ended (0.00s)1593 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1594 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1595 --- PASS: TestParseSingleRange/single_byte (0.00s)1596 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1597 --- PASS: TestParseSingleRange/suffix (0.00s)1598 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1599 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1600 --- PASS: TestParseSingleRange/closed (0.00s)1601 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1602 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1603 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1604 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1605=== CONT TestIsValidCachePath/narinfo16062026-07-19 09:52:23.857 UTC [92080] ERROR: relation "goose_db_version" does not exist at character 3616072026-07-19 09:52:23.857 UTC [92080] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1608=== CONT TestIsValidCachePath/index.html1609--- PASS: TestService_AuthMiddleware_OIDC (0.39s)1610 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1611 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1612 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1613 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1614=== CONT TestIsValidCachePath/short_hash1615=== CONT TestIsValidCachePath/wrong_extension1616=== CONT TestIsValidCachePath/leading_slash1617=== CONT TestIsValidCachePath/empty1618=== CONT TestIsValidCachePath/random_path1619=== CONT TestIsValidCachePath/invalid_char_u1620=== CONT TestIsValidCachePath/invalid_char_e1621=== CONT TestIsValidCachePath/traversal_in_middle1622=== CONT TestIsValidCachePath/traversal_parent1623=== CONT TestIsValidCachePath/nar_uncompressed1624=== CONT TestIsValidCachePath/log1625=== CONT TestIsValidCachePath/ls1626=== CONT TestIsValidCachePath/nix-cache-info1627=== CONT TestIsValidCachePath/nar_xz1628=== CONT TestIsValidCachePath/nar_bz21629=== CONT TestIsValidCachePath/nar_zst1630=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1631=== CONT TestIsValidCachePath/realisation1632--- PASS: TestIsValidCachePath (0.00s)1633 --- PASS: TestIsValidCachePath/narinfo (0.00s)1634 --- PASS: TestIsValidCachePath/index.html (0.00s)1635 --- PASS: TestIsValidCachePath/short_hash (0.00s)1636 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1637 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1638 --- PASS: TestIsValidCachePath/empty (0.00s)1639 --- PASS: TestIsValidCachePath/random_path (0.00s)1640 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1641 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1642 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1643 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1644 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1645 --- PASS: TestIsValidCachePath/log (0.00s)1646 --- PASS: TestIsValidCachePath/ls (0.00s)1647 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1648 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1649 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1650 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1651 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1652 --- PASS: TestIsValidCachePath/realisation (0.00s)16532026/07/19 09:52:23 OK 20241026095416_initial_model.sql (5.15ms)16542026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (567.71µs)16552026/07/19 09:52:23 OK 20251218171726_add_pins.sql (1.1ms)16562026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (3.5ms)16572026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000016582026/07/19 09:52:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures16592026/07/19 09:52:23 INFO Garbage collection started16602026/07/19 09:52:23 INFO Aborted multipart uploads count=016612026/07/19 09:52:23 OK 1_commit_pending_closure.sql (5.53ms)16622026/07/19 09:52:23 WARN Force mode enabled - objects will be deleted immediately without grace period16632026/07/19 09:52:23 OK 2_object_stats_trigger.sql (594.71µs)16642026/07/19 09:52:23 goose: up to current file version: 216652026/07/19 09:52:23 INFO Received uploads request method=POST path=/api/pending_closures16662026/07/19 09:52:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16672026/07/19 09:52:23 INFO Uploading mdvphry8kyhw4fgckli43akf8mhnnnfj-unpinned-file.txt (128B)16682026/07/19 09:52:23 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16692026/07/19 09:52:23 WARN Failed to register uploaded object key=mdvphry8kyhw4fgckli43akf8mhnnnfj.ls error="server returned 404: 404 page not found\n"16702026/07/19 09:52:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16712026/07/19 09:52:23 INFO Signed narinfos id=2 count=116722026/07/19 09:52:23 INFO Uploading 1 narinfos16732026/07/19 09:52:23 WARN Failed to register uploaded object key=mdvphry8kyhw4fgckli43akf8mhnnnfj.narinfo error="server returned 404: 404 page not found\n"16742026/07/19 09:52:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16752026/07/19 09:52:23 INFO Completed upload id=216762026/07/19 09:52:23 INFO Upload complete. (88ms)16772026/07/19 09:52:23 INFO Received create pin request method=POST path=/api/pins/myapp16782026-07-19 09:52:23.961 UTC [92093] ERROR: relation "goose_db_version" does not exist at character 3616792026-07-19 09:52:23.961 UTC [92093] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16802026/07/19 09:52:23 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-91752-1574309481/TestPinProtectsFromGC3647456582/001/store/92pq38vy03whg2dx42zmsmlldbx844pj-pinned-file.txt narinfo_key=92pq38vy03whg2dx42zmsmlldbx844pj.narinfo16812026/07/19 09:52:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures16822026/07/19 09:52:23 INFO Garbage collection started16832026/07/19 09:52:23 INFO Aborted multipart uploads count=016842026/07/19 09:52:23 WARN Force mode enabled - objects will be deleted immediately without grace period16852026/07/19 09:52:23 OK 20241026095416_initial_model.sql (4.36ms)16862026/07/19 09:52:23 OK 20251210153512_drop_unused_gin_index.sql (484.25µs)16872026/07/19 09:52:23 OK 20251218171726_add_pins.sql (1.32ms)16882026/07/19 09:52:23 OK 20260628120000_add_object_size_and_stats.sql (1.56ms)16892026/07/19 09:52:23 goose: successfully migrated database to version: 2026062812000016902026/07/19 09:52:23 OK 1_commit_pending_closure.sql (1.07ms)16912026/07/19 09:52:23 OK 2_object_stats_trigger.sql (317.79µs)16922026/07/19 09:52:23 goose: up to current file version: 21693--- PASS: TestUploadHandlersRejectOversizedBody (0.05s)1694 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1695 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1696 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.30s)16972026-07-19 09:52:24.006 UTC [92098] ERROR: relation "goose_db_version" does not exist at character 3616982026-07-19 09:52:24.006 UTC [92098] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16992026/07/19 09:52:24 OK 20241026095416_initial_model.sql (4.42ms)17002026/07/19 09:52:24 OK 20251210153512_drop_unused_gin_index.sql (606.5µs)17012026/07/19 09:52:24 OK 20251218171726_add_pins.sql (863.92µs)17022026/07/19 09:52:24 OK 20260628120000_add_object_size_and_stats.sql (2.58ms)17032026/07/19 09:52:24 goose: successfully migrated database to version: 2026062812000017042026/07/19 09:52:24 OK 1_commit_pending_closure.sql (946.21µs)17052026/07/19 09:52:24 OK 2_object_stats_trigger.sql (223.38µs)17062026/07/19 09:52:24 goose: up to current file version: 217072026/07/19 09:52:24 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_closures17082026/07/19 09:52:24 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=198.332788ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1709=== NAME TestOrphanedObjectsGCStressTest1710 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1711 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1712=== NAME TestOrphanedObjectsGC1713 orphaned_objects_gc_test.go:290: GC Test Summary:1714 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1715 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1716 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1717 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1718 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1719--- PASS: TestOrphanedObjectsGC (0.54s)17202026/07/19 09:52:24 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1721=== NAME TestOrphanedObjectsGCStressTest1722 orphaned_objects_gc_test.go:509: Stress test completed successfully:1723 orphaned_objects_gc_test.go:510: - Active objects preserved: 201724 orphaned_objects_gc_test.go:511: - Objects deleted: 2101725 orphaned_objects_gc_test.go:512: - Total GC'd: 2101726--- PASS: TestOrphanedObjectsGCStressTest (0.84s)17272026/07/19 09:52:24 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=017282026/07/19 09:52:24 INFO Vacuumed table table=pending_closures17292026/07/19 09:52:24 INFO Vacuumed table table=pending_objects17302026/07/19 09:52:24 INFO Vacuumed table table=multipart_uploads17312026/07/19 09:52:24 INFO Vacuumed table table=closures17322026/07/19 09:52:24 INFO Vacuumed table table=objects17332026/07/19 09:52:24 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=017342026/07/19 09:52:24 INFO Vacuumed table table=pending_closures17352026/07/19 09:52:24 INFO Vacuumed table table=pending_objects17362026/07/19 09:52:24 INFO Vacuumed table table=multipart_uploads17372026/07/19 09:52:24 INFO Vacuumed table table=closures17382026/07/19 09:52:24 INFO Vacuumed table table=objects17392026/07/19 09:52:24 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=421.711373ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17402026/07/19 09:52:24 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=865.090316ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17412026/07/19 09:52:25 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.710550514s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17422026/07/19 09:52:25 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01743=== NAME TestClientIntegration1744 client_integration_test.go:303: Objects in database after GC:1745 client_integration_test.go:303: Successfully deleted all objects with GC --force1746--- PASS: TestClientIntegration (2.66s)17472026/07/19 09:52:25 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01748=== NAME TestPinProtectsFromGC1749 client_integration_test.go:709: Pin successfully protected closure from garbage collection1750--- PASS: TestPinProtectsFromGC (2.80s)17512026/07/19 09:52:26 WARN Rate limiter enabled after throttle name=s3-test rate=517522026/07/19 09:52:26 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1753=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1754 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101755 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001756--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.37s)1757--- PASS: TestClientErrorHandling (0.00s)1758 --- PASS: TestClientErrorHandling/InvalidStorePath (0.25s)1759 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.32s)1760 --- PASS: TestClientErrorHandling/ServerNotAvailable (3.49s)1761PASS1762{"timestamp":"2026-07-19T09:52:27.841279Z","level":"ERROR","fields":{"message":"Unknown connection IO error:Cancelled","peer_addr":"127.0.0.1:59070"},"target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":973,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}17632026-07-19 09:52:27.906 UTC [91787] LOG: received smart shutdown request17642026-07-19 09:52:27.907 UTC [91787] LOG: background worker "logical replication launcher" (PID 91797) exited with exit code 117652026-07-19 09:52:27.916 UTC [91792] LOG: shutting down17662026-07-19 09:52:27.916 UTC [91792] LOG: checkpoint starting: shutdown immediate17672026-07-19 09:52:28.968 UTC [91792] LOG: checkpoint complete: wrote 13241 buffers (80.8%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 13 recycled; write=0.793 s, sync=0.257 s, total=1.053 s; sync files=15167, longest=0.001 s, average=0.001 s; distance=212068 kB, estimate=212068 kB; lsn=0/E69E630, redo lsn=0/E69E63017682026-07-19 09:52:28.972 UTC [91787] LOG: database system is shut down1769Running OIDC tests...1770=== RUN TestGlobMatch1771=== PAUSE TestGlobMatch1772=== RUN TestAudienceForIssuer1773=== PAUSE TestAudienceForIssuer1774=== RUN TestValidateToken_ValidToken1775=== PAUSE TestValidateToken_ValidToken1776=== RUN TestValidateToken_WrongAudience1777=== PAUSE TestValidateToken_WrongAudience1778=== RUN TestValidateToken_Expired1779=== PAUSE TestValidateToken_Expired1780=== RUN TestValidateToken_BoundClaimsMismatch1781=== PAUSE TestValidateToken_BoundClaimsMismatch1782=== RUN TestValidateToken_BoundSubjectMismatch1783=== PAUSE TestValidateToken_BoundSubjectMismatch1784=== RUN TestValidateToken_MultipleProviders1785=== PAUSE TestValidateToken_MultipleProviders1786=== RUN TestValidateToken_NoMatchingProvider1787=== PAUSE TestValidateToken_NoMatchingProvider1788=== CONT TestGlobMatch1789=== CONT TestValidateToken_MultipleProviders1790=== CONT TestValidateToken_BoundSubjectMismatch1791=== CONT TestValidateToken_NoMatchingProvider1792=== CONT TestValidateToken_BoundClaimsMismatch1793=== RUN TestGlobMatch/foo_foo1794=== PAUSE TestGlobMatch/foo_foo1795=== RUN TestGlobMatch/foo_bar1796=== PAUSE TestGlobMatch/foo_bar1797=== RUN TestGlobMatch/*_1798=== PAUSE TestGlobMatch/*_1799=== RUN TestGlobMatch/*_anything1800=== PAUSE TestGlobMatch/*_anything1801=== RUN TestGlobMatch/foo*_foo1802=== PAUSE TestGlobMatch/foo*_foo1803=== RUN TestGlobMatch/foo*_foobar1804=== PAUSE TestGlobMatch/foo*_foobar1805=== RUN TestGlobMatch/foo*_bar1806=== PAUSE TestGlobMatch/foo*_bar1807=== CONT TestValidateToken_Expired1808=== CONT TestValidateToken_WrongAudience1809=== CONT TestValidateToken_ValidToken1810=== CONT TestAudienceForIssuer1811--- PASS: TestAudienceForIssuer (0.00s)1812=== RUN TestGlobMatch/*bar_bar1813=== PAUSE TestGlobMatch/*bar_bar1814=== RUN TestGlobMatch/*bar_foobar1815=== PAUSE TestGlobMatch/*bar_foobar1816=== RUN TestGlobMatch/*bar_foo1817=== PAUSE TestGlobMatch/*bar_foo1818=== RUN TestGlobMatch/foo*bar_foobar1819=== PAUSE TestGlobMatch/foo*bar_foobar1820=== RUN TestGlobMatch/foo*bar_foo123bar1821=== PAUSE TestGlobMatch/foo*bar_foo123bar1822=== RUN TestGlobMatch/foo*bar_foobarbaz1823=== PAUSE TestGlobMatch/foo*bar_foobarbaz1824=== RUN TestGlobMatch/*/*_foo/bar1825=== PAUSE TestGlobMatch/*/*_foo/bar1826=== RUN TestGlobMatch/*/*_foo1827=== PAUSE TestGlobMatch/*/*_foo1828=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1829=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1830=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01831=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01832=== RUN TestGlobMatch/refs/*/main_refs/heads/main1833=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1834=== RUN TestGlobMatch/fo?_foo1835=== PAUSE TestGlobMatch/fo?_foo1836=== RUN TestGlobMatch/fo?_fo1837=== PAUSE TestGlobMatch/fo?_fo1838=== RUN TestGlobMatch/fo?_fooo1839=== PAUSE TestGlobMatch/fo?_fooo1840=== RUN TestGlobMatch/?oo_foo1841=== PAUSE TestGlobMatch/?oo_foo1842=== RUN TestGlobMatch/?oo_boo1843=== PAUSE TestGlobMatch/?oo_boo1844=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1845=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1846=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1847=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1848=== CONT TestGlobMatch/foo_foo1849=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1850=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1851=== CONT TestGlobMatch/?oo_boo1852=== CONT TestGlobMatch/?oo_foo1853=== CONT TestGlobMatch/fo?_fooo1854=== CONT TestGlobMatch/fo?_fo1855=== CONT TestGlobMatch/refs/*/main_refs/heads/main1856=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01857=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1858=== CONT TestGlobMatch/*/*_foo1859=== CONT TestGlobMatch/*/*_foo/bar1860=== CONT TestGlobMatch/foo*bar_foobarbaz1861=== CONT TestGlobMatch/foo*bar_foo123bar1862=== CONT TestGlobMatch/foo*_foobar1863=== CONT TestGlobMatch/*bar_foo1864=== CONT TestGlobMatch/*bar_foobar1865=== CONT TestGlobMatch/*bar_bar1866=== CONT TestGlobMatch/foo*_bar1867=== CONT TestGlobMatch/*_anything1868=== CONT TestGlobMatch/foo*_foo1869=== CONT TestGlobMatch/*_1870=== CONT TestGlobMatch/foo_bar1871=== CONT TestGlobMatch/foo*bar_foobar1872=== CONT TestGlobMatch/fo?_foo1873--- PASS: TestGlobMatch (0.00s)1874 --- PASS: TestGlobMatch/foo_foo (0.00s)1875 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1876 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1877 --- PASS: TestGlobMatch/?oo_boo (0.00s)1878 --- PASS: TestGlobMatch/?oo_foo (0.00s)1879 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1880 --- PASS: TestGlobMatch/fo?_fo (0.00s)1881 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1882 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1883 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1884 --- PASS: TestGlobMatch/*/*_foo (0.00s)1885 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1886 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1887 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1888 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1889 --- PASS: TestGlobMatch/*bar_foo (0.00s)1890 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1891 --- PASS: TestGlobMatch/*bar_bar (0.00s)1892 --- PASS: TestGlobMatch/foo*_bar (0.00s)1893 --- PASS: TestGlobMatch/*_anything (0.00s)1894 --- PASS: TestGlobMatch/foo*_foo (0.00s)1895 --- PASS: TestGlobMatch/*_ (0.00s)1896 --- PASS: TestGlobMatch/foo_bar (0.00s)1897 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1898 --- PASS: TestGlobMatch/fo?_foo (0.00s)18992026/07/19 09:52:29 INFO OIDC provider initialized name=provider119002026/07/19 09:52:29 INFO OIDC provider initialized name=test19012026/07/19 09:52:29 INFO OIDC provider initialized name=test19022026/07/19 09:52:29 INFO OIDC provider initialized name=test19032026/07/19 09:52:29 INFO OIDC provider initialized name=provider119042026/07/19 09:52:29 INFO OIDC provider initialized name=test19052026/07/19 09:52:29 INFO OIDC provider initialized name=test19062026/07/19 09:52:29 INFO OIDC provider initialized name=provider21907--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1908--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1909--- PASS: TestValidateToken_ValidToken (0.01s)1910--- PASS: TestValidateToken_WrongAudience (0.01s)1911--- PASS: TestValidateToken_Expired (0.01s)1912--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1913--- PASS: TestValidateToken_MultipleProviders (0.01s)1914PASS1915Running hook tests...1916=== RUN TestSendPathsEmpty1917=== PAUSE TestSendPathsEmpty1918=== RUN TestQueueEnqueueAndFetch1919=== PAUSE TestQueueEnqueueAndFetch1920=== RUN TestQueueDeduplication1921=== PAUSE TestQueueDeduplication1922=== RUN TestQueueRemove1923=== PAUSE TestQueueRemove1924=== RUN TestQueueFetchBatchLimit1925=== PAUSE TestQueueFetchBatchLimit1926=== RUN TestQueueFetchRemoveLifecycle1927=== PAUSE TestQueueFetchRemoveLifecycle1928=== RUN TestQueueConcurrentWriters1929=== PAUSE TestQueueConcurrentWriters1930=== RUN TestServerClientIntegration1931=== PAUSE TestServerClientIntegration1932=== RUN TestServerQueueError1933=== PAUSE TestServerQueueError1934=== RUN TestGetListenerSocketActivation1935 server_test.go:210: === RUN TestGetListenerSocketActivation1936 --- PASS: TestGetListenerSocketActivation (0.00s)1937 PASS1938 1939--- PASS: TestGetListenerSocketActivation (0.01s)1940=== RUN TestWorkerUploadsAndRemoves1941=== PAUSE TestWorkerUploadsAndRemoves1942=== RUN TestWorkerSkipsGCdPaths1943=== PAUSE TestWorkerSkipsGCdPaths1944=== RUN TestWorkerPrunesClosureDeps1945=== PAUSE TestWorkerPrunesClosureDeps1946=== CONT TestSendPathsEmpty1947--- PASS: TestSendPathsEmpty (0.00s)1948=== CONT TestQueueConcurrentWriters1949=== CONT TestWorkerSkipsGCdPaths1950=== CONT TestWorkerUploadsAndRemoves1951=== CONT TestQueueFetchRemoveLifecycle1952=== CONT TestQueueFetchBatchLimit1953=== CONT TestQueueRemove1954=== CONT TestQueueDeduplication1955=== CONT TestQueueEnqueueAndFetch1956=== CONT TestWorkerPrunesClosureDeps1957=== CONT TestServerQueueError19582026/07/19 09:52:29 ERROR Failed to queue paths error="permission denied" count=11959--- PASS: TestServerQueueError (0.00s)1960=== CONT TestServerClientIntegration1961--- PASS: TestServerClientIntegration (0.00s)19622026/07/19 09:52:29 INFO Upload queue status pending=219632026/07/19 09:52:29 INFO Uploading batch count=219642026/07/19 09:52:29 INFO Upload queue status pending=219652026/07/19 09:52:29 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-91752-1574309481/TestWorkerSkipsGCdPaths3527968481/002/nonexistent19662026/07/19 09:52:29 INFO Uploading batch count=11967--- PASS: TestQueueDeduplication (0.01s)1968--- PASS: TestQueueFetchRemoveLifecycle (0.01s)1969--- PASS: TestQueueFetchBatchLimit (0.01s)19702026/07/19 09:52:29 INFO Upload queue status pending=219712026/07/19 09:52:29 INFO Uploading batch count=11972--- PASS: TestQueueRemove (0.01s)1973--- PASS: TestQueueEnqueueAndFetch (0.01s)1974--- PASS: TestWorkerUploadsAndRemoves (0.06s)1975--- PASS: TestWorkerSkipsGCdPaths (0.06s)1976--- PASS: TestWorkerPrunesClosureDeps (0.06s)1977--- PASS: TestQueueConcurrentWriters (0.16s)1978PASS