niks3-go-unit-tests
aarch64-darwin.go-unit-tests
· build #96
· 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 TestResolveStorePath72=== CONT TestConvertHashToNix3273=== RUN TestConvertHashToNix32/SRI_format_to_Nix3274=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix3275=== RUN TestConvertHashToNix32/already_Nix32_format76=== PAUSE TestConvertHashToNix32/already_Nix32_format77=== RUN TestConvertHashToNix32/invalid_format78=== PAUSE TestConvertHashToNix32/invalid_format79=== CONT TestConvertHashToNix32/SRI_format_to_Nix3280=== CONT TestParsePathInfoJSON81=== RUN TestParsePathInfoJSON/Nix_format82=== PAUSE TestParsePathInfoJSON/Nix_format83=== RUN TestParsePathInfoJSON/Lix_format84=== PAUSE TestParsePathInfoJSON/Lix_format85=== RUN TestParsePathInfoJSON/empty_input86=== PAUSE TestParsePathInfoJSON/empty_input87=== RUN TestParsePathInfoJSON/whitespace_only88=== PAUSE TestParsePathInfoJSON/whitespace_only89=== RUN TestParsePathInfoJSON/invalid_JSON90=== PAUSE TestParsePathInfoJSON/invalid_JSON91=== CONT TestParsePathInfoJSON/Nix_format92=== CONT TestParsePathInfoJSONMultiplePaths93=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths94=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths95=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths96=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths97=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths98--- PASS: TestResolveStorePath (0.00s)99=== CONT TestScriptTokenEmptyCommand100--- PASS: TestScriptTokenEmptyCommand (0.00s)101=== CONT TestScriptTokenScriptFails102=== CONT TestPathInfoHashCompatibility103=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)104=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)105=== CONT TestParsePathInfoJSON/invalid_JSON106=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon107=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon108=== CONT TestConvertHashToNix32/invalid_format109=== CONT TestRateLimiterFeedback110=== RUN TestRateLimiterFeedback/429_enables_limiter111=== CONT TestGetStorePathHash112=== PAUSE TestRateLimiterFeedback/429_enables_limiter113=== RUN TestGetStorePathHash/valid_store_path114=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI115=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI116=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512117=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512118=== CONT TestConvertHashToNix32/already_Nix32_format119=== PAUSE TestGetStorePathHash/valid_store_path120=== RUN TestGetStorePathHash/basename_without_hyphen_should_error121=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error122=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error123=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error124=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error125=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error126=== RUN TestRateLimiterFeedback/503_enables_limiter127=== PAUSE TestRateLimiterFeedback/503_enables_limiter128=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter129--- PASS: TestConvertHashToNix32 (0.00s)130 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)131 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)132 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)133=== CONT TestScriptTokenBadJSON134=== CONT TestPathInfoCACompatibility135=== RUN TestPathInfoCACompatibility/null_ca_field136=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter137=== CONT TestParsePathInfoJSON/empty_input138=== PAUSE TestPathInfoCACompatibility/null_ca_field139=== RUN TestPathInfoCACompatibility/old_string_format_-_text140=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text141=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive142=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths143=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter144=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter145=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive146=== CONT TestScriptTokenEmptyToken147=== RUN TestPathInfoCACompatibility/new_structured_format_-_text148=== CONT TestFileTokenReadsAndCaches149=== CONT TestParsePathInfoJSON/whitespace_only150=== CONT TestScriptTokenCachesUntilRefresh151=== CONT TestParsePathInfoJSON/Lix_format152=== CONT TestFileTokenMissing153=== CONT TestScriptTokenNoExpiryRerunsEveryCall154=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text155=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method156=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method157=== CONT TestSetClientTLS158--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)159 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)160 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)161--- PASS: TestParsePathInfoJSON (0.00s)162 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)163 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)164 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)165 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)166 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)167=== CONT TestFileTokenEmpty168--- PASS: TestFileTokenReadsAndCaches (0.00s)169=== CONT TestStaticToken170--- PASS: TestStaticToken (0.00s)171=== CONT TestSetClientTLSErrors172--- PASS: TestFileTokenEmpty (0.00s)173=== CONT TestSetClientTLSDoesNotMutateDefaultTransport174--- PASS: TestFileTokenMissing (0.00s)175=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1762026/07/09 07:47:13 WARN Rate limiter enabled after throttle name=server-test rate=5177=== RUN TestSetClientTLSErrors/missing_cert_file178=== PAUSE TestSetClientTLSErrors/missing_cert_file179=== RUN TestSetClientTLSErrors/missing_key_file180=== PAUSE TestSetClientTLSErrors/missing_key_file181=== RUN TestSetClientTLSErrors/missing_ca_file182=== PAUSE TestSetClientTLSErrors/missing_ca_file183=== RUN TestSetClientTLSErrors/invalid_ca_file184=== PAUSE TestSetClientTLSErrors/invalid_ca_file185=== CONT TestDumpPathSingleFile186--- PASS: TestDoServerRequestAttachesToken (0.01s)187=== CONT TestEncodeNixBase32WithRealHash188--- PASS: TestEncodeNixBase32WithRealHash (0.00s)189=== CONT TestEncodeNixBase32190=== RUN TestEncodeNixBase32/test_string_hash191=== PAUSE TestEncodeNixBase32/test_string_hash192=== RUN TestEncodeNixBase32/empty_input193=== PAUSE TestEncodeNixBase32/empty_input194=== CONT TestDumpPathWriterError195--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)196=== RUN TestSetClientTLS/rejects_connection_without_client_cert197=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert198=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA199=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA200=== RUN TestSetClientTLS/preserves_debug_logging_transport201=== PAUSE TestSetClientTLS/preserves_debug_logging_transport202=== CONT TestShellSplitErrors203--- PASS: TestShellSplitErrors (0.00s)204=== CONT TestDoWithRetry_BodyReplayedViaGetBody205--- PASS: TestScriptTokenScriptFails (0.01s)206=== CONT TestUploadMultipart_SupersededByPeer207=== RUN TestUploadMultipart_SupersededByPeer/exists208=== PAUSE TestUploadMultipart_SupersededByPeer/exists209=== RUN TestUploadMultipart_SupersededByPeer/missing210=== PAUSE TestUploadMultipart_SupersededByPeer/missing211=== CONT TestDumpPathMatchesNix212=== CONT TestShellSplit213--- PASS: TestShellSplit (0.00s)214=== CONT TestPartSizeForNAR215=== RUN TestPartSizeForNAR/zero_stays_at_minimum216=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum217=== RUN TestPartSizeForNAR/small_stays_at_minimum218=== PAUSE TestPartSizeForNAR/small_stays_at_minimum219=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum220=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum221=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts222=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts223=== RUN TestPartSizeForNAR/1_TiB224=== PAUSE TestPartSizeForNAR/1_TiB225=== RUN TestPartSizeForNAR/5_TiB_S3_max_object226=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object227=== RUN TestPartSizeForNAR/capped_at_5_GiB228=== PAUSE TestPartSizeForNAR/capped_at_5_GiB229=== CONT TestCaseHackSuffix2302026/07/09 07:47:13 WARN Rate limiter enabled after throttle name=server-test rate=52312026/07/09 07:47:13 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:527052322026/07/09 07:47:13 WARN Rate limiter backed off name=server-test rate=52332026/07/09 07:47:13 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:52705234--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)235=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)236=== CONT TestGetStorePathHash/valid_store_path237=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error238=== CONT TestGetStorePathHash/basename_without_hyphen_should_error239=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI240=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512241=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon242--- PASS: TestPathInfoHashCompatibility (0.00s)243 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)244 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)245 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)246 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)247=== CONT TestRateLimiterFeedback/429_enables_limiter2482026/07/09 07:47:13 WARN Rate limiter enabled after throttle name=server-test rate=52492026/07/09 07:47:13 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:527072502026/07/09 07:47:13 WARN Rate limiter backed off name=server-test rate=5251=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter252=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter253=== CONT TestRateLimiterFeedback/503_enables_limiter2542026/07/09 07:47:13 WARN Rate limiter enabled after throttle name=server-test rate=52552026/07/09 07:47:13 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:527132562026/07/09 07:47:13 WARN Rate limiter backed off name=server-test rate=5257--- PASS: TestRateLimiterFeedback (0.00s)258 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)259 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)260 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)261 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)262=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error263--- PASS: TestGetStorePathHash (0.00s)264 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)265 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)266 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)267 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)268=== CONT TestPathInfoCACompatibility/null_ca_field269=== CONT TestPathInfoCACompatibility/new_structured_format_-_text270=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method271=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive272=== CONT TestPathInfoCACompatibility/old_string_format_-_text273--- PASS: TestPathInfoCACompatibility (0.00s)274 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)275 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)276 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)277 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)278 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)279=== CONT TestSetClientTLSErrors/missing_cert_file280=== CONT TestSetClientTLSErrors/missing_ca_file281=== CONT TestSetClientTLSErrors/invalid_ca_file282=== CONT TestSetClientTLSErrors/missing_key_file283=== CONT TestEncodeNixBase32/test_string_hash284=== CONT TestEncodeNixBase32/empty_input285--- PASS: TestEncodeNixBase32 (0.00s)286 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)287 --- PASS: TestEncodeNixBase32/empty_input (0.00s)288=== CONT TestSetClientTLS/rejects_connection_without_client_cert289--- PASS: TestScriptTokenEmptyToken (0.01s)290=== CONT TestSetClientTLS/preserves_debug_logging_transport291--- PASS: TestSetClientTLSErrors (0.00s)292 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)293 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)294 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)295 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)296--- PASS: TestScriptTokenBadJSON (0.01s)297=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA298=== CONT TestUploadMultipart_SupersededByPeer/exists299=== CONT TestUploadMultipart_SupersededByPeer/missing300=== CONT TestPartSizeForNAR/zero_stays_at_minimum301=== CONT TestPartSizeForNAR/1_TiB302=== CONT TestPartSizeForNAR/capped_at_5_GiB303=== CONT TestPartSizeForNAR/5_TiB_S3_max_object304=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum305=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts306=== CONT TestPartSizeForNAR/small_stays_at_minimum307--- PASS: TestPartSizeForNAR (0.00s)308 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)309 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)310 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)311 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)312 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)313 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)314 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)315--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)316 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)317 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)3182026/07/09 07:47:13 http: TLS handshake error from 127.0.0.1:52715: read tcp 127.0.0.1:52704->127.0.0.1:52715: use of closed network connection319--- 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: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)324--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)325--- PASS: TestDumpPathWriterError (0.04s)326--- PASS: TestDumpPathSingleFile (0.06s)327--- PASS: TestCaseHackSuffix (0.06s)328--- PASS: TestDumpPathMatchesNix (0.09s)329--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)330PASS331Running server tests...332The files belonging to this database system will be owned by user "_nixbld11".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-30502-2751901220/postgres1900480739/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-30502-2751901220/postgres1900480739/data -l logfile start358359/nix/var/nix/builds/nix-30502-2751901220/postgres1900480739:5432 - no response3602026-07-09 07:47:15.279 UTC [30730] LOG: starting PostgreSQL 18.4 on aarch64-apple-darwin25.3.0, compiled by clang version 21.1.8, 64-bit3612026-07-09 07:47:15.280 UTC [30730] LOG: listening on Unix socket "/nix/var/nix/builds/nix-30502-2751901220/postgres1900480739/.s.PGSQL.5432"3622026-07-09 07:47:15.284 UTC [30737] LOG: database system was shut down at 2026-07-09 07:47:15 UTC3632026-07-09 07:47:15.286 UTC [30730] LOG: database system is ready to accept connections364/nix/var/nix/builds/nix-30502-2751901220/postgres1900480739:5432 - accepting connections365<jemalloc>: option background_thread currently supports pthread only366{"timestamp":"2026-07-09T07:47:15.415905Z","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(8)"}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-09 07:47:15.586 UTC [30788] ERROR: relation "goose_db_version" does not exist at character 363952026-07-09 07:47:15.586 UTC [30788] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC3962026/07/09 07:47:15 OK 20241026095416_initial_model.sql (9.04ms)3972026/07/09 07:47:15 OK 20251210153512_drop_unused_gin_index.sql (1.08ms)3982026/07/09 07:47:15 OK 20251218171726_add_pins.sql (1.57ms)3992026/07/09 07:47:15 OK 20260628120000_add_object_size_and_stats.sql (1.61ms)4002026/07/09 07:47:15 goose: successfully migrated database to version: 202606281200004012026/07/09 07:47:15 OK 1_commit_pending_closure.sql (1.7ms)4022026/07/09 07:47:15 OK 2_object_stats_trigger.sql (437.83µs)4032026/07/09 07:47:15 goose: up to current file version: 2404--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.11s)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 TestService_Rustfstest478=== PAUSE TestService_Rustfstest479=== RUN TestSystemdListenerNotActivated480--- PASS: TestSystemdListenerNotActivated (0.00s)481=== RUN TestWatchdogBeatsWhenHealthy482--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)483=== RUN TestWatchdogSkipsWhenUnhealthy4842026/07/09 07:47:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4852026/07/09 07:47:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4862026/07/09 07:47:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4872026/07/09 07:47:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4882026/07/09 07:47:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4892026/07/09 07:47:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4902026/07/09 07:47:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4912026/07/09 07:47:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4922026/07/09 07:47:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4932026/07/09 07:47:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"494--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)495=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle496=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle497=== RUN TestProxyWriteTimeout498=== PAUSE TestProxyWriteTimeout499=== RUN TestIsValidUploadKey500=== PAUSE TestIsValidUploadKey501=== RUN TestUploadHandlersRejectInvalidKeys502=== PAUSE TestUploadHandlersRejectInvalidKeys503=== RUN TestUploadHandlersRejectOversizedBody504=== PAUSE TestUploadHandlersRejectOversizedBody505=== RUN TestService_cleanupPendingClosuresHandler506=== PAUSE TestService_cleanupPendingClosuresHandler507=== RUN TestService_createPendingClosureHandler508=== PAUSE TestService_createPendingClosureHandler509=== RUN TestService_verifyS3Integrity510=== PAUSE TestService_verifyS3Integrity511=== RUN TestCompleteMultipartUnregistered512=== PAUSE TestCompleteMultipartUnregistered513=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT514=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT515=== CONT TestService_AuthMiddleware516=== CONT TestMultipartCleanup517=== CONT TestUploadHandlersRejectInvalidKeys518=== CONT TestProxyWriteTimeout519=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info520=== CONT TestGCTaskStore_StartNew521=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info522=== CONT TestService_Rustfstest523=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal524--- PASS: TestGCTaskStore_StartNew (0.00s)525=== CONT TestReadProxyDisabled526=== CONT TestIsValidUploadKey527=== RUN TestIsValidUploadKey/narinfo528=== PAUSE TestIsValidUploadKey/narinfo529=== RUN TestIsValidUploadKey/nar_zst530=== PAUSE TestIsValidUploadKey/nar_zst531=== RUN TestIsValidUploadKey/nar_xz532=== PAUSE TestIsValidUploadKey/nar_xz533=== RUN TestIsValidUploadKey/nar_plain534=== PAUSE TestIsValidUploadKey/nar_plain535=== RUN TestIsValidUploadKey/listing536=== PAUSE TestIsValidUploadKey/listing537=== RUN TestIsValidUploadKey/build_log538=== PAUSE TestIsValidUploadKey/build_log539=== RUN TestIsValidUploadKey/build_log_home-manager_file540=== PAUSE TestIsValidUploadKey/build_log_home-manager_file541=== RUN TestIsValidUploadKey/build_log_plus_in_name542=== PAUSE TestIsValidUploadKey/build_log_plus_in_name543=== RUN TestIsValidUploadKey/build_log_question_mark544=== PAUSE TestIsValidUploadKey/build_log_question_mark545=== RUN TestIsValidUploadKey/build_log_equals546=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal547=== PAUSE TestIsValidUploadKey/build_log_equals548=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key549=== RUN TestIsValidUploadKey/realisation550=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key551=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key552=== RUN TestProxyWriteTimeout/narinfo553=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key554=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle555=== PAUSE TestProxyWriteTimeout/narinfo556=== CONT TestService_verifyS3Integrity557=== CONT TestCompleteMultipartUnregistered558=== PAUSE TestIsValidUploadKey/realisation559=== RUN TestProxyWriteTimeout/1_GiB_nar560=== PAUSE TestProxyWriteTimeout/1_GiB_nar561=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT562=== RUN TestProxyWriteTimeout/10_GiB_nar563=== PAUSE TestProxyWriteTimeout/10_GiB_nar564=== RUN TestProxyWriteTimeout/unknown_size565=== PAUSE TestProxyWriteTimeout/unknown_size566=== RUN TestIsValidUploadKey/realisation_plus_in_output567=== PAUSE TestIsValidUploadKey/realisation_plus_in_output568=== CONT TestService_createPendingClosureHandler569=== RUN TestIsValidUploadKey/nix-cache-info570=== PAUSE TestIsValidUploadKey/nix-cache-info571=== RUN TestIsValidUploadKey/index.html572=== PAUSE TestIsValidUploadKey/index.html573=== RUN TestIsValidUploadKey/narinfo_key,_nar_type574=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type575=== RUN TestIsValidUploadKey/nar_key,_narinfo_type576=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type577=== RUN TestIsValidUploadKey/listing_key,_narinfo_type578=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type579=== RUN TestIsValidUploadKey/traversal580=== PAUSE TestIsValidUploadKey/traversal581=== RUN TestIsValidUploadKey/traversal_nar582=== PAUSE TestIsValidUploadKey/traversal_nar583=== RUN TestIsValidUploadKey/absolute584=== PAUSE TestIsValidUploadKey/absolute585=== RUN TestIsValidUploadKey/empty_key586=== PAUSE TestIsValidUploadKey/empty_key587=== RUN TestIsValidUploadKey/unknown_type588=== PAUSE TestIsValidUploadKey/unknown_type589=== CONT TestService_cleanupPendingClosuresHandler5902026-07-09 07:47:16.232 UTC [30817] ERROR: relation "goose_db_version" does not exist at character 365912026-07-09 07:47:16.232 UTC [30817] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5922026-07-09 07:47:16.248 UTC [30819] ERROR: relation "goose_db_version" does not exist at character 365932026-07-09 07:47:16.248 UTC [30819] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5942026-07-09 07:47:16.255 UTC [30820] ERROR: relation "goose_db_version" does not exist at character 365952026-07-09 07:47:16.255 UTC [30820] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5962026-07-09 07:47:16.258 UTC [30821] ERROR: relation "goose_db_version" does not exist at character 365972026-07-09 07:47:16.258 UTC [30821] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5982026/07/09 07:47:16 OK 20241026095416_initial_model.sql (17.47ms)5992026-07-09 07:47:16.268 UTC [30822] ERROR: relation "goose_db_version" does not exist at character 366002026-07-09 07:47:16.268 UTC [30822] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6012026/07/09 07:47:16 OK 20251210153512_drop_unused_gin_index.sql (4.81ms)6022026-07-09 07:47:16.272 UTC [30823] ERROR: relation "goose_db_version" does not exist at character 366032026-07-09 07:47:16.272 UTC [30823] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6042026-07-09 07:47:16.275 UTC [30824] ERROR: relation "goose_db_version" does not exist at character 366052026-07-09 07:47:16.275 UTC [30824] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6062026-07-09 07:47:16.275 UTC [30825] ERROR: relation "goose_db_version" does not exist at character 366072026-07-09 07:47:16.275 UTC [30825] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6082026/07/09 07:47:16 OK 20251218171726_add_pins.sql (6.72ms)6092026/07/09 07:47:16 OK 20241026095416_initial_model.sql (10.11ms)6102026-07-09 07:47:16.278 UTC [30826] ERROR: relation "goose_db_version" does not exist at character 366112026-07-09 07:47:16.278 UTC [30826] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6122026/07/09 07:47:16 OK 20260628120000_add_object_size_and_stats.sql (2.52ms)6132026/07/09 07:47:16 goose: successfully migrated database to version: 202606281200006142026/07/09 07:47:16 OK 20251210153512_drop_unused_gin_index.sql (2.21ms)6152026/07/09 07:47:16 OK 20241026095416_initial_model.sql (16.15ms)6162026-07-09 07:47:16.280 UTC [30827] ERROR: relation "goose_db_version" does not exist at character 366172026-07-09 07:47:16.280 UTC [30827] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6182026/07/09 07:47:16 OK 1_commit_pending_closure.sql (2.64ms)6192026/07/09 07:47:16 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)6202026/07/09 07:47:16 OK 20251218171726_add_pins.sql (2.99ms)6212026/07/09 07:47:16 OK 20241026095416_initial_model.sql (11.41ms)6222026/07/09 07:47:16 OK 2_object_stats_trigger.sql (1.73ms)6232026/07/09 07:47:16 goose: up to current file version: 26242026/07/09 07:47:16 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)6252026/07/09 07:47:16 OK 20251218171726_add_pins.sql (2.45ms)6262026/07/09 07:47:16 OK 20260628120000_add_object_size_and_stats.sql (2.65ms)6272026/07/09 07:47:16 goose: successfully migrated database to version: 202606281200006282026/07/09 07:47:16 OK 20260628120000_add_object_size_and_stats.sql (2.44ms)6292026/07/09 07:47:16 goose: successfully migrated database to version: 202606281200006302026/07/09 07:47:16 OK 20251218171726_add_pins.sql (3.27ms)6312026/07/09 07:47:16 OK 1_commit_pending_closure.sql (2.66ms)6322026/07/09 07:47:16 INFO Received uploads request method=POST path=/api/pending_closures6332026/07/09 07:47:16 OK 20241026095416_initial_model.sql (9.85ms)6342026/07/09 07:47:16 OK 2_object_stats_trigger.sql (759.88µs)6352026/07/09 07:47:16 goose: up to current file version: 26362026/07/09 07:47:16 OK 1_commit_pending_closure.sql (2.17ms)6372026/07/09 07:47:16 OK 2_object_stats_trigger.sql (892.92µs)6382026/07/09 07:47:16 goose: up to current file version: 26392026/07/09 07:47:16 OK 20251210153512_drop_unused_gin_index.sql (1.32ms)6402026/07/09 07:47:16 OK 20260628120000_add_object_size_and_stats.sql (2.37ms)6412026/07/09 07:47:16 goose: successfully migrated database to version: 202606281200006422026/07/09 07:47:16 OK 20241026095416_initial_model.sql (9.95ms)6432026/07/09 07:47:16 OK 20241026095416_initial_model.sql (8.89ms)6442026/07/09 07:47:16 INFO Received uploads request method=POST path=/api/pending_closures6452026/07/09 07:47:16 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)6462026/07/09 07:47:16 OK 1_commit_pending_closure.sql (2.22ms)6472026/07/09 07:47:16 OK 20251210153512_drop_unused_gin_index.sql (1.23ms)6482026/07/09 07:47:16 OK 20241026095416_initial_model.sql (10.32ms)6492026/07/09 07:47:16 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"650--- PASS: TestService_AuthMiddleware (0.45s)651=== CONT TestUploadHandlersRejectOversizedBody6522026/07/09 07:47:16 OK 20251218171726_add_pins.sql (3.08ms)6532026/07/09 07:47:16 OK 2_object_stats_trigger.sql (1.35ms)6542026/07/09 07:47:16 goose: up to current file version: 26552026/07/09 07:47:16 OK 20251218171726_add_pins.sql (16.3ms)6562026/07/09 07:47:16 OK 20251218171726_add_pins.sql (17.18ms)6572026/07/09 07:47:16 OK 20241026095416_initial_model.sql (22.34ms)6582026/07/09 07:47:16 OK 20241026095416_initial_model.sql (25.16ms)6592026/07/09 07:47:16 OK 20251210153512_drop_unused_gin_index.sql (16.19ms)660--- PASS: TestReadProxyDisabled (0.47s)661=== CONT TestServerTLSConfig662=== RUN TestServerTLSConfig/no_client_CA663=== PAUSE TestServerTLSConfig/no_client_CA664=== RUN TestServerTLSConfig/missing_CA_file665=== PAUSE TestServerTLSConfig/missing_CA_file666=== RUN TestServerTLSConfig/not_a_PEM_file667=== PAUSE TestServerTLSConfig/not_a_PEM_file668=== CONT TestService_NativeMTLS6692026/07/09 07:47:16 OK 20260628120000_add_object_size_and_stats.sql (6.59ms)6702026/07/09 07:47:16 goose: successfully migrated database to version: 202606281200006712026/07/09 07:47:16 OK 20260628120000_add_object_size_and_stats.sql (6.04ms)6722026/07/09 07:47:16 goose: successfully migrated database to version: 202606281200006732026/07/09 07:47:16 OK 20251210153512_drop_unused_gin_index.sql (7.49ms)6742026/07/09 07:47:16 OK 20251210153512_drop_unused_gin_index.sql (7.58ms)6752026/07/09 07:47:16 OK 20260628120000_add_object_size_and_stats.sql (9.62ms)6762026/07/09 07:47:16 goose: successfully migrated database to version: 202606281200006772026/07/09 07:47:16 OK 20251218171726_add_pins.sql (9.75ms)6782026/07/09 07:47:16 OK 1_commit_pending_closure.sql (4.61ms)6792026/07/09 07:47:16 OK 1_commit_pending_closure.sql (4.89ms)6802026/07/09 07:47:16 OK 20251218171726_add_pins.sql (9.49ms)6812026/07/09 07:47:16 OK 1_commit_pending_closure.sql (7.8ms)6822026/07/09 07:47:16 OK 20251218171726_add_pins.sql (10.1ms)683=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure684=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure685=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart686=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart6872026/07/09 07:47:16 OK 2_object_stats_trigger.sql (7.63ms)688=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts6892026/07/09 07:47:16 goose: up to current file version: 2690=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts691=== CONT TestMetricsInventory6922026/07/09 07:47:16 OK 2_object_stats_trigger.sql (7.69ms)6932026/07/09 07:47:16 goose: up to current file version: 26942026/07/09 07:47:16 OK 2_object_stats_trigger.sql (2.12ms)6952026/07/09 07:47:16 goose: up to current file version: 26962026/07/09 07:47:16 INFO Received cleanup request method=DELETE path=/api/pending_closures6972026/07/09 07:47:16 INFO Received uploads request method=POST path=/api/pending_closures6982026/07/09 07:47:16 INFO Received uploads request method=POST path=/api/pending_closures6992026/07/09 07:47:16 INFO Received uploads request method=POST path=/api/pending_closures7002026/07/09 07:47:16 OK 20260628120000_add_object_size_and_stats.sql (12.05ms)7012026/07/09 07:47:16 goose: successfully migrated database to version: 202606281200007022026/07/09 07:47:16 INFO Received uploads request method=POST path=/api/pending_closures7032026/07/09 07:47:16 OK 20260628120000_add_object_size_and_stats.sql (20.99ms)7042026/07/09 07:47:16 goose: successfully migrated database to version: 202606281200007052026/07/09 07:47:16 OK 20260628120000_add_object_size_and_stats.sql (11.8ms)7062026/07/09 07:47:16 goose: successfully migrated database to version: 202606281200007072026/07/09 07:47:16 OK 1_commit_pending_closure.sql (3.77ms)7082026/07/09 07:47:16 OK 1_commit_pending_closure.sql (2.94ms)7092026/07/09 07:47:16 OK 1_commit_pending_closure.sql (2.97ms)7102026/07/09 07:47:16 OK 2_object_stats_trigger.sql (970.67µs)7112026/07/09 07:47:16 goose: up to current file version: 27122026/07/09 07:47:16 OK 2_object_stats_trigger.sql (1.08ms)7132026/07/09 07:47:16 goose: up to current file version: 27142026/07/09 07:47:16 OK 2_object_stats_trigger.sql (1.41ms)7152026/07/09 07:47:16 goose: up to current file version: 2716--- PASS: TestService_Rustfstest (0.50s)717=== CONT TestNARDeduplicationMetadataUploadBug7182026/07/09 07:47:16 INFO Aborted multipart uploads count=07192026/07/09 07:47:16 INFO Received uploads request method=POST path=/api/pending_closures7202026/07/09 07:47:16 INFO Received uploads request method=POST path=/api/pending_closures7212026/07/09 07:47:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7222026/07/09 07:47:16 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst723--- PASS: TestCompleteMultipartUnregistered (0.51s)724=== CONT TestGenerateLandingPage725--- PASS: TestGenerateLandingPage (0.00s)726=== CONT TestService_healthCheckHandler7272026/07/09 07:47:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7282026/07/09 07:47:16 INFO Received cleanup request method=DELETE path=/api/pending_closures729--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.51s)730=== CONT TestGracefulShutdownDrainsInflight7312026/07/09 07:47:16 INFO Starting HTTP server address=127.0.0.1:527657322026/07/09 07:47:16 INFO Shutdown signal received, draining in-flight requests timeout=10s7332026/07/09 07:47:16 INFO Aborted multipart uploads count=17342026/07/09 07:47:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7352026-07-09 07:47:16.362 UTC [30825] ERROR: Closure does not exist: id=17362026-07-09 07:47:16.362 UTC [30825] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE7372026-07-09 07:47:16.362 UTC [30825] STATEMENT: -- name: CommitPendingClosure :exec738 SELECT commit_pending_closure($1::bigint)739 740--- PASS: TestService_cleanupPendingClosuresHandler (0.52s)741=== CONT TestGCTaskStore_Fail742--- PASS: TestGCTaskStore_Fail (0.00s)743=== CONT TestGCTaskStore_PhaseUpdates744--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)745=== CONT TestGCTaskStore_CompletedAllowsNewTask746--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)747=== CONT TestGCTaskStore_GetReturnsLatest748--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)749=== CONT TestGCTaskStore_GetEmpty750--- PASS: TestGCTaskStore_GetEmpty (0.00s)751=== CONT TestGCTaskStore_ConflictDifferentParams752--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)753=== CONT TestGCTaskStore_DeduplicateSameParams754--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)755=== CONT TestReadProxyRootRedirectsToIndexHTML756--- PASS: TestGracefulShutdownDrainsInflight (0.07s)757=== CONT TestReadProxyConditionalGet7582026-07-09 07:47:16.448 UTC [30841] ERROR: relation "goose_db_version" does not exist at character 367592026-07-09 07:47:16.448 UTC [30841] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7602026-07-09 07:47:16.449 UTC [30842] ERROR: relation "goose_db_version" does not exist at character 367612026-07-09 07:47:16.449 UTC [30842] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7622026/07/09 07:47:16 INFO Received cleanup request method=DELETE path=/api/pending_closures7632026/07/09 07:47:16 INFO Aborted multipart uploads count=1764--- PASS: TestMultipartCleanup (0.62s)765=== CONT TestReadProxyHead7662026/07/09 07:47:16 OK 20241026095416_initial_model.sql (11.97ms)7672026/07/09 07:47:16 OK 20241026095416_initial_model.sql (12.73ms)7682026/07/09 07:47:16 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)7692026/07/09 07:47:16 OK 20251210153512_drop_unused_gin_index.sql (1.42ms)7702026/07/09 07:47:16 OK 20251218171726_add_pins.sql (2.97ms)7712026/07/09 07:47:16 OK 20260628120000_add_object_size_and_stats.sql (1.98ms)7722026/07/09 07:47:16 goose: successfully migrated database to version: 202606281200007732026-07-09 07:47:16.480 UTC [30846] ERROR: relation "goose_db_version" does not exist at character 367742026-07-09 07:47:16.480 UTC [30846] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7752026/07/09 07:47:16 OK 20251218171726_add_pins.sql (6.5ms)7762026/07/09 07:47:16 OK 1_commit_pending_closure.sql (2.11ms)7772026/07/09 07:47:16 OK 2_object_stats_trigger.sql (855.88µs)7782026/07/09 07:47:16 goose: up to current file version: 27792026/07/09 07:47:16 OK 20260628120000_add_object_size_and_stats.sql (5.3ms)7802026/07/09 07:47:16 goose: successfully migrated database to version: 202606281200007812026/07/09 07:47:16 OK 1_commit_pending_closure.sql (1.94ms)7822026/07/09 07:47:16 OK 2_object_stats_trigger.sql (306.75µs)7832026/07/09 07:47:16 goose: up to current file version: 2784--- PASS: TestMetricsInventory (0.16s)785=== CONT TestReadProxyInvalidPath7862026/07/09 07:47:16 WARN mTLS auth: subject not in bound subjects subject="CN=reader"7872026/07/09 07:47:16 WARN mTLS auth: subject not in bound subjects subject="CN=writer"788--- PASS: TestService_NativeMTLS (0.18s)789=== CONT TestGCMetrics7902026/07/09 07:47:16 OK 20241026095416_initial_model.sql (14.87ms)7912026/07/09 07:47:16 OK 20251210153512_drop_unused_gin_index.sql (618.71µs)7922026/07/09 07:47:16 OK 20251218171726_add_pins.sql (927.92µs)7932026/07/09 07:47:16 OK 20260628120000_add_object_size_and_stats.sql (1.44ms)7942026/07/09 07:47:16 goose: successfully migrated database to version: 202606281200007952026/07/09 07:47:16 OK 1_commit_pending_closure.sql (1.87ms)7962026/07/09 07:47:16 OK 2_object_stats_trigger.sql (839.38µs)7972026/07/09 07:47:16 goose: up to current file version: 2798{"timestamp":"2026-07-09T07:47:16.511901Z","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(6)"}7992026/07/09 07:47:16 INFO Created nix-cache-info in bucket bucket=bucket148002026/07/09 07:47:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8012026/07/09 07:47:16 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MzhkMDkxZDItNTc4My00YmYzLWI2NGItMDQxN2QwYzQ4OTI0LjdhYWQ5Mjg4LTA0ODUtNDczOC1hNDNmLWM2ZTVhNjk4ODIzM3gxNzgzNTgzMjM2MjkyMTQ3MDAw parts=108022026/07/09 07:47:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8032026/07/09 07:47:16 INFO Completed upload id=18042026/07/09 07:47:16 INFO Received uploads request method=POST path=/api/pending_closures8052026/07/09 07:47:16 INFO Received uploads request method=POST path=/api/pending_closures8062026/07/09 07:47:16 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8072026/07/09 07:47:16 WARN Found objects in DB but missing from S3, will re-upload count=1808--- PASS: TestService_verifyS3Integrity (0.69s)809=== CONT TestReadProxy4048102026/07/09 07:47:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8112026/07/09 07:47:16 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MzhkMDkxZDItNTc4My00YmYzLWI2NGItMDQxN2QwYzQ4OTI0LjlmOTQ4YTU3LTcwNjItNDg0YS04MDNjLWEyMjFjODgyZTZjZngxNzgzNTgzMjM2MzUzMjMzMDAw parts=108122026/07/09 07:47:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8132026/07/09 07:47:16 INFO Completed upload id=18142026/07/09 07:47:16 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008152026/07/09 07:47:16 INFO Received uploads request method=POST path=/api/pending_closures8162026/07/09 07:47:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures8172026/07/09 07:47:16 INFO Aborted multipart uploads count=08182026/07/09 07:47:16 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=08192026/07/09 07:47:16 INFO Vacuumed table table=pending_closures8202026/07/09 07:47:16 INFO Vacuumed table table=pending_objects8212026/07/09 07:47:16 INFO Vacuumed table table=multipart_uploads8222026/07/09 07:47:16 INFO Vacuumed table table=closures823=== NAME TestNARDeduplicationMetadataUploadBug824 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-30502-2751901220/TestNARDeduplicationMetadataUploadBug3188180236/001/store/rha5l9522s7pry6aclq3vqjb69799299-file1.txt8252026/07/09 07:47:16 INFO Vacuumed table table=objects8262026-07-09 07:47:16.686 UTC [30860] ERROR: relation "goose_db_version" does not exist at character 368272026-07-09 07:47:16.686 UTC [30860] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8282026-07-09 07:47:16.688 UTC [30862] ERROR: relation "goose_db_version" does not exist at character 368292026-07-09 07:47:16.688 UTC [30862] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8302026/07/09 07:47:16 OK 20241026095416_initial_model.sql (12.04ms)8312026/07/09 07:47:16 OK 20251210153512_drop_unused_gin_index.sql (551.83µs)8322026/07/09 07:47:16 OK 20251218171726_add_pins.sql (952.58µs)8332026/07/09 07:47:16 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000834--- PASS: TestService_createPendingClosureHandler (0.87s)835=== CONT TestGCBugBareHashReferences8362026/07/09 07:47:16 OK 20260628120000_add_object_size_and_stats.sql (7.56ms)8372026/07/09 07:47:16 goose: successfully migrated database to version: 202606281200008382026/07/09 07:47:16 OK 20241026095416_initial_model.sql (19.39ms)8392026/07/09 07:47:16 OK 20251210153512_drop_unused_gin_index.sql (808.04µs)8402026/07/09 07:47:16 OK 1_commit_pending_closure.sql (1.6ms)8412026/07/09 07:47:16 OK 2_object_stats_trigger.sql (335.25µs)8422026/07/09 07:47:16 goose: up to current file version: 28432026/07/09 07:47:16 OK 20251218171726_add_pins.sql (4.01ms)8442026/07/09 07:47:16 OK 20260628120000_add_object_size_and_stats.sql (4.53ms)8452026/07/09 07:47:16 goose: successfully migrated database to version: 20260628120000846--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.37s)847=== CONT TestReadProxyNarStreaming8482026/07/09 07:47:16 OK 1_commit_pending_closure.sql (1.88ms)8492026/07/09 07:47:16 OK 2_object_stats_trigger.sql (803.75µs)8502026/07/09 07:47:16 goose: up to current file version: 2851--- PASS: TestService_healthCheckHandler (0.38s)852=== CONT TestReadProxyNarinfoAlreadyDecompressed8532026/07/09 07:47:16 INFO Received uploads request method=POST path=/api/pending_closures8542026/07/09 07:47:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8552026/07/09 07:47:16 INFO Uploading rha5l9522s7pry6aclq3vqjb69799299-file1.txt (160B)8562026/07/09 07:47:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8572026/07/09 07:47:16 INFO Signed narinfos id=1 count=18582026/07/09 07:47:16 INFO Uploading 1 narinfos8592026/07/09 07:47:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8602026/07/09 07:47:16 INFO Completed upload id=18612026/07/09 07:47:16 INFO Upload complete. (155ms)862=== NAME TestNARDeduplicationMetadataUploadBug863 metadata_upload_test.go:54: Retrieved narinfo from S3:864 StorePath: /nix/var/nix/builds/nix-30502-2751901220/TestNARDeduplicationMetadataUploadBug3188180236/001/store/rha5l9522s7pry6aclq3vqjb69799299-file1.txt865 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst866 Compression: zstd867 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf868 NarSize: 160869 References: 870 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf871 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)872 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):873 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}8742026-07-09 07:47:16.912 UTC [30911] ERROR: relation "goose_db_version" does not exist at character 368752026-07-09 07:47:16.912 UTC [30911] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8762026/07/09 07:47:16 OK 20241026095416_initial_model.sql (10.99ms)8772026/07/09 07:47:16 OK 20251210153512_drop_unused_gin_index.sql (739.13µs)8782026/07/09 07:47:16 OK 20251218171726_add_pins.sql (1.09ms)8792026/07/09 07:47:16 OK 20260628120000_add_object_size_and_stats.sql (6.05ms)8802026/07/09 07:47:16 goose: successfully migrated database to version: 202606281200008812026/07/09 07:47:16 OK 1_commit_pending_closure.sql (1.75ms)8822026/07/09 07:47:16 OK 2_object_stats_trigger.sql (492.79µs)8832026/07/09 07:47:16 goose: up to current file version: 2884--- PASS: TestReadProxyConditionalGet (0.52s)885=== CONT TestReadProxyNarinfo886=== NAME TestNARDeduplicationMetadataUploadBug887 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-30502-2751901220/TestNARDeduplicationMetadataUploadBug3188180236/001/store/r87g90klp6v508x83frhqqrzbnfqd5mp-file2.txt8882026-07-09 07:47:16.989 UTC [30916] ERROR: relation "goose_db_version" does not exist at character 368892026-07-09 07:47:16.989 UTC [30916] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8902026-07-09 07:47:17.005 UTC [30918] ERROR: relation "goose_db_version" does not exist at character 368912026-07-09 07:47:17.005 UTC [30918] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8922026-07-09 07:47:17.008 UTC [30920] ERROR: relation "goose_db_version" does not exist at character 368932026-07-09 07:47:17.008 UTC [30920] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8942026/07/09 07:47:17 OK 20241026095416_initial_model.sql (20.46ms)8952026/07/09 07:47:17 OK 20251210153512_drop_unused_gin_index.sql (684.96µs)8962026/07/09 07:47:17 OK 20251218171726_add_pins.sql (2.43ms)8972026/07/09 07:47:17 OK 20241026095416_initial_model.sql (10.32ms)8982026/07/09 07:47:17 OK 20251210153512_drop_unused_gin_index.sql (1.98ms)8992026/07/09 07:47:17 OK 20251218171726_add_pins.sql (1.17ms)9002026/07/09 07:47:17 OK 20241026095416_initial_model.sql (19.54ms)9012026-07-09 07:47:17.038 UTC [30926] ERROR: relation "goose_db_version" does not exist at character 369022026-07-09 07:47:17.038 UTC [30926] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9032026/07/09 07:47:17 OK 20251210153512_drop_unused_gin_index.sql (536.96µs)9042026/07/09 07:47:17 OK 20260628120000_add_object_size_and_stats.sql (17.62ms)9052026/07/09 07:47:17 goose: successfully migrated database to version: 202606281200009062026/07/09 07:47:17 OK 20251218171726_add_pins.sql (4.92ms)9072026/07/09 07:47:17 OK 20260628120000_add_object_size_and_stats.sql (11.88ms)9082026/07/09 07:47:17 goose: successfully migrated database to version: 202606281200009092026/07/09 07:47:17 OK 1_commit_pending_closure.sql (1.9ms)9102026/07/09 07:47:17 OK 2_object_stats_trigger.sql (847.67µs)9112026/07/09 07:47:17 goose: up to current file version: 29122026/07/09 07:47:17 OK 1_commit_pending_closure.sql (1.73ms)9132026/07/09 07:47:17 OK 2_object_stats_trigger.sql (833.21µs)9142026/07/09 07:47:17 goose: up to current file version: 29152026/07/09 07:47:17 OK 20260628120000_add_object_size_and_stats.sql (4.8ms)9162026/07/09 07:47:17 goose: successfully migrated database to version: 20260628120000917--- PASS: TestReadProxyHead (0.59s)918=== CONT TestIsValidCachePath919=== RUN TestIsValidCachePath/narinfo920=== PAUSE TestIsValidCachePath/narinfo921=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars922=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars923=== RUN TestIsValidCachePath/nar_zst924=== PAUSE TestIsValidCachePath/nar_zst925=== RUN TestIsValidCachePath/nar_xz926=== PAUSE TestIsValidCachePath/nar_xz927=== RUN TestIsValidCachePath/nar_bz2928=== PAUSE TestIsValidCachePath/nar_bz2929=== RUN TestIsValidCachePath/nar_uncompressed930=== PAUSE TestIsValidCachePath/nar_uncompressed931=== RUN TestIsValidCachePath/ls932=== PAUSE TestIsValidCachePath/ls933=== RUN TestIsValidCachePath/log934=== PAUSE TestIsValidCachePath/log935=== RUN TestIsValidCachePath/realisation936=== PAUSE TestIsValidCachePath/realisation937=== RUN TestIsValidCachePath/nix-cache-info938=== PAUSE TestIsValidCachePath/nix-cache-info939=== RUN TestIsValidCachePath/index.html940=== PAUSE TestIsValidCachePath/index.html941=== RUN TestIsValidCachePath/traversal_parent942=== PAUSE TestIsValidCachePath/traversal_parent943=== RUN TestIsValidCachePath/traversal_in_middle944=== PAUSE TestIsValidCachePath/traversal_in_middle945=== RUN TestIsValidCachePath/invalid_char_e946=== PAUSE TestIsValidCachePath/invalid_char_e947=== RUN TestIsValidCachePath/invalid_char_u948=== PAUSE TestIsValidCachePath/invalid_char_u949=== RUN TestIsValidCachePath/random_path950=== PAUSE TestIsValidCachePath/random_path951=== RUN TestIsValidCachePath/empty952=== PAUSE TestIsValidCachePath/empty953=== RUN TestIsValidCachePath/leading_slash954=== PAUSE TestIsValidCachePath/leading_slash955=== RUN TestIsValidCachePath/wrong_extension956=== PAUSE TestIsValidCachePath/wrong_extension957=== RUN TestIsValidCachePath/short_hash958=== PAUSE TestIsValidCachePath/short_hash959=== CONT TestParseSingleRange960=== RUN TestParseSingleRange/none961=== PAUSE TestParseSingleRange/none962=== RUN TestParseSingleRange/unknown_unit963=== PAUSE TestParseSingleRange/unknown_unit964=== RUN TestParseSingleRange/multi-range_ignored965=== PAUSE TestParseSingleRange/multi-range_ignored966=== RUN TestParseSingleRange/malformed_no_dash967=== PAUSE TestParseSingleRange/malformed_no_dash968=== RUN TestParseSingleRange/malformed_both_empty969=== PAUSE TestParseSingleRange/malformed_both_empty970=== RUN TestParseSingleRange/malformed_end_before_start971=== PAUSE TestParseSingleRange/malformed_end_before_start972=== RUN TestParseSingleRange/closed973=== PAUSE TestParseSingleRange/closed974=== RUN TestParseSingleRange/open-ended975=== PAUSE TestParseSingleRange/open-ended976=== RUN TestParseSingleRange/end_clamped_to_size977=== PAUSE TestParseSingleRange/end_clamped_to_size978=== RUN TestParseSingleRange/suffix979=== PAUSE TestParseSingleRange/suffix980=== RUN TestParseSingleRange/suffix_exceeds_size981=== PAUSE TestParseSingleRange/suffix_exceeds_size982=== RUN TestParseSingleRange/single_byte983=== PAUSE TestParseSingleRange/single_byte984=== RUN TestParseSingleRange/start_past_EOF985=== PAUSE TestParseSingleRange/start_past_EOF986=== RUN TestParseSingleRange/start_far_past_EOF987=== PAUSE TestParseSingleRange/start_far_past_EOF988=== CONT TestResurrectedObjectNotDeleted9892026/07/09 07:47:17 OK 1_commit_pending_closure.sql (13.7ms)9902026/07/09 07:47:17 OK 2_object_stats_trigger.sql (445.33µs)9912026/07/09 07:47:17 goose: up to current file version: 2992--- PASS: TestReadProxyInvalidPath (0.58s)993=== CONT TestOrphanedObjectsGCStressTest9942026/07/09 07:47:17 INFO Aborted multipart uploads count=09952026/07/09 07:47:17 WARN Force mode enabled - objects will be deleted immediately without grace period9962026/07/09 07:47:17 OK 20241026095416_initial_model.sql (35.6ms)9972026/07/09 07:47:17 OK 20251210153512_drop_unused_gin_index.sql (853.88µs)9982026/07/09 07:47:17 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=09992026/07/09 07:47:17 INFO Vacuumed table table=pending_closures10002026/07/09 07:47:17 INFO Vacuumed table table=pending_objects10012026/07/09 07:47:17 OK 20251218171726_add_pins.sql (2.24ms)10022026/07/09 07:47:17 INFO Vacuumed table table=multipart_uploads10032026/07/09 07:47:17 INFO Vacuumed table table=closures10042026/07/09 07:47:17 INFO Vacuumed table table=objects10052026/07/09 07:47:17 OK 20260628120000_add_object_size_and_stats.sql (17.69ms)10062026/07/09 07:47:17 goose: successfully migrated database to version: 202606281200001007--- PASS: TestGCMetrics (0.61s)1008=== CONT TestOrphanedObjectsGC10092026/07/09 07:47:17 OK 1_commit_pending_closure.sql (13.76ms)10102026/07/09 07:47:17 OK 2_object_stats_trigger.sql (13.15ms)10112026/07/09 07:47:17 goose: up to current file version: 21012--- PASS: TestReadProxy404 (0.62s)1013=== CONT TestObjectStatsTrigger10142026/07/09 07:47:17 INFO Received uploads request method=POST path=/api/pending_closures10152026/07/09 07:47:17 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)10162026/07/09 07:47:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10172026/07/09 07:47:17 INFO Signed narinfos id=2 count=110182026/07/09 07:47:17 INFO Uploading 1 narinfos10192026/07/09 07:47:17 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10202026/07/09 07:47:17 INFO Completed upload id=210212026/07/09 07:47:17 INFO Upload complete. (193ms)1022=== NAME TestNARDeduplicationMetadataUploadBug1023 metadata_upload_test.go:76: Retrieved narinfo from S3:1024 StorePath: /nix/var/nix/builds/nix-30502-2751901220/TestNARDeduplicationMetadataUploadBug3188180236/001/store/r87g90klp6v508x83frhqqrzbnfqd5mp-file2.txt1025 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1026 Compression: zstd1027 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1028 NarSize: 1601029 References: 1030 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1031 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1032 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1033 {"version":1,"root":{"type":"regular","size":44}}1034--- PASS: TestNARDeduplicationMetadataUploadBug (0.89s)1035=== CONT TestPinProtectsFromGC10362026-07-09 07:47:17.272 UTC [30953] ERROR: relation "goose_db_version" does not exist at character 3610372026-07-09 07:47:17.272 UTC [30953] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10382026-07-09 07:47:17.306 UTC [30955] ERROR: relation "goose_db_version" does not exist at character 3610392026-07-09 07:47:17.306 UTC [30955] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10402026/07/09 07:47:17 OK 20241026095416_initial_model.sql (43.68ms)10412026/07/09 07:47:17 OK 20251210153512_drop_unused_gin_index.sql (525.83µs)10422026/07/09 07:47:17 OK 20251218171726_add_pins.sql (1.16ms)10432026-07-09 07:47:17.370 UTC [30959] ERROR: relation "goose_db_version" does not exist at character 3610442026-07-09 07:47:17.370 UTC [30959] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10452026/07/09 07:47:17 OK 20260628120000_add_object_size_and_stats.sql (41.63ms)10462026/07/09 07:47:17 goose: successfully migrated database to version: 2026062812000010472026/07/09 07:47:17 OK 1_commit_pending_closure.sql (2.03ms)10482026/07/09 07:47:17 OK 20241026095416_initial_model.sql (49.87ms)10492026/07/09 07:47:17 OK 2_object_stats_trigger.sql (402.17µs)10502026/07/09 07:47:17 goose: up to current file version: 210512026/07/09 07:47:17 OK 20251210153512_drop_unused_gin_index.sql (958.58µs)10522026/07/09 07:47:17 OK 20251218171726_add_pins.sql (3.62ms)10532026/07/09 07:47:17 OK 20260628120000_add_object_size_and_stats.sql (5.83ms)10542026/07/09 07:47:17 goose: successfully migrated database to version: 2026062812000010552026/07/09 07:47:17 OK 20241026095416_initial_model.sql (10.71ms)10562026/07/09 07:47:17 OK 20251210153512_drop_unused_gin_index.sql (420.67µs)10572026/07/09 07:47:17 OK 1_commit_pending_closure.sql (1.11ms)10582026/07/09 07:47:17 OK 2_object_stats_trigger.sql (278.96µs)10592026/07/09 07:47:17 goose: up to current file version: 210602026/07/09 07:47:17 OK 20251218171726_add_pins.sql (2.54ms)10612026/07/09 07:47:17 OK 20260628120000_add_object_size_and_stats.sql (2.57ms)10622026/07/09 07:47:17 goose: successfully migrated database to version: 202606281200001063--- PASS: TestReadProxyNarStreaming (0.67s)1064=== CONT TestRedundantMultipartUpload10652026/07/09 07:47:17 OK 1_commit_pending_closure.sql (1.26ms)10662026/07/09 07:47:17 OK 2_object_stats_trigger.sql (1.47ms)10672026/07/09 07:47:17 goose: up to current file version: 21068--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.67s)1069=== CONT TestClientWithDependencies10702026-07-09 07:47:17.524 UTC [30964] ERROR: relation "goose_db_version" does not exist at character 3610712026-07-09 07:47:17.524 UTC [30964] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10722026/07/09 07:47:17 OK 20241026095416_initial_model.sql (10.72ms)10732026/07/09 07:47:17 OK 20251210153512_drop_unused_gin_index.sql (707.29µs)10742026/07/09 07:47:17 OK 20251218171726_add_pins.sql (957.67µs)10752026/07/09 07:47:17 OK 20260628120000_add_object_size_and_stats.sql (6.64ms)10762026/07/09 07:47:17 goose: successfully migrated database to version: 2026062812000010772026/07/09 07:47:17 OK 1_commit_pending_closure.sql (1.2ms)10782026/07/09 07:47:17 OK 2_object_stats_trigger.sql (501.38µs)10792026/07/09 07:47:17 goose: up to current file version: 21080--- PASS: TestReadProxyNarinfo (0.61s)1081=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1082--- PASS: TestGCBugBareHashReferences (0.95s)1083=== CONT TestClientMultipleUploads10842026-07-09 07:47:17.665 UTC [30969] ERROR: relation "goose_db_version" does not exist at character 3610852026-07-09 07:47:17.665 UTC [30969] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10862026-07-09 07:47:17.695 UTC [30971] ERROR: relation "goose_db_version" does not exist at character 3610872026-07-09 07:47:17.695 UTC [30971] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10882026-07-09 07:47:17.716 UTC [30973] ERROR: relation "goose_db_version" does not exist at character 3610892026-07-09 07:47:17.716 UTC [30973] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10902026-07-09 07:47:17.729 UTC [30975] ERROR: relation "goose_db_version" does not exist at character 3610912026-07-09 07:47:17.729 UTC [30975] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10922026/07/09 07:47:17 OK 20241026095416_initial_model.sql (34.92ms)10932026/07/09 07:47:17 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)10942026/07/09 07:47:17 OK 20241026095416_initial_model.sql (31.48ms)10952026/07/09 07:47:17 OK 20251218171726_add_pins.sql (2.28ms)10962026/07/09 07:47:17 OK 20241026095416_initial_model.sql (11.67ms)10972026/07/09 07:47:17 OK 20251210153512_drop_unused_gin_index.sql (864.33µs)10982026/07/09 07:47:17 OK 20251210153512_drop_unused_gin_index.sql (773.79µs)10992026/07/09 07:47:17 OK 20251218171726_add_pins.sql (2.72ms)11002026/07/09 07:47:17 OK 20251218171726_add_pins.sql (2.91ms)11012026/07/09 07:47:17 OK 20260628120000_add_object_size_and_stats.sql (7.44ms)11022026/07/09 07:47:17 goose: successfully migrated database to version: 2026062812000011032026-07-09 07:47:17.760 UTC [30976] ERROR: relation "goose_db_version" does not exist at character 3611042026-07-09 07:47:17.760 UTC [30976] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11052026/07/09 07:47:17 OK 20241026095416_initial_model.sql (22.46ms)11062026/07/09 07:47:17 OK 1_commit_pending_closure.sql (2.11ms)11072026/07/09 07:47:17 OK 2_object_stats_trigger.sql (569.29µs)11082026/07/09 07:47:17 goose: up to current file version: 211092026/07/09 07:47:17 OK 20251210153512_drop_unused_gin_index.sql (907µs)11102026/07/09 07:47:17 OK 20260628120000_add_object_size_and_stats.sql (7.65ms)11112026/07/09 07:47:17 goose: successfully migrated database to version: 2026062812000011122026/07/09 07:47:17 OK 20251218171726_add_pins.sql (2.78ms)11132026/07/09 07:47:17 OK 20260628120000_add_object_size_and_stats.sql (9.97ms)11142026/07/09 07:47:17 goose: successfully migrated database to version: 2026062812000011152026/07/09 07:47:17 OK 1_commit_pending_closure.sql (2.37ms)11162026/07/09 07:47:17 OK 2_object_stats_trigger.sql (578.71µs)11172026/07/09 07:47:17 goose: up to current file version: 211182026/07/09 07:47:17 OK 1_commit_pending_closure.sql (2.02ms)11192026/07/09 07:47:17 OK 2_object_stats_trigger.sql (506.54µs)11202026/07/09 07:47:17 goose: up to current file version: 211212026/07/09 07:47:17 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)11222026/07/09 07:47:17 goose: successfully migrated database to version: 2026062812000011232026/07/09 07:47:17 OK 1_commit_pending_closure.sql (2.3ms)11242026/07/09 07:47:17 OK 2_object_stats_trigger.sql (574.17µs)11252026/07/09 07:47:17 goose: up to current file version: 211262026/07/09 07:47:17 OK 20241026095416_initial_model.sql (14.32ms)11272026/07/09 07:47:17 OK 20251210153512_drop_unused_gin_index.sql (1.51ms)1128--- PASS: TestObjectStatsTrigger (0.63s)1129=== CONT TestClientIntegration11302026/07/09 07:47:17 OK 20251218171726_add_pins.sql (3.25ms)11312026/07/09 07:47:17 OK 20260628120000_add_object_size_and_stats.sql (4.58ms)11322026/07/09 07:47:17 goose: successfully migrated database to version: 2026062812000011332026/07/09 07:47:17 OK 1_commit_pending_closure.sql (2.14ms)11342026/07/09 07:47:17 OK 2_object_stats_trigger.sql (770.42µs)11352026/07/09 07:47:17 goose: up to current file version: 21136--- PASS: TestResurrectedObjectNotDeleted (0.75s)1137=== CONT TestReadProxyRangeRequest11382026/07/09 07:47:17 INFO Created nix-cache-info in bucket bucket=bucket3011392026-07-09 07:47:17.883 UTC [30985] ERROR: relation "goose_db_version" does not exist at character 3611402026-07-09 07:47:17.883 UTC [30985] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11412026-07-09 07:47:17.919 UTC [30987] ERROR: relation "goose_db_version" does not exist at character 3611422026-07-09 07:47:17.919 UTC [30987] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11432026/07/09 07:47:17 OK 20241026095416_initial_model.sql (13.28ms)11442026/07/09 07:47:17 OK 20251210153512_drop_unused_gin_index.sql (990.38µs)11452026/07/09 07:47:17 OK 20251218171726_add_pins.sql (2.65ms)11462026/07/09 07:47:17 OK 20260628120000_add_object_size_and_stats.sql (4.99ms)11472026/07/09 07:47:17 goose: successfully migrated database to version: 2026062812000011482026/07/09 07:47:17 OK 1_commit_pending_closure.sql (2.07ms)11492026/07/09 07:47:17 OK 2_object_stats_trigger.sql (620.67µs)11502026/07/09 07:47:17 goose: up to current file version: 211512026/07/09 07:47:17 INFO Received uploads request method=POST path=/api/pending_closures11522026/07/09 07:47:17 INFO Received uploads request method=POST path=/api/pending_closures11532026/07/09 07:47:17 OK 20241026095416_initial_model.sql (22.58ms)11542026/07/09 07:47:17 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)11552026/07/09 07:47:17 OK 20251218171726_add_pins.sql (2.63ms)11562026/07/09 07:47:17 OK 20260628120000_add_object_size_and_stats.sql (9.83ms)11572026/07/09 07:47:17 goose: successfully migrated database to version: 2026062812000011582026/07/09 07:47:17 OK 1_commit_pending_closure.sql (2.5ms)11592026/07/09 07:47:17 OK 2_object_stats_trigger.sql (652.42µs)11602026/07/09 07:47:17 goose: up to current file version: 211612026/07/09 07:47:17 INFO Created nix-cache-info in bucket bucket=bucket321162=== NAME TestPinProtectsFromGC1163 client_integration_test.go:646: Pinned store path: /nix/var/nix/builds/nix-30502-2751901220/TestPinProtectsFromGC3885920049/001/store/351xka54lg0rlrl1sglxg6b5qbp107gs-pinned-file.txt1164 client_integration_test.go:647: Unpinned store path: /nix/var/nix/builds/nix-30502-2751901220/TestPinProtectsFromGC3885920049/001/store/h6p6s7yp95rrk0gd4lwca60rvmc3kqmj-unpinned-file.txt11652026-07-09 07:47:18.018 UTC [30991] ERROR: relation "goose_db_version" does not exist at character 3611662026-07-09 07:47:18.018 UTC [30991] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1167=== NAME TestOrphanedObjectsGC1168 orphaned_objects_gc_test.go:290: GC Test Summary:1169 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1170 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1171 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1172 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1173 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1174--- PASS: TestOrphanedObjectsGC (0.92s)1175=== CONT TestService_AuthMiddleware_OIDC11762026/07/09 07:47:18 INFO OIDC provider initialized name=test11772026/07/09 07:47:18 OK 20241026095416_initial_model.sql (12.69ms)11782026/07/09 07:47:18 OK 20251210153512_drop_unused_gin_index.sql (1.1ms)11792026/07/09 07:47:18 OK 20251218171726_add_pins.sql (2.44ms)11802026/07/09 07:47:18 OK 20260628120000_add_object_size_and_stats.sql (5.42ms)11812026/07/09 07:47:18 goose: successfully migrated database to version: 2026062812000011822026/07/09 07:47:18 OK 1_commit_pending_closure.sql (2.39ms)11832026/07/09 07:47:18 OK 2_object_stats_trigger.sql (657µs)11842026/07/09 07:47:18 goose: up to current file version: 211852026/07/09 07:47:18 INFO Received uploads request method=POST path=/api/pending_closures11862026/07/09 07:47:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1187{"timestamp":"2026-07-09T07:47:18.093495Z","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(11)"}1188{"timestamp":"2026-07-09T07:47:18.093586Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket33, 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(11)"}11892026/07/09 07:47:18 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=MzhkMDkxZDItNTc4My00YmYzLWI2NGItMDQxN2QwYzQ4OTI0LmQ3NGFmZGRjLTE1NDEtNDE4Ny1iMWRjLTY4YWU1ZmUzNmMxZngxNzgzNTgzMjM4MDgwMDIzMDAw11902026/07/09 07:47:18 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzhkMDkxZDItNTc4My00YmYzLWI2NGItMDQxN2QwYzQ4OTI0LmQ3NGFmZGRjLTE1NDEtNDE4Ny1iMWRjLTY4YWU1ZmUzNmMxZngxNzgzNTgzMjM4MDgwMDIzMDAw parts=11191--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.54s)1192=== CONT TestClientErrorHandling1193=== RUN TestClientErrorHandling/InvalidStorePath1194=== PAUSE TestClientErrorHandling/InvalidStorePath1195=== RUN TestClientErrorHandling/InvalidAuthToken1196=== PAUSE TestClientErrorHandling/InvalidAuthToken1197=== RUN TestClientErrorHandling/ServerNotAvailable1198=== PAUSE TestClientErrorHandling/ServerNotAvailable1199=== CONT TestClientCADerivations12002026-07-09 07:47:18.099 UTC [30998] ERROR: relation "goose_db_version" does not exist at character 3612012026-07-09 07:47:18.099 UTC [30998] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12022026/07/09 07:47:18 OK 20241026095416_initial_model.sql (16.57ms)12032026/07/09 07:47:18 OK 20251210153512_drop_unused_gin_index.sql (1.18ms)12042026/07/09 07:47:18 OK 20251218171726_add_pins.sql (2.53ms)12052026/07/09 07:47:18 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)12062026/07/09 07:47:18 goose: successfully migrated database to version: 2026062812000012072026/07/09 07:47:18 OK 1_commit_pending_closure.sql (2.3ms)12082026/07/09 07:47:18 OK 2_object_stats_trigger.sql (651.46µs)12092026/07/09 07:47:18 goose: up to current file version: 212102026/07/09 07:47:18 INFO Created nix-cache-info in bucket bucket=bucket3412112026-07-09 07:47:18.164 UTC [31005] ERROR: relation "goose_db_version" does not exist at character 3612122026-07-09 07:47:18.164 UTC [31005] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12132026/07/09 07:47:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12142026/07/09 07:47:18 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MzhkMDkxZDItNTc4My00YmYzLWI2NGItMDQxN2QwYzQ4OTI0LmVmMjI5ZGY2LTlmYjctNDU0MS1iZjMzLWE5YTM2NDM0NjljNXgxNzgzNTgzMjM3OTQyMDExMDAw parts=121215--- PASS: TestRedundantMultipartUpload (0.78s)1216=== CONT TestCacheStatsHandler12172026/07/09 07:47:18 OK 20241026095416_initial_model.sql (18.78ms)12182026/07/09 07:47:18 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)12192026/07/09 07:47:18 OK 20251218171726_add_pins.sql (2.76ms)12202026/07/09 07:47:18 OK 20260628120000_add_object_size_and_stats.sql (3.52ms)12212026/07/09 07:47:18 goose: successfully migrated database to version: 2026062812000012222026/07/09 07:47:18 OK 1_commit_pending_closure.sql (2.32ms)12232026/07/09 07:47:18 OK 2_object_stats_trigger.sql (591.13µs)12242026/07/09 07:47:18 goose: up to current file version: 212252026/07/09 07:47:18 INFO Created nix-cache-info in bucket bucket=bucket3512262026/07/09 07:47:18 INFO Received uploads request method=POST path=/api/pending_closures12272026/07/09 07:47:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12282026/07/09 07:47:18 INFO Uploading 351xka54lg0rlrl1sglxg6b5qbp107gs-pinned-file.txt (128B)1229=== NAME TestClientMultipleUploads1230 client_integration_test.go:338: Created store path 0: /nix/var/nix/builds/nix-30502-2751901220/TestClientMultipleUploads793002913/001/store/mc8w8is4k8ck2jzsldvf17dpvb9hx1xr-test-file-0.txt12312026-07-09 07:47:18.232 UTC [31012] ERROR: relation "goose_db_version" does not exist at character 3612322026-07-09 07:47:18.232 UTC [31012] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12332026/07/09 07:47:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12342026/07/09 07:47:18 INFO Signed narinfos id=1 count=112352026/07/09 07:47:18 INFO Uploading 1 narinfos12362026/07/09 07:47:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12372026/07/09 07:47:18 INFO Completed upload id=112382026/07/09 07:47:18 INFO Upload complete. (187ms)12392026/07/09 07:47:18 OK 20241026095416_initial_model.sql (17.89ms)12402026/07/09 07:47:18 OK 20251210153512_drop_unused_gin_index.sql (1.09ms)12412026/07/09 07:47:18 OK 20251218171726_add_pins.sql (2.36ms)12422026/07/09 07:47:18 OK 20260628120000_add_object_size_and_stats.sql (6.57ms)12432026/07/09 07:47:18 goose: successfully migrated database to version: 2026062812000012442026/07/09 07:47:18 OK 1_commit_pending_closure.sql (2.22ms)12452026/07/09 07:47:18 OK 2_object_stats_trigger.sql (610.54µs)12462026/07/09 07:47:18 goose: up to current file version: 21247--- PASS: TestReadProxyRangeRequest (0.48s)1248=== CONT TestService_ReadAuthMiddleware1249=== NAME TestClientIntegration1250 client_integration_test.go:276: Created store path: /nix/var/nix/builds/nix-30502-2751901220/TestClientIntegration4063900385/002/store/7jvfp5m9b8mpi6j853vimvs140ryxc7m-test-file.txt1251=== NAME TestClientMultipleUploads1252 client_integration_test.go:338: Created store path 1: /nix/var/nix/builds/nix-30502-2751901220/TestClientMultipleUploads793002913/001/store/1jhraaclvf8qwcqibdi7nmpmpdnm3xx9-test-file-1.txt12532026-07-09 07:47:18.349 UTC [31023] ERROR: relation "goose_db_version" does not exist at character 3612542026-07-09 07:47:18.349 UTC [31023] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12552026/07/09 07:47:18 OK 20241026095416_initial_model.sql (11.72ms)12562026/07/09 07:47:18 OK 20251210153512_drop_unused_gin_index.sql (1.11ms)1257 client_integration_test.go:338: Created store path 2: /nix/var/nix/builds/nix-30502-2751901220/TestClientMultipleUploads793002913/001/store/r8z663p20nbz3cn7yvfzyg69npx0l704-test-file-2.txt12582026/07/09 07:47:18 OK 20251218171726_add_pins.sql (2.72ms)12592026/07/09 07:47:18 OK 20260628120000_add_object_size_and_stats.sql (11.98ms)12602026/07/09 07:47:18 goose: successfully migrated database to version: 2026062812000012612026-07-09 07:47:18.386 UTC [31034] ERROR: relation "goose_db_version" does not exist at character 3612622026-07-09 07:47:18.386 UTC [31034] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12632026/07/09 07:47:18 OK 1_commit_pending_closure.sql (2.58ms)12642026/07/09 07:47:18 OK 2_object_stats_trigger.sql (1.05ms)12652026/07/09 07:47:18 goose: up to current file version: 21266=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1267=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1268=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1269=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1270=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1271=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1272=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1273=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1274=== CONT TestCacheConfigHandler1275=== RUN TestCacheConfigHandler/full_config,_no_issuer1276=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1277=== RUN TestCacheConfigHandler/no_cache_url_configured1278=== PAUSE TestCacheConfigHandler/no_cache_url_configured1279=== RUN TestCacheConfigHandler/no_signing_keys1280=== PAUSE TestCacheConfigHandler/no_signing_keys1281=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1282=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1283=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12842026/07/09 07:47:18 OK 20241026095416_initial_model.sql (12.79ms)12852026/07/09 07:47:18 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)12862026/07/09 07:47:18 OK 20251218171726_add_pins.sql (2.71ms)12872026/07/09 07:47:18 OK 20260628120000_add_object_size_and_stats.sql (3.15ms)12882026/07/09 07:47:18 goose: successfully migrated database to version: 2026062812000012892026/07/09 07:47:18 OK 1_commit_pending_closure.sql (2.36ms)12902026/07/09 07:47:18 OK 2_object_stats_trigger.sql (561.5µs)12912026/07/09 07:47:18 goose: up to current file version: 212922026/07/09 07:47:18 INFO Created nix-cache-info in bucket bucket=bucket3812932026/07/09 07:47:18 INFO Received uploads request method=POST path=/api/pending_closures12942026/07/09 07:47:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12952026/07/09 07:47:18 INFO Uploading h6p6s7yp95rrk0gd4lwca60rvmc3kqmj-unpinned-file.txt (128B)12962026/07/09 07:47:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12972026/07/09 07:47:18 INFO Signed narinfos id=2 count=112982026/07/09 07:47:18 INFO Uploading 1 narinfos12992026/07/09 07:47:18 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13002026/07/09 07:47:18 INFO Completed upload id=213012026/07/09 07:47:18 INFO Upload complete. (157ms)13022026-07-09 07:47:18.521 UTC [31046] ERROR: relation "goose_db_version" does not exist at character 3613032026-07-09 07:47:18.521 UTC [31046] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13042026-07-09 07:47:18.529 UTC [31047] ERROR: relation "goose_db_version" does not exist at character 3613052026-07-09 07:47:18.529 UTC [31047] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13062026/07/09 07:47:18 INFO Received create pin request method=POST path=/api/pins/myapp13072026/07/09 07:47:18 INFO Received uploads request method=POST path=/api/pending_closures13082026/07/09 07:47:18 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-30502-2751901220/TestPinProtectsFromGC3885920049/001/store/351xka54lg0rlrl1sglxg6b5qbp107gs-pinned-file.txt narinfo_key=351xka54lg0rlrl1sglxg6b5qbp107gs.narinfo13092026/07/09 07:47:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures13102026/07/09 07:47:18 INFO Garbage collection started13112026/07/09 07:47:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13122026/07/09 07:47:18 INFO Uploading 7jvfp5m9b8mpi6j853vimvs140ryxc7m-test-file.txt (152B)13132026/07/09 07:47:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13142026/07/09 07:47:18 INFO Signed narinfos id=1 count=113152026/07/09 07:47:18 INFO Uploading 1 narinfos13162026/07/09 07:47:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13172026/07/09 07:47:18 OK 20241026095416_initial_model.sql (9.83ms)13182026/07/09 07:47:18 INFO Aborted multipart uploads count=013192026/07/09 07:47:18 OK 20241026095416_initial_model.sql (11.15ms)13202026/07/09 07:47:18 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)13212026/07/09 07:47:18 INFO Completed upload id=113222026/07/09 07:47:18 INFO Upload complete. (174ms)13232026/07/09 07:47:18 OK 20251210153512_drop_unused_gin_index.sql (929.96µs)1324=== NAME TestClientIntegration1325 client_integration_test.go:292: Retrieved narinfo from S3:1326 StorePath: /nix/var/nix/builds/nix-30502-2751901220/TestClientIntegration4063900385/002/store/7jvfp5m9b8mpi6j853vimvs140ryxc7m-test-file.txt1327 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1328 Compression: zstd1329 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11330 NarSize: 1521331 References: 1332 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk113332026/07/09 07:47:18 WARN Force mode enabled - objects will be deleted immediately without grace period13342026/07/09 07:47:18 OK 20251218171726_add_pins.sql (2.63ms)13352026/07/09 07:47:18 OK 20251218171726_add_pins.sql (3.03ms)1336 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1337 client_integration_test.go:293: Decompressed .ls content (64 bytes):1338 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1339 client_integration_test.go:296: Testing garbage collection...13402026/07/09 07:47:18 OK 20260628120000_add_object_size_and_stats.sql (4.31ms)13412026/07/09 07:47:18 goose: successfully migrated database to version: 2026062812000013422026/07/09 07:47:18 OK 20260628120000_add_object_size_and_stats.sql (4.21ms)13432026/07/09 07:47:18 goose: successfully migrated database to version: 2026062812000013442026/07/09 07:47:18 OK 1_commit_pending_closure.sql (2.46ms)13452026/07/09 07:47:18 OK 1_commit_pending_closure.sql (1.78ms)13462026/07/09 07:47:18 OK 2_object_stats_trigger.sql (554.04µs)13472026/07/09 07:47:18 goose: up to current file version: 213482026/07/09 07:47:18 OK 2_object_stats_trigger.sql (511.04µs)13492026/07/09 07:47:18 goose: up to current file version: 213502026/07/09 07:47:18 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1351--- PASS: TestService_ReadAuthMiddleware (0.28s)1352=== CONT TestService_AuthMiddleware_MTLSProxyHeader1353=== NAME TestOrphanedObjectsGCStressTest1354 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1355--- PASS: TestCacheStatsHandler (0.39s)1356=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info13572026/07/09 07:47:18 INFO Received uploads request method=POST path=/1358=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key13592026/07/09 07:47:18 INFO Received request for more parts method=POST path=/1360=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key13612026/07/09 07:47:18 INFO Received complete multipart upload request method=POST path=/1362=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal13632026/07/09 07:47:18 INFO Received uploads request method=POST path=/1364--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1365 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1366 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1367 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1368 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1369=== CONT TestProxyWriteTimeout/narinfo1370=== CONT TestProxyWriteTimeout/unknown_size1371=== CONT TestProxyWriteTimeout/10_GiB_nar1372=== CONT TestProxyWriteTimeout/1_GiB_nar1373--- PASS: TestProxyWriteTimeout (0.00s)1374 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1375 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1376 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1377 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1378=== CONT TestIsValidUploadKey/narinfo1379=== CONT TestIsValidUploadKey/nix-cache-info1380=== CONT TestIsValidUploadKey/realisation_plus_in_output1381=== CONT TestIsValidUploadKey/realisation1382=== CONT TestIsValidUploadKey/build_log_equals1383=== CONT TestIsValidUploadKey/build_log_question_mark1384=== CONT TestIsValidUploadKey/build_log_plus_in_name1385=== CONT TestIsValidUploadKey/nar_plain1386=== CONT TestIsValidUploadKey/build_log1387=== CONT TestIsValidUploadKey/build_log_home-manager_file1388=== CONT TestIsValidUploadKey/nar_xz1389=== CONT TestIsValidUploadKey/nar_zst1390=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1391=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1392=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1393=== CONT TestIsValidUploadKey/empty_key1394=== CONT TestIsValidUploadKey/unknown_type1395=== CONT TestIsValidUploadKey/absolute1396=== CONT TestIsValidUploadKey/index.html1397=== CONT TestIsValidUploadKey/traversal_nar1398=== CONT TestIsValidUploadKey/listing1399=== CONT TestIsValidUploadKey/traversal1400--- PASS: TestIsValidUploadKey (0.00s)1401 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1402 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1403 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1404 --- PASS: TestIsValidUploadKey/realisation (0.00s)1405 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1406 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1407 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1408 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1409 --- PASS: TestIsValidUploadKey/build_log (0.00s)1410 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1411 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1412 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1413 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1414 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1415 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1416 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1417 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1418 --- PASS: TestIsValidUploadKey/absolute (0.00s)1419 --- PASS: TestIsValidUploadKey/index.html (0.00s)1420 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1421 --- PASS: TestIsValidUploadKey/listing (0.00s)1422 --- PASS: TestIsValidUploadKey/traversal (0.00s)1423=== CONT TestServerTLSConfig/no_client_CA1424=== CONT TestServerTLSConfig/not_a_PEM_file1425=== CONT TestServerTLSConfig/missing_CA_file1426--- PASS: TestServerTLSConfig (0.00s)1427 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1428 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1429 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1430=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14312026/07/09 07:47:18 INFO Received uploads request method=POST path=/1432=== NAME TestOrphanedObjectsGCStressTest1433 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion14342026-07-09 07:47:18.598 UTC [31058] ERROR: relation "goose_db_version" does not exist at character 3614352026-07-09 07:47:18.598 UTC [31058] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14362026/07/09 07:47:18 INFO Received uploads request method=POST path=/api/pending_closures14372026/07/09 07:47:18 INFO Received uploads request method=POST path=/api/pending_closures14382026/07/09 07:47:18 INFO Received uploads request method=POST path=/api/pending_closures14392026/07/09 07:47:18 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14402026/07/09 07:47:18 INFO Uploading 1jhraaclvf8qwcqibdi7nmpmpdnm3xx9-test-file-1.txt (160B)14412026/07/09 07:47:18 INFO Uploading mc8w8is4k8ck2jzsldvf17dpvb9hx1xr-test-file-0.txt (160B)14422026/07/09 07:47:18 INFO Uploading r8z663p20nbz3cn7yvfzyg69npx0l704-test-file-2.txt (160B)14432026/07/09 07:47:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures14442026/07/09 07:47:18 INFO Garbage collection started14452026/07/09 07:47:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14462026/07/09 07:47:18 INFO Signed narinfos id=1 count=114472026/07/09 07:47:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14482026/07/09 07:47:18 INFO Signed narinfos id=2 count=114492026/07/09 07:47:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign14502026/07/09 07:47:18 INFO Signed narinfos id=3 count=114512026/07/09 07:47:18 INFO Uploading 3 narinfos14522026/07/09 07:47:18 INFO Aborted multipart uploads count=014532026/07/09 07:47:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14542026/07/09 07:47:18 WARN Force mode enabled - objects will be deleted immediately without grace period14552026/07/09 07:47:18 OK 20241026095416_initial_model.sql (12.58ms)14562026/07/09 07:47:18 INFO Completed upload id=114572026/07/09 07:47:18 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14582026/07/09 07:47:18 OK 20251210153512_drop_unused_gin_index.sql (932.04µs)14592026/07/09 07:47:18 INFO Completed upload id=214602026/07/09 07:47:18 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete14612026/07/09 07:47:18 INFO Completed upload id=314622026/07/09 07:47:18 INFO Upload complete. (185ms)1463=== NAME TestClientMultipleUploads1464 client_integration_test.go:349: Uploaded 3 paths in 255.0135ms14652026/07/09 07:47:18 OK 20251218171726_add_pins.sql (1.48ms)14662026/07/09 07:47:18 OK 20260628120000_add_object_size_and_stats.sql (2.82ms)14672026/07/09 07:47:18 goose: successfully migrated database to version: 2026062812000014682026/07/09 07:47:18 OK 1_commit_pending_closure.sql (1.96ms)14692026/07/09 07:47:18 OK 2_object_stats_trigger.sql (739.46µs)14702026/07/09 07:47:18 goose: up to current file version: 21471--- PASS: TestClientMultipleUploads (0.97s)1472=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14732026/07/09 07:47:18 INFO Received request for more parts method=POST path=/14742026/07/09 07:47:18 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14752026/07/09 07:47:18 WARN mTLS auth: bound subjects configured but subject DN unavailable14762026/07/09 07:47:18 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1477--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.24s)1478=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14792026/07/09 07:47:18 INFO Received complete multipart upload request method=POST path=/1480=== CONT TestIsValidCachePath/narinfo1481=== CONT TestIsValidCachePath/index.html1482=== CONT TestIsValidCachePath/short_hash1483=== CONT TestIsValidCachePath/wrong_extension1484=== CONT TestIsValidCachePath/leading_slash1485=== CONT TestIsValidCachePath/empty1486=== CONT TestIsValidCachePath/random_path1487=== CONT TestIsValidCachePath/invalid_char_u1488=== CONT TestIsValidCachePath/invalid_char_e1489=== CONT TestIsValidCachePath/traversal_in_middle1490=== CONT TestIsValidCachePath/traversal_parent1491=== CONT TestIsValidCachePath/nar_uncompressed1492=== CONT TestIsValidCachePath/nix-cache-info1493=== CONT TestIsValidCachePath/realisation1494=== CONT TestIsValidCachePath/log1495=== CONT TestIsValidCachePath/ls1496=== CONT TestIsValidCachePath/nar_xz1497=== CONT TestIsValidCachePath/nar_bz21498=== CONT TestIsValidCachePath/nar_zst1499=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1500--- PASS: TestIsValidCachePath (0.00s)1501 --- PASS: TestIsValidCachePath/narinfo (0.00s)1502 --- PASS: TestIsValidCachePath/index.html (0.00s)1503 --- PASS: TestIsValidCachePath/short_hash (0.00s)1504 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1505 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1506 --- PASS: TestIsValidCachePath/empty (0.00s)1507 --- PASS: TestIsValidCachePath/random_path (0.00s)1508 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1509 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1510 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1511 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1512 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1513 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1514 --- PASS: TestIsValidCachePath/realisation (0.00s)1515 --- PASS: TestIsValidCachePath/log (0.00s)1516 --- PASS: TestIsValidCachePath/ls (0.00s)1517 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1518 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1519 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1520 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1521=== CONT TestParseSingleRange/none1522=== CONT TestParseSingleRange/open-ended1523=== CONT TestParseSingleRange/start_far_past_EOF1524=== CONT TestParseSingleRange/start_past_EOF1525=== CONT TestParseSingleRange/single_byte1526=== CONT TestParseSingleRange/suffix_exceeds_size1527=== CONT TestParseSingleRange/suffix1528=== CONT TestParseSingleRange/end_clamped_to_size1529=== CONT TestParseSingleRange/malformed_both_empty1530=== CONT TestParseSingleRange/closed1531=== CONT TestParseSingleRange/malformed_end_before_start1532=== CONT TestParseSingleRange/multi-range_ignored1533=== CONT TestParseSingleRange/malformed_no_dash1534=== CONT TestParseSingleRange/unknown_unit1535--- PASS: TestParseSingleRange (0.00s)1536 --- PASS: TestParseSingleRange/none (0.00s)1537 --- PASS: TestParseSingleRange/open-ended (0.00s)1538 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1539 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1540 --- PASS: TestParseSingleRange/single_byte (0.00s)1541 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1542 --- PASS: TestParseSingleRange/suffix (0.00s)1543 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1544 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1545 --- PASS: TestParseSingleRange/closed (0.00s)1546 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1547 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1548 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1549 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1550=== CONT TestClientErrorHandling/InvalidStorePath1551=== CONT TestClientErrorHandling/ServerNotAvailable15522026-07-09 07:47:18.732 UTC [31066] ERROR: relation "goose_db_version" does not exist at character 3615532026-07-09 07:47:18.732 UTC [31066] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1554=== NAME TestClientWithDependencies1555 client_integration_test.go:593: Built derivation: /nix/var/nix/builds/nix-30502-2751901220/TestClientWithDependencies1508381034/001/store/fmliqv736c54dn0z3rdibjdrkngrpihz-test-script15562026/07/09 07:47:18 OK 20241026095416_initial_model.sql (11.56ms)15572026/07/09 07:47:18 OK 20251210153512_drop_unused_gin_index.sql (960.13µs)15582026/07/09 07:47:18 OK 20251218171726_add_pins.sql (1.5ms)15592026/07/09 07:47:18 OK 20260628120000_add_object_size_and_stats.sql (2.58ms)15602026/07/09 07:47:18 goose: successfully migrated database to version: 2026062812000015612026/07/09 07:47:18 OK 1_commit_pending_closure.sql (2.05ms)15622026/07/09 07:47:18 OK 2_object_stats_trigger.sql (568.5µs)15632026/07/09 07:47:18 goose: up to current file version: 21564=== NAME TestOrphanedObjectsGCStressTest1565 orphaned_objects_gc_test.go:509: Stress test completed successfully:1566 orphaned_objects_gc_test.go:510: - Active objects preserved: 201567 orphaned_objects_gc_test.go:511: - Objects deleted: 2101568 orphaned_objects_gc_test.go:512: - Total GC'd: 2101569--- PASS: TestOrphanedObjectsGCStressTest (1.71s)1570=== CONT TestClientErrorHandling/InvalidAuthToken1571--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.22s)1572=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token15732026/07/09 07:47:18 INFO OIDC auth successful provider=test1574=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected15752026/07/09 07:47:18 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]1576=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1577=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected15782026/07/09 07:47:18 WARN Authentication failed token_preview=eyJhbGciOi...AXI5RuWyWA 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]1579=== CONT TestCacheConfigHandler/full_config,_no_issuer1580=== CONT TestCacheConfigHandler/no_signing_keys1581=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1582=== CONT TestCacheConfigHandler/no_cache_url_configured1583--- PASS: TestCacheConfigHandler (0.00s)1584 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1585 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1586 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1587 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1588--- PASS: TestService_AuthMiddleware_OIDC (0.37s)1589 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1590 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1591 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1592 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1593=== NAME TestClientWithDependencies1594 client_integration_test.go:595: Found 1 dependencies (including self)15952026-07-09 07:47:18.833 UTC [31076] ERROR: relation "goose_db_version" does not exist at character 3615962026-07-09 07:47:18.833 UTC [31076] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15972026/07/09 07:47:18 OK 20241026095416_initial_model.sql (10.71ms)15982026/07/09 07:47:18 OK 20251210153512_drop_unused_gin_index.sql (1.31ms)15992026/07/09 07:47:18 OK 20251218171726_add_pins.sql (3.03ms)16002026/07/09 07:47:18 OK 20260628120000_add_object_size_and_stats.sql (2.68ms)16012026/07/09 07:47:18 goose: successfully migrated database to version: 2026062812000016022026/07/09 07:47:18 OK 1_commit_pending_closure.sql (2.14ms)16032026/07/09 07:47:18 OK 2_object_stats_trigger.sql (612.33µs)16042026/07/09 07:47:18 goose: up to current file version: 216052026-07-09 07:47:18.899 UTC [31082] ERROR: relation "goose_db_version" does not exist at character 3616062026-07-09 07:47:18.899 UTC [31082] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16072026/07/09 07:47:18 OK 20241026095416_initial_model.sql (9.1ms)16082026/07/09 07:47:18 OK 20251210153512_drop_unused_gin_index.sql (1ms)16092026/07/09 07:47:18 OK 20251218171726_add_pins.sql (2.58ms)16102026/07/09 07:47:18 OK 20260628120000_add_object_size_and_stats.sql (3.08ms)16112026/07/09 07:47:18 goose: successfully migrated database to version: 2026062812000016122026/07/09 07:47:18 OK 1_commit_pending_closure.sql (1.84ms)16132026/07/09 07:47:18 OK 2_object_stats_trigger.sql (603.42µs)16142026/07/09 07:47:18 goose: up to current file version: 216152026/07/09 07:47:18 INFO Received uploads request method=POST path=/api/pending_closures16162026/07/09 07:47:18 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_closures16172026/07/09 07:47:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16182026/07/09 07:47:18 INFO Uploading fmliqv736c54dn0z3rdibjdrkngrpihz-test-script (136B)16192026/07/09 07:47:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16202026/07/09 07:47:18 INFO Signed narinfos id=1 count=116212026/07/09 07:47:18 INFO Uploading 1 narinfos16222026/07/09 07:47:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16232026/07/09 07:47:18 INFO Completed upload id=116242026/07/09 07:47:18 INFO Upload complete. (80ms)1625 client_integration_test.go:597: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-30502-2751901220/TestClientWithDependencies1508381034/001/store) requires matching store prefix1626--- PASS: TestClientWithDependencies (1.55s)1627=== NAME TestClientCADerivations1628 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-30502-2751901220/TestClientCADerivations900333956/001/store/bkcziz8drn24wr6b4d36zkdw1nkisvx1-ca-test16292026/07/09 07:47:19 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=216.576059ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1630 client_ca_test.go:139: Found 1 dependencies (including self)16312026/07/09 07:47:19 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"16322026/07/09 07:47:19 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=376.841013ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16332026/07/09 07:47:19 INFO Received uploads request method=POST path=/api/pending_closures16342026/07/09 07:47:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16352026/07/09 07:47:19 INFO Uploading bkcziz8drn24wr6b4d36zkdw1nkisvx1-ca-test (144B)16362026/07/09 07:47:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16372026/07/09 07:47:19 INFO Signed narinfos id=1 count=116382026/07/09 07:47:19 INFO Uploading 1 narinfos16392026/07/09 07:47:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16402026/07/09 07:47:19 INFO Completed upload id=116412026/07/09 07:47:19 INFO Upload complete. (144ms)1642 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-30502-2751901220/TestClientCADerivations900333956/001/store/bkcziz8drn24wr6b4d36zkdw1nkisvx1-ca-test1643 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1644 Compression: zstd1645 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1646 NarSize: 1441647 References: 1648 Deriver: /nix/var/nix/builds/nix-30502-2751901220/TestClientCADerivations900333956/001/store/kfnfffc6r5580prg4m1xkp2b1hzkjblg-ca-test.drv1649 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1650 client_ca_test.go:185: Checking for realisation files in S3...1651 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1652 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16532026/07/09 07:47:19 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=016542026/07/09 07:47:19 INFO Vacuumed table table=pending_closures16552026/07/09 07:47:19 INFO Vacuumed table table=pending_objects16562026/07/09 07:47:19 INFO Vacuumed table table=multipart_uploads16572026/07/09 07:47:19 INFO Vacuumed table table=closures16582026/07/09 07:47:19 INFO Vacuumed table table=objects16592026/07/09 07:47:19 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=016602026/07/09 07:47:19 INFO Vacuumed table table=pending_closures16612026/07/09 07:47:19 INFO Vacuumed table table=pending_objects16622026/07/09 07:47:19 INFO Vacuumed table table=multipart_uploads1663 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket38?endpoint=http://localhost:52723®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-30502-2751901220/TestClientCADerivations900333956/001/store'1664 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 116652026/07/09 07:47:19 INFO Vacuumed table table=closures1666--- PASS: TestClientCADerivations (1.27s)16672026/07/09 07:47:19 INFO Vacuumed table table=objects1668--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)1669 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)1670 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)1671 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.84s)16722026/07/09 07:47:19 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=732.867644ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16732026/07/09 07:47:20 WARN Rate limiter enabled after throttle name=s3-test rate=516742026/07/09 07:47:20 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1675=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1676 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101677 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001678--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.25s)16792026/07/09 07:47:20 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.502055403s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16802026/07/09 07:47:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01681=== NAME TestPinProtectsFromGC1682 client_integration_test.go:709: Pin successfully protected closure from garbage collection1683--- PASS: TestPinProtectsFromGC (3.32s)16842026/07/09 07:47:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01685=== NAME TestClientIntegration1686 client_integration_test.go:303: Objects in database after GC:1687 client_integration_test.go:303: Successfully deleted all objects with GC --force1688--- PASS: TestClientIntegration (2.84s)1689--- PASS: TestClientErrorHandling (0.00s)1690 --- PASS: TestClientErrorHandling/InvalidStorePath (0.26s)1691 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.43s)1692 --- PASS: TestClientErrorHandling/ServerNotAvailable (3.21s)1693PASS1694{"timestamp":"2026-07-09T07:47:22.38174Z","level":"ERROR","fields":{"message":"Unknown connection IO error:Cancelled","peer_addr":"127.0.0.1:52775"},"target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":973,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}16952026-07-09 07:47:22.460 UTC [30730] LOG: received smart shutdown request16962026-07-09 07:47:22.465 UTC [30730] LOG: background worker "logical replication launcher" (PID 30740) exited with exit code 116972026-07-09 07:47:22.473 UTC [30735] LOG: shutting down16982026-07-09 07:47:22.474 UTC [30735] LOG: checkpoint starting: shutdown immediate16992026-07-09 07:47:24.335 UTC [30735] LOG: checkpoint complete: wrote 13546 buffers (82.7%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 12 recycled; write=1.098 s, sync=0.760 s, total=1.862 s; sync files=14509, longest=0.006 s, average=0.001 s; distance=202875 kB, estimate=202875 kB; lsn=0/DDA4338, redo lsn=0/DDA433817002026-07-09 07:47:24.344 UTC [30730] LOG: database system is shut down1701Running OIDC tests...1702=== RUN TestGlobMatch1703=== PAUSE TestGlobMatch1704=== RUN TestAudienceForIssuer1705=== PAUSE TestAudienceForIssuer1706=== RUN TestValidateToken_ValidToken1707=== PAUSE TestValidateToken_ValidToken1708=== RUN TestValidateToken_WrongAudience1709=== PAUSE TestValidateToken_WrongAudience1710=== RUN TestValidateToken_Expired1711=== PAUSE TestValidateToken_Expired1712=== RUN TestValidateToken_BoundClaimsMismatch1713=== PAUSE TestValidateToken_BoundClaimsMismatch1714=== RUN TestValidateToken_BoundSubjectMismatch1715=== PAUSE TestValidateToken_BoundSubjectMismatch1716=== RUN TestValidateToken_MultipleProviders1717=== PAUSE TestValidateToken_MultipleProviders1718=== RUN TestValidateToken_NoMatchingProvider1719=== PAUSE TestValidateToken_NoMatchingProvider1720=== CONT TestGlobMatch1721=== RUN TestGlobMatch/foo_foo1722=== PAUSE TestGlobMatch/foo_foo1723=== RUN TestGlobMatch/foo_bar1724=== PAUSE TestGlobMatch/foo_bar1725=== RUN TestGlobMatch/*_1726=== PAUSE TestGlobMatch/*_1727=== CONT TestValidateToken_MultipleProviders1728=== CONT TestValidateToken_NoMatchingProvider1729=== CONT TestValidateToken_BoundClaimsMismatch1730=== CONT TestValidateToken_BoundSubjectMismatch1731=== RUN TestGlobMatch/*_anything1732=== PAUSE TestGlobMatch/*_anything1733=== RUN TestGlobMatch/foo*_foo1734=== PAUSE TestGlobMatch/foo*_foo1735=== RUN TestGlobMatch/foo*_foobar1736=== PAUSE TestGlobMatch/foo*_foobar1737=== RUN TestGlobMatch/foo*_bar1738=== PAUSE TestGlobMatch/foo*_bar1739=== CONT TestValidateToken_Expired1740=== CONT TestValidateToken_WrongAudience1741=== CONT TestValidateToken_ValidToken1742=== CONT TestAudienceForIssuer1743--- PASS: TestAudienceForIssuer (0.00s)1744=== RUN TestGlobMatch/*bar_bar1745=== PAUSE TestGlobMatch/*bar_bar1746=== RUN TestGlobMatch/*bar_foobar1747=== PAUSE TestGlobMatch/*bar_foobar1748=== RUN TestGlobMatch/*bar_foo1749=== PAUSE TestGlobMatch/*bar_foo1750=== RUN TestGlobMatch/foo*bar_foobar1751=== PAUSE TestGlobMatch/foo*bar_foobar1752=== RUN TestGlobMatch/foo*bar_foo123bar1753=== PAUSE TestGlobMatch/foo*bar_foo123bar1754=== RUN TestGlobMatch/foo*bar_foobarbaz1755=== PAUSE TestGlobMatch/foo*bar_foobarbaz1756=== RUN TestGlobMatch/*/*_foo/bar1757=== PAUSE TestGlobMatch/*/*_foo/bar1758=== RUN TestGlobMatch/*/*_foo1759=== PAUSE TestGlobMatch/*/*_foo1760=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1761=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1762=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01763=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01764=== RUN TestGlobMatch/refs/*/main_refs/heads/main1765=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1766=== RUN TestGlobMatch/fo?_foo1767=== PAUSE TestGlobMatch/fo?_foo1768=== RUN TestGlobMatch/fo?_fo1769=== PAUSE TestGlobMatch/fo?_fo1770=== RUN TestGlobMatch/fo?_fooo1771=== PAUSE TestGlobMatch/fo?_fooo1772=== RUN TestGlobMatch/?oo_foo1773=== PAUSE TestGlobMatch/?oo_foo1774=== RUN TestGlobMatch/?oo_boo1775=== PAUSE TestGlobMatch/?oo_boo1776=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1777=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1778=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1779=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1780=== CONT TestGlobMatch/foo_foo1781=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1782=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1783=== CONT TestGlobMatch/?oo_boo1784=== CONT TestGlobMatch/?oo_foo1785=== CONT TestGlobMatch/fo?_fooo1786=== CONT TestGlobMatch/fo?_fo1787=== CONT TestGlobMatch/fo?_foo1788=== CONT TestGlobMatch/refs/*/main_refs/heads/main1789=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01790=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1791=== CONT TestGlobMatch/*/*_foo1792=== CONT TestGlobMatch/*/*_foo/bar1793=== CONT TestGlobMatch/foo*bar_foobarbaz1794=== CONT TestGlobMatch/foo*bar_foo123bar1795=== CONT TestGlobMatch/foo*bar_foobar1796=== CONT TestGlobMatch/*bar_foo1797=== CONT TestGlobMatch/*bar_foobar1798=== CONT TestGlobMatch/*bar_bar1799=== CONT TestGlobMatch/foo*_foo1800=== CONT TestGlobMatch/*_1801=== CONT TestGlobMatch/foo*_bar1802=== CONT TestGlobMatch/foo*_foobar1803=== CONT TestGlobMatch/foo_bar1804=== CONT TestGlobMatch/*_anything1805--- PASS: TestGlobMatch (0.00s)1806 --- PASS: TestGlobMatch/foo_foo (0.00s)1807 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1808 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1809 --- PASS: TestGlobMatch/?oo_boo (0.00s)1810 --- PASS: TestGlobMatch/?oo_foo (0.00s)1811 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1812 --- PASS: TestGlobMatch/fo?_fo (0.00s)1813 --- PASS: TestGlobMatch/fo?_foo (0.00s)1814 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1815 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1816 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1817 --- PASS: TestGlobMatch/*/*_foo (0.00s)1818 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1819 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1820 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1821 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1822 --- PASS: TestGlobMatch/*bar_foo (0.00s)1823 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1824 --- PASS: TestGlobMatch/*bar_bar (0.00s)1825 --- PASS: TestGlobMatch/foo*_foo (0.00s)1826 --- PASS: TestGlobMatch/*_ (0.00s)1827 --- PASS: TestGlobMatch/foo*_bar (0.00s)1828 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1829 --- PASS: TestGlobMatch/foo_bar (0.00s)1830 --- PASS: TestGlobMatch/*_anything (0.00s)18312026/07/09 07:47:25 INFO OIDC provider initialized name=test18322026/07/09 07:47:25 INFO OIDC provider initialized name=provider118332026/07/09 07:47:25 INFO OIDC provider initialized name=provider118342026/07/09 07:47:25 INFO OIDC provider initialized name=test18352026/07/09 07:47:25 INFO OIDC provider initialized name=test18362026/07/09 07:47:25 INFO OIDC provider initialized name=test18372026/07/09 07:47:25 INFO OIDC provider initialized name=test18382026/07/09 07:47:25 INFO OIDC provider initialized name=provider21839--- PASS: TestValidateToken_WrongAudience (0.01s)1840--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1841--- PASS: TestValidateToken_ValidToken (0.01s)1842--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1843--- PASS: TestValidateToken_Expired (0.01s)1844--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1845--- PASS: TestValidateToken_MultipleProviders (0.01s)1846PASS1847Running hook tests...1848=== RUN TestSendPathsEmpty1849=== PAUSE TestSendPathsEmpty1850=== RUN TestQueueEnqueueAndFetch1851=== PAUSE TestQueueEnqueueAndFetch1852=== RUN TestQueueDeduplication1853=== PAUSE TestQueueDeduplication1854=== RUN TestQueueRemove1855=== PAUSE TestQueueRemove1856=== RUN TestQueueFetchBatchLimit1857=== PAUSE TestQueueFetchBatchLimit1858=== RUN TestQueueFetchRemoveLifecycle1859=== PAUSE TestQueueFetchRemoveLifecycle1860=== RUN TestQueueConcurrentWriters1861=== PAUSE TestQueueConcurrentWriters1862=== RUN TestServerClientIntegration1863=== PAUSE TestServerClientIntegration1864=== RUN TestServerQueueError1865=== PAUSE TestServerQueueError1866=== RUN TestGetListenerSocketActivation1867 server_test.go:210: === RUN TestGetListenerSocketActivation1868 --- PASS: TestGetListenerSocketActivation (0.00s)1869 PASS1870 1871--- PASS: TestGetListenerSocketActivation (0.01s)1872=== RUN TestWorkerUploadsAndRemoves1873=== PAUSE TestWorkerUploadsAndRemoves1874=== RUN TestWorkerSkipsGCdPaths1875=== PAUSE TestWorkerSkipsGCdPaths1876=== RUN TestWorkerPrunesClosureDeps1877=== PAUSE TestWorkerPrunesClosureDeps1878=== CONT TestSendPathsEmpty1879--- PASS: TestSendPathsEmpty (0.00s)1880=== CONT TestWorkerUploadsAndRemoves1881=== CONT TestWorkerSkipsGCdPaths1882=== CONT TestQueueFetchRemoveLifecycle1883=== CONT TestServerQueueError1884=== CONT TestServerClientIntegration1885=== CONT TestQueueConcurrentWriters1886=== CONT TestWorkerPrunesClosureDeps1887=== CONT TestQueueFetchBatchLimit18882026/07/09 07:47:25 ERROR Failed to queue paths error="permission denied" count=11889=== CONT TestQueueDeduplication1890=== CONT TestQueueEnqueueAndFetch1891--- PASS: TestServerQueueError (0.00s)1892=== CONT TestQueueRemove1893--- PASS: TestServerClientIntegration (0.00s)1894--- PASS: TestQueueFetchBatchLimit (0.01s)18952026/07/09 07:47:25 INFO Upload queue status pending=218962026/07/09 07:47:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-30502-2751901220/TestWorkerSkipsGCdPaths1067835410/002/nonexistent1897--- PASS: TestQueueFetchRemoveLifecycle (0.01s)18982026/07/09 07:47:25 INFO Uploading batch count=118992026/07/09 07:47:25 INFO Upload queue status pending=219002026/07/09 07:47:25 INFO Uploading batch count=11901--- PASS: TestQueueDeduplication (0.01s)19022026/07/09 07:47:25 INFO Upload queue status pending=219032026/07/09 07:47:25 INFO Uploading batch count=21904--- PASS: TestQueueEnqueueAndFetch (0.01s)1905--- PASS: TestQueueRemove (0.01s)1906--- PASS: TestWorkerPrunesClosureDeps (0.06s)1907--- PASS: TestWorkerSkipsGCdPaths (0.07s)1908--- PASS: TestWorkerUploadsAndRemoves (0.07s)1909--- PASS: TestQueueConcurrentWriters (0.10s)1910PASS