niks3-go-unit-tests
aarch64-darwin.go-unit-tests
· build #95
· 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 TestRateLimiterFeedback_400DoesNotCountAsSuccess732026/07/09 07:42:49 WARN Rate limiter enabled after throttle name=server-test rate=574=== CONT TestRateLimiterFeedback75=== RUN TestRateLimiterFeedback/429_enables_limiter76=== PAUSE TestRateLimiterFeedback/429_enables_limiter77=== RUN TestRateLimiterFeedback/503_enables_limiter78=== PAUSE TestRateLimiterFeedback/503_enables_limiter79=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter80=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter81=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter82=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter83=== CONT TestPathInfoCACompatibility84=== RUN TestPathInfoCACompatibility/null_ca_field85=== PAUSE TestPathInfoCACompatibility/null_ca_field86=== RUN TestPathInfoCACompatibility/old_string_format_-_text87=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text88=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive89=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive90=== RUN TestPathInfoCACompatibility/new_structured_format_-_text91=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text92=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method93=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method94--- PASS: TestResolveStorePath (0.00s)95--- PASS: TestDoServerRequestAttachesToken (0.00s)96=== CONT TestDumpPathSingleFile97=== CONT TestParsePathInfoJSON98=== RUN TestParsePathInfoJSON/Nix_format99=== PAUSE TestParsePathInfoJSON/Nix_format100=== RUN TestParsePathInfoJSON/Lix_format101=== PAUSE TestParsePathInfoJSON/Lix_format102=== RUN TestParsePathInfoJSON/empty_input103=== PAUSE TestParsePathInfoJSON/empty_input104=== RUN TestParsePathInfoJSON/whitespace_only105=== PAUSE TestParsePathInfoJSON/whitespace_only106=== RUN TestParsePathInfoJSON/invalid_JSON107=== PAUSE TestParsePathInfoJSON/invalid_JSON108=== CONT TestPathInfoHashCompatibility109=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)110=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)111=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon112=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon113=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI114=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI115=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512116=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512117=== CONT TestDumpPathMatchesNix118=== CONT TestUploadMultipart_SupersededByPeer119=== RUN TestUploadMultipart_SupersededByPeer/exists120=== PAUSE TestUploadMultipart_SupersededByPeer/exists121=== RUN TestUploadMultipart_SupersededByPeer/missing122=== PAUSE TestUploadMultipart_SupersededByPeer/missing123=== CONT TestPartSizeForNAR124=== RUN TestPartSizeForNAR/zero_stays_at_minimum125=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum126=== RUN TestPartSizeForNAR/small_stays_at_minimum127=== PAUSE TestPartSizeForNAR/small_stays_at_minimum128=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum129=== CONT TestConvertHashToNix32130=== CONT TestEncodeNixBase32131=== CONT TestEncodeNixBase32WithRealHash132=== CONT TestParsePathInfoJSONMultiplePaths133=== CONT TestDumpPathWriterError134=== CONT TestGetStorePathHash135=== RUN TestGetStorePathHash/valid_store_path136=== PAUSE TestGetStorePathHash/valid_store_path137=== RUN TestGetStorePathHash/basename_without_hyphen_should_error138=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error139=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error140=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error141=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error142=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error143=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum144=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts145=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts146=== RUN TestPartSizeForNAR/1_TiB147=== PAUSE TestPartSizeForNAR/1_TiB148--- PASS: TestEncodeNixBase32WithRealHash (0.00s)149=== CONT TestFileTokenMissing150--- PASS: TestFileTokenMissing (0.00s)151=== CONT TestScriptTokenEmptyCommand152--- PASS: TestScriptTokenEmptyCommand (0.00s)153=== CONT TestScriptTokenScriptFails154=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths155=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths156=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths157=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths158=== CONT TestScriptTokenBadJSON159=== RUN TestPartSizeForNAR/5_TiB_S3_max_object160=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object161=== RUN TestPartSizeForNAR/capped_at_5_GiB162=== PAUSE TestPartSizeForNAR/capped_at_5_GiB163=== CONT TestScriptTokenEmptyToken164=== RUN TestConvertHashToNix32/SRI_format_to_Nix32165=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32166=== RUN TestConvertHashToNix32/already_Nix32_format167=== PAUSE TestConvertHashToNix32/already_Nix32_format168=== RUN TestConvertHashToNix32/invalid_format169=== PAUSE TestConvertHashToNix32/invalid_format170=== CONT TestScriptTokenCachesUntilRefresh171=== RUN TestEncodeNixBase32/test_string_hash172=== PAUSE TestEncodeNixBase32/test_string_hash173=== RUN TestEncodeNixBase32/empty_input174=== PAUSE TestEncodeNixBase32/empty_input175=== CONT TestScriptTokenNoExpiryRerunsEveryCall176=== CONT TestCaseHackSuffix177--- PASS: TestScriptTokenScriptFails (0.02s)178=== CONT TestFileTokenEmpty179--- PASS: TestFileTokenEmpty (0.00s)180=== CONT TestSetClientTLSDoesNotMutateDefaultTransport181--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)182=== CONT TestFileTokenReadsAndCaches183--- PASS: TestFileTokenReadsAndCaches (0.00s)184=== CONT TestStaticToken185--- PASS: TestStaticToken (0.00s)186=== CONT TestSetClientTLSErrors187=== RUN TestSetClientTLSErrors/missing_cert_file188=== PAUSE TestSetClientTLSErrors/missing_cert_file189=== RUN TestSetClientTLSErrors/missing_key_file190=== PAUSE TestSetClientTLSErrors/missing_key_file191=== RUN TestSetClientTLSErrors/missing_ca_file192=== PAUSE TestSetClientTLSErrors/missing_ca_file193=== RUN TestSetClientTLSErrors/invalid_ca_file194=== PAUSE TestSetClientTLSErrors/invalid_ca_file195=== CONT TestShellSplitErrors196--- PASS: TestShellSplitErrors (0.00s)197=== CONT TestSetClientTLS198--- PASS: TestScriptTokenEmptyToken (0.07s)199=== CONT TestShellSplit200--- PASS: TestShellSplit (0.00s)201=== CONT TestDoWithRetry_BodyReplayedViaGetBody202--- PASS: TestScriptTokenBadJSON (0.07s)203=== CONT TestRateLimiterFeedback/429_enables_limiter2042026/07/09 07:42:49 WARN Rate limiter enabled after throttle name=server-test rate=52052026/07/09 07:42:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:521832062026/07/09 07:42:49 WARN Rate limiter enabled after throttle name=server-test rate=52072026/07/09 07:42:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:521852082026/07/09 07:42:49 WARN Rate limiter backed off name=server-test rate=5209=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2102026/07/09 07:42:49 WARN Rate limiter backed off name=server-test rate=52112026/07/09 07:42:49 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:52183212=== RUN TestSetClientTLS/rejects_connection_without_client_cert213=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert214=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA215=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA216=== RUN TestSetClientTLS/preserves_debug_logging_transport217=== PAUSE TestSetClientTLS/preserves_debug_logging_transport218=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter219=== CONT TestRateLimiterFeedback/503_enables_limiter220--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)221=== CONT TestPathInfoCACompatibility/null_ca_field222=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method223=== CONT TestPathInfoCACompatibility/new_structured_format_-_text224=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive225=== CONT TestPathInfoCACompatibility/old_string_format_-_text226--- PASS: TestPathInfoCACompatibility (0.00s)227 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)228 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)229 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)230 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)231 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)232=== CONT TestParsePathInfoJSON/Nix_format233=== CONT TestParsePathInfoJSON/invalid_JSON234=== CONT TestParsePathInfoJSON/empty_input235=== CONT TestParsePathInfoJSON/whitespace_only236=== CONT TestParsePathInfoJSON/Lix_format237--- PASS: TestParsePathInfoJSON (0.00s)238 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)239 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)240 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)241 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)242 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)243=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)244=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512245=== CONT TestUploadMultipart_SupersededByPeer/exists246=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI247=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon248--- PASS: TestPathInfoHashCompatibility (0.00s)249 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)250 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)251 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.01s)252 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)253=== CONT TestUploadMultipart_SupersededByPeer/missing2542026/07/09 07:42:49 WARN Rate limiter enabled after throttle name=server-test rate=52552026/07/09 07:42:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:521922562026/07/09 07:42:49 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/200_does_not_enable_limiter (0.01s)260 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)261 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.02s)262=== CONT TestGetStorePathHash/valid_store_path263=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error264=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error265=== CONT TestGetStorePathHash/basename_without_hyphen_should_error266--- PASS: TestGetStorePathHash (0.00s)267 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)268 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)269 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)270 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)271=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths272--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)273 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)274 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.02s)275=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts276=== CONT TestPartSizeForNAR/zero_stays_at_minimum277=== CONT TestPartSizeForNAR/capped_at_5_GiB278=== CONT TestConvertHashToNix32/SRI_format_to_Nix32279=== CONT TestPartSizeForNAR/5_TiB_S3_max_object280=== CONT TestConvertHashToNix32/already_Nix32_format281=== CONT TestPartSizeForNAR/1_TiB282=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum283=== CONT TestPartSizeForNAR/small_stays_at_minimum284=== CONT TestEncodeNixBase32/test_string_hash285--- PASS: TestPartSizeForNAR (0.01s)286 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)287 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)288 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)289 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)290 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)291 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)292 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)293=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths294--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)295 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)296 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)297=== CONT TestConvertHashToNix32/invalid_format298--- PASS: TestConvertHashToNix32 (0.00s)299 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)300 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)301 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)302=== CONT TestSetClientTLSErrors/missing_cert_file303=== CONT TestEncodeNixBase32/empty_input304--- PASS: TestEncodeNixBase32 (0.00s)305 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)306 --- PASS: TestEncodeNixBase32/empty_input (0.00s)307=== CONT TestSetClientTLSErrors/invalid_ca_file308=== CONT TestSetClientTLSErrors/missing_ca_file309=== CONT TestSetClientTLSErrors/missing_key_file310=== CONT TestSetClientTLS/rejects_connection_without_client_cert311=== CONT TestSetClientTLS/preserves_debug_logging_transport312=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA313--- PASS: TestSetClientTLSErrors (0.01s)314 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)315 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)316 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)317 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)318--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.10s)319--- PASS: TestScriptTokenCachesUntilRefresh (0.11s)320--- PASS: TestDumpPathWriterError (0.13s)3212026/07/09 07:42:49 http: TLS handshake error from 127.0.0.1:52199: remote error: tls: bad certificate322--- PASS: TestSetClientTLS (0.01s)323 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)324 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)325 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)326--- PASS: TestDumpPathSingleFile (0.18s)327--- PASS: TestCaseHackSuffix (0.16s)328--- PASS: TestDumpPathMatchesNix (0.19s)329--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)330PASS331Running server tests...332The files belonging to this database system will be owned by user "_nixbld10".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 disabled.340341creating directory /nix/var/nix/builds/nix-24416-4031681480/postgres783864079/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-24416-4031681480/postgres783864079/data -l logfile start358359/nix/var/nix/builds/nix-24416-4031681480/postgres783864079:5432 - no response3602026-07-09 07:42:51.486 UTC [24466] LOG: starting PostgreSQL 17.10 on aarch64-apple-darwin25.3.0, compiled by clang version 21.1.8, 64-bit3612026-07-09 07:42:51.486 UTC [24466] LOG: listening on Unix socket "/nix/var/nix/builds/nix-24416-4031681480/postgres783864079/.s.PGSQL.5432"3622026-07-09 07:42:51.490 UTC [24470] LOG: database system was shut down at 2026-07-09 07:42:51 UTC3632026-07-09 07:42:51.494 UTC [24466] LOG: database system is ready to accept connections364/nix/var/nix/builds/nix-24416-4031681480/postgres783864079:5432 - accepting connections365<jemalloc>: option background_thread currently supports pthread only366{"timestamp":"2026-07-09T07:42:51.661279Z","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:42:51.781 UTC [24521] ERROR: relation "goose_db_version" does not exist at character 363952026-07-09 07:42:51.781 UTC [24521] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC3962026/07/09 07:42:51 OK 20241026095416_initial_model.sql (7.64ms)3972026/07/09 07:42:51 OK 20251210153512_drop_unused_gin_index.sql (1.17ms)3982026/07/09 07:42:51 OK 20251218171726_add_pins.sql (2.48ms)3992026/07/09 07:42:51 OK 20260628120000_add_object_size_and_stats.sql (2.68ms)4002026/07/09 07:42:51 goose: successfully migrated database to version: 202606281200004012026/07/09 07:42:51 OK 1_commit_pending_closure.sql (3.3ms)4022026/07/09 07:42:51 OK 2_object_stats_trigger.sql (631.75µs)4032026/07/09 07:42:51 goose: up to current file version: 2404--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.10s)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:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4852026/07/09 07:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4862026/07/09 07:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4872026/07/09 07:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4882026/07/09 07:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4892026/07/09 07:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4902026/07/09 07:42:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4912026/07/09 07:42:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4922026/07/09 07:42:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4932026/07/09 07:42:52 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 TestGCTaskStore_StartNew518--- PASS: TestGCTaskStore_StartNew (0.00s)519=== CONT TestServerTLSConfig520=== RUN TestServerTLSConfig/no_client_CA521=== PAUSE TestServerTLSConfig/no_client_CA522=== RUN TestServerTLSConfig/missing_CA_file523=== PAUSE TestServerTLSConfig/missing_CA_file524=== RUN TestServerTLSConfig/not_a_PEM_file525=== PAUSE TestServerTLSConfig/not_a_PEM_file526=== CONT TestServerTLSConfig/no_client_CA527=== CONT TestService_NativeMTLS528=== CONT TestMetricsInventory529=== CONT TestNARDeduplicationMetadataUploadBug530=== CONT TestGenerateLandingPage531=== CONT TestReadProxyDisabled532=== CONT TestReadProxyRootRedirectsToIndexHTML533=== CONT TestReadProxyConditionalGet534=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT535--- PASS: TestGenerateLandingPage (0.00s)536=== CONT TestReadProxyHead5372026-07-09 07:42:52.324 UTC [24543] ERROR: relation "goose_db_version" does not exist at character 365382026-07-09 07:42:52.324 UTC [24543] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5392026-07-09 07:42:52.324 UTC [24544] ERROR: relation "goose_db_version" does not exist at character 365402026-07-09 07:42:52.324 UTC [24544] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5412026-07-09 07:42:52.370 UTC [24545] ERROR: relation "goose_db_version" does not exist at character 365422026-07-09 07:42:52.370 UTC [24545] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5432026-07-09 07:42:52.375 UTC [24546] ERROR: relation "goose_db_version" does not exist at character 365442026-07-09 07:42:52.375 UTC [24546] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5452026-07-09 07:42:52.377 UTC [24548] ERROR: relation "goose_db_version" does not exist at character 365462026-07-09 07:42:52.377 UTC [24548] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5472026-07-09 07:42:52.377 UTC [24547] ERROR: relation "goose_db_version" does not exist at character 365482026-07-09 07:42:52.377 UTC [24547] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5492026-07-09 07:42:52.378 UTC [24551] ERROR: relation "goose_db_version" does not exist at character 365502026-07-09 07:42:52.378 UTC [24551] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5512026-07-09 07:42:52.379 UTC [24550] ERROR: relation "goose_db_version" does not exist at character 365522026-07-09 07:42:52.379 UTC [24550] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5532026-07-09 07:42:52.385 UTC [24549] ERROR: relation "goose_db_version" does not exist at character 365542026-07-09 07:42:52.385 UTC [24549] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5552026-07-09 07:42:52.387 UTC [24552] ERROR: relation "goose_db_version" does not exist at character 365562026-07-09 07:42:52.387 UTC [24552] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5572026/07/09 07:42:52 OK 20241026095416_initial_model.sql (16.13ms)5582026/07/09 07:42:52 OK 20241026095416_initial_model.sql (16.89ms)5592026/07/09 07:42:52 OK 20241026095416_initial_model.sql (17.69ms)5602026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (17.8ms)5612026/07/09 07:42:52 OK 20241026095416_initial_model.sql (23.81ms)5622026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (23.62ms)5632026/07/09 07:42:52 OK 20241026095416_initial_model.sql (27.13ms)5642026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (13.44ms)5652026/07/09 07:42:52 OK 20241026095416_initial_model.sql (23.82ms)5662026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (13.52ms)5672026/07/09 07:42:52 OK 20241026095416_initial_model.sql (32.89ms)5682026/07/09 07:42:52 OK 20241026095416_initial_model.sql (27.32ms)5692026/07/09 07:42:52 OK 20251218171726_add_pins.sql (20.7ms)5702026/07/09 07:42:52 OK 20251218171726_add_pins.sql (16.84ms)5712026/07/09 07:42:52 OK 20251218171726_add_pins.sql (11.44ms)5722026/07/09 07:42:52 OK 20241026095416_initial_model.sql (32.31ms)5732026/07/09 07:42:52 OK 20241026095416_initial_model.sql (38.77ms)5742026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (14.74ms)5752026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (9.72ms)5762026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (9.58ms)5772026/07/09 07:42:52 OK 20251218171726_add_pins.sql (11.24ms)5782026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (11.49ms)5792026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (8.09ms)5802026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (8.41ms)5812026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (12.45ms)5822026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200005832026/07/09 07:42:52 OK 20251218171726_add_pins.sql (6.11ms)5842026/07/09 07:42:52 OK 20251218171726_add_pins.sql (7.98ms)5852026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (11.46ms)5862026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200005872026/07/09 07:42:52 OK 20251218171726_add_pins.sql (6.71ms)5882026/07/09 07:42:52 OK 20251218171726_add_pins.sql (11.16ms)5892026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (11.09ms)5902026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200005912026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (7.18ms)5922026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200005932026/07/09 07:42:52 OK 20251218171726_add_pins.sql (8.26ms)5942026/07/09 07:42:52 OK 1_commit_pending_closure.sql (9.39ms)5952026/07/09 07:42:52 OK 1_commit_pending_closure.sql (7.36ms)5962026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (9.38ms)5972026/07/09 07:42:52 OK 20251218171726_add_pins.sql (10.27ms)5982026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200005992026/07/09 07:42:52 OK 1_commit_pending_closure.sql (6.89ms)6002026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (7.66ms)6012026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200006022026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (7.56ms)6032026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200006042026/07/09 07:42:52 OK 1_commit_pending_closure.sql (7.8ms)6052026/07/09 07:42:52 OK 2_object_stats_trigger.sql (652.83µs)6062026/07/09 07:42:52 goose: up to current file version: 26072026/07/09 07:42:52 OK 2_object_stats_trigger.sql (714.25µs)6082026/07/09 07:42:52 goose: up to current file version: 26092026/07/09 07:42:52 OK 2_object_stats_trigger.sql (670.79µs)6102026/07/09 07:42:52 goose: up to current file version: 26112026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (8.32ms)6122026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200006132026/07/09 07:42:52 OK 2_object_stats_trigger.sql (639.25µs)6142026/07/09 07:42:52 goose: up to current file version: 26152026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (3.75ms)6162026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200006172026/07/09 07:42:52 OK 1_commit_pending_closure.sql (1.71ms)6182026/07/09 07:42:52 OK 1_commit_pending_closure.sql (1.85ms)6192026/07/09 07:42:52 OK 1_commit_pending_closure.sql (2.1ms)6202026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (2.31ms)6212026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200006222026/07/09 07:42:52 OK 2_object_stats_trigger.sql (502µs)6232026/07/09 07:42:52 goose: up to current file version: 26242026/07/09 07:42:52 OK 2_object_stats_trigger.sql (588.5µs)6252026/07/09 07:42:52 goose: up to current file version: 26262026/07/09 07:42:52 OK 2_object_stats_trigger.sql (494.96µs)6272026/07/09 07:42:52 goose: up to current file version: 26282026/07/09 07:42:52 OK 1_commit_pending_closure.sql (1.97ms)6292026/07/09 07:42:52 OK 1_commit_pending_closure.sql (1.62ms)6302026/07/09 07:42:52 OK 2_object_stats_trigger.sql (574.67µs)6312026/07/09 07:42:52 goose: up to current file version: 26322026/07/09 07:42:52 OK 2_object_stats_trigger.sql (441.42µs)6332026/07/09 07:42:52 goose: up to current file version: 26342026/07/09 07:42:52 OK 1_commit_pending_closure.sql (2.14ms)6352026/07/09 07:42:52 OK 2_object_stats_trigger.sql (453.96µs)6362026/07/09 07:42:52 goose: up to current file version: 26372026/07/09 07:42:52 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"638--- PASS: TestService_AuthMiddleware (0.43s)639=== CONT TestReadProxyInvalidPath640--- PASS: TestMetricsInventory (0.43s)641=== CONT TestReadProxy4046422026/07/09 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures6432026/07/09 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures644--- PASS: TestReadProxyDisabled (0.44s)645=== CONT TestReadProxyNarStreaming646{"timestamp":"2026-07-09T07:42:52.484116Z","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(9)"}6472026/07/09 07:42:52 WARN mTLS auth: subject not in bound subjects subject="CN=reader"6482026/07/09 07:42:52 WARN mTLS auth: subject not in bound subjects subject="CN=writer"649--- PASS: TestService_NativeMTLS (0.44s)650=== CONT TestReadProxyNarinfoAlreadyDecompressed651--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.44s)652=== CONT TestReadProxyNarinfo653--- PASS: TestReadProxyHead (0.44s)654=== CONT TestIsValidCachePath655=== RUN TestIsValidCachePath/narinfo656=== PAUSE TestIsValidCachePath/narinfo657=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars658=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars659=== RUN TestIsValidCachePath/nar_zst660=== PAUSE TestIsValidCachePath/nar_zst661=== RUN TestIsValidCachePath/nar_xz662=== PAUSE TestIsValidCachePath/nar_xz663=== RUN TestIsValidCachePath/nar_bz2664=== PAUSE TestIsValidCachePath/nar_bz2665=== RUN TestIsValidCachePath/nar_uncompressed666=== PAUSE TestIsValidCachePath/nar_uncompressed667=== RUN TestIsValidCachePath/ls668=== PAUSE TestIsValidCachePath/ls669=== RUN TestIsValidCachePath/log670=== PAUSE TestIsValidCachePath/log671=== RUN TestIsValidCachePath/realisation672=== PAUSE TestIsValidCachePath/realisation673=== RUN TestIsValidCachePath/nix-cache-info674=== PAUSE TestIsValidCachePath/nix-cache-info675=== RUN TestIsValidCachePath/index.html676=== PAUSE TestIsValidCachePath/index.html677=== RUN TestIsValidCachePath/2026/07/09 07:42:52 INFO Created nix-cache-info in bucket bucket=bucket8678traversal_parent679=== PAUSE TestIsValidCachePath/traversal_parent680=== RUN TestIsValidCachePath/traversal_in_middle681=== PAUSE TestIsValidCachePath/traversal_in_middle682=== RUN TestIsValidCachePath/invalid_char_e683=== PAUSE TestIsValidCachePath/invalid_char_e684=== RUN TestIsValidCachePath/invalid_char_u685=== PAUSE TestIsValidCachePath/invalid_char_u686=== RUN TestIsValidCachePath/random_path687=== PAUSE TestIsValidCachePath/random_path688=== RUN TestIsValidCachePath/empty689=== PAUSE TestIsValidCachePath/empty690=== RUN TestIsValidCachePath/leading_slash691=== PAUSE TestIsValidCachePath/leading_slash692=== RUN TestIsValidCachePath/wrong_extension693=== PAUSE TestIsValidCachePath/wrong_extension694=== RUN TestIsValidCachePath/short_hash695=== PAUSE TestIsValidCachePath/short_hash696=== CONT TestParseSingleRange697=== RUN TestParseSingleRange/none698=== PAUSE TestParseSingleRange/none699=== RUN TestParseSingleRange/unknown_unit700=== PAUSE TestParseSingleRange/unknown_unit701=== RUN TestParseSingleRange/multi-range_ignored702=== PAUSE TestParseSingleRange/multi-range_ignored703=== RUN TestParseSingleRange/malformed_no_dash704=== PAUSE TestParseSingleRange/malformed_no_dash705=== RUN TestParseSingleRange/malformed_both_empty706=== PAUSE TestParseSingleRange/malformed_both_empty707=== RUN TestParseSingleRange/malformed_end_before_start708=== PAUSE TestParseSingleRange/malformed_end_before_start709=== RUN TestParseSingleRange/closed710=== PAUSE TestParseSingleRange/closed711=== RUN TestParseSingleRange/open-ended712=== PAUSE TestParseSingleRange/open-ended713=== RUN TestParseSingleRange/end_clamped_to_size714=== PAUSE TestParseSingleRange/end_clamped_to_size715=== RUN TestParseSingleRange/suffix716=== PAUSE TestParseSingleRange/suffix717=== RUN TestParseSingleRange/suffix_exceeds_size718=== PAUSE TestParseSingleRange/suffix_exceeds_size719=== RUN TestParseSingleRange/single_byte720=== PAUSE TestParseSingleRange/single_byte721=== RUN TestParseSingleRange/start_past_EOF722=== PAUSE TestParseSingleRange/start_past_EOF723=== RUN TestParseSingleRange/start_far_past_EOF724=== PAUSE TestParseSingleRange/start_far_past_EOF725=== CONT TestResurrectedObjectNotDeleted726--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.45s)727=== CONT TestOrphanedObjectsGCStressTest728--- PASS: TestReadProxyConditionalGet (0.45s)729=== CONT TestOrphanedObjectsGC7302026/07/09 07:42:52 INFO Received cleanup request method=DELETE path=/api/pending_closures7312026/07/09 07:42:52 INFO Aborted multipart uploads count=1732--- PASS: TestMultipartCleanup (0.59s)733=== CONT TestObjectStatsTrigger734=== NAME TestNARDeduplicationMetadataUploadBug735 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-24416-4031681480/TestNARDeduplicationMetadataUploadBug3030014488/001/store/2wxmpn9b3lf0kqz4iy0syjy163a887hp-file1.txt7362026-07-09 07:42:52.734 UTC [24596] ERROR: relation "goose_db_version" does not exist at character 367372026-07-09 07:42:52.734 UTC [24596] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7382026-07-09 07:42:52.758 UTC [24597] ERROR: relation "goose_db_version" does not exist at character 367392026-07-09 07:42:52.758 UTC [24597] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7402026/07/09 07:42:52 OK 20241026095416_initial_model.sql (15.65ms)7412026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)7422026/07/09 07:42:52 OK 20251218171726_add_pins.sql (3.31ms)7432026/07/09 07:42:52 OK 20241026095416_initial_model.sql (16.04ms)7442026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (1.14ms)7452026/07/09 07:42:52 OK 20251218171726_add_pins.sql (2.55ms)7462026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (6.72ms)7472026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200007482026/07/09 07:42:52 OK 1_commit_pending_closure.sql (3.14ms)7492026/07/09 07:42:52 OK 2_object_stats_trigger.sql (706.08µs)7502026/07/09 07:42:52 goose: up to current file version: 27512026-07-09 07:42:52.802 UTC [24600] ERROR: relation "goose_db_version" does not exist at character 367522026-07-09 07:42:52.802 UTC [24600] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC753--- PASS: TestReadProxyNarStreaming (0.32s)754=== CONT TestGCTaskStore_GetReturnsLatest755--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)756=== CONT TestService_healthCheckHandler7572026-07-09 07:42:52.806 UTC [24601] ERROR: relation "goose_db_version" does not exist at character 367582026-07-09 07:42:52.806 UTC [24601] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7592026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (12.55ms)7602026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200007612026/07/09 07:42:52 OK 1_commit_pending_closure.sql (1.95ms)7622026/07/09 07:42:52 OK 2_object_stats_trigger.sql (532.5µs)7632026/07/09 07:42:52 goose: up to current file version: 2764--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.33s)765=== CONT TestGracefulShutdownDrainsInflight7662026/07/09 07:42:52 INFO Starting HTTP server address=127.0.0.1:522517672026/07/09 07:42:52 INFO Shutdown signal received, draining in-flight requests timeout=10s7682026/07/09 07:42:52 OK 20241026095416_initial_model.sql (10.28ms)7692026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (1.03ms)7702026/07/09 07:42:52 OK 20251218171726_add_pins.sql (2.41ms)7712026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (5.81ms)7722026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200007732026-07-09 07:42:52.831 UTC [24604] ERROR: relation "goose_db_version" does not exist at character 367742026-07-09 07:42:52.831 UTC [24604] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7752026/07/09 07:42:52 OK 1_commit_pending_closure.sql (2.06ms)7762026/07/09 07:42:52 OK 20241026095416_initial_model.sql (17.4ms)7772026/07/09 07:42:52 OK 2_object_stats_trigger.sql (546.63µs)7782026/07/09 07:42:52 goose: up to current file version: 27792026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (1.13ms)780--- PASS: TestReadProxyInvalidPath (0.37s)781=== CONT TestGCTaskStore_Fail782--- PASS: TestGCTaskStore_Fail (0.00s)783=== CONT TestGCTaskStore_PhaseUpdates7842026/07/09 07:42:52 OK 20251218171726_add_pins.sql (2.78ms)785--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)786=== CONT TestGCTaskStore_CompletedAllowsNewTask787--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)788=== CONT TestCompleteMultipartUnregistered7892026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)7902026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200007912026/07/09 07:42:52 OK 1_commit_pending_closure.sql (1.74ms)7922026/07/09 07:42:52 OK 2_object_stats_trigger.sql (816.75µs)7932026/07/09 07:42:52 goose: up to current file version: 2794--- PASS: TestReadProxy404 (0.37s)795=== CONT TestProxyWriteTimeout796=== RUN TestProxyWriteTimeout/narinfo797=== PAUSE TestProxyWriteTimeout/narinfo798=== RUN TestProxyWriteTimeout/1_GiB_nar799=== PAUSE TestProxyWriteTimeout/1_GiB_nar800=== RUN TestProxyWriteTimeout/10_GiB_nar801=== PAUSE TestProxyWriteTimeout/10_GiB_nar802=== RUN TestProxyWriteTimeout/unknown_size803=== PAUSE TestProxyWriteTimeout/unknown_size804=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle8052026/07/09 07:42:52 OK 20241026095416_initial_model.sql (13.94ms)8062026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)8072026/07/09 07:42:52 OK 20251218171726_add_pins.sql (1.35ms)8082026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (7.76ms)8092026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200008102026/07/09 07:42:52 OK 1_commit_pending_closure.sql (2.24ms)8112026/07/09 07:42:52 OK 2_object_stats_trigger.sql (577.17µs)8122026/07/09 07:42:52 goose: up to current file version: 28132026-07-09 07:42:52.869 UTC [24611] ERROR: relation "goose_db_version" does not exist at character 368142026-07-09 07:42:52.869 UTC [24611] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC815--- PASS: TestReadProxyNarinfo (0.39s)816=== CONT TestService_Rustfstest817--- PASS: TestGracefulShutdownDrainsInflight (0.07s)818=== CONT TestCompleteMultipartUpload_ErrorButObjectExists8192026-07-09 07:42:52.891 UTC [24613] ERROR: relation "goose_db_version" does not exist at character 368202026-07-09 07:42:52.891 UTC [24613] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8212026/07/09 07:42:52 OK 20241026095416_initial_model.sql (15.86ms)8222026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (944.42µs)8232026/07/09 07:42:52 OK 20251218171726_add_pins.sql (4.86ms)8242026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (3.32ms)8252026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200008262026/07/09 07:42:52 OK 1_commit_pending_closure.sql (2.53ms)8272026/07/09 07:42:52 OK 2_object_stats_trigger.sql (628.63µs)8282026/07/09 07:42:52 goose: up to current file version: 28292026/07/09 07:42:52 OK 20241026095416_initial_model.sql (20.13ms)8302026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (1.62ms)8312026/07/09 07:42:52 OK 20251218171726_add_pins.sql (3.65ms)8322026/07/09 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures8332026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (9.5ms)8342026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200008352026/07/09 07:42:52 OK 1_commit_pending_closure.sql (2.38ms)8362026/07/09 07:42:52 OK 2_object_stats_trigger.sql (567.71µs)8372026/07/09 07:42:52 goose: up to current file version: 28382026-07-09 07:42:52.945 UTC [24618] ERROR: relation "goose_db_version" does not exist at character 368392026-07-09 07:42:52.945 UTC [24618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8402026/07/09 07:42:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8412026/07/09 07:42:52 INFO Uploading 2wxmpn9b3lf0kqz4iy0syjy163a887hp-file1.txt (160B)842--- PASS: TestResurrectedObjectNotDeleted (0.46s)843=== CONT TestRedundantMultipartUpload8442026/07/09 07:42:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8452026/07/09 07:42:52 INFO Signed narinfos id=1 count=18462026/07/09 07:42:52 INFO Uploading 1 narinfos8472026/07/09 07:42:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8482026/07/09 07:42:52 INFO Completed upload id=18492026/07/09 07:42:52 INFO Upload complete. (188ms)850=== NAME TestNARDeduplicationMetadataUploadBug851 metadata_upload_test.go:54: Retrieved narinfo from S3:852 StorePath: /nix/var/nix/builds/nix-24416-4031681480/TestNARDeduplicationMetadataUploadBug3030014488/001/store/2wxmpn9b3lf0kqz4iy0syjy163a887hp-file1.txt853 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst854 Compression: zstd855 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf856 NarSize: 160857 References: 858 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf859 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)860 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):861 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}8622026/07/09 07:42:52 OK 20241026095416_initial_model.sql (14.43ms)8632026/07/09 07:42:52 OK 20251210153512_drop_unused_gin_index.sql (1.19ms)8642026/07/09 07:42:52 OK 20251218171726_add_pins.sql (4.69ms)8652026/07/09 07:42:52 OK 20260628120000_add_object_size_and_stats.sql (3.75ms)8662026/07/09 07:42:52 goose: successfully migrated database to version: 202606281200008672026/07/09 07:42:52 OK 1_commit_pending_closure.sql (2.68ms)8682026/07/09 07:42:52 OK 2_object_stats_trigger.sql (589.83µs)8692026/07/09 07:42:52 goose: up to current file version: 2870 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-24416-4031681480/TestNARDeduplicationMetadataUploadBug3030014488/001/store/mbndx8vlr33qzd3avyyxf79y924gv4j7-file2.txt8712026-07-09 07:42:53.154 UTC [24626] ERROR: relation "goose_db_version" does not exist at character 368722026-07-09 07:42:53.154 UTC [24626] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8732026-07-09 07:42:53.154 UTC [24627] ERROR: relation "goose_db_version" does not exist at character 368742026-07-09 07:42:53.154 UTC [24627] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8752026/07/09 07:42:53 OK 20241026095416_initial_model.sql (17.32ms)8762026/07/09 07:42:53 OK 20251210153512_drop_unused_gin_index.sql (1.18ms)8772026/07/09 07:42:53 OK 20241026095416_initial_model.sql (19.19ms)8782026/07/09 07:42:53 OK 20251210153512_drop_unused_gin_index.sql (695.92µs)8792026/07/09 07:42:53 OK 20251218171726_add_pins.sql (4.49ms)8802026/07/09 07:42:53 OK 20251218171726_add_pins.sql (4.35ms)8812026/07/09 07:42:53 OK 20260628120000_add_object_size_and_stats.sql (4.51ms)8822026/07/09 07:42:53 goose: successfully migrated database to version: 202606281200008832026/07/09 07:42:53 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)8842026/07/09 07:42:53 goose: successfully migrated database to version: 202606281200008852026/07/09 07:42:53 OK 1_commit_pending_closure.sql (1.58ms)8862026/07/09 07:42:53 OK 1_commit_pending_closure.sql (1.61ms)8872026/07/09 07:42:53 OK 2_object_stats_trigger.sql (333.67µs)8882026/07/09 07:42:53 goose: up to current file version: 28892026/07/09 07:42:53 OK 2_object_stats_trigger.sql (398.71µs)8902026/07/09 07:42:53 goose: up to current file version: 2891--- PASS: TestService_healthCheckHandler (0.40s)892=== CONT TestReadProxyRangeRequest893--- PASS: TestObjectStatsTrigger (0.58s)894=== CONT TestIsValidUploadKey895=== RUN TestIsValidUploadKey/narinfo896=== PAUSE TestIsValidUploadKey/narinfo897=== RUN TestIsValidUploadKey/nar_zst898=== PAUSE TestIsValidUploadKey/nar_zst899=== RUN TestIsValidUploadKey/nar_xz900=== PAUSE TestIsValidUploadKey/nar_xz901=== RUN TestIsValidUploadKey/nar_plain902=== PAUSE TestIsValidUploadKey/nar_plain903=== RUN TestIsValidUploadKey/listing904=== PAUSE TestIsValidUploadKey/listing905=== RUN TestIsValidUploadKey/build_log906=== PAUSE TestIsValidUploadKey/build_log907=== RUN TestIsValidUploadKey/build_log_home-manager_file908=== PAUSE TestIsValidUploadKey/build_log_home-manager_file909=== RUN TestIsValidUploadKey/build_log_plus_in_name910=== PAUSE TestIsValidUploadKey/build_log_plus_in_name911=== RUN TestIsValidUploadKey/build_log_question_mark912=== PAUSE TestIsValidUploadKey/build_log_question_mark913=== RUN TestIsValidUploadKey/build_log_equals914=== PAUSE TestIsValidUploadKey/build_log_equals915=== RUN TestIsValidUploadKey/realisation916=== PAUSE TestIsValidUploadKey/realisation917=== RUN TestIsValidUploadKey/realisation_plus_in_output918=== PAUSE TestIsValidUploadKey/realisation_plus_in_output919=== RUN TestIsValidUploadKey/nix-cache-info920=== PAUSE TestIsValidUploadKey/nix-cache-info921=== RUN TestIsValidUploadKey/index.html922=== PAUSE TestIsValidUploadKey/index.html923=== RUN TestIsValidUploadKey/narinfo_key,_nar_type924=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type925=== RUN TestIsValidUploadKey/nar_key,_narinfo_type926=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type927=== RUN TestIsValidUploadKey/listing_key,_narinfo_type928=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type929=== RUN TestIsValidUploadKey/traversal930=== PAUSE TestIsValidUploadKey/traversal931=== RUN TestIsValidUploadKey/traversal_nar932=== PAUSE TestIsValidUploadKey/traversal_nar933=== RUN TestIsValidUploadKey/absolute934=== PAUSE TestIsValidUploadKey/absolute935=== RUN TestIsValidUploadKey/empty_key936=== PAUSE TestIsValidUploadKey/empty_key937=== RUN TestIsValidUploadKey/unknown_type938=== PAUSE TestIsValidUploadKey/unknown_type939=== CONT TestUploadHandlersRejectOversizedBody9402026-07-09 07:42:53.241 UTC [24632] ERROR: relation "goose_db_version" does not exist at character 369412026-07-09 07:42:53.241 UTC [24632] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9422026-07-09 07:42:53.245 UTC [24633] ERROR: relation "goose_db_version" does not exist at character 369432026-07-09 07:42:53.245 UTC [24633] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC944=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure945=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure946=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart947=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart948=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts949=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts950=== CONT TestUploadHandlersRejectInvalidKeys951=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info952=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info953=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal954=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal955=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key956=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key957=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key958=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key959=== CONT TestService_verifyS3Integrity960=== NAME TestOrphanedObjectsGC961 orphaned_objects_gc_test.go:290: GC Test Summary:962 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A963 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B964 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)965 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)966 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects967--- PASS: TestOrphanedObjectsGC (0.76s)968=== CONT TestService_cleanupPendingClosuresHandler9692026/07/09 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures9702026/07/09 07:42:53 OK 20241026095416_initial_model.sql (13.2ms)9712026/07/09 07:42:53 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)9722026/07/09 07:42:53 OK 20241026095416_initial_model.sql (12.29ms)9732026/07/09 07:42:53 OK 20251210153512_drop_unused_gin_index.sql (1.25ms)9742026/07/09 07:42:53 OK 20251210153512_drop_unused_gin_index.sql (9.7ms)9752026/07/09 07:42:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9762026/07/09 07:42:53 INFO Signed narinfos id=2 count=19772026/07/09 07:42:53 INFO Uploading 1 narinfos9782026/07/09 07:42:53 OK 20251218171726_add_pins.sql (11.31ms)9792026/07/09 07:42:53 OK 20251218171726_add_pins.sql (2.08ms)9802026/07/09 07:42:53 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9812026/07/09 07:42:53 INFO Completed upload id=29822026/07/09 07:42:53 INFO Upload complete. (171ms)983=== NAME TestNARDeduplicationMetadataUploadBug984 metadata_upload_test.go:76: Retrieved narinfo from S3:985 StorePath: /nix/var/nix/builds/nix-24416-4031681480/TestNARDeduplicationMetadataUploadBug3030014488/001/store/mbndx8vlr33qzd3avyyxf79y924gv4j7-file2.txt986 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst987 Compression: zstd988 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf989 NarSize: 160990 References: 991 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf992 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)993 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):994 {"version":1,"root":{"type":"regular","size":44}}995--- PASS: TestNARDeduplicationMetadataUploadBug (1.24s)996=== CONT TestService_createPendingClosureHandler9972026/07/09 07:42:53 OK 20260628120000_add_object_size_and_stats.sql (12.66ms)9982026/07/09 07:42:53 goose: successfully migrated database to version: 202606281200009992026/07/09 07:42:53 OK 20260628120000_add_object_size_and_stats.sql (13.25ms)10002026/07/09 07:42:53 goose: successfully migrated database to version: 2026062812000010012026/07/09 07:42:53 OK 1_commit_pending_closure.sql (2ms)10022026/07/09 07:42:53 OK 1_commit_pending_closure.sql (2.1ms)10032026-07-09 07:42:53.293 UTC [24640] ERROR: relation "goose_db_version" does not exist at character 3610042026-07-09 07:42:53.293 UTC [24640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10052026/07/09 07:42:53 OK 2_object_stats_trigger.sql (577.58µs)10062026/07/09 07:42:53 goose: up to current file version: 210072026/07/09 07:42:53 OK 2_object_stats_trigger.sql (696.71µs)10082026/07/09 07:42:53 goose: up to current file version: 210092026/07/09 07:42:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10102026/07/09 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures10112026/07/09 07:42:53 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1012--- PASS: TestCompleteMultipartUnregistered (0.47s)1013=== CONT TestGCTaskStore_GetEmpty1014--- PASS: TestGCTaskStore_GetEmpty (0.00s)1015=== CONT TestServerTLSConfig/not_a_PEM_file1016=== CONT TestServerTLSConfig/missing_CA_file1017--- PASS: TestServerTLSConfig (0.00s)1018 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1019 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1020 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1021=== CONT TestClientErrorHandling1022=== RUN TestClientErrorHandling/InvalidStorePath1023=== PAUSE TestClientErrorHandling/InvalidStorePath1024=== RUN TestClientErrorHandling/InvalidAuthToken1025=== PAUSE TestClientErrorHandling/InvalidAuthToken1026=== RUN TestClientErrorHandling/ServerNotAvailable1027=== PAUSE TestClientErrorHandling/ServerNotAvailable1028=== CONT TestGCMetrics10292026-07-09 07:42:53.320 UTC [24643] ERROR: relation "goose_db_version" does not exist at character 3610302026-07-09 07:42:53.320 UTC [24643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10312026/07/09 07:42:53 OK 20241026095416_initial_model.sql (13.61ms)10322026/07/09 07:42:53 OK 20251210153512_drop_unused_gin_index.sql (821.17µs)10332026/07/09 07:42:53 OK 20251218171726_add_pins.sql (2.56ms)10342026/07/09 07:42:53 OK 20260628120000_add_object_size_and_stats.sql (3.61ms)10352026/07/09 07:42:53 goose: successfully migrated database to version: 2026062812000010362026/07/09 07:42:53 OK 1_commit_pending_closure.sql (2.31ms)10372026/07/09 07:42:53 OK 20241026095416_initial_model.sql (14.88ms)10382026/07/09 07:42:53 OK 2_object_stats_trigger.sql (605.13µs)10392026/07/09 07:42:53 goose: up to current file version: 210402026/07/09 07:42:53 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)10412026/07/09 07:42:53 OK 20251218171726_add_pins.sql (2.31ms)10422026/07/09 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures10432026/07/09 07:42:53 OK 20260628120000_add_object_size_and_stats.sql (4.81ms)10442026/07/09 07:42:53 goose: successfully migrated database to version: 2026062812000010452026/07/09 07:42:53 OK 1_commit_pending_closure.sql (2.26ms)10462026/07/09 07:42:53 OK 2_object_stats_trigger.sql (719.71µs)10472026/07/09 07:42:53 goose: up to current file version: 21048--- PASS: TestService_Rustfstest (0.48s)1049=== CONT TestGCBugBareHashReferences10502026/07/09 07:42:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10512026/07/09 07:42:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1052{"timestamp":"2026-07-09T07:42:53.38064Z","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(10)"}1053{"timestamp":"2026-07-09T07:42:53.380663Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket24, object=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst"},"target":"rustfs_ecstore::set_disk","filename":"crates/ecstore/src/set_disk.rs","line_number":3534,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}10542026/07/09 07:42:53 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=ZGQwOGIyYjctZjUzOS00MjMyLThhYmYtZGE3ZjQ5ZGEyYmJjLjVjMmNmNTYzLTFmMDgtNDkzOC1iY2U3LTg5MGE2ZDA2YmM5Y3gxNzgzNTgyOTczMzU4MDQ5MDAw10552026/07/09 07:42:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGQwOGIyYjctZjUzOS00MjMyLThhYmYtZGE3ZjQ5ZGEyYmJjLjVjMmNmNTYzLTFmMDgtNDkzOC1iY2U3LTg5MGE2ZDA2YmM5Y3gxNzgzNTgyOTczMzU4MDQ5MDAw parts=11056--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.50s)1057=== CONT TestPinProtectsFromGC10582026-07-09 07:42:53.401 UTC [24649] ERROR: relation "goose_db_version" does not exist at character 3610592026-07-09 07:42:53.401 UTC [24649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10602026/07/09 07:42:53 OK 20241026095416_initial_model.sql (17.53ms)10612026/07/09 07:42:53 OK 20251210153512_drop_unused_gin_index.sql (1.4ms)10622026/07/09 07:42:53 OK 20251218171726_add_pins.sql (3.22ms)10632026/07/09 07:42:53 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)10642026/07/09 07:42:53 goose: successfully migrated database to version: 2026062812000010652026/07/09 07:42:53 OK 1_commit_pending_closure.sql (2.43ms)10662026/07/09 07:42:53 OK 2_object_stats_trigger.sql (709.79µs)10672026/07/09 07:42:53 goose: up to current file version: 210682026/07/09 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures10692026/07/09 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures1070=== NAME TestOrphanedObjectsGCStressTest1071 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1072 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion10732026/07/09 07:42:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10742026/07/09 07:42:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZGQwOGIyYjctZjUzOS00MjMyLThhYmYtZGE3ZjQ5ZGEyYmJjLmM0MGI2YTkzLTBlYmMtNGI3Yi1iMTMyLTU4N2IxYzBhZGQwNXgxNzgzNTgyOTczNDU5NDk5MDAw parts=121075--- PASS: TestRedundantMultipartUpload (0.72s)1076=== CONT TestClientWithDependencies10772026-07-09 07:42:53.687 UTC [24652] ERROR: relation "goose_db_version" does not exist at character 3610782026-07-09 07:42:53.687 UTC [24652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10792026-07-09 07:42:53.689 UTC [24653] ERROR: relation "goose_db_version" does not exist at character 3610802026-07-09 07:42:53.689 UTC [24653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10812026-07-09 07:42:53.691 UTC [24654] ERROR: relation "goose_db_version" does not exist at character 3610822026-07-09 07:42:53.691 UTC [24654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10832026-07-09 07:42:53.718 UTC [24655] ERROR: relation "goose_db_version" does not exist at character 3610842026-07-09 07:42:53.718 UTC [24655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10852026/07/09 07:42:53 OK 20241026095416_initial_model.sql (16.81ms)10862026/07/09 07:42:53 OK 20251210153512_drop_unused_gin_index.sql (794.71µs)10872026/07/09 07:42:53 OK 20241026095416_initial_model.sql (17.66ms)10882026/07/09 07:42:53 OK 20251210153512_drop_unused_gin_index.sql (613.42µs)10892026/07/09 07:42:53 OK 20251218171726_add_pins.sql (2.42ms)10902026/07/09 07:42:53 OK 20241026095416_initial_model.sql (21ms)10912026/07/09 07:42:53 OK 20251218171726_add_pins.sql (2.08ms)10922026/07/09 07:42:53 OK 20251210153512_drop_unused_gin_index.sql (950.58µs)10932026/07/09 07:42:53 OK 20251218171726_add_pins.sql (4.43ms)10942026/07/09 07:42:53 OK 20260628120000_add_object_size_and_stats.sql (6.26ms)10952026/07/09 07:42:53 goose: successfully migrated database to version: 2026062812000010962026/07/09 07:42:53 OK 20260628120000_add_object_size_and_stats.sql (7.64ms)10972026/07/09 07:42:53 goose: successfully migrated database to version: 2026062812000010982026/07/09 07:42:53 OK 1_commit_pending_closure.sql (2.06ms)10992026/07/09 07:42:53 OK 1_commit_pending_closure.sql (1.8ms)11002026/07/09 07:42:53 OK 2_object_stats_trigger.sql (447.79µs)11012026/07/09 07:42:53 goose: up to current file version: 211022026/07/09 07:42:53 OK 2_object_stats_trigger.sql (512.38µs)11032026/07/09 07:42:53 goose: up to current file version: 211042026/07/09 07:42:53 OK 20260628120000_add_object_size_and_stats.sql (6.58ms)11052026/07/09 07:42:53 goose: successfully migrated database to version: 2026062812000011062026/07/09 07:42:53 OK 1_commit_pending_closure.sql (2.07ms)11072026/07/09 07:42:53 OK 2_object_stats_trigger.sql (675.21µs)11082026/07/09 07:42:53 goose: up to current file version: 211092026/07/09 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures11102026/07/09 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures11112026/07/09 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures11122026-07-09 07:42:53.741 UTC [24657] ERROR: relation "goose_db_version" does not exist at character 3611132026-07-09 07:42:53.741 UTC [24657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1114--- PASS: TestReadProxyRangeRequest (0.54s)1115=== CONT TestClientMultipleUploads11162026/07/09 07:42:53 INFO Aborted multipart uploads count=011172026/07/09 07:42:53 OK 20241026095416_initial_model.sql (21.02ms)11182026/07/09 07:42:53 OK 20251210153512_drop_unused_gin_index.sql (691.21µs)11192026/07/09 07:42:53 WARN Force mode enabled - objects will be deleted immediately without grace period11202026/07/09 07:42:53 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=011212026/07/09 07:42:53 INFO Vacuumed table table=pending_closures11222026/07/09 07:42:53 OK 20251218171726_add_pins.sql (3.37ms)11232026/07/09 07:42:53 INFO Vacuumed table table=pending_objects11242026/07/09 07:42:53 INFO Vacuumed table table=multipart_uploads11252026/07/09 07:42:53 INFO Vacuumed table table=closures11262026/07/09 07:42:53 INFO Vacuumed table table=objects1127--- PASS: TestGCMetrics (0.45s)1128=== CONT TestClientIntegration11292026-07-09 07:42:53.776 UTC [24659] ERROR: relation "goose_db_version" does not exist at character 3611302026-07-09 07:42:53.776 UTC [24659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11312026/07/09 07:42:53 OK 20260628120000_add_object_size_and_stats.sql (26.76ms)11322026/07/09 07:42:53 goose: successfully migrated database to version: 2026062812000011332026/07/09 07:42:53 OK 20241026095416_initial_model.sql (29.56ms)11342026/07/09 07:42:53 OK 20251210153512_drop_unused_gin_index.sql (971.21µs)11352026/07/09 07:42:53 OK 1_commit_pending_closure.sql (2.38ms)11362026/07/09 07:42:53 OK 2_object_stats_trigger.sql (586.17µs)11372026/07/09 07:42:53 goose: up to current file version: 211382026/07/09 07:42:53 OK 20251218171726_add_pins.sql (2.76ms)11392026/07/09 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures11402026/07/09 07:42:53 OK 20260628120000_add_object_size_and_stats.sql (4.93ms)11412026/07/09 07:42:53 goose: successfully migrated database to version: 2026062812000011422026/07/09 07:42:53 OK 1_commit_pending_closure.sql (2.58ms)11432026/07/09 07:42:53 OK 2_object_stats_trigger.sql (649.08µs)11442026/07/09 07:42:53 goose: up to current file version: 211452026/07/09 07:42:53 INFO Received cleanup request method=DELETE path=/api/pending_closures11462026-07-09 07:42:53.801 UTC [24663] ERROR: relation "goose_db_version" does not exist at character 3611472026-07-09 07:42:53.801 UTC [24663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11482026/07/09 07:42:53 INFO Aborted multipart uploads count=011492026/07/09 07:42:53 OK 20241026095416_initial_model.sql (30.96ms)11502026/07/09 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures11512026/07/09 07:42:53 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)11522026/07/09 07:42:53 OK 20251218171726_add_pins.sql (1.89ms)11532026/07/09 07:42:53 OK 20260628120000_add_object_size_and_stats.sql (2.87ms)11542026/07/09 07:42:53 goose: successfully migrated database to version: 2026062812000011552026/07/09 07:42:53 OK 1_commit_pending_closure.sql (2.49ms)11562026/07/09 07:42:53 OK 2_object_stats_trigger.sql (900.04µs)11572026/07/09 07:42:53 goose: up to current file version: 211582026/07/09 07:42:53 INFO Received cleanup request method=DELETE path=/api/pending_closures11592026/07/09 07:42:53 INFO Aborted multipart uploads count=111602026/07/09 07:42:53 OK 20241026095416_initial_model.sql (14.39ms)11612026/07/09 07:42:53 OK 20251210153512_drop_unused_gin_index.sql (731µs)11622026/07/09 07:42:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11632026-07-09 07:42:53.836 UTC [24657] ERROR: Closure does not exist: id=111642026-07-09 07:42:53.836 UTC [24657] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE11652026-07-09 07:42:53.836 UTC [24657] STATEMENT: -- name: CommitPendingClosure :exec1166 SELECT commit_pending_closure($1::bigint)1167 1168--- PASS: TestService_cleanupPendingClosuresHandler (0.58s)1169=== CONT TestGCTaskStore_ConflictDifferentParams1170--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1171=== CONT TestService_AuthMiddleware_OIDC11722026/07/09 07:42:53 OK 20251218171726_add_pins.sql (1.37ms)11732026/07/09 07:42:53 INFO OIDC provider initialized name=test11742026/07/09 07:42:53 OK 20260628120000_add_object_size_and_stats.sql (2.58ms)11752026/07/09 07:42:53 goose: successfully migrated database to version: 2026062812000011762026/07/09 07:42:53 OK 1_commit_pending_closure.sql (2.1ms)11772026/07/09 07:42:53 OK 2_object_stats_trigger.sql (655.04µs)11782026/07/09 07:42:53 goose: up to current file version: 211792026/07/09 07:42:53 INFO Created nix-cache-info in bucket bucket=bucket331180=== NAME TestOrphanedObjectsGCStressTest1181 orphaned_objects_gc_test.go:509: Stress test completed successfully:1182 orphaned_objects_gc_test.go:510: - Active objects preserved: 201183 orphaned_objects_gc_test.go:511: - Objects deleted: 2101184 orphaned_objects_gc_test.go:512: - Total GC'd: 2101185--- PASS: TestOrphanedObjectsGCStressTest (1.39s)1186=== CONT TestClientCADerivations11872026/07/09 07:42:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11882026/07/09 07:42:53 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZGQwOGIyYjctZjUzOS00MjMyLThhYmYtZGE3ZjQ5ZGEyYmJjLjk2N2U4MmJhLTdlNTktNDNiOS1iODQ0LWQzOTIxODZmNzFkYngxNzgzNTgyOTczNzQ3MTE3MDAw parts=1011892026/07/09 07:42:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11902026/07/09 07:42:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11912026/07/09 07:42:53 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZGQwOGIyYjctZjUzOS00MjMyLThhYmYtZGE3ZjQ5ZGEyYmJjLjA5N2I4ZGFkLTdjMzYtNDNiNS04ZjdlLTYzMGUwOGNkYjYzMHgxNzgzNTgyOTczNzkxMjU0MDAw parts=1011922026/07/09 07:42:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11932026/07/09 07:42:54 INFO Completed upload id=111942026/07/09 07:42:54 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011952026/07/09 07:42:54 INFO Received uploads request method=POST path=/api/pending_closures11962026/07/09 07:42:54 INFO Completed upload id=111972026/07/09 07:42:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures11982026/07/09 07:42:54 INFO Received uploads request method=POST path=/api/pending_closures11992026/07/09 07:42:54 INFO Received uploads request method=POST path=/api/pending_closures1200=== NAME TestPinProtectsFromGC1201 client_integration_test.go:646: Pinned store path: /nix/var/nix/builds/nix-24416-4031681480/TestPinProtectsFromGC4293081699/001/store/qzdskppljbvl73389l4c18kimxad749n-pinned-file.txt1202 client_integration_test.go:647: Unpinned store path: /nix/var/nix/builds/nix-24416-4031681480/TestPinProtectsFromGC4293081699/001/store/1n7cbw9l2m5dqj7mxmd15kz7xpsd5kdn-unpinned-file.txt12032026/07/09 07:42:54 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12042026/07/09 07:42:54 WARN Found objects in DB but missing from S3, will re-upload count=11205--- PASS: TestService_verifyS3Integrity (0.76s)1206=== CONT TestCacheStatsHandler12072026/07/09 07:42:54 INFO Aborted multipart uploads count=012082026/07/09 07:42:54 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=012092026/07/09 07:42:54 INFO Vacuumed table table=pending_closures12102026/07/09 07:42:54 INFO Vacuumed table table=pending_objects12112026/07/09 07:42:54 INFO Vacuumed table table=multipart_uploads12122026/07/09 07:42:54 INFO Vacuumed table table=closures12132026/07/09 07:42:54 INFO Vacuumed table table=objects12142026/07/09 07:42:54 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001215--- PASS: TestService_createPendingClosureHandler (0.77s)1216=== CONT TestCacheConfigHandler1217=== RUN TestCacheConfigHandler/full_config,_no_issuer1218=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1219=== RUN TestCacheConfigHandler/no_cache_url_configured1220=== PAUSE TestCacheConfigHandler/no_cache_url_configured1221=== RUN TestCacheConfigHandler/no_signing_keys1222=== PAUSE TestCacheConfigHandler/no_signing_keys1223=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1224=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1225=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12262026-07-09 07:42:54.053 UTC [24676] ERROR: relation "goose_db_version" does not exist at character 3612272026-07-09 07:42:54.053 UTC [24676] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1228--- PASS: TestGCBugBareHashReferences (0.69s)1229=== CONT TestService_ReadAuthMiddleware12302026/07/09 07:42:54 OK 20241026095416_initial_model.sql (12.39ms)12312026/07/09 07:42:54 OK 20251210153512_drop_unused_gin_index.sql (985.83µs)12322026/07/09 07:42:54 OK 20251218171726_add_pins.sql (2.87ms)12332026/07/09 07:42:54 OK 20260628120000_add_object_size_and_stats.sql (5.31ms)12342026/07/09 07:42:54 goose: successfully migrated database to version: 2026062812000012352026/07/09 07:42:54 OK 1_commit_pending_closure.sql (2.04ms)12362026/07/09 07:42:54 OK 2_object_stats_trigger.sql (664.88µs)12372026/07/09 07:42:54 goose: up to current file version: 212382026-07-09 07:42:54.096 UTC [24683] ERROR: relation "goose_db_version" does not exist at character 3612392026-07-09 07:42:54.096 UTC [24683] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12402026/07/09 07:42:54 INFO Created nix-cache-info in bucket bucket=bucket3412412026-07-09 07:42:54.098 UTC [24684] ERROR: relation "goose_db_version" does not exist at character 3612422026-07-09 07:42:54.098 UTC [24684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12432026/07/09 07:42:54 OK 20241026095416_initial_model.sql (14.28ms)12442026/07/09 07:42:54 OK 20251210153512_drop_unused_gin_index.sql (784.88µs)12452026/07/09 07:42:54 OK 20241026095416_initial_model.sql (11.41ms)12462026/07/09 07:42:54 OK 20251210153512_drop_unused_gin_index.sql (754.04µs)12472026/07/09 07:42:54 OK 20251218171726_add_pins.sql (1.6ms)12482026/07/09 07:42:54 OK 20251218171726_add_pins.sql (2.59ms)12492026/07/09 07:42:54 OK 20260628120000_add_object_size_and_stats.sql (4.06ms)12502026/07/09 07:42:54 goose: successfully migrated database to version: 2026062812000012512026/07/09 07:42:54 OK 20260628120000_add_object_size_and_stats.sql (2.77ms)12522026/07/09 07:42:54 goose: successfully migrated database to version: 2026062812000012532026/07/09 07:42:54 OK 1_commit_pending_closure.sql (2.1ms)12542026/07/09 07:42:54 OK 1_commit_pending_closure.sql (1.99ms)12552026/07/09 07:42:54 OK 2_object_stats_trigger.sql (526.75µs)12562026/07/09 07:42:54 goose: up to current file version: 212572026/07/09 07:42:54 OK 2_object_stats_trigger.sql (559.88µs)12582026/07/09 07:42:54 goose: up to current file version: 212592026/07/09 07:42:54 INFO Created nix-cache-info in bucket bucket=bucket3612602026/07/09 07:42:54 INFO Created nix-cache-info in bucket bucket=bucket3512612026-07-09 07:42:54.189 UTC [24691] ERROR: relation "goose_db_version" does not exist at character 3612622026-07-09 07:42:54.189 UTC [24691] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12632026/07/09 07:42:54 INFO Received uploads request method=POST path=/api/pending_closures1264=== NAME TestClientIntegration1265 client_integration_test.go:276: Created store path: /nix/var/nix/builds/nix-24416-4031681480/TestClientIntegration788366517/002/store/8w0af2dr2m55nc7zz365prrbky5d85c1-test-file.txt12662026/07/09 07:42:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12672026/07/09 07:42:54 INFO Uploading qzdskppljbvl73389l4c18kimxad749n-pinned-file.txt (128B)1268=== NAME TestClientMultipleUploads1269 client_integration_test.go:338: Created store path 0: /nix/var/nix/builds/nix-24416-4031681480/TestClientMultipleUploads2112801378/001/store/s8lsmi6d3h43a1bgyi0rr56cs2rcq4if-test-file-0.txt12702026/07/09 07:42:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12712026/07/09 07:42:54 INFO Signed narinfos id=1 count=112722026/07/09 07:42:54 OK 20241026095416_initial_model.sql (53.66ms)12732026/07/09 07:42:54 INFO Uploading 1 narinfos12742026/07/09 07:42:54 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)12752026/07/09 07:42:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12762026/07/09 07:42:54 OK 20251218171726_add_pins.sql (1.73ms)12772026/07/09 07:42:54 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)12782026/07/09 07:42:54 goose: successfully migrated database to version: 2026062812000012792026/07/09 07:42:54 OK 1_commit_pending_closure.sql (2.02ms)12802026-07-09 07:42:54.266 UTC [24700] ERROR: relation "goose_db_version" does not exist at character 3612812026-07-09 07:42:54.266 UTC [24700] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12822026/07/09 07:42:54 OK 2_object_stats_trigger.sql (553.42µs)12832026/07/09 07:42:54 goose: up to current file version: 212842026/07/09 07:42:54 INFO Completed upload id=112852026/07/09 07:42:54 INFO Upload complete. (194ms)1286=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1287=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1288=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1289=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1290=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1291=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1292=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1293=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1294=== CONT TestService_AuthMiddleware_MTLSProxyHeader12952026/07/09 07:42:54 OK 20241026095416_initial_model.sql (9.13ms)12962026/07/09 07:42:54 OK 20251210153512_drop_unused_gin_index.sql (796.08µs)12972026/07/09 07:42:54 OK 20251218171726_add_pins.sql (1.16ms)12982026/07/09 07:42:54 OK 20260628120000_add_object_size_and_stats.sql (1.8ms)12992026/07/09 07:42:54 goose: successfully migrated database to version: 2026062812000013002026/07/09 07:42:54 OK 1_commit_pending_closure.sql (2.12ms)13012026/07/09 07:42:54 OK 2_object_stats_trigger.sql (330.38µs)13022026/07/09 07:42:54 goose: up to current file version: 213032026/07/09 07:42:54 INFO Created nix-cache-info in bucket bucket=bucket3813042026-07-09 07:42:54.319 UTC [24708] ERROR: relation "goose_db_version" does not exist at character 3613052026-07-09 07:42:54.319 UTC [24708] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13062026/07/09 07:42:54 OK 20241026095416_initial_model.sql (10.07ms)13072026/07/09 07:42:54 OK 20251210153512_drop_unused_gin_index.sql (905.29µs)13082026/07/09 07:42:54 OK 20251218171726_add_pins.sql (1.2ms)13092026/07/09 07:42:54 OK 20260628120000_add_object_size_and_stats.sql (3.45ms)13102026/07/09 07:42:54 goose: successfully migrated database to version: 2026062812000013112026/07/09 07:42:54 OK 1_commit_pending_closure.sql (1.74ms)1312=== NAME TestClientMultipleUploads1313 client_integration_test.go:338: Created store path 1: /nix/var/nix/builds/nix-24416-4031681480/TestClientMultipleUploads2112801378/001/store/3636379zxrf81kzwh1ffnrv7mmp1dwdn-test-file-1.txt13142026/07/09 07:42:54 OK 2_object_stats_trigger.sql (587.33µs)13152026/07/09 07:42:54 goose: up to current file version: 21316--- PASS: TestCacheStatsHandler (0.38s)1317=== CONT TestGCTaskStore_DeduplicateSameParams1318--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1319=== CONT TestIsValidCachePath/narinfo1320=== CONT TestIsValidCachePath/index.html1321=== CONT TestIsValidCachePath/short_hash1322=== CONT TestIsValidCachePath/wrong_extension1323=== CONT TestIsValidCachePath/leading_slash1324=== CONT TestIsValidCachePath/empty1325=== CONT TestIsValidCachePath/random_path1326=== CONT TestIsValidCachePath/invalid_char_u1327=== CONT TestIsValidCachePath/invalid_char_e1328=== CONT TestIsValidCachePath/traversal_in_middle1329=== CONT TestIsValidCachePath/traversal_parent1330=== CONT TestIsValidCachePath/nar_uncompressed1331=== CONT TestIsValidCachePath/nix-cache-info1332=== CONT TestIsValidCachePath/realisation1333=== CONT TestIsValidCachePath/log1334=== CONT TestIsValidCachePath/ls1335=== CONT TestIsValidCachePath/nar_xz1336=== CONT TestIsValidCachePath/nar_bz21337=== CONT TestIsValidCachePath/nar_zst1338=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1339--- PASS: TestIsValidCachePath (0.00s)1340 --- PASS: TestIsValidCachePath/narinfo (0.00s)1341 --- PASS: TestIsValidCachePath/index.html (0.00s)1342 --- PASS: TestIsValidCachePath/short_hash (0.00s)1343 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1344 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1345 --- PASS: TestIsValidCachePath/empty (0.00s)1346 --- PASS: TestIsValidCachePath/random_path (0.00s)1347 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1348 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1349 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1350 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1351 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1352 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1353 --- PASS: TestIsValidCachePath/realisation (0.00s)1354 --- PASS: TestIsValidCachePath/log (0.00s)1355 --- PASS: TestIsValidCachePath/ls (0.00s)1356 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1357 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1358 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1359 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1360=== CONT TestParseSingleRange/none1361=== CONT TestParseSingleRange/open-ended1362=== CONT TestParseSingleRange/start_far_past_EOF1363=== CONT TestParseSingleRange/start_past_EOF1364=== CONT TestParseSingleRange/single_byte1365=== CONT TestParseSingleRange/suffix_exceeds_size1366=== CONT TestParseSingleRange/suffix1367=== CONT TestParseSingleRange/end_clamped_to_size1368=== CONT TestParseSingleRange/malformed_both_empty1369=== CONT TestParseSingleRange/closed1370=== CONT TestParseSingleRange/malformed_end_before_start1371=== CONT TestParseSingleRange/multi-range_ignored1372=== CONT TestParseSingleRange/malformed_no_dash1373=== CONT TestParseSingleRange/unknown_unit1374--- PASS: TestParseSingleRange (0.00s)1375 --- PASS: TestParseSingleRange/none (0.00s)1376 --- PASS: TestParseSingleRange/open-ended (0.00s)1377 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1378 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1379 --- PASS: TestParseSingleRange/single_byte (0.00s)1380 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1381 --- PASS: TestParseSingleRange/suffix (0.00s)1382 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1383 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1384 --- PASS: TestParseSingleRange/closed (0.00s)1385 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1386 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1387 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1388 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1389=== CONT TestProxyWriteTimeout/narinfo1390=== CONT TestProxyWriteTimeout/10_GiB_nar1391=== CONT TestProxyWriteTimeout/unknown_size1392=== CONT TestProxyWriteTimeout/1_GiB_nar1393--- PASS: TestProxyWriteTimeout (0.00s)1394 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1395 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1396 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1397 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1398=== CONT TestIsValidUploadKey/narinfo1399=== CONT TestIsValidUploadKey/realisation_plus_in_output1400=== CONT TestIsValidUploadKey/unknown_type1401=== CONT TestIsValidUploadKey/empty_key1402=== CONT TestIsValidUploadKey/absolute1403=== CONT TestIsValidUploadKey/traversal_nar1404=== CONT TestIsValidUploadKey/traversal1405=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1406=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1407=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1408=== CONT TestIsValidUploadKey/index.html1409=== CONT TestIsValidUploadKey/nix-cache-info1410=== CONT TestIsValidUploadKey/build_log_home-manager_file1411=== CONT TestIsValidUploadKey/realisation1412=== CONT TestIsValidUploadKey/build_log_equals1413=== CONT TestIsValidUploadKey/build_log_question_mark1414=== CONT TestIsValidUploadKey/build_log_plus_in_name1415=== CONT TestIsValidUploadKey/nar_plain1416=== CONT TestIsValidUploadKey/build_log1417=== CONT TestIsValidUploadKey/listing1418=== CONT TestIsValidUploadKey/nar_xz1419=== CONT TestIsValidUploadKey/nar_zst1420--- PASS: TestIsValidUploadKey (0.00s)1421 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1422 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1423 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1424 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1425 --- PASS: TestIsValidUploadKey/absolute (0.00s)1426 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1427 --- PASS: TestIsValidUploadKey/traversal (0.00s)1428 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1429 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1430 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1431 --- PASS: TestIsValidUploadKey/index.html (0.00s)1432 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1433 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1434 --- PASS: TestIsValidUploadKey/realisation (0.00s)1435 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1436 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1437 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1438 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1439 --- PASS: TestIsValidUploadKey/build_log (0.00s)1440 --- PASS: TestIsValidUploadKey/listing (0.00s)1441 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1442 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1443=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14442026/07/09 07:42:54 INFO Received uploads request method=POST path=/14452026-07-09 07:42:54.390 UTC [24718] ERROR: relation "goose_db_version" does not exist at character 3614462026-07-09 07:42:54.390 UTC [24718] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14472026-07-09 07:42:54.392 UTC [24719] ERROR: relation "goose_db_version" does not exist at character 3614482026-07-09 07:42:54.392 UTC [24719] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1449=== NAME TestClientMultipleUploads1450 client_integration_test.go:338: Created store path 2: /nix/var/nix/builds/nix-24416-4031681480/TestClientMultipleUploads2112801378/001/store/xycgy8y31pf9lg3xw40xmapdg32j076w-test-file-2.txt14512026/07/09 07:42:54 OK 20241026095416_initial_model.sql (9.37ms)14522026/07/09 07:42:54 INFO Received uploads request method=POST path=/api/pending_closures14532026/07/09 07:42:54 OK 20241026095416_initial_model.sql (13.67ms)14542026/07/09 07:42:54 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)14552026/07/09 07:42:54 OK 20251210153512_drop_unused_gin_index.sql (645.46µs)14562026/07/09 07:42:54 OK 20251218171726_add_pins.sql (1.52ms)14572026/07/09 07:42:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14582026/07/09 07:42:54 INFO Uploading 8w0af2dr2m55nc7zz365prrbky5d85c1-test-file.txt (152B)14592026/07/09 07:42:54 OK 20251218171726_add_pins.sql (2.1ms)14602026/07/09 07:42:54 OK 20260628120000_add_object_size_and_stats.sql (2.48ms)14612026/07/09 07:42:54 goose: successfully migrated database to version: 2026062812000014622026/07/09 07:42:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14632026/07/09 07:42:54 INFO Signed narinfos id=1 count=114642026/07/09 07:42:54 INFO Uploading 1 narinfos14652026/07/09 07:42:54 OK 1_commit_pending_closure.sql (1.36ms)14662026/07/09 07:42:54 OK 20260628120000_add_object_size_and_stats.sql (3.52ms)14672026/07/09 07:42:54 goose: successfully migrated database to version: 2026062812000014682026/07/09 07:42:54 OK 2_object_stats_trigger.sql (389.58µs)14692026/07/09 07:42:54 goose: up to current file version: 214702026/07/09 07:42:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14712026/07/09 07:42:54 OK 1_commit_pending_closure.sql (1.37ms)14722026/07/09 07:42:54 OK 2_object_stats_trigger.sql (401.08µs)14732026/07/09 07:42:54 goose: up to current file version: 214742026/07/09 07:42:54 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1475--- PASS: TestService_ReadAuthMiddleware (0.36s)1476=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14772026/07/09 07:42:54 INFO Received request for more parts method=POST path=/14782026/07/09 07:42:54 INFO Completed upload id=114792026/07/09 07:42:54 INFO Upload complete. (130ms)14802026/07/09 07:42:54 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14812026/07/09 07:42:54 WARN mTLS auth: bound subjects configured but subject DN unavailable14822026/07/09 07:42:54 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1483--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.37s)1484=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14852026/07/09 07:42:54 INFO Received complete multipart upload request method=POST path=/1486=== NAME TestClientIntegration1487 client_integration_test.go:292: Retrieved narinfo from S3:1488 StorePath: /nix/var/nix/builds/nix-24416-4031681480/TestClientIntegration788366517/002/store/8w0af2dr2m55nc7zz365prrbky5d85c1-test-file.txt1489 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1490 Compression: zstd1491 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11492 NarSize: 1521493 References: 1494 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11495 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1496 client_integration_test.go:293: Decompressed .ls content (64 bytes):1497 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1498 client_integration_test.go:296: Testing garbage collection...1499=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15002026/07/09 07:42:54 INFO Received uploads request method=POST path=/1501=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15022026/07/09 07:42:54 INFO Received request for more parts method=POST path=/1503=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15042026/07/09 07:42:54 INFO Received uploads request method=POST path=/1505=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15062026/07/09 07:42:54 INFO Received complete multipart upload request method=POST path=/1507--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1508 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1509 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1510 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1511 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1512=== CONT TestClientErrorHandling/InvalidStorePath1513=== CONT TestClientErrorHandling/InvalidAuthToken15142026-07-09 07:42:54.461 UTC [24728] ERROR: relation "goose_db_version" does not exist at character 3615152026-07-09 07:42:54.461 UTC [24728] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15162026/07/09 07:42:54 OK 20241026095416_initial_model.sql (6.48ms)15172026/07/09 07:42:54 OK 20251210153512_drop_unused_gin_index.sql (972.92µs)15182026/07/09 07:42:54 OK 20251218171726_add_pins.sql (2.54ms)15192026/07/09 07:42:54 OK 20260628120000_add_object_size_and_stats.sql (2.87ms)15202026/07/09 07:42:54 goose: successfully migrated database to version: 2026062812000015212026/07/09 07:42:54 OK 1_commit_pending_closure.sql (2.12ms)15222026/07/09 07:42:54 OK 2_object_stats_trigger.sql (361.21µs)15232026/07/09 07:42:54 goose: up to current file version: 21524--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.21s)1525=== CONT TestClientErrorHandling/ServerNotAvailable15262026/07/09 07:42:54 INFO Received uploads request method=POST path=/api/pending_closures15272026/07/09 07:42:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15282026/07/09 07:42:54 INFO Uploading 1n7cbw9l2m5dqj7mxmd15kz7xpsd5kdn-unpinned-file.txt (128B)15292026/07/09 07:42:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures15302026/07/09 07:42:54 INFO Garbage collection started15312026/07/09 07:42:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15322026/07/09 07:42:54 INFO Signed narinfos id=2 count=115332026/07/09 07:42:54 INFO Uploading 1 narinfos15342026/07/09 07:42:54 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15352026/07/09 07:42:54 INFO Completed upload id=215362026/07/09 07:42:54 INFO Upload complete. (152ms)15372026/07/09 07:42:54 INFO Aborted multipart uploads count=015382026/07/09 07:42:54 WARN Force mode enabled - objects will be deleted immediately without grace period15392026/07/09 07:42:54 INFO Received create pin request method=POST path=/api/pins/myapp1540=== NAME TestClientWithDependencies1541 client_integration_test.go:593: Built derivation: /nix/var/nix/builds/nix-24416-4031681480/TestClientWithDependencies2179375474/001/store/4cbzz1hd8p9mlf4z8jqlvyiap5p70grw-test-script15422026/07/09 07:42:54 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-24416-4031681480/TestPinProtectsFromGC4293081699/001/store/qzdskppljbvl73389l4c18kimxad749n-pinned-file.txt narinfo_key=qzdskppljbvl73389l4c18kimxad749n.narinfo15432026/07/09 07:42:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures15442026/07/09 07:42:54 INFO Garbage collection started15452026/07/09 07:42:54 INFO Aborted multipart uploads count=015462026/07/09 07:42:54 WARN Force mode enabled - objects will be deleted immediately without grace period15472026-07-09 07:42:54.610 UTC [24745] ERROR: relation "goose_db_version" does not exist at character 3615482026-07-09 07:42:54.610 UTC [24745] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15492026-07-09 07:42:54.613 UTC [24747] ERROR: relation "goose_db_version" does not exist at character 3615502026-07-09 07:42:54.613 UTC [24747] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15512026/07/09 07:42:54 INFO Received uploads request method=POST path=/api/pending_closures1552 client_integration_test.go:595: Found 1 dependencies (including self)15532026/07/09 07:42:54 INFO Received uploads request method=POST path=/api/pending_closures15542026/07/09 07:42:54 OK 20241026095416_initial_model.sql (9.54ms)15552026/07/09 07:42:54 OK 20241026095416_initial_model.sql (10.15ms)15562026/07/09 07:42:54 OK 20251210153512_drop_unused_gin_index.sql (1.1ms)15572026/07/09 07:42:54 OK 20251210153512_drop_unused_gin_index.sql (828.88µs)15582026/07/09 07:42:54 INFO Received uploads request method=POST path=/api/pending_closures15592026/07/09 07:42:54 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15602026/07/09 07:42:54 INFO Uploading s8lsmi6d3h43a1bgyi0rr56cs2rcq4if-test-file-0.txt (160B)15612026/07/09 07:42:54 INFO Uploading 3636379zxrf81kzwh1ffnrv7mmp1dwdn-test-file-1.txt (160B)15622026/07/09 07:42:54 INFO Uploading xycgy8y31pf9lg3xw40xmapdg32j076w-test-file-2.txt (160B)15632026/07/09 07:42:54 OK 20251218171726_add_pins.sql (2.34ms)15642026/07/09 07:42:54 OK 20251218171726_add_pins.sql (3.47ms)15652026/07/09 07:42:54 OK 20260628120000_add_object_size_and_stats.sql (2.88ms)15662026/07/09 07:42:54 goose: successfully migrated database to version: 2026062812000015672026/07/09 07:42:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15682026/07/09 07:42:54 OK 20260628120000_add_object_size_and_stats.sql (2.72ms)15692026/07/09 07:42:54 goose: successfully migrated database to version: 2026062812000015702026/07/09 07:42:54 INFO Signed narinfos id=1 count=115712026/07/09 07:42:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15722026/07/09 07:42:54 INFO Signed narinfos id=2 count=115732026/07/09 07:42:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15742026/07/09 07:42:54 INFO Signed narinfos id=3 count=115752026/07/09 07:42:54 INFO Uploading 3 narinfos15762026/07/09 07:42:54 OK 1_commit_pending_closure.sql (2.03ms)15772026/07/09 07:42:54 OK 2_object_stats_trigger.sql (536.33µs)15782026/07/09 07:42:54 goose: up to current file version: 215792026/07/09 07:42:54 OK 1_commit_pending_closure.sql (1.92ms)15802026/07/09 07:42:54 OK 2_object_stats_trigger.sql (588.33µs)15812026/07/09 07:42:54 goose: up to current file version: 215822026/07/09 07:42:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15832026/07/09 07:42:54 INFO Completed upload id=115842026/07/09 07:42:54 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15852026/07/09 07:42:54 INFO Completed upload id=215862026/07/09 07:42:54 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete15872026/07/09 07:42:54 INFO Completed upload id=315882026/07/09 07:42:54 INFO Upload complete. (164ms)1589=== NAME TestClientMultipleUploads1590 client_integration_test.go:349: Uploaded 3 paths in 248.315208ms1591--- PASS: TestClientMultipleUploads (0.92s)1592=== CONT TestCacheConfigHandler/full_config,_no_issuer1593=== CONT TestCacheConfigHandler/no_signing_keys1594=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1595=== CONT TestCacheConfigHandler/no_cache_url_configured1596--- PASS: TestCacheConfigHandler (0.00s)1597 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1598 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1599 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1600 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1601=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token16022026/07/09 07:42:54 INFO OIDC auth successful provider=test1603=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected16042026/07/09 07:42:54 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]1605=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1606=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16072026/07/09 07:42:54 WARN Authentication failed token_preview=eyJhbGciOi...Ey0aEBC1rw 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]1608--- PASS: TestService_AuthMiddleware_OIDC (0.43s)1609 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1610 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1611 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1612 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)16132026/07/09 07:42:54 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_closures16142026/07/09 07:42:54 INFO Received uploads request method=POST path=/api/pending_closures16152026/07/09 07:42:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16162026/07/09 07:42:54 INFO Uploading 4cbzz1hd8p9mlf4z8jqlvyiap5p70grw-test-script (136B)16172026/07/09 07:42:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16182026/07/09 07:42:54 INFO Signed narinfos id=1 count=116192026/07/09 07:42:54 INFO Uploading 1 narinfos16202026/07/09 07:42:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16212026/07/09 07:42:54 INFO Completed upload id=116222026/07/09 07:42:54 INFO Upload complete. (70ms)1623=== NAME TestClientWithDependencies1624 client_integration_test.go:597: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-24416-4031681480/TestClientWithDependencies2179375474/001/store) requires matching store prefix1625--- PASS: TestClientWithDependencies (1.09s)1626=== NAME TestClientCADerivations1627 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-24416-4031681480/TestClientCADerivations2419286506/001/store/7hbn87n8b4gqh7pvwbg4hsh7y3mad0rv-ca-test16282026/07/09 07:42:54 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.999637ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1629 client_ca_test.go:139: Found 1 dependencies (including self)16302026/07/09 07:42:54 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1631--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)1632 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)1633 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)1634 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.55s)16352026/07/09 07:42:55 INFO Received uploads request method=POST path=/api/pending_closures16362026/07/09 07:42:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16372026/07/09 07:42:55 INFO Uploading 7hbn87n8b4gqh7pvwbg4hsh7y3mad0rv-ca-test (144B)16382026/07/09 07:42:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16392026/07/09 07:42:55 INFO Signed narinfos id=1 count=116402026/07/09 07:42:55 INFO Uploading 1 narinfos16412026/07/09 07:42:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16422026/07/09 07:42:55 INFO Completed upload id=116432026/07/09 07:42:55 INFO Upload complete. (111ms)1644=== NAME TestClientCADerivations1645 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-24416-4031681480/TestClientCADerivations2419286506/001/store/7hbn87n8b4gqh7pvwbg4hsh7y3mad0rv-ca-test1646 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1647 Compression: zstd1648 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1649 NarSize: 1441650 References: 1651 Deriver: /nix/var/nix/builds/nix-24416-4031681480/TestClientCADerivations2419286506/001/store/4jc67xcif6rr3dn1v7bq5hwj8qndp1s6-ca-test.drv1652 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1653 client_ca_test.go:185: Checking for realisation files in S3...1654 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1655 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16562026/07/09 07:42:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=360.502221ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1657 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket38?endpoint=http://localhost:52202®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-24416-4031681480/TestClientCADerivations2419286506/001/store'1658 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11659--- PASS: TestClientCADerivations (1.19s)16602026/07/09 07:42:55 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=016612026/07/09 07:42:55 INFO Vacuumed table table=pending_closures16622026/07/09 07:42:55 INFO Vacuumed table table=pending_objects16632026/07/09 07:42:55 INFO Vacuumed table table=multipart_uploads16642026/07/09 07:42:55 INFO Vacuumed table table=closures16652026/07/09 07:42:55 INFO Vacuumed table table=objects16662026/07/09 07:42:55 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=016672026/07/09 07:42:55 INFO Vacuumed table table=pending_closures16682026/07/09 07:42:55 INFO Vacuumed table table=pending_objects16692026/07/09 07:42:55 INFO Vacuumed table table=multipart_uploads16702026/07/09 07:42:55 INFO Vacuumed table table=closures16712026/07/09 07:42:55 INFO Vacuumed table table=objects16722026/07/09 07:42:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=813.000911ms 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:42:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.536214161s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16742026/07/09 07:42:56 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01675=== NAME TestClientIntegration1676 client_integration_test.go:303: Objects in database after GC:1677 client_integration_test.go:303: Successfully deleted all objects with GC --force1678--- PASS: TestClientIntegration (2.74s)16792026/07/09 07:42:56 WARN Rate limiter enabled after throttle name=s3-test rate=516802026/07/09 07:42:56 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1681=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1682 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101683 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001684--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.68s)16852026/07/09 07:42:56 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01686=== NAME TestPinProtectsFromGC1687 client_integration_test.go:709: Pin successfully protected closure from garbage collection1688--- PASS: TestPinProtectsFromGC (3.19s)1689--- PASS: TestClientErrorHandling (0.00s)1690 --- PASS: TestClientErrorHandling/InvalidStorePath (0.25s)1691 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.42s)1692 --- PASS: TestClientErrorHandling/ServerNotAvailable (3.27s)1693PASS16942026-07-09 07:42:58.302 UTC [24466] LOG: received smart shutdown request16952026-07-09 07:42:58.303 UTC [24466] LOG: background worker "logical replication launcher" (PID 24473) exited with exit code 116962026-07-09 07:42:58.313 UTC [24468] LOG: shutting down16972026-07-09 07:42:58.313 UTC [24468] LOG: checkpoint starting: shutdown immediate16982026-07-09 07:42:59.462 UTC [24468] LOG: checkpoint complete: wrote 13450 buffers (82.1%); 0 WAL file(s) added, 0 removed, 12 recycled; write=0.746 s, sync=0.400 s, total=1.150 s; sync files=14421, longest=0.001 s, average=0.001 s; distance=197510 kB, estimate=197510 kB; lsn=0/D5F4588, redo lsn=0/D5F458816992026-07-09 07:42:59.467 UTC [24466] LOG: database system is shut down1700Running OIDC tests...1701=== RUN TestGlobMatch1702=== PAUSE TestGlobMatch1703=== RUN TestAudienceForIssuer1704=== PAUSE TestAudienceForIssuer1705=== RUN TestValidateToken_ValidToken1706=== PAUSE TestValidateToken_ValidToken1707=== RUN TestValidateToken_WrongAudience1708=== PAUSE TestValidateToken_WrongAudience1709=== RUN TestValidateToken_Expired1710=== PAUSE TestValidateToken_Expired1711=== RUN TestValidateToken_BoundClaimsMismatch1712=== PAUSE TestValidateToken_BoundClaimsMismatch1713=== RUN TestValidateToken_BoundSubjectMismatch1714=== PAUSE TestValidateToken_BoundSubjectMismatch1715=== RUN TestValidateToken_MultipleProviders1716=== PAUSE TestValidateToken_MultipleProviders1717=== RUN TestValidateToken_NoMatchingProvider1718=== PAUSE TestValidateToken_NoMatchingProvider1719=== CONT TestGlobMatch1720=== RUN TestGlobMatch/foo_foo1721=== PAUSE TestGlobMatch/foo_foo1722=== RUN TestGlobMatch/foo_bar1723=== PAUSE TestGlobMatch/foo_bar1724=== CONT TestValidateToken_MultipleProviders1725=== CONT TestValidateToken_BoundSubjectMismatch1726=== RUN TestGlobMatch/*_1727=== PAUSE TestGlobMatch/*_1728=== RUN TestGlobMatch/*_anything1729=== PAUSE TestGlobMatch/*_anything1730=== RUN TestGlobMatch/foo*_foo1731=== PAUSE TestGlobMatch/foo*_foo1732=== RUN TestGlobMatch/foo*_foobar1733=== PAUSE TestGlobMatch/foo*_foobar1734=== CONT TestValidateToken_Expired1735=== CONT TestValidateToken_WrongAudience1736=== CONT TestValidateToken_ValidToken1737=== CONT TestAudienceForIssuer1738--- PASS: TestAudienceForIssuer (0.00s)1739=== CONT TestValidateToken_BoundClaimsMismatch1740=== CONT TestValidateToken_NoMatchingProvider1741=== RUN TestGlobMatch/foo*_bar1742=== PAUSE TestGlobMatch/foo*_bar1743=== RUN TestGlobMatch/*bar_bar1744=== PAUSE TestGlobMatch/*bar_bar1745=== RUN TestGlobMatch/*bar_foobar1746=== PAUSE TestGlobMatch/*bar_foobar1747=== RUN TestGlobMatch/*bar_foo1748=== PAUSE TestGlobMatch/*bar_foo1749=== RUN TestGlobMatch/foo*bar_foobar1750=== PAUSE TestGlobMatch/foo*bar_foobar1751=== RUN TestGlobMatch/foo*bar_foo123bar1752=== PAUSE TestGlobMatch/foo*bar_foo123bar1753=== RUN TestGlobMatch/foo*bar_foobarbaz1754=== PAUSE TestGlobMatch/foo*bar_foobarbaz1755=== RUN TestGlobMatch/*/*_foo/bar1756=== PAUSE TestGlobMatch/*/*_foo/bar1757=== RUN TestGlobMatch/*/*_foo1758=== PAUSE TestGlobMatch/*/*_foo1759=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1760=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1761=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01762=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01763=== RUN TestGlobMatch/refs/*/main_refs/heads/main1764=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1765=== RUN TestGlobMatch/fo?_foo1766=== PAUSE TestGlobMatch/fo?_foo1767=== RUN TestGlobMatch/fo?_fo1768=== PAUSE TestGlobMatch/fo?_fo1769=== RUN TestGlobMatch/fo?_fooo1770=== PAUSE TestGlobMatch/fo?_fooo1771=== RUN TestGlobMatch/?oo_foo1772=== PAUSE TestGlobMatch/?oo_foo1773=== RUN TestGlobMatch/?oo_boo1774=== PAUSE TestGlobMatch/?oo_boo1775=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1776=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1777=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1778=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1779=== CONT TestGlobMatch/foo_foo1780=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1781=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1782=== CONT TestGlobMatch/?oo_boo1783=== CONT TestGlobMatch/?oo_foo1784=== CONT TestGlobMatch/fo?_fooo1785=== CONT TestGlobMatch/fo?_fo1786=== CONT TestGlobMatch/fo?_foo1787=== CONT TestGlobMatch/refs/*/main_refs/heads/main1788=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01789=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1790=== CONT TestGlobMatch/*/*_foo1791=== CONT TestGlobMatch/*/*_foo/bar1792=== CONT TestGlobMatch/foo*bar_foobarbaz1793=== CONT TestGlobMatch/foo*bar_foo123bar1794=== CONT TestGlobMatch/foo*bar_foobar1795=== CONT TestGlobMatch/*bar_foo1796=== CONT TestGlobMatch/*bar_foobar1797=== CONT TestGlobMatch/*bar_bar1798=== CONT TestGlobMatch/foo*_bar1799=== CONT TestGlobMatch/foo*_foobar1800=== CONT TestGlobMatch/foo*_foo1801=== CONT TestGlobMatch/*_anything1802=== CONT TestGlobMatch/*_1803=== CONT TestGlobMatch/foo_bar1804--- PASS: TestGlobMatch (0.00s)1805 --- PASS: TestGlobMatch/foo_foo (0.00s)1806 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1807 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1808 --- PASS: TestGlobMatch/?oo_boo (0.00s)1809 --- PASS: TestGlobMatch/?oo_foo (0.00s)1810 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1811 --- PASS: TestGlobMatch/fo?_fo (0.00s)1812 --- PASS: TestGlobMatch/fo?_foo (0.00s)1813 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1814 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1815 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1816 --- PASS: TestGlobMatch/*/*_foo (0.00s)1817 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1818 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1819 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1820 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1821 --- PASS: TestGlobMatch/*bar_foo (0.00s)1822 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1823 --- PASS: TestGlobMatch/*bar_bar (0.00s)1824 --- PASS: TestGlobMatch/foo*_bar (0.00s)1825 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1826 --- PASS: TestGlobMatch/foo*_foo (0.00s)1827 --- PASS: TestGlobMatch/*_anything (0.00s)1828 --- PASS: TestGlobMatch/*_ (0.00s)1829 --- PASS: TestGlobMatch/foo_bar (0.00s)18302026/07/09 07:43:00 INFO OIDC provider initialized name=provider118312026/07/09 07:43:00 INFO OIDC provider initialized name=provider118322026/07/09 07:43:00 INFO OIDC provider initialized name=test18332026/07/09 07:43:00 INFO OIDC provider initialized name=test18342026/07/09 07:43:00 INFO OIDC provider initialized name=test18352026/07/09 07:43:00 INFO OIDC provider initialized name=test18362026/07/09 07:43:00 INFO OIDC provider initialized name=test18372026/07/09 07:43:00 INFO OIDC provider initialized name=provider21838--- PASS: TestValidateToken_ValidToken (0.01s)1839--- PASS: TestValidateToken_WrongAudience (0.01s)1840--- PASS: TestValidateToken_Expired (0.01s)1841--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1842--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1843--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1844--- PASS: TestValidateToken_MultipleProviders (0.01s)1845PASS1846Running hook tests...1847=== RUN TestSendPathsEmpty1848=== PAUSE TestSendPathsEmpty1849=== RUN TestQueueEnqueueAndFetch1850=== PAUSE TestQueueEnqueueAndFetch1851=== RUN TestQueueDeduplication1852=== PAUSE TestQueueDeduplication1853=== RUN TestQueueRemove1854=== PAUSE TestQueueRemove1855=== RUN TestQueueFetchBatchLimit1856=== PAUSE TestQueueFetchBatchLimit1857=== RUN TestQueueFetchRemoveLifecycle1858=== PAUSE TestQueueFetchRemoveLifecycle1859=== RUN TestQueueConcurrentWriters1860=== PAUSE TestQueueConcurrentWriters1861=== RUN TestServerClientIntegration1862=== PAUSE TestServerClientIntegration1863=== RUN TestServerQueueError1864=== PAUSE TestServerQueueError1865=== RUN TestGetListenerSocketActivation1866 server_test.go:210: === RUN TestGetListenerSocketActivation1867 --- PASS: TestGetListenerSocketActivation (0.00s)1868 PASS1869 1870--- PASS: TestGetListenerSocketActivation (0.01s)1871=== RUN TestWorkerUploadsAndRemoves1872=== PAUSE TestWorkerUploadsAndRemoves1873=== RUN TestWorkerSkipsGCdPaths1874=== PAUSE TestWorkerSkipsGCdPaths1875=== RUN TestWorkerPrunesClosureDeps1876=== PAUSE TestWorkerPrunesClosureDeps1877=== CONT TestSendPathsEmpty1878--- PASS: TestSendPathsEmpty (0.00s)1879=== CONT TestQueueFetchRemoveLifecycle1880=== CONT TestQueueConcurrentWriters1881=== CONT TestQueueRemove1882=== CONT TestWorkerUploadsAndRemoves1883=== CONT TestWorkerPrunesClosureDeps1884=== CONT TestWorkerSkipsGCdPaths1885=== CONT TestQueueFetchBatchLimit1886=== CONT TestServerQueueError1887=== CONT TestQueueDeduplication1888=== CONT TestServerClientIntegration18892026/07/09 07:43:00 ERROR Failed to queue paths error="permission denied" count=11890--- PASS: TestServerClientIntegration (0.00s)1891=== CONT TestQueueEnqueueAndFetch1892--- PASS: TestServerQueueError (0.00s)1893--- PASS: TestQueueEnqueueAndFetch (0.00s)18942026/07/09 07:43:00 INFO Upload queue status pending=218952026/07/09 07:43:00 INFO Uploading batch count=21896--- PASS: TestQueueFetchRemoveLifecycle (0.01s)1897--- PASS: TestQueueRemove (0.01s)18982026/07/09 07:43:00 INFO Upload queue status pending=218992026/07/09 07:43:00 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-24416-4031681480/TestWorkerSkipsGCdPaths3113661455/002/nonexistent1900--- PASS: TestQueueFetchBatchLimit (0.01s)19012026/07/09 07:43:00 INFO Uploading batch count=11902--- PASS: TestQueueDeduplication (0.01s)19032026/07/09 07:43:00 INFO Upload queue status pending=219042026/07/09 07:43:00 INFO Uploading batch count=11905--- PASS: TestWorkerPrunesClosureDeps (0.06s)1906--- PASS: TestWorkerUploadsAndRemoves (0.06s)1907--- PASS: TestWorkerSkipsGCdPaths (0.06s)1908--- PASS: TestQueueConcurrentWriters (0.15s)1909PASS