niks3-go-unit-tests
aarch64-darwin.go-unit-tests
· build #100
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestCaseHackSuffix5=== PAUSE TestCaseHackSuffix6=== RUN TestPartSizeForNAR7=== PAUSE TestPartSizeForNAR8=== RUN TestUploadMultipart_SupersededByPeer9=== PAUSE TestUploadMultipart_SupersededByPeer10=== RUN TestDumpPathMatchesNix11=== PAUSE TestDumpPathMatchesNix12=== RUN TestDumpPathSingleFile13=== PAUSE TestDumpPathSingleFile14=== RUN TestDumpPathWriterError15=== PAUSE TestDumpPathWriterError16=== RUN TestEncodeNixBase3217=== PAUSE TestEncodeNixBase3218=== RUN TestEncodeNixBase32WithRealHash19=== PAUSE TestEncodeNixBase32WithRealHash20=== RUN TestConvertHashToNix3221=== PAUSE TestConvertHashToNix3222=== RUN TestGetStorePathHash23=== PAUSE TestGetStorePathHash24=== RUN TestPathInfoHashCompatibility25=== PAUSE TestPathInfoHashCompatibility26=== RUN TestParsePathInfoJSON27=== PAUSE TestParsePathInfoJSON28=== RUN TestParsePathInfoJSONMultiplePaths29=== PAUSE TestParsePathInfoJSONMultiplePaths30=== RUN TestPathInfoCACompatibility31=== PAUSE TestPathInfoCACompatibility32=== RUN TestRateLimiterFeedback33=== PAUSE TestRateLimiterFeedback34=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess35=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess36=== RUN TestResolveStorePath37=== PAUSE TestResolveStorePath38=== RUN TestDoWithRetry_BodyReplayedViaGetBody39=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody40=== RUN TestShellSplit41=== PAUSE TestShellSplit42=== RUN TestShellSplitErrors43=== PAUSE TestShellSplitErrors44=== RUN TestSetClientTLS45=== PAUSE TestSetClientTLS46=== RUN TestSetClientTLSDoesNotMutateDefaultTransport47=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport48=== RUN TestSetClientTLSErrors49=== PAUSE TestSetClientTLSErrors50=== RUN TestStaticToken51=== PAUSE TestStaticToken52=== RUN TestFileTokenReadsAndCaches53=== PAUSE TestFileTokenReadsAndCaches54=== RUN TestFileTokenMissing55=== PAUSE TestFileTokenMissing56=== RUN TestFileTokenEmpty57=== PAUSE TestFileTokenEmpty58=== RUN TestScriptTokenNoExpiryRerunsEveryCall59=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall60=== RUN TestScriptTokenCachesUntilRefresh61=== PAUSE TestScriptTokenCachesUntilRefresh62=== RUN TestScriptTokenEmptyToken63=== PAUSE TestScriptTokenEmptyToken64=== RUN TestScriptTokenBadJSON65=== PAUSE TestScriptTokenBadJSON66=== RUN TestScriptTokenScriptFails67=== PAUSE TestScriptTokenScriptFails68=== RUN TestScriptTokenEmptyCommand69=== PAUSE TestScriptTokenEmptyCommand70=== CONT TestDoServerRequestAttachesToken71=== CONT TestResolveStorePath72=== CONT TestConvertHashToNix3273=== RUN TestConvertHashToNix32/SRI_format_to_Nix3274=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix3275=== RUN TestConvertHashToNix32/already_Nix32_format76=== PAUSE TestConvertHashToNix32/already_Nix32_format77=== CONT TestParsePathInfoJSONMultiplePaths78=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths79=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths80=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths81=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths82=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess83=== CONT TestScriptTokenBadJSON842026/07/18 13:54:16 WARN Rate limiter enabled after throttle name=server-test rate=585=== CONT TestRateLimiterFeedback86=== RUN TestRateLimiterFeedback/429_enables_limiter87=== PAUSE TestRateLimiterFeedback/429_enables_limiter88=== RUN TestRateLimiterFeedback/503_enables_limiter89=== PAUSE TestRateLimiterFeedback/503_enables_limiter90=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter91=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter92=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter93=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter94=== CONT TestPathInfoCACompatibility95=== CONT TestScriptTokenEmptyToken96=== RUN TestPathInfoCACompatibility/null_ca_field97=== PAUSE TestPathInfoCACompatibility/null_ca_field98=== RUN TestPathInfoCACompatibility/old_string_format_-_text99=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text100=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive101=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive102=== RUN TestPathInfoCACompatibility/new_structured_format_-_text103=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text104=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method105=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method106=== CONT TestFileTokenMissing107=== CONT TestScriptTokenCachesUntilRefresh108=== CONT TestScriptTokenEmptyCommand109--- PASS: TestScriptTokenEmptyCommand (0.00s)110=== CONT TestFileTokenEmpty111--- PASS: TestFileTokenMissing (0.00s)112=== CONT TestPathInfoHashCompatibility113=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)114=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)115=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon116=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon117=== CONT TestScriptTokenScriptFails118=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI119=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI120=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512121=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512122=== CONT TestParsePathInfoJSON123=== RUN TestParsePathInfoJSON/Nix_format124=== PAUSE TestParsePathInfoJSON/Nix_format125=== RUN TestParsePathInfoJSON/Lix_format126=== PAUSE TestParsePathInfoJSON/Lix_format127=== RUN TestConvertHashToNix32/invalid_format128--- PASS: TestResolveStorePath (0.00s)129=== CONT TestDumpPathSingleFile130=== RUN TestParsePathInfoJSON/empty_input131=== PAUSE TestParsePathInfoJSON/empty_input132=== PAUSE TestConvertHashToNix32/invalid_format133=== CONT TestEncodeNixBase32WithRealHash134=== RUN TestParsePathInfoJSON/whitespace_only135=== PAUSE TestParsePathInfoJSON/whitespace_only136=== RUN TestParsePathInfoJSON/invalid_JSON137=== PAUSE TestParsePathInfoJSON/invalid_JSON138--- PASS: TestEncodeNixBase32WithRealHash (0.00s)139=== CONT TestEncodeNixBase32140=== CONT TestDumpPathWriterError141=== RUN TestEncodeNixBase32/test_string_hash142=== PAUSE TestEncodeNixBase32/test_string_hash143=== RUN TestEncodeNixBase32/empty_input144=== PAUSE TestEncodeNixBase32/empty_input145=== CONT TestGetStorePathHash146=== RUN TestGetStorePathHash/valid_store_path147=== PAUSE TestGetStorePathHash/valid_store_path148=== RUN TestGetStorePathHash/basename_without_hyphen_should_error149=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error150=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error151=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error152=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error153=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error154=== CONT TestSetClientTLSDoesNotMutateDefaultTransport155--- PASS: TestFileTokenEmpty (0.00s)156--- PASS: TestDoServerRequestAttachesToken (0.01s)157=== CONT TestStaticToken158=== CONT TestFileTokenReadsAndCaches159--- PASS: TestStaticToken (0.00s)160=== CONT TestSetClientTLSErrors161--- PASS: TestScriptTokenScriptFails (0.01s)162=== CONT TestUploadMultipart_SupersededByPeer163--- PASS: TestFileTokenReadsAndCaches (0.00s)164=== RUN TestUploadMultipart_SupersededByPeer/exists165=== CONT TestDumpPathMatchesNix166=== PAUSE TestUploadMultipart_SupersededByPeer/exists167=== RUN TestUploadMultipart_SupersededByPeer/missing168=== PAUSE TestUploadMultipart_SupersededByPeer/missing169=== CONT TestPartSizeForNAR170=== RUN TestPartSizeForNAR/zero_stays_at_minimum171=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum172=== RUN TestPartSizeForNAR/small_stays_at_minimum173=== PAUSE TestPartSizeForNAR/small_stays_at_minimum174=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum175=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum176=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts177=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts178=== RUN TestPartSizeForNAR/1_TiB179=== PAUSE TestPartSizeForNAR/1_TiB180=== RUN TestPartSizeForNAR/5_TiB_S3_max_object181=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object182=== RUN TestPartSizeForNAR/capped_at_5_GiB183=== PAUSE TestPartSizeForNAR/capped_at_5_GiB184=== CONT TestShellSplitErrors185--- PASS: TestShellSplitErrors (0.00s)186=== CONT TestSetClientTLS187=== 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 TestShellSplit196--- PASS: TestShellSplit (0.00s)197=== CONT TestDoWithRetry_BodyReplayedViaGetBody198--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)199=== CONT TestCaseHackSuffix200=== RUN TestSetClientTLS/rejects_connection_without_client_cert201=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert2022026/07/18 13:54:16 WARN Rate limiter enabled after throttle name=server-test rate=52032026/07/18 13:54:16 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:57401204=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA205=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA206=== RUN TestSetClientTLS/preserves_debug_logging_transport207=== PAUSE TestSetClientTLS/preserves_debug_logging_transport208=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2092026/07/18 13:54:16 WARN Rate limiter backed off name=server-test rate=52102026/07/18 13:54:16 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:57401211=== CONT TestScriptTokenNoExpiryRerunsEveryCall212--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)213=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths214=== CONT TestRateLimiterFeedback/429_enables_limiter215--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)216 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)217 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)2182026/07/18 13:54:16 WARN Rate limiter enabled after throttle name=server-test rate=52192026/07/18 13:54:16 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:574042202026/07/18 13:54:16 WARN Rate limiter backed off name=server-test rate=5221=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter222=== CONT TestPathInfoCACompatibility/null_ca_field223=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter224--- PASS: TestScriptTokenBadJSON (0.02s)225=== CONT TestRateLimiterFeedback/503_enables_limiter226--- PASS: TestScriptTokenEmptyToken (0.02s)227=== CONT TestPathInfoCACompatibility/new_structured_format_-_text228=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive229=== CONT TestPathInfoCACompatibility/old_string_format_-_text230=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method231--- PASS: TestPathInfoCACompatibility (0.00s)232 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)233 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)234 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)235 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)236 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)237=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI238=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)239=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512240=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon241=== CONT TestConvertHashToNix32/SRI_format_to_Nix32242=== CONT TestConvertHashToNix32/invalid_format243=== CONT TestConvertHashToNix32/already_Nix32_format244--- PASS: TestConvertHashToNix32 (0.00s)245 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)246 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)247 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)248=== CONT TestParsePathInfoJSON/Nix_format249=== CONT TestEncodeNixBase32/test_string_hash250=== CONT TestGetStorePathHash/valid_store_path251=== CONT TestEncodeNixBase32/empty_input252--- PASS: TestEncodeNixBase32 (0.00s)253 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)254 --- PASS: TestEncodeNixBase32/empty_input (0.00s)255=== CONT TestParsePathInfoJSON/whitespace_only256=== CONT TestParsePathInfoJSON/invalid_JSON257=== CONT TestParsePathInfoJSON/empty_input258=== CONT TestParsePathInfoJSON/Lix_format259--- PASS: TestParsePathInfoJSON (0.00s)260 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)261 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)262 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)263 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)264 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)265=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error266=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error267=== CONT TestGetStorePathHash/basename_without_hyphen_should_error268--- PASS: TestGetStorePathHash (0.00s)269 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)270 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)271 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)272 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)273=== CONT TestUploadMultipart_SupersededByPeer/exists2742026/07/18 13:54:16 WARN Rate limiter enabled after throttle name=server-test rate=52752026/07/18 13:54:16 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:57410276--- PASS: TestPathInfoHashCompatibility (0.00s)277 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)278 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)279 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)280 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)281=== CONT TestPartSizeForNAR/zero_stays_at_minimum282=== CONT TestUploadMultipart_SupersededByPeer/missing2832026/07/18 13:54:16 WARN Rate limiter backed off name=server-test rate=5284--- PASS: TestRateLimiterFeedback (0.00s)285 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)286 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)287 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)288 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)289=== CONT TestPartSizeForNAR/1_TiB290=== CONT TestPartSizeForNAR/capped_at_5_GiB291=== CONT TestPartSizeForNAR/5_TiB_S3_max_object292=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum293=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts294=== CONT TestPartSizeForNAR/small_stays_at_minimum295--- PASS: TestPartSizeForNAR (0.00s)296 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)297 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)298 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)299 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)300 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)301 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)302 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)303=== CONT TestSetClientTLSErrors/missing_cert_file304=== CONT TestSetClientTLSErrors/invalid_ca_file305=== CONT TestSetClientTLSErrors/missing_ca_file306=== CONT TestSetClientTLSErrors/missing_key_file307=== CONT TestSetClientTLS/rejects_connection_without_client_cert308=== CONT TestSetClientTLS/preserves_debug_logging_transport309--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)310 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)311 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)312=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA313--- PASS: TestSetClientTLSErrors (0.01s)314 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)315 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)316 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)317 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3182026/07/18 13:54:16 http: TLS handshake error from 127.0.0.1:57416: remote error: tls: bad certificate319--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)320--- PASS: TestSetClientTLS (0.00s)321 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)322 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)323 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)324--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)325--- PASS: TestDumpPathWriterError (0.04s)326--- PASS: TestDumpPathSingleFile (0.13s)327--- PASS: TestCaseHackSuffix (0.12s)328--- PASS: TestDumpPathMatchesNix (0.13s)329--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)330PASS331Running server tests...332The files belonging to this database system will be owned by user "_nixbld1".333This user must also own the server process.334335The database cluster will be initialized with locale "C".336The default database encoding has accordingly been set to "SQL_ASCII".337The default text search configuration will be set to "english".338339Data page checksums are enabled.340341creating directory /nix/var/nix/builds/nix-47566-740631855/postgres3903279396/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-47566-740631855/postgres3903279396/data -l logfile start3583592026-07-18 13:54:19.842 UTC [47603] LOG: starting PostgreSQL 18.4 on aarch64-apple-darwin25.3.0, compiled by clang version 21.1.8, 64-bit3602026-07-18 13:54:19.842 UTC [47603] LOG: listening on Unix socket "/nix/var/nix/builds/nix-47566-740631855/postgres3903279396/.s.PGSQL.5432"3612026-07-18 13:54:19.844 UTC [47610] LOG: database system was shut down at 2026-07-18 13:54:19 UTC3622026-07-18 13:54:19.845 UTC [47603] LOG: database system is ready to accept connections363/nix/var/nix/builds/nix-47566-740631855/postgres3903279396:5432 - accepting connections364<jemalloc>: option background_thread currently supports pthread only365=== RUN TestService_AuthMiddleware366=== PAUSE TestService_AuthMiddleware367=== RUN TestService_AuthMiddleware_MTLSProxyHeader368=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader369=== RUN TestService_AuthMiddleware_MTLSBoundSubjects370=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects371=== RUN TestService_ReadAuthMiddleware372=== PAUSE TestService_ReadAuthMiddleware373=== RUN TestService_AuthMiddleware_OIDC374=== PAUSE TestService_AuthMiddleware_OIDC375=== RUN TestCacheConfigHandler376=== PAUSE TestCacheConfigHandler377=== RUN TestCacheStatsHandler378=== PAUSE TestCacheStatsHandler379=== RUN TestClientCADerivations380=== PAUSE TestClientCADerivations381=== RUN TestClientErrorHandling382=== PAUSE TestClientErrorHandling383=== RUN TestClientIntegration384=== PAUSE TestClientIntegration385=== RUN TestClientMultipleUploads386=== PAUSE TestClientMultipleUploads387=== RUN TestClientWithDependencies388=== PAUSE TestClientWithDependencies389=== RUN TestPinProtectsFromGC390=== PAUSE TestPinProtectsFromGC391=== RUN TestGCAdvisoryLockBlocksConcurrentRun392{"timestamp":"2026-07-18T13:54:21.743852Z","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(5)"}3932026-07-18 13:54:22.033 UTC [47660] ERROR: relation "goose_db_version" does not exist at character 363942026-07-18 13:54:22.033 UTC [47660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC3952026/07/18 13:54:22 OK 20241026095416_initial_model.sql (3.67ms)3962026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (510.33µs)3972026/07/18 13:54:22 OK 20251218171726_add_pins.sql (832.17µs)3982026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (954.17µs)3992026/07/18 13:54:22 goose: successfully migrated database to version: 202606281200004002026/07/18 13:54:22 OK 1_commit_pending_closure.sql (959.79µs)4012026/07/18 13:54:22 OK 2_object_stats_trigger.sql (209.83µs)4022026/07/18 13:54:22 goose: up to current file version: 2403--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.31s)404=== RUN TestGCBugBareHashReferences405=== PAUSE TestGCBugBareHashReferences406=== RUN TestGCMetrics407=== PAUSE TestGCMetrics408=== RUN TestGCTaskStore_StartNew409=== PAUSE TestGCTaskStore_StartNew410=== RUN TestGCTaskStore_DeduplicateSameParams411=== PAUSE TestGCTaskStore_DeduplicateSameParams412=== RUN TestGCTaskStore_ConflictDifferentParams413=== PAUSE TestGCTaskStore_ConflictDifferentParams414=== RUN TestGCTaskStore_GetEmpty415=== PAUSE TestGCTaskStore_GetEmpty416=== RUN TestGCTaskStore_GetReturnsLatest417=== PAUSE TestGCTaskStore_GetReturnsLatest418=== RUN TestGCTaskStore_CompletedAllowsNewTask419=== PAUSE TestGCTaskStore_CompletedAllowsNewTask420=== RUN TestGCTaskStore_PhaseUpdates421=== PAUSE TestGCTaskStore_PhaseUpdates422=== RUN TestGCTaskStore_Fail423=== PAUSE TestGCTaskStore_Fail424=== RUN TestGracefulShutdownDrainsInflight425=== PAUSE TestGracefulShutdownDrainsInflight426=== RUN TestService_healthCheckHandler427=== PAUSE TestService_healthCheckHandler428=== RUN TestGenerateLandingPage429=== PAUSE TestGenerateLandingPage430=== RUN TestNARDeduplicationMetadataUploadBug431=== PAUSE TestNARDeduplicationMetadataUploadBug432=== RUN TestMetricsInventory433=== PAUSE TestMetricsInventory434=== RUN TestService_NativeMTLS435=== PAUSE TestService_NativeMTLS436=== RUN TestServerTLSConfig437=== PAUSE TestServerTLSConfig438=== RUN TestMultipartCleanup439=== PAUSE TestMultipartCleanup440=== RUN TestObjectStatsTrigger441=== PAUSE TestObjectStatsTrigger442=== RUN TestOrphanedObjectsGC443=== PAUSE TestOrphanedObjectsGC444=== RUN TestOrphanedObjectsGCStressTest445=== PAUSE TestOrphanedObjectsGCStressTest446=== RUN TestResurrectedObjectNotDeleted447=== PAUSE TestResurrectedObjectNotDeleted448=== RUN TestParseSingleRange449=== PAUSE TestParseSingleRange450=== RUN TestIsValidCachePath451=== PAUSE TestIsValidCachePath452=== RUN TestReadProxyNarinfo453=== PAUSE TestReadProxyNarinfo454=== RUN TestReadProxyNarinfoAlreadyDecompressed455=== PAUSE TestReadProxyNarinfoAlreadyDecompressed456=== RUN TestReadProxyNarStreaming457=== PAUSE TestReadProxyNarStreaming458=== RUN TestReadProxy404459=== PAUSE TestReadProxy404460=== RUN TestReadProxyInvalidPath461=== PAUSE TestReadProxyInvalidPath462=== RUN TestReadProxyHead463=== PAUSE TestReadProxyHead464=== RUN TestReadProxyConditionalGet465=== PAUSE TestReadProxyConditionalGet466=== RUN TestReadProxyRootRedirectsToIndexHTML467=== PAUSE TestReadProxyRootRedirectsToIndexHTML468=== RUN TestReadProxyDisabled469=== PAUSE TestReadProxyDisabled470=== RUN TestReadProxyRangeRequest471=== PAUSE TestReadProxyRangeRequest472=== RUN TestRedundantMultipartUpload473=== PAUSE TestRedundantMultipartUpload474=== RUN TestCompleteMultipartUpload_ErrorButObjectExists475=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists476=== RUN TestCompletedNarNotReofferedAcrossClosures477=== PAUSE TestCompletedNarNotReofferedAcrossClosures478=== RUN TestService_Rustfstest479=== PAUSE TestService_Rustfstest480=== RUN TestSystemdListenerNotActivated481--- PASS: TestSystemdListenerNotActivated (0.00s)482=== RUN TestWatchdogBeatsWhenHealthy483--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)484=== RUN TestWatchdogSkipsWhenUnhealthy4852026/07/18 13:54:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4862026/07/18 13:54:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4872026/07/18 13:54:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4882026/07/18 13:54:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4892026/07/18 13:54:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4902026/07/18 13:54:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4912026/07/18 13:54:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4922026/07/18 13:54:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4932026/07/18 13:54:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4942026/07/18 13:54:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"495--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)496=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle497=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle498=== RUN TestProxyWriteTimeout499=== PAUSE TestProxyWriteTimeout500=== RUN TestIsValidUploadKey501=== PAUSE TestIsValidUploadKey502=== RUN TestUploadHandlersRejectInvalidKeys503=== PAUSE TestUploadHandlersRejectInvalidKeys504=== RUN TestUploadHandlersRejectOversizedBody505=== PAUSE TestUploadHandlersRejectOversizedBody506=== RUN TestService_cleanupPendingClosuresHandler507=== PAUSE TestService_cleanupPendingClosuresHandler508=== RUN TestService_createPendingClosureHandler509=== PAUSE TestService_createPendingClosureHandler510=== RUN TestService_verifyS3Integrity511=== PAUSE TestService_verifyS3Integrity512=== RUN TestCompleteMultipartUnregistered513=== PAUSE TestCompleteMultipartUnregistered514=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT515=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT516=== CONT TestService_AuthMiddleware517=== CONT TestObjectStatsTrigger518=== CONT TestReadProxyRangeRequest519=== CONT TestReadProxyNarStreaming520=== CONT TestUploadHandlersRejectInvalidKeys521=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info522=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info523=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal524=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal525=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT526=== CONT TestCompleteMultipartUnregistered527=== CONT TestService_verifyS3Integrity528=== CONT TestService_createPendingClosureHandler529=== CONT TestService_cleanupPendingClosuresHandler530=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key531=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key532=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key533=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key534=== CONT TestUploadHandlersRejectOversizedBody535=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart536=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart537=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts538=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts539=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure540=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure541=== CONT TestGCTaskStore_DeduplicateSameParams542--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)543=== CONT TestMultipartCleanup5442026-07-18 13:54:22.571 UTC [47683] ERROR: relation "goose_db_version" does not exist at character 365452026-07-18 13:54:22.571 UTC [47683] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5462026-07-18 13:54:22.571 UTC [47682] ERROR: relation "goose_db_version" does not exist at character 365472026-07-18 13:54:22.571 UTC [47682] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5482026-07-18 13:54:22.577 UTC [47684] ERROR: relation "goose_db_version" does not exist at character 365492026-07-18 13:54:22.577 UTC [47684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5502026-07-18 13:54:22.580 UTC [47685] ERROR: relation "goose_db_version" does not exist at character 365512026-07-18 13:54:22.580 UTC [47685] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5522026-07-18 13:54:22.581 UTC [47686] ERROR: relation "goose_db_version" does not exist at character 365532026-07-18 13:54:22.581 UTC [47686] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5542026-07-18 13:54:22.583 UTC [47688] ERROR: relation "goose_db_version" does not exist at character 365552026-07-18 13:54:22.583 UTC [47688] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5562026-07-18 13:54:22.583 UTC [47687] ERROR: relation "goose_db_version" does not exist at character 365572026-07-18 13:54:22.583 UTC [47687] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5582026-07-18 13:54:22.583 UTC [47690] ERROR: relation "goose_db_version" does not exist at character 365592026-07-18 13:54:22.583 UTC [47690] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5602026/07/18 13:54:22 OK 20241026095416_initial_model.sql (6.14ms)5612026/07/18 13:54:22 OK 20241026095416_initial_model.sql (6.71ms)5622026-07-18 13:54:22.584 UTC [47689] ERROR: relation "goose_db_version" does not exist at character 365632026-07-18 13:54:22.584 UTC [47689] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5642026-07-18 13:54:22.585 UTC [47691] ERROR: relation "goose_db_version" does not exist at character 365652026-07-18 13:54:22.585 UTC [47691] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5662026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (600.25µs)5672026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (844.46µs)5682026/07/18 13:54:22 OK 20251218171726_add_pins.sql (1.42ms)5692026/07/18 13:54:22 OK 20251218171726_add_pins.sql (1.78ms)5702026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (1.3ms)5712026/07/18 13:54:22 goose: successfully migrated database to version: 202606281200005722026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (1.68ms)5732026/07/18 13:54:22 goose: successfully migrated database to version: 202606281200005742026/07/18 13:54:22 OK 20241026095416_initial_model.sql (7.23ms)5752026/07/18 13:54:22 OK 1_commit_pending_closure.sql (1.76ms)5762026/07/18 13:54:22 OK 1_commit_pending_closure.sql (1.54ms)5772026/07/18 13:54:22 OK 2_object_stats_trigger.sql (351.42µs)5782026/07/18 13:54:22 goose: up to current file version: 25792026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (707.58µs)5802026/07/18 13:54:22 OK 2_object_stats_trigger.sql (617.75µs)5812026/07/18 13:54:22 goose: up to current file version: 25822026/07/18 13:54:22 OK 20241026095416_initial_model.sql (6.07ms)5832026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (810.54µs)5842026/07/18 13:54:22 OK 20251218171726_add_pins.sql (1.43ms)5852026/07/18 13:54:22 OK 20251218171726_add_pins.sql (1.79ms)5862026/07/18 13:54:22 OK 20241026095416_initial_model.sql (7.11ms)5872026/07/18 13:54:22 OK 20241026095416_initial_model.sql (8.33ms)5882026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (2.25ms)5892026/07/18 13:54:22 goose: successfully migrated database to version: 202606281200005902026/07/18 13:54:22 OK 20241026095416_initial_model.sql (8.41ms)5912026/07/18 13:54:22 OK 20241026095416_initial_model.sql (9.13ms)5922026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (983.75µs)5932026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (577.08µs)5942026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (1.32ms)5952026/07/18 13:54:22 goose: successfully migrated database to version: 202606281200005962026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)5972026/07/18 13:54:22 OK 20241026095416_initial_model.sql (7.13ms)5982026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (830.38µs)5992026/07/18 13:54:22 OK 20241026095416_initial_model.sql (7.39ms)6002026/07/18 13:54:22 OK 20251218171726_add_pins.sql (1.01ms)601{"timestamp":"2026-07-18T13:54:22.596323Z","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(5)"}6022026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (919.5µs)6032026/07/18 13:54:22 OK 20251218171726_add_pins.sql (1.4ms)6042026/07/18 13:54:22 OK 1_commit_pending_closure.sql (2.07ms)6052026/07/18 13:54:22 OK 1_commit_pending_closure.sql (1.42ms)6062026/07/18 13:54:22 OK 20251218171726_add_pins.sql (928.54µs)6072026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (752.29µs)6082026/07/18 13:54:22 OK 20251218171726_add_pins.sql (1.38ms)6092026/07/18 13:54:22 OK 2_object_stats_trigger.sql (442.96µs)6102026/07/18 13:54:22 goose: up to current file version: 26112026/07/18 13:54:22 OK 2_object_stats_trigger.sql (555.58µs)6122026/07/18 13:54:22 goose: up to current file version: 26132026/07/18 13:54:22 OK 20251218171726_add_pins.sql (1.03ms)6142026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (1.15ms)6152026/07/18 13:54:22 goose: successfully migrated database to version: 202606281200006162026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (1.84ms)6172026/07/18 13:54:22 goose: successfully migrated database to version: 202606281200006182026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (1.6ms)619--- PASS: TestObjectStatsTrigger (0.32s)6202026/07/18 13:54:22 goose: successfully migrated database to version: 20260628120000621=== CONT TestServerTLSConfig622=== RUN TestServerTLSConfig/no_client_CA623=== PAUSE TestServerTLSConfig/no_client_CA624=== RUN TestServerTLSConfig/missing_CA_file625=== PAUSE TestServerTLSConfig/missing_CA_file626=== RUN TestServerTLSConfig/not_a_PEM_file627=== PAUSE TestServerTLSConfig/not_a_PEM_file628=== CONT TestService_NativeMTLS6292026/07/18 13:54:22 OK 20251218171726_add_pins.sql (2.23ms)6302026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (1.97ms)6312026/07/18 13:54:22 goose: successfully migrated database to version: 202606281200006322026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (2.88ms)6332026/07/18 13:54:22 goose: successfully migrated database to version: 202606281200006342026/07/18 13:54:22 OK 1_commit_pending_closure.sql (1.96ms)6352026/07/18 13:54:22 OK 1_commit_pending_closure.sql (1.99ms)6362026/07/18 13:54:22 INFO Received uploads request method=POST path=/api/pending_closures6372026/07/18 13:54:22 INFO Received uploads request method=POST path=/api/pending_closures6382026/07/18 13:54:22 OK 2_object_stats_trigger.sql (419.38µs)6392026/07/18 13:54:22 goose: up to current file version: 26402026/07/18 13:54:22 INFO Received uploads request method=POST path=/api/pending_closures6412026/07/18 13:54:22 OK 1_commit_pending_closure.sql (2.38ms)6422026/07/18 13:54:22 OK 2_object_stats_trigger.sql (912.58µs)6432026/07/18 13:54:22 goose: up to current file version: 26442026/07/18 13:54:22 OK 1_commit_pending_closure.sql (1.27ms)6452026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (4.15ms)6462026/07/18 13:54:22 goose: successfully migrated database to version: 20260628120000647--- PASS: TestReadProxyNarStreaming (0.32s)648=== CONT TestMetricsInventory6492026/07/18 13:54:22 OK 2_object_stats_trigger.sql (2.73ms)6502026/07/18 13:54:22 goose: up to current file version: 26512026/07/18 13:54:22 OK 2_object_stats_trigger.sql (497.92µs)6522026/07/18 13:54:22 goose: up to current file version: 26532026/07/18 13:54:22 OK 1_commit_pending_closure.sql (3.88ms)6542026/07/18 13:54:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete6552026/07/18 13:54:22 OK 1_commit_pending_closure.sql (1.78ms)6562026/07/18 13:54:22 OK 2_object_stats_trigger.sql (497.54µs)6572026/07/18 13:54:22 goose: up to current file version: 26582026/07/18 13:54:22 OK 2_object_stats_trigger.sql (354.42µs)6592026/07/18 13:54:22 goose: up to current file version: 26602026/07/18 13:54:22 INFO Received cleanup request method=DELETE path=/api/pending_closures6612026/07/18 13:54:22 INFO Received uploads request method=POST path=/api/pending_closures6622026/07/18 13:54:22 INFO Received uploads request method=POST path=/api/pending_closures6632026/07/18 13:54:22 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst664--- PASS: TestCompleteMultipartUnregistered (0.33s)665=== CONT TestNARDeduplicationMetadataUploadBug6662026/07/18 13:54:22 INFO Received uploads request method=POST path=/api/pending_closures6672026/07/18 13:54:22 INFO Aborted multipart uploads count=06682026/07/18 13:54:22 INFO Received uploads request method=POST path=/api/pending_closures6692026/07/18 13:54:22 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"670--- PASS: TestService_AuthMiddleware (0.33s)671=== CONT TestGenerateLandingPage672--- PASS: TestGenerateLandingPage (0.00s)673=== CONT TestService_healthCheckHandler674--- PASS: TestReadProxyRangeRequest (0.33s)675=== CONT TestGracefulShutdownDrainsInflight6762026/07/18 13:54:22 INFO Starting HTTP server address=127.0.0.1:574856772026/07/18 13:54:22 INFO Shutdown signal received, draining in-flight requests timeout=10s678--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.34s)679=== CONT TestGCTaskStore_Fail680--- PASS: TestGCTaskStore_Fail (0.00s)681=== CONT TestGCTaskStore_PhaseUpdates682--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)683=== CONT TestGCTaskStore_CompletedAllowsNewTask684--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)685=== CONT TestGCTaskStore_GetReturnsLatest686--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)687=== CONT TestGCTaskStore_GetEmpty6882026/07/18 13:54:22 INFO Received cleanup request method=DELETE path=/api/pending_closures689--- PASS: TestGCTaskStore_GetEmpty (0.00s)690=== CONT TestGCTaskStore_ConflictDifferentParams691--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)692=== CONT TestService_Rustfstest6932026/07/18 13:54:22 INFO Aborted multipart uploads count=16942026/07/18 13:54:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete6952026-07-18 13:54:22.618 UTC [47686] ERROR: Closure does not exist: id=16962026-07-18 13:54:22.618 UTC [47686] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE6972026-07-18 13:54:22.618 UTC [47686] STATEMENT: -- name: CommitPendingClosure :exec698 SELECT commit_pending_closure($1::bigint)699 700--- PASS: TestService_cleanupPendingClosuresHandler (0.34s)701=== CONT TestIsValidUploadKey702=== RUN TestIsValidUploadKey/narinfo703=== PAUSE TestIsValidUploadKey/narinfo704=== RUN TestIsValidUploadKey/nar_zst705=== PAUSE TestIsValidUploadKey/nar_zst706=== RUN TestIsValidUploadKey/nar_xz707=== PAUSE TestIsValidUploadKey/nar_xz708=== RUN TestIsValidUploadKey/nar_plain709=== PAUSE TestIsValidUploadKey/nar_plain710=== RUN TestIsValidUploadKey/listing711=== PAUSE TestIsValidUploadKey/listing712=== RUN TestIsValidUploadKey/build_log713=== PAUSE TestIsValidUploadKey/build_log714=== RUN TestIsValidUploadKey/build_log_home-manager_file715=== PAUSE TestIsValidUploadKey/build_log_home-manager_file716=== RUN TestIsValidUploadKey/build_log_plus_in_name717=== PAUSE TestIsValidUploadKey/build_log_plus_in_name718=== RUN TestIsValidUploadKey/build_log_question_mark719=== PAUSE TestIsValidUploadKey/build_log_question_mark720=== RUN TestIsValidUploadKey/build_log_equals721=== PAUSE TestIsValidUploadKey/build_log_equals722=== RUN TestIsValidUploadKey/realisation723=== PAUSE TestIsValidUploadKey/realisation724=== RUN TestIsValidUploadKey/realisation_plus_in_output725=== PAUSE TestIsValidUploadKey/realisation_plus_in_output726=== RUN TestIsValidUploadKey/nix-cache-info727=== PAUSE TestIsValidUploadKey/nix-cache-info728=== RUN TestIsValidUploadKey/index.html729=== PAUSE TestIsValidUploadKey/index.html730=== RUN TestIsValidUploadKey/narinfo_key,_nar_type731=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type732=== RUN TestIsValidUploadKey/nar_key,_narinfo_type733=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type734=== RUN TestIsValidUploadKey/listing_key,_narinfo_type735=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type736=== RUN TestIsValidUploadKey/traversal737=== PAUSE TestIsValidUploadKey/traversal738=== RUN TestIsValidUploadKey/traversal_nar739=== PAUSE TestIsValidUploadKey/traversal_nar740=== RUN TestIsValidUploadKey/absolute741=== PAUSE TestIsValidUploadKey/absolute742=== RUN TestIsValidUploadKey/empty_key743=== PAUSE TestIsValidUploadKey/empty_key744=== RUN TestIsValidUploadKey/unknown_type745=== PAUSE TestIsValidUploadKey/unknown_type746=== CONT TestProxyWriteTimeout747=== RUN TestProxyWriteTimeout/narinfo748=== PAUSE TestProxyWriteTimeout/narinfo749=== RUN TestProxyWriteTimeout/1_GiB_nar750=== PAUSE TestProxyWriteTimeout/1_GiB_nar751=== RUN TestProxyWriteTimeout/10_GiB_nar752=== PAUSE TestProxyWriteTimeout/10_GiB_nar753=== RUN TestProxyWriteTimeout/unknown_size754=== PAUSE TestProxyWriteTimeout/unknown_size755=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle756--- PASS: TestGracefulShutdownDrainsInflight (0.07s)757=== CONT TestCompleteMultipartUpload_ErrorButObjectExists7582026-07-18 13:54:22.708 UTC [47727] ERROR: relation "goose_db_version" does not exist at character 367592026-07-18 13:54:22.708 UTC [47727] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7602026/07/18 13:54:22 INFO Received cleanup request method=DELETE path=/api/pending_closures7612026/07/18 13:54:22 INFO Aborted multipart uploads count=17622026/07/18 13:54:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7632026/07/18 13:54:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7642026/07/18 13:54:22 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YzZlNDA2NTItZWM4OC00ZTdjLTg4YTQtNzM4NDFkZDYyZWEzLjI2OWU3MTFlLWQ1NDUtNDg5OS05NWU1LWVjNjk5M2UzZGQ5OXgxNzg0MzgyODYyNjA3Njk2MDAw parts=107652026/07/18 13:54:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7662026/07/18 13:54:22 INFO Completed upload id=17672026/07/18 13:54:22 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000007682026/07/18 13:54:22 INFO Received uploads request method=POST path=/api/pending_closures7692026/07/18 13:54:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures770--- PASS: TestMultipartCleanup (0.40s)771=== CONT TestCompletedNarNotReofferedAcrossClosures7722026/07/18 13:54:22 INFO Aborted multipart uploads count=07732026/07/18 13:54:22 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YzZlNDA2NTItZWM4OC00ZTdjLTg4YTQtNzM4NDFkZDYyZWEzLjJjNGUzZGM2LWEwNGQtNDg4Zi1hZjQ2LTg3YWJiYzcxMjZhNHgxNzg0MzgyODYyNjExNTY3MDAw parts=107742026/07/18 13:54:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7752026/07/18 13:54:22 INFO Completed upload id=17762026/07/18 13:54:22 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=07772026/07/18 13:54:22 INFO Received uploads request method=POST path=/api/pending_closures7782026/07/18 13:54:22 INFO Received uploads request method=POST path=/api/pending_closures7792026/07/18 13:54:22 INFO Vacuumed table table=pending_closures7802026/07/18 13:54:22 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo7812026/07/18 13:54:22 WARN Found objects in DB but missing from S3, will re-upload count=1782--- PASS: TestService_verifyS3Integrity (0.47s)783=== CONT TestClientErrorHandling784=== RUN TestClientErrorHandling/InvalidStorePath785=== PAUSE TestClientErrorHandling/InvalidStorePath786=== RUN TestClientErrorHandling/InvalidAuthToken787=== PAUSE TestClientErrorHandling/InvalidAuthToken788=== RUN TestClientErrorHandling/ServerNotAvailable789=== PAUSE TestClientErrorHandling/ServerNotAvailable790=== CONT TestGCTaskStore_StartNew791--- PASS: TestGCTaskStore_StartNew (0.00s)792=== CONT TestGCMetrics7932026-07-18 13:54:22.758 UTC [47732] ERROR: relation "goose_db_version" does not exist at character 367942026-07-18 13:54:22.758 UTC [47732] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7952026/07/18 13:54:22 INFO Vacuumed table table=pending_objects7962026/07/18 13:54:22 OK 20241026095416_initial_model.sql (20.09ms)7972026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (377.5µs)7982026/07/18 13:54:22 OK 20251218171726_add_pins.sql (724.42µs)7992026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (893.75µs)8002026/07/18 13:54:22 goose: successfully migrated database to version: 202606281200008012026/07/18 13:54:22 OK 1_commit_pending_closure.sql (804.63µs)8022026/07/18 13:54:22 OK 2_object_stats_trigger.sql (211.63µs)8032026/07/18 13:54:22 goose: up to current file version: 28042026/07/18 13:54:22 INFO Vacuumed table table=multipart_uploads8052026/07/18 13:54:22 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8062026/07/18 13:54:22 WARN mTLS auth: subject not in bound subjects subject="CN=writer"807--- PASS: TestService_NativeMTLS (0.18s)808=== CONT TestGCBugBareHashReferences8092026/07/18 13:54:22 INFO Vacuumed table table=closures8102026/07/18 13:54:22 INFO Vacuumed table table=objects8112026/07/18 13:54:22 OK 20241026095416_initial_model.sql (19.57ms)8122026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (344.67µs)8132026/07/18 13:54:22 OK 20251218171726_add_pins.sql (860.04µs)8142026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (3.83ms)8152026/07/18 13:54:22 goose: successfully migrated database to version: 202606281200008162026/07/18 13:54:22 OK 1_commit_pending_closure.sql (1.26ms)8172026/07/18 13:54:22 OK 2_object_stats_trigger.sql (319.46µs)8182026/07/18 13:54:22 goose: up to current file version: 28192026-07-18 13:54:22.807 UTC [47736] ERROR: relation "goose_db_version" does not exist at character 368202026-07-18 13:54:22.807 UTC [47736] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC821--- PASS: TestMetricsInventory (0.22s)822=== CONT TestPinProtectsFromGC8232026/07/18 13:54:22 OK 20241026095416_initial_model.sql (8.3ms)8242026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (427.54µs)8252026/07/18 13:54:22 OK 20251218171726_add_pins.sql (735.88µs)8262026-07-18 13:54:22.828 UTC [47738] ERROR: relation "goose_db_version" does not exist at character 368272026-07-18 13:54:22.828 UTC [47738] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8282026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (5.89ms)8292026/07/18 13:54:22 goose: successfully migrated database to version: 202606281200008302026/07/18 13:54:22 OK 1_commit_pending_closure.sql (895µs)8312026/07/18 13:54:22 OK 2_object_stats_trigger.sql (215µs)8322026/07/18 13:54:22 goose: up to current file version: 28332026/07/18 13:54:22 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000834--- PASS: TestService_createPendingClosureHandler (0.56s)835=== CONT TestClientWithDependencies8362026/07/18 13:54:22 INFO Created nix-cache-info in bucket bucket=bucket148372026/07/18 13:54:22 OK 20241026095416_initial_model.sql (8ms)8382026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (398.5µs)8392026/07/18 13:54:22 OK 20251218171726_add_pins.sql (1.43ms)8402026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (3.35ms)8412026/07/18 13:54:22 goose: successfully migrated database to version: 202606281200008422026/07/18 13:54:22 OK 1_commit_pending_closure.sql (1.29ms)8432026/07/18 13:54:22 OK 2_object_stats_trigger.sql (696.5µs)8442026/07/18 13:54:22 goose: up to current file version: 2845--- PASS: TestService_healthCheckHandler (0.24s)846=== CONT TestClientMultipleUploads847=== NAME TestNARDeduplicationMetadataUploadBug848 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-47566-740631855/TestNARDeduplicationMetadataUploadBug2107962480/001/store/bp4zglfqpp631arns7n0izdsvy4qp6wm-file1.txt8492026-07-18 13:54:22.952 UTC [47747] ERROR: relation "goose_db_version" does not exist at character 368502026-07-18 13:54:22.952 UTC [47747] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8512026-07-18 13:54:22.970 UTC [47749] ERROR: relation "goose_db_version" does not exist at character 368522026-07-18 13:54:22.970 UTC [47749] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8532026/07/18 13:54:22 OK 20241026095416_initial_model.sql (15.41ms)8542026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (700.92µs)8552026/07/18 13:54:22 OK 20251218171726_add_pins.sql (3.2ms)8562026/07/18 13:54:22 OK 20241026095416_initial_model.sql (6.99ms)8572026/07/18 13:54:22 OK 20251210153512_drop_unused_gin_index.sql (645.08µs)8582026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (2.95ms)8592026/07/18 13:54:22 goose: successfully migrated database to version: 202606281200008602026/07/18 13:54:22 OK 20251218171726_add_pins.sql (1.03ms)8612026/07/18 13:54:22 OK 1_commit_pending_closure.sql (1.12ms)8622026/07/18 13:54:22 OK 2_object_stats_trigger.sql (293.83µs)8632026/07/18 13:54:22 goose: up to current file version: 28642026/07/18 13:54:22 INFO Received uploads request method=POST path=/api/pending_closures8652026/07/18 13:54:22 OK 20260628120000_add_object_size_and_stats.sql (2.64ms)8662026/07/18 13:54:22 goose: successfully migrated database to version: 202606281200008672026/07/18 13:54:22 OK 1_commit_pending_closure.sql (1.87ms)8682026/07/18 13:54:22 OK 2_object_stats_trigger.sql (221.75µs)8692026/07/18 13:54:22 goose: up to current file version: 2870--- PASS: TestService_Rustfstest (0.38s)871=== CONT TestClientIntegration8722026/07/18 13:54:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8732026/07/18 13:54:23 INFO Received uploads request method=POST path=/api/pending_closures8742026/07/18 13:54:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8752026/07/18 13:54:23 INFO Uploading bp4zglfqpp631arns7n0izdsvy4qp6wm-file1.txt (160B)8762026/07/18 13:54:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8772026/07/18 13:54:23 INFO Signed narinfos id=1 count=18782026/07/18 13:54:23 INFO Uploading 1 narinfos8792026/07/18 13:54:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8802026/07/18 13:54:23 INFO Completed upload id=18812026/07/18 13:54:23 INFO Upload complete. (88ms)882=== NAME TestNARDeduplicationMetadataUploadBug883 metadata_upload_test.go:54: Retrieved narinfo from S3:884 StorePath: /nix/var/nix/builds/nix-47566-740631855/TestNARDeduplicationMetadataUploadBug2107962480/001/store/bp4zglfqpp631arns7n0izdsvy4qp6wm-file1.txt885 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst886 Compression: zstd887 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf888 NarSize: 160889 References: 890 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf891 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)892 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):893 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}894 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-47566-740631855/TestNARDeduplicationMetadataUploadBug2107962480/001/store/73581av122skqx9ky7ilwk5fhz51n3wa-file2.txt8952026-07-18 13:54:23.185 UTC [47763] ERROR: relation "goose_db_version" does not exist at character 368962026-07-18 13:54:23.185 UTC [47763] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8972026-07-18 13:54:23.187 UTC [47764] ERROR: relation "goose_db_version" does not exist at character 368982026-07-18 13:54:23.187 UTC [47764] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8992026/07/18 13:54:23 INFO Received uploads request method=POST path=/api/pending_closures9002026/07/18 13:54:23 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)9012026/07/18 13:54:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9022026/07/18 13:54:23 INFO Signed narinfos id=2 count=19032026/07/18 13:54:23 INFO Uploading 1 narinfos9042026-07-18 13:54:23.209 UTC [47766] ERROR: relation "goose_db_version" does not exist at character 369052026-07-18 13:54:23.209 UTC [47766] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9062026/07/18 13:54:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9072026/07/18 13:54:23 INFO Completed upload id=29082026/07/18 13:54:23 INFO Upload complete. (72ms)909 metadata_upload_test.go:76: Retrieved narinfo from S3:910 StorePath: /nix/var/nix/builds/nix-47566-740631855/TestNARDeduplicationMetadataUploadBug2107962480/001/store/73581av122skqx9ky7ilwk5fhz51n3wa-file2.txt911 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst912 Compression: zstd913 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf914 NarSize: 160915 References: 916 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf917 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)918 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):919 {"version":1,"root":{"type":"regular","size":44}}920--- PASS: TestNARDeduplicationMetadataUploadBug (0.61s)921=== CONT TestOrphanedObjectsGCStressTest9222026/07/18 13:54:23 OK 20241026095416_initial_model.sql (9.51ms)9232026/07/18 13:54:23 OK 20241026095416_initial_model.sql (6.47ms)9242026/07/18 13:54:23 OK 20251210153512_drop_unused_gin_index.sql (425.25µs)9252026/07/18 13:54:23 OK 20251210153512_drop_unused_gin_index.sql (479µs)9262026/07/18 13:54:23 OK 20251218171726_add_pins.sql (2.22ms)9272026/07/18 13:54:23 OK 20251218171726_add_pins.sql (2.46ms)9282026-07-18 13:54:23.230 UTC [47769] ERROR: relation "goose_db_version" does not exist at character 369292026-07-18 13:54:23.230 UTC [47769] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9302026/07/18 13:54:23 OK 20241026095416_initial_model.sql (19.2ms)9312026/07/18 13:54:23 OK 20260628120000_add_object_size_and_stats.sql (11.46ms)9322026/07/18 13:54:23 goose: successfully migrated database to version: 202606281200009332026/07/18 13:54:23 OK 20260628120000_add_object_size_and_stats.sql (12.04ms)9342026/07/18 13:54:23 goose: successfully migrated database to version: 202606281200009352026/07/18 13:54:23 OK 20251210153512_drop_unused_gin_index.sql (806.08µs)9362026/07/18 13:54:23 OK 1_commit_pending_closure.sql (1.14ms)9372026/07/18 13:54:23 OK 1_commit_pending_closure.sql (1.67ms)9382026/07/18 13:54:23 OK 2_object_stats_trigger.sql (212.88µs)9392026/07/18 13:54:23 goose: up to current file version: 29402026/07/18 13:54:23 OK 2_object_stats_trigger.sql (320.83µs)9412026/07/18 13:54:23 goose: up to current file version: 29422026/07/18 13:54:23 INFO Received uploads request method=POST path=/api/pending_closures9432026-07-18 13:54:23.245 UTC [47770] ERROR: relation "goose_db_version" does not exist at character 369442026-07-18 13:54:23.245 UTC [47770] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9452026/07/18 13:54:23 OK 20251218171726_add_pins.sql (11.81ms)9462026/07/18 13:54:23 OK 20260628120000_add_object_size_and_stats.sql (2.96ms)9472026/07/18 13:54:23 goose: successfully migrated database to version: 202606281200009482026/07/18 13:54:23 OK 1_commit_pending_closure.sql (1.05ms)9492026/07/18 13:54:23 OK 2_object_stats_trigger.sql (530.17µs)9502026/07/18 13:54:23 goose: up to current file version: 29512026/07/18 13:54:23 OK 20241026095416_initial_model.sql (18.99ms)9522026/07/18 13:54:23 INFO Received uploads request method=POST path=/api/pending_closures9532026/07/18 13:54:23 OK 20251210153512_drop_unused_gin_index.sql (456.13µs)9542026/07/18 13:54:23 OK 20251218171726_add_pins.sql (4.59ms)9552026/07/18 13:54:23 OK 20260628120000_add_object_size_and_stats.sql (2.84ms)9562026/07/18 13:54:23 goose: successfully migrated database to version: 202606281200009572026/07/18 13:54:23 OK 20241026095416_initial_model.sql (9.83ms)9582026/07/18 13:54:23 OK 20251210153512_drop_unused_gin_index.sql (615.83µs)9592026/07/18 13:54:23 OK 1_commit_pending_closure.sql (1.52ms)9602026/07/18 13:54:23 OK 2_object_stats_trigger.sql (715.46µs)9612026/07/18 13:54:23 goose: up to current file version: 29622026/07/18 13:54:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete963{"timestamp":"2026-07-18T13:54:23.268185Z","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(6)"}964{"timestamp":"2026-07-18T13:54:23.268206Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket20, 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(6)"}9652026/07/18 13:54:23 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=YzZlNDA2NTItZWM4OC00ZTdjLTg4YTQtNzM4NDFkZDYyZWEzLjE1NTg1NjdmLWUwZWQtNDVmZC1hOTBkLTdmODc0MzcwMTJmZXgxNzg0MzgyODYzMjYyNjM1MDAw9662026/07/18 13:54:23 OK 20251218171726_add_pins.sql (4.23ms)9672026/07/18 13:54:23 INFO Aborted multipart uploads count=09682026/07/18 13:54:23 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzZlNDA2NTItZWM4OC00ZTdjLTg4YTQtNzM4NDFkZDYyZWEzLjE1NTg1NjdmLWUwZWQtNDVmZC1hOTBkLTdmODc0MzcwMTJmZXgxNzg0MzgyODYzMjYyNjM1MDAw parts=1969--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.59s)970=== CONT TestResurrectedObjectNotDeleted9712026/07/18 13:54:23 OK 20260628120000_add_object_size_and_stats.sql (5.78ms)9722026/07/18 13:54:23 goose: successfully migrated database to version: 202606281200009732026/07/18 13:54:23 WARN Force mode enabled - objects will be deleted immediately without grace period9742026/07/18 13:54:23 OK 1_commit_pending_closure.sql (2.45ms)9752026/07/18 13:54:23 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=09762026/07/18 13:54:23 OK 2_object_stats_trigger.sql (316.42µs)9772026/07/18 13:54:23 goose: up to current file version: 29782026/07/18 13:54:23 INFO Vacuumed table table=pending_closures9792026/07/18 13:54:23 INFO Vacuumed table table=pending_objects9802026/07/18 13:54:23 INFO Vacuumed table table=multipart_uploads9812026/07/18 13:54:23 INFO Vacuumed table table=closures9822026/07/18 13:54:23 INFO Vacuumed table table=objects983--- PASS: TestGCMetrics (0.53s)984=== CONT TestReadProxyNarinfo9852026/07/18 13:54:23 INFO Created nix-cache-info in bucket bucket=bucket229862026-07-18 13:54:23.288 UTC [47776] ERROR: relation "goose_db_version" does not exist at character 369872026-07-18 13:54:23.288 UTC [47776] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9882026-07-18 13:54:23.313 UTC [47779] ERROR: relation "goose_db_version" does not exist at character 369892026-07-18 13:54:23.313 UTC [47779] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9902026/07/18 13:54:23 OK 20241026095416_initial_model.sql (56.48ms)9912026/07/18 13:54:23 OK 20251210153512_drop_unused_gin_index.sql (454.88µs)9922026/07/18 13:54:23 OK 20251218171726_add_pins.sql (1.19ms)9932026/07/18 13:54:23 OK 20241026095416_initial_model.sql (6.74ms)9942026/07/18 13:54:23 OK 20251210153512_drop_unused_gin_index.sql (515.54µs)9952026/07/18 13:54:23 OK 20251218171726_add_pins.sql (742.21µs)9962026/07/18 13:54:23 OK 20260628120000_add_object_size_and_stats.sql (7.98ms)9972026/07/18 13:54:23 goose: successfully migrated database to version: 202606281200009982026/07/18 13:54:23 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)9992026/07/18 13:54:23 goose: successfully migrated database to version: 2026062812000010002026/07/18 13:54:23 OK 1_commit_pending_closure.sql (1.41ms)10012026/07/18 13:54:23 OK 1_commit_pending_closure.sql (804.17µs)10022026/07/18 13:54:23 OK 2_object_stats_trigger.sql (268.71µs)10032026/07/18 13:54:23 goose: up to current file version: 210042026/07/18 13:54:23 OK 2_object_stats_trigger.sql (360.38µs)10052026/07/18 13:54:23 goose: up to current file version: 210062026/07/18 13:54:23 INFO Created nix-cache-info in bucket bucket=bucket2410072026/07/18 13:54:23 INFO Created nix-cache-info in bucket bucket=bucket231008=== NAME TestPinProtectsFromGC1009 client_integration_test.go:646: Pinned store path: /nix/var/nix/builds/nix-47566-740631855/TestPinProtectsFromGC3173657647/001/store/5jhp6qw7lsbcq25m2ziprpy6whifn4z3-pinned-file.txt1010 client_integration_test.go:647: Unpinned store path: /nix/var/nix/builds/nix-47566-740631855/TestPinProtectsFromGC3173657647/001/store/i5kyyl8x3ki40m5dis64cmrcqq18q698-unpinned-file.txt10112026/07/18 13:54:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10122026/07/18 13:54:23 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YzZlNDA2NTItZWM4OC00ZTdjLTg4YTQtNzM4NDFkZDYyZWEzLjU4ZmEzYzAyLTM3NGYtNDhjMS05YTRiLTdkYTBlNjlkNjc3MHgxNzg0MzgyODYzMjUzNjM2MDAw parts=1210132026/07/18 13:54:23 INFO Received uploads request method=POST path=/api/pending_closures1014--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.68s)1015=== CONT TestReadProxyNarinfoAlreadyDecompressed1016=== NAME TestClientMultipleUploads1017 client_integration_test.go:338: Created store path 0: /nix/var/nix/builds/nix-47566-740631855/TestClientMultipleUploads1532105287/001/store/0jmq71n6ccid8dfdqcsv339j9hiyxcy8-test-file-0.txt10182026-07-18 13:54:23.456 UTC [47793] ERROR: relation "goose_db_version" does not exist at character 3610192026-07-18 13:54:23.456 UTC [47793] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1020--- PASS: TestGCBugBareHashReferences (0.69s)1021=== CONT TestIsValidCachePath1022=== RUN TestIsValidCachePath/narinfo1023=== PAUSE TestIsValidCachePath/narinfo1024=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1025=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1026=== RUN TestIsValidCachePath/nar_zst1027=== PAUSE TestIsValidCachePath/nar_zst1028=== RUN TestIsValidCachePath/nar_xz1029=== PAUSE TestIsValidCachePath/nar_xz1030=== RUN TestIsValidCachePath/nar_bz21031=== PAUSE TestIsValidCachePath/nar_bz21032=== RUN TestIsValidCachePath/nar_uncompressed1033=== PAUSE TestIsValidCachePath/nar_uncompressed1034=== RUN TestIsValidCachePath/ls1035=== PAUSE TestIsValidCachePath/ls1036=== RUN TestIsValidCachePath/log1037=== PAUSE TestIsValidCachePath/log1038=== RUN TestIsValidCachePath/realisation1039=== PAUSE TestIsValidCachePath/realisation1040=== RUN TestIsValidCachePath/nix-cache-info1041=== PAUSE TestIsValidCachePath/nix-cache-info1042=== RUN TestIsValidCachePath/index.html1043=== PAUSE TestIsValidCachePath/index.html1044=== RUN TestIsValidCachePath/traversal_parent1045=== PAUSE TestIsValidCachePath/traversal_parent1046=== RUN TestIsValidCachePath/traversal_in_middle1047=== PAUSE TestIsValidCachePath/traversal_in_middle1048=== RUN TestIsValidCachePath/invalid_char_e1049=== PAUSE TestIsValidCachePath/invalid_char_e1050=== RUN TestIsValidCachePath/invalid_char_u1051=== PAUSE TestIsValidCachePath/invalid_char_u1052=== RUN TestIsValidCachePath/random_path1053=== PAUSE TestIsValidCachePath/random_path1054=== RUN TestIsValidCachePath/empty1055=== PAUSE TestIsValidCachePath/empty1056=== RUN TestIsValidCachePath/leading_slash1057=== PAUSE TestIsValidCachePath/leading_slash1058=== RUN TestIsValidCachePath/wrong_extension1059=== PAUSE TestIsValidCachePath/wrong_extension1060=== RUN TestIsValidCachePath/short_hash1061=== PAUSE TestIsValidCachePath/short_hash1062=== CONT TestReadProxyConditionalGet10632026/07/18 13:54:23 OK 20241026095416_initial_model.sql (7.48ms)10642026/07/18 13:54:23 OK 20251210153512_drop_unused_gin_index.sql (596.96µs)10652026/07/18 13:54:23 OK 20251218171726_add_pins.sql (955.17µs)10662026/07/18 13:54:23 OK 20260628120000_add_object_size_and_stats.sql (4.73ms)10672026/07/18 13:54:23 goose: successfully migrated database to version: 2026062812000010682026/07/18 13:54:23 OK 1_commit_pending_closure.sql (1.41ms)10692026/07/18 13:54:23 OK 2_object_stats_trigger.sql (525.88µs)10702026/07/18 13:54:23 goose: up to current file version: 21071=== NAME TestClientMultipleUploads1072 client_integration_test.go:338: Created store path 1: /nix/var/nix/builds/nix-47566-740631855/TestClientMultipleUploads1532105287/001/store/80v1pd0cp56id171xf5d4smbhzhvr82v-test-file-1.txt10732026/07/18 13:54:23 INFO Created nix-cache-info in bucket bucket=bucket2510742026/07/18 13:54:23 INFO Received uploads request method=POST path=/api/pending_closures10752026/07/18 13:54:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10762026/07/18 13:54:23 INFO Uploading 5jhp6qw7lsbcq25m2ziprpy6whifn4z3-pinned-file.txt (128B)10772026/07/18 13:54:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10782026/07/18 13:54:23 INFO Signed narinfos id=1 count=110792026/07/18 13:54:23 INFO Uploading 1 narinfos10802026/07/18 13:54:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1081 client_integration_test.go:338: Created store path 2: /nix/var/nix/builds/nix-47566-740631855/TestClientMultipleUploads1532105287/001/store/7hhdifaqlz8b1pn2k8s4pfqv7lj9ivgq-test-file-2.txt10822026/07/18 13:54:23 INFO Completed upload id=110832026/07/18 13:54:23 INFO Upload complete. (119ms)1084=== NAME TestClientIntegration1085 client_integration_test.go:276: Created store path: /nix/var/nix/builds/nix-47566-740631855/TestClientIntegration417577769/002/store/a5hp8ga1wh0g7529rnh2faz7wkbqz5v0-test-file.txt10862026-07-18 13:54:23.602 UTC [47815] ERROR: relation "goose_db_version" does not exist at character 3610872026-07-18 13:54:23.602 UTC [47815] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10882026-07-18 13:54:23.620 UTC [47818] ERROR: relation "goose_db_version" does not exist at character 3610892026-07-18 13:54:23.620 UTC [47818] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10902026/07/18 13:54:23 OK 20241026095416_initial_model.sql (18.05ms)10912026/07/18 13:54:23 OK 20251210153512_drop_unused_gin_index.sql (823.33µs)10922026/07/18 13:54:23 OK 20251218171726_add_pins.sql (2.18ms)10932026-07-18 13:54:23.627 UTC [47820] ERROR: relation "goose_db_version" does not exist at character 3610942026-07-18 13:54:23.627 UTC [47820] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10952026/07/18 13:54:23 OK 20260628120000_add_object_size_and_stats.sql (8.97ms)10962026/07/18 13:54:23 goose: successfully migrated database to version: 2026062812000010972026/07/18 13:54:23 OK 1_commit_pending_closure.sql (1.62ms)10982026/07/18 13:54:23 OK 2_object_stats_trigger.sql (618.33µs)10992026/07/18 13:54:23 goose: up to current file version: 21100=== NAME TestClientWithDependencies1101 client_integration_test.go:593: Built derivation: /nix/var/nix/builds/nix-47566-740631855/TestClientWithDependencies3269495799/001/store/n6d7prg3k9zd9zr7hajb55d5r2x8qhxp-test-script11022026/07/18 13:54:23 OK 20241026095416_initial_model.sql (7.44ms)11032026/07/18 13:54:23 OK 20251210153512_drop_unused_gin_index.sql (1.37ms)11042026/07/18 13:54:23 OK 20241026095416_initial_model.sql (6ms)11052026/07/18 13:54:23 OK 20251210153512_drop_unused_gin_index.sql (728.88µs)11062026/07/18 13:54:23 OK 20251218171726_add_pins.sql (1.69ms)11072026/07/18 13:54:23 OK 20251218171726_add_pins.sql (1.14ms)11082026/07/18 13:54:23 OK 20260628120000_add_object_size_and_stats.sql (2.31ms)11092026/07/18 13:54:23 goose: successfully migrated database to version: 2026062812000011102026/07/18 13:54:23 OK 1_commit_pending_closure.sql (886.92µs)11112026/07/18 13:54:23 OK 2_object_stats_trigger.sql (290.13µs)11122026/07/18 13:54:23 goose: up to current file version: 211132026/07/18 13:54:23 OK 20260628120000_add_object_size_and_stats.sql (4.47ms)11142026/07/18 13:54:23 goose: successfully migrated database to version: 2026062812000011152026/07/18 13:54:23 OK 1_commit_pending_closure.sql (1.7ms)11162026/07/18 13:54:23 OK 2_object_stats_trigger.sql (661.5µs)11172026/07/18 13:54:23 goose: up to current file version: 21118--- PASS: TestReadProxyNarinfo (0.38s)1119=== CONT TestReadProxyDisabled11202026/07/18 13:54:23 INFO Received uploads request method=POST path=/api/pending_closures11212026/07/18 13:54:23 INFO Received uploads request method=POST path=/api/pending_closures11222026/07/18 13:54:23 INFO Received uploads request method=POST path=/api/pending_closures11232026/07/18 13:54:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11242026/07/18 13:54:23 INFO Uploading i5kyyl8x3ki40m5dis64cmrcqq18q698-unpinned-file.txt (128B)11252026/07/18 13:54:23 INFO Received uploads request method=POST path=/api/pending_closures11262026/07/18 13:54:23 INFO Received uploads request method=POST path=/api/pending_closures11272026/07/18 13:54:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11282026/07/18 13:54:23 INFO Uploading a5hp8ga1wh0g7529rnh2faz7wkbqz5v0-test-file.txt (152B)11292026/07/18 13:54:23 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)11302026/07/18 13:54:23 INFO Uploading 80v1pd0cp56id171xf5d4smbhzhvr82v-test-file-1.txt (160B)11312026/07/18 13:54:23 INFO Uploading 7hhdifaqlz8b1pn2k8s4pfqv7lj9ivgq-test-file-2.txt (160B)11322026/07/18 13:54:23 INFO Uploading 0jmq71n6ccid8dfdqcsv339j9hiyxcy8-test-file-0.txt (160B)11332026/07/18 13:54:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11342026/07/18 13:54:23 INFO Signed narinfos id=2 count=111352026/07/18 13:54:23 INFO Uploading 1 narinfos11362026/07/18 13:54:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11372026/07/18 13:54:23 INFO Signed narinfos id=1 count=111382026/07/18 13:54:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11392026/07/18 13:54:23 INFO Uploading 1 narinfos11402026/07/18 13:54:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11412026/07/18 13:54:23 INFO Signed narinfos id=1 count=111422026/07/18 13:54:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign1143--- PASS: TestResurrectedObjectNotDeleted (0.40s)11442026/07/18 13:54:23 INFO Signed narinfos id=2 count=11145=== CONT TestReadProxyRootRedirectsToIndexHTML11462026/07/18 13:54:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign11472026/07/18 13:54:23 INFO Completed upload id=211482026/07/18 13:54:23 INFO Upload complete. (90ms)11492026/07/18 13:54:23 INFO Signed narinfos id=3 count=111502026/07/18 13:54:23 INFO Uploading 3 narinfos11512026/07/18 13:54:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11522026/07/18 13:54:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1153=== NAME TestClientWithDependencies1154 client_integration_test.go:595: Found 1 dependencies (including self)11552026-07-18 13:54:23.687 UTC [47833] ERROR: relation "goose_db_version" does not exist at character 3611562026-07-18 13:54:23.687 UTC [47833] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11572026/07/18 13:54:23 INFO Completed upload id=111582026/07/18 13:54:23 INFO Completed upload id=111592026/07/18 13:54:23 INFO Upload complete. (103ms)11602026/07/18 13:54:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11612026/07/18 13:54:23 INFO Completed upload id=211622026/07/18 13:54:23 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete11632026/07/18 13:54:23 INFO Completed upload id=311642026/07/18 13:54:23 INFO Upload complete. (112ms)1165=== NAME TestClientMultipleUploads1166 client_integration_test.go:349: Uploaded 3 paths in 151.552291ms1167=== NAME TestClientIntegration1168 client_integration_test.go:292: Retrieved narinfo from S3:1169 StorePath: /nix/var/nix/builds/nix-47566-740631855/TestClientIntegration417577769/002/store/a5hp8ga1wh0g7529rnh2faz7wkbqz5v0-test-file.txt1170 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1171 Compression: zstd1172 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11173 NarSize: 1521174 References: 1175 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11176 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1177 client_integration_test.go:293: Decompressed .ls content (64 bytes):1178 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1179 client_integration_test.go:296: Testing garbage collection...1180--- PASS: TestClientMultipleUploads (0.85s)1181=== CONT TestRedundantMultipartUpload11822026-07-18 13:54:23.708 UTC [47838] ERROR: relation "goose_db_version" does not exist at character 3611832026-07-18 13:54:23.708 UTC [47838] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11842026/07/18 13:54:23 INFO Received create pin request method=POST path=/api/pins/myapp11852026/07/18 13:54:23 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-47566-740631855/TestPinProtectsFromGC3173657647/001/store/5jhp6qw7lsbcq25m2ziprpy6whifn4z3-pinned-file.txt narinfo_key=5jhp6qw7lsbcq25m2ziprpy6whifn4z3.narinfo11862026/07/18 13:54:23 OK 20241026095416_initial_model.sql (23.45ms)11872026/07/18 13:54:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures11882026/07/18 13:54:23 OK 20251210153512_drop_unused_gin_index.sql (454µs)11892026/07/18 13:54:23 INFO Garbage collection started11902026/07/18 13:54:23 OK 20251218171726_add_pins.sql (2.23ms)11912026/07/18 13:54:23 INFO Aborted multipart uploads count=011922026/07/18 13:54:23 OK 20260628120000_add_object_size_and_stats.sql (5.37ms)11932026/07/18 13:54:23 goose: successfully migrated database to version: 2026062812000011942026/07/18 13:54:23 WARN Force mode enabled - objects will be deleted immediately without grace period11952026/07/18 13:54:23 OK 1_commit_pending_closure.sql (940.83µs)11962026/07/18 13:54:23 OK 2_object_stats_trigger.sql (266.38µs)11972026/07/18 13:54:23 goose: up to current file version: 211982026/07/18 13:54:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures11992026/07/18 13:54:23 INFO Garbage collection started1200--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.32s)1201=== CONT TestService_AuthMiddleware_OIDC12022026/07/18 13:54:23 INFO OIDC provider initialized name=test12032026/07/18 13:54:23 INFO Aborted multipart uploads count=012042026/07/18 13:54:23 WARN Force mode enabled - objects will be deleted immediately without grace period12052026/07/18 13:54:23 OK 20241026095416_initial_model.sql (20.1ms)12062026/07/18 13:54:23 OK 20251210153512_drop_unused_gin_index.sql (628.92µs)12072026/07/18 13:54:23 OK 20251218171726_add_pins.sql (1.23ms)12082026/07/18 13:54:23 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)12092026/07/18 13:54:23 goose: successfully migrated database to version: 2026062812000012102026/07/18 13:54:23 OK 1_commit_pending_closure.sql (1.25ms)12112026/07/18 13:54:23 OK 2_object_stats_trigger.sql (256.29µs)12122026/07/18 13:54:23 goose: up to current file version: 212132026/07/18 13:54:23 INFO Received uploads request method=POST path=/api/pending_closures1214--- PASS: TestReadProxyConditionalGet (0.29s)1215=== CONT TestClientCADerivations12162026/07/18 13:54:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12172026/07/18 13:54:23 INFO Uploading n6d7prg3k9zd9zr7hajb55d5r2x8qhxp-test-script (136B)12182026/07/18 13:54:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12192026/07/18 13:54:23 INFO Signed narinfos id=1 count=112202026/07/18 13:54:23 INFO Uploading 1 narinfos12212026/07/18 13:54:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12222026/07/18 13:54:23 INFO Completed upload id=112232026/07/18 13:54:23 INFO Upload complete. (50ms)1224=== NAME TestClientWithDependencies1225 client_integration_test.go:597: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-47566-740631855/TestClientWithDependencies3269495799/001/store) requires matching store prefix1226--- PASS: TestClientWithDependencies (0.94s)1227=== CONT TestCacheStatsHandler12282026-07-18 13:54:23.912 UTC [47853] ERROR: relation "goose_db_version" does not exist at character 3612292026-07-18 13:54:23.912 UTC [47853] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12302026/07/18 13:54:23 OK 20241026095416_initial_model.sql (11.1ms)12312026/07/18 13:54:23 OK 20251210153512_drop_unused_gin_index.sql (730.21µs)12322026/07/18 13:54:23 OK 20251218171726_add_pins.sql (1.88ms)12332026/07/18 13:54:23 OK 20260628120000_add_object_size_and_stats.sql (2.14ms)12342026/07/18 13:54:23 goose: successfully migrated database to version: 2026062812000012352026/07/18 13:54:23 OK 1_commit_pending_closure.sql (2.02ms)12362026/07/18 13:54:23 OK 2_object_stats_trigger.sql (464.38µs)12372026/07/18 13:54:23 goose: up to current file version: 21238--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.26s)1239=== CONT TestCacheConfigHandler1240=== RUN TestCacheConfigHandler/full_config,_no_issuer1241=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1242=== RUN TestCacheConfigHandler/no_cache_url_configured1243=== PAUSE TestCacheConfigHandler/no_cache_url_configured1244=== RUN TestCacheConfigHandler/no_signing_keys1245=== PAUSE TestCacheConfigHandler/no_signing_keys1246=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1247=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1248=== CONT TestOrphanedObjectsGC12492026-07-18 13:54:23.949 UTC [47857] ERROR: relation "goose_db_version" does not exist at character 3612502026-07-18 13:54:23.949 UTC [47857] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12512026-07-18 13:54:23.950 UTC [47858] ERROR: relation "goose_db_version" does not exist at character 3612522026-07-18 13:54:23.950 UTC [47858] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12532026/07/18 13:54:23 OK 20241026095416_initial_model.sql (8.07ms)12542026/07/18 13:54:23 OK 20241026095416_initial_model.sql (6.16ms)12552026/07/18 13:54:23 OK 20251210153512_drop_unused_gin_index.sql (379.5µs)12562026/07/18 13:54:23 OK 20251210153512_drop_unused_gin_index.sql (440.42µs)12572026/07/18 13:54:23 OK 20251218171726_add_pins.sql (773.79µs)12582026/07/18 13:54:23 OK 20251218171726_add_pins.sql (827.67µs)12592026/07/18 13:54:23 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)12602026/07/18 13:54:23 goose: successfully migrated database to version: 2026062812000012612026/07/18 13:54:23 OK 20260628120000_add_object_size_and_stats.sql (3.79ms)12622026/07/18 13:54:23 goose: successfully migrated database to version: 2026062812000012632026/07/18 13:54:23 OK 1_commit_pending_closure.sql (1.32ms)12642026/07/18 13:54:23 OK 2_object_stats_trigger.sql (333.63µs)12652026/07/18 13:54:23 goose: up to current file version: 212662026/07/18 13:54:23 OK 1_commit_pending_closure.sql (2.1ms)12672026/07/18 13:54:23 OK 2_object_stats_trigger.sql (254.5µs)12682026/07/18 13:54:23 goose: up to current file version: 212692026/07/18 13:54:23 INFO Received uploads request method=POST path=/api/pending_closures1270--- PASS: TestReadProxyDisabled (0.33s)1271=== CONT TestReadProxyInvalidPath12722026-07-18 13:54:23.997 UTC [47862] ERROR: relation "goose_db_version" does not exist at character 3612732026-07-18 13:54:23.997 UTC [47862] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12742026/07/18 13:54:24 INFO Received uploads request method=POST path=/api/pending_closures12752026/07/18 13:54:24 OK 20241026095416_initial_model.sql (37.54ms)12762026/07/18 13:54:24 OK 20251210153512_drop_unused_gin_index.sql (562.5µs)12772026/07/18 13:54:24 OK 20251218171726_add_pins.sql (1.02ms)12782026/07/18 13:54:24 OK 20260628120000_add_object_size_and_stats.sql (3.53ms)12792026/07/18 13:54:24 goose: successfully migrated database to version: 2026062812000012802026/07/18 13:54:24 OK 1_commit_pending_closure.sql (1.15ms)12812026/07/18 13:54:24 OK 2_object_stats_trigger.sql (254.88µs)12822026/07/18 13:54:24 goose: up to current file version: 21283=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1284=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1285=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1286=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1287=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1288=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1289=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1290=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1291=== CONT TestReadProxyHead12922026/07/18 13:54:24 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=012932026/07/18 13:54:24 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=012942026-07-18 13:54:24.081 UTC [47865] ERROR: relation "goose_db_version" does not exist at character 3612952026-07-18 13:54:24.081 UTC [47865] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12962026/07/18 13:54:24 INFO Vacuumed table table=pending_closures12972026/07/18 13:54:24 INFO Vacuumed table table=pending_objects1298=== NAME TestOrphanedObjectsGCStressTest1299 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains13002026/07/18 13:54:24 INFO Vacuumed table table=multipart_uploads13012026/07/18 13:54:24 INFO Vacuumed table table=closures13022026/07/18 13:54:24 INFO Vacuumed table table=objects13032026/07/18 13:54:24 INFO Vacuumed table table=pending_closures1304 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion13052026/07/18 13:54:24 OK 20241026095416_initial_model.sql (4.93ms)13062026/07/18 13:54:24 OK 20251210153512_drop_unused_gin_index.sql (442.54µs)13072026/07/18 13:54:24 OK 20251218171726_add_pins.sql (807.29µs)13082026/07/18 13:54:24 OK 20260628120000_add_object_size_and_stats.sql (909.96µs)13092026/07/18 13:54:24 goose: successfully migrated database to version: 2026062812000013102026/07/18 13:54:24 OK 1_commit_pending_closure.sql (896.96µs)13112026/07/18 13:54:24 OK 2_object_stats_trigger.sql (203.42µs)13122026/07/18 13:54:24 goose: up to current file version: 213132026/07/18 13:54:24 INFO Vacuumed table table=pending_objects13142026/07/18 13:54:24 INFO Vacuumed table table=multipart_uploads13152026/07/18 13:54:24 INFO Created nix-cache-info in bucket bucket=bucket3513162026/07/18 13:54:24 INFO Vacuumed table table=closures13172026/07/18 13:54:24 INFO Vacuumed table table=objects13182026/07/18 13:54:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13192026-07-18 13:54:24.139 UTC [47867] ERROR: relation "goose_db_version" does not exist at character 3613202026-07-18 13:54:24.139 UTC [47867] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13212026/07/18 13:54:24 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YzZlNDA2NTItZWM4OC00ZTdjLTg4YTQtNzM4NDFkZDYyZWEzLmU4NmZhYTc2LTI3NGMtNGYxYy05Y2YxLWRlMzJmOGEyZDI0NngxNzg0MzgyODYzOTkwMzk2MDAw parts=121322--- PASS: TestRedundantMultipartUpload (0.47s)1323=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13242026/07/18 13:54:24 OK 20241026095416_initial_model.sql (28.55ms)13252026/07/18 13:54:24 OK 20251210153512_drop_unused_gin_index.sql (655.04µs)13262026/07/18 13:54:24 OK 20251218171726_add_pins.sql (5.4ms)13272026/07/18 13:54:24 OK 20260628120000_add_object_size_and_stats.sql (4.66ms)13282026/07/18 13:54:24 goose: successfully migrated database to version: 2026062812000013292026/07/18 13:54:24 OK 1_commit_pending_closure.sql (850.42µs)13302026/07/18 13:54:24 OK 2_object_stats_trigger.sql (193.38µs)13312026/07/18 13:54:24 goose: up to current file version: 21332--- PASS: TestCacheStatsHandler (0.43s)1333=== CONT TestService_ReadAuthMiddleware1334=== NAME TestOrphanedObjectsGCStressTest1335 orphaned_objects_gc_test.go:509: Stress test completed successfully:1336 orphaned_objects_gc_test.go:510: - Active objects preserved: 201337 orphaned_objects_gc_test.go:511: - Objects deleted: 2101338 orphaned_objects_gc_test.go:512: - Total GC'd: 2101339--- PASS: TestOrphanedObjectsGCStressTest (1.00s)1340=== CONT TestReadProxy40413412026-07-18 13:54:24.273 UTC [47878] ERROR: relation "goose_db_version" does not exist at character 3613422026-07-18 13:54:24.273 UTC [47878] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13432026/07/18 13:54:24 OK 20241026095416_initial_model.sql (7.86ms)13442026/07/18 13:54:24 OK 20251210153512_drop_unused_gin_index.sql (365.38µs)13452026/07/18 13:54:24 OK 20251218171726_add_pins.sql (746.04µs)13462026/07/18 13:54:24 OK 20260628120000_add_object_size_and_stats.sql (1.66ms)13472026/07/18 13:54:24 goose: successfully migrated database to version: 2026062812000013482026/07/18 13:54:24 OK 1_commit_pending_closure.sql (888.42µs)13492026/07/18 13:54:24 OK 2_object_stats_trigger.sql (216.08µs)13502026/07/18 13:54:24 goose: up to current file version: 213512026-07-18 13:54:24.294 UTC [47879] ERROR: relation "goose_db_version" does not exist at character 3613522026-07-18 13:54:24.294 UTC [47879] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13532026/07/18 13:54:24 OK 20241026095416_initial_model.sql (10.46ms)13542026/07/18 13:54:24 OK 20251210153512_drop_unused_gin_index.sql (493.21µs)13552026/07/18 13:54:24 OK 20251218171726_add_pins.sql (1.18ms)13562026/07/18 13:54:24 OK 20260628120000_add_object_size_and_stats.sql (1.78ms)13572026/07/18 13:54:24 goose: successfully migrated database to version: 2026062812000013582026/07/18 13:54:24 OK 1_commit_pending_closure.sql (878.63µs)13592026/07/18 13:54:24 OK 2_object_stats_trigger.sql (183.25µs)13602026/07/18 13:54:24 goose: up to current file version: 21361--- PASS: TestReadProxyInvalidPath (0.33s)1362=== CONT TestService_AuthMiddleware_MTLSProxyHeader1363=== NAME TestClientCADerivations1364 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-47566-740631855/TestClientCADerivations3600116052/001/store/24969rihf9jawgm2wdgsznzjb8gz6bk1-ca-test13652026-07-18 13:54:24.338 UTC [47883] ERROR: relation "goose_db_version" does not exist at character 3613662026-07-18 13:54:24.338 UTC [47883] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13672026/07/18 13:54:24 OK 20241026095416_initial_model.sql (8.92ms)13682026/07/18 13:54:24 OK 20251210153512_drop_unused_gin_index.sql (514.83µs)13692026/07/18 13:54:24 OK 20251218171726_add_pins.sql (3.61ms)1370 client_ca_test.go:139: Found 1 dependencies (including self)13712026/07/18 13:54:24 OK 20260628120000_add_object_size_and_stats.sql (10.02ms)13722026/07/18 13:54:24 goose: successfully migrated database to version: 2026062812000013732026/07/18 13:54:24 OK 1_commit_pending_closure.sql (1.04ms)13742026/07/18 13:54:24 OK 2_object_stats_trigger.sql (454.08µs)13752026/07/18 13:54:24 goose: up to current file version: 21376--- PASS: TestReadProxyHead (0.32s)1377=== CONT TestParseSingleRange1378=== RUN TestParseSingleRange/none1379=== PAUSE TestParseSingleRange/none1380=== RUN TestParseSingleRange/unknown_unit1381=== PAUSE TestParseSingleRange/unknown_unit1382=== RUN TestParseSingleRange/multi-range_ignored1383=== PAUSE TestParseSingleRange/multi-range_ignored1384=== RUN TestParseSingleRange/malformed_no_dash1385=== PAUSE TestParseSingleRange/malformed_no_dash1386=== RUN TestParseSingleRange/malformed_both_empty1387=== PAUSE TestParseSingleRange/malformed_both_empty1388=== RUN TestParseSingleRange/malformed_end_before_start1389=== PAUSE TestParseSingleRange/malformed_end_before_start1390=== RUN TestParseSingleRange/closed1391=== PAUSE TestParseSingleRange/closed1392=== RUN TestParseSingleRange/open-ended1393=== PAUSE TestParseSingleRange/open-ended1394=== RUN TestParseSingleRange/end_clamped_to_size1395=== PAUSE TestParseSingleRange/end_clamped_to_size1396=== RUN TestParseSingleRange/suffix1397=== PAUSE TestParseSingleRange/suffix1398=== RUN TestParseSingleRange/suffix_exceeds_size1399=== PAUSE TestParseSingleRange/suffix_exceeds_size1400=== RUN TestParseSingleRange/single_byte1401=== PAUSE TestParseSingleRange/single_byte1402=== RUN TestParseSingleRange/start_past_EOF1403=== PAUSE TestParseSingleRange/start_past_EOF1404=== RUN TestParseSingleRange/start_far_past_EOF1405=== PAUSE TestParseSingleRange/start_far_past_EOF1406=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14072026/07/18 13:54:24 INFO Received uploads request method=POST path=/1408=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14092026/07/18 13:54:24 INFO Received complete multipart upload request method=POST path=/1410=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14112026/07/18 13:54:24 INFO Received request for more parts method=POST path=/1412=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14132026/07/18 13:54:24 INFO Received uploads request method=POST path=/1414--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1415 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1416 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1417 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1418 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1419=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14202026/07/18 13:54:24 INFO Received complete multipart upload request method=POST path=/1421=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14222026/07/18 13:54:24 INFO Received uploads request method=POST path=/14232026-07-18 13:54:24.399 UTC [47887] ERROR: relation "goose_db_version" does not exist at character 3614242026-07-18 13:54:24.399 UTC [47887] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14252026/07/18 13:54:24 OK 20241026095416_initial_model.sql (4.93ms)14262026/07/18 13:54:24 OK 20251210153512_drop_unused_gin_index.sql (652.79µs)14272026/07/18 13:54:24 OK 20251218171726_add_pins.sql (1.06ms)14282026/07/18 13:54:24 OK 20260628120000_add_object_size_and_stats.sql (1.67ms)14292026/07/18 13:54:24 goose: successfully migrated database to version: 2026062812000014302026/07/18 13:54:24 OK 1_commit_pending_closure.sql (1.27ms)14312026/07/18 13:54:24 OK 2_object_stats_trigger.sql (418.17µs)14322026/07/18 13:54:24 goose: up to current file version: 214332026/07/18 13:54:24 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14342026/07/18 13:54:24 WARN mTLS auth: bound subjects configured but subject DN unavailable14352026/07/18 13:54:24 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1436--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.25s)1437=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14382026/07/18 13:54:24 INFO Received request for more parts method=POST path=/1439=== CONT TestServerTLSConfig/no_client_CA1440=== CONT TestServerTLSConfig/not_a_PEM_file1441=== CONT TestServerTLSConfig/missing_CA_file1442--- PASS: TestServerTLSConfig (0.00s)1443 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1444 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1445 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1446=== CONT TestIsValidUploadKey/narinfo1447=== CONT TestProxyWriteTimeout/narinfo1448=== CONT TestIsValidUploadKey/unknown_type1449=== CONT TestIsValidUploadKey/empty_key1450=== CONT TestIsValidUploadKey/absolute1451=== CONT TestIsValidUploadKey/traversal_nar1452=== CONT TestIsValidUploadKey/traversal1453=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1454=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1455=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1456=== CONT TestIsValidUploadKey/index.html1457=== CONT TestIsValidUploadKey/nix-cache-info1458=== CONT TestIsValidUploadKey/realisation_plus_in_output1459=== CONT TestIsValidUploadKey/realisation1460=== CONT TestIsValidUploadKey/build_log_equals1461=== CONT TestIsValidUploadKey/build_log_question_mark1462=== CONT TestIsValidUploadKey/build_log_plus_in_name1463=== CONT TestIsValidUploadKey/build_log_home-manager_file1464=== CONT TestIsValidUploadKey/build_log1465=== CONT TestIsValidUploadKey/listing1466=== CONT TestIsValidUploadKey/nar_plain1467=== CONT TestProxyWriteTimeout/unknown_size1468=== CONT TestProxyWriteTimeout/10_GiB_nar1469=== CONT TestProxyWriteTimeout/1_GiB_nar1470--- PASS: TestProxyWriteTimeout (0.00s)1471 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1472 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1473 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1474 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1475=== CONT TestIsValidUploadKey/nar_xz1476=== CONT TestIsValidUploadKey/nar_zst1477--- PASS: TestIsValidUploadKey (0.00s)1478 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1479 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1480 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1481 --- PASS: TestIsValidUploadKey/absolute (0.00s)1482 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1483 --- PASS: TestIsValidUploadKey/traversal (0.00s)1484 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1485 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1486 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1487 --- PASS: TestIsValidUploadKey/index.html (0.00s)1488 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1489 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1490 --- PASS: TestIsValidUploadKey/realisation (0.00s)1491 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1492 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1493 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1494 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1495 --- PASS: TestIsValidUploadKey/build_log (0.00s)1496 --- PASS: TestIsValidUploadKey/listing (0.00s)1497 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1498 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1499 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1500=== CONT TestClientErrorHandling/InvalidStorePath15012026-07-18 13:54:24.439 UTC [47891] ERROR: relation "goose_db_version" does not exist at character 3615022026-07-18 13:54:24.439 UTC [47891] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15032026-07-18 13:54:24.454 UTC [47894] ERROR: relation "goose_db_version" does not exist at character 3615042026-07-18 13:54:24.454 UTC [47894] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15052026/07/18 13:54:24 OK 20241026095416_initial_model.sql (9.76ms)15062026/07/18 13:54:24 OK 20251210153512_drop_unused_gin_index.sql (528.75µs)15072026/07/18 13:54:24 OK 20251218171726_add_pins.sql (952.67µs)15082026/07/18 13:54:24 OK 20260628120000_add_object_size_and_stats.sql (1.46ms)15092026/07/18 13:54:24 goose: successfully migrated database to version: 2026062812000015102026/07/18 13:54:24 OK 20241026095416_initial_model.sql (5.82ms)15112026/07/18 13:54:24 OK 1_commit_pending_closure.sql (958.63µs)15122026/07/18 13:54:24 OK 2_object_stats_trigger.sql (429.42µs)15132026/07/18 13:54:24 goose: up to current file version: 215142026/07/18 13:54:24 OK 20251210153512_drop_unused_gin_index.sql (614.08µs)15152026/07/18 13:54:24 OK 20251218171726_add_pins.sql (1.16ms)15162026/07/18 13:54:24 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1517--- PASS: TestService_ReadAuthMiddleware (0.27s)1518=== CONT TestClientErrorHandling/ServerNotAvailable15192026/07/18 13:54:24 INFO Received uploads request method=POST path=/api/pending_closures15202026/07/18 13:54:24 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)15212026/07/18 13:54:24 goose: successfully migrated database to version: 2026062812000015222026/07/18 13:54:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15232026/07/18 13:54:24 INFO Uploading 24969rihf9jawgm2wdgsznzjb8gz6bk1-ca-test (144B)15242026/07/18 13:54:24 OK 1_commit_pending_closure.sql (1.73ms)15252026/07/18 13:54:24 OK 2_object_stats_trigger.sql (343.75µs)15262026/07/18 13:54:24 goose: up to current file version: 215272026/07/18 13:54:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15282026/07/18 13:54:24 INFO Signed narinfos id=1 count=115292026/07/18 13:54:24 INFO Uploading 1 narinfos1530--- PASS: TestReadProxy404 (0.27s)1531=== CONT TestClientErrorHandling/InvalidAuthToken15322026/07/18 13:54:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15332026/07/18 13:54:24 INFO Completed upload id=115342026/07/18 13:54:24 INFO Upload complete. (88ms)1535=== NAME TestClientCADerivations1536 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-47566-740631855/TestClientCADerivations3600116052/001/store/24969rihf9jawgm2wdgsznzjb8gz6bk1-ca-test1537 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1538 Compression: zstd1539 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1540 NarSize: 1441541 References: 1542 Deriver: /nix/var/nix/builds/nix-47566-740631855/TestClientCADerivations3600116052/001/store/14lfrkqj1zhxbxhgy79ha3hirmbz71lb-ca-test.drv1543 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1544 client_ca_test.go:185: Checking for realisation files in S3...1545 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1546 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1547=== NAME TestOrphanedObjectsGC1548 orphaned_objects_gc_test.go:290: GC Test Summary:1549 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1550 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1551 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1552 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1553 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1554--- PASS: TestOrphanedObjectsGC (0.61s)1555=== CONT TestIsValidCachePath/narinfo1556=== CONT TestIsValidCachePath/index.html1557=== CONT TestIsValidCachePath/short_hash1558=== CONT TestIsValidCachePath/wrong_extension1559=== CONT TestIsValidCachePath/leading_slash1560=== CONT TestIsValidCachePath/empty1561=== CONT TestIsValidCachePath/random_path1562=== CONT TestIsValidCachePath/invalid_char_u1563=== CONT TestIsValidCachePath/invalid_char_e1564=== CONT TestIsValidCachePath/traversal_in_middle1565=== CONT TestIsValidCachePath/traversal_parent1566=== CONT TestIsValidCachePath/nar_uncompressed1567=== CONT TestIsValidCachePath/nix-cache-info1568=== CONT TestIsValidCachePath/realisation1569=== CONT TestIsValidCachePath/log1570=== CONT TestIsValidCachePath/ls1571=== CONT TestIsValidCachePath/nar_zst1572=== CONT TestIsValidCachePath/nar_bz21573=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1574=== CONT TestIsValidCachePath/nar_xz1575--- PASS: TestIsValidCachePath (0.00s)1576 --- PASS: TestIsValidCachePath/narinfo (0.00s)1577 --- PASS: TestIsValidCachePath/index.html (0.00s)1578 --- PASS: TestIsValidCachePath/short_hash (0.00s)1579 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1580 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1581 --- PASS: TestIsValidCachePath/empty (0.00s)1582 --- PASS: TestIsValidCachePath/random_path (0.00s)1583 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1584 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1585 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1586 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1587 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1588 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1589 --- PASS: TestIsValidCachePath/realisation (0.00s)1590 --- PASS: TestIsValidCachePath/log (0.00s)1591 --- PASS: TestIsValidCachePath/ls (0.00s)1592 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1593 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1594 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1595 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1596=== CONT TestCacheConfigHandler/full_config,_no_issuer1597=== CONT TestCacheConfigHandler/no_signing_keys1598=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1599=== CONT TestCacheConfigHandler/no_cache_url_configured1600--- PASS: TestCacheConfigHandler (0.00s)1601 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1602 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1603 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1604 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1605=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token16062026/07/18 13:54:24 INFO OIDC auth successful provider=test1607=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected16082026/07/18 13:54:24 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]1609=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1610=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16112026-07-18 13:54:24.550 UTC [47903] ERROR: relation "goose_db_version" does not exist at character 3616122026-07-18 13:54:24.550 UTC [47903] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16132026/07/18 13:54:24 WARN Authentication failed token_preview=eyJhbGciOi...kz0QIGl9Gw 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]1614=== CONT TestParseSingleRange/none1615=== CONT TestParseSingleRange/open-ended1616=== CONT TestParseSingleRange/start_far_past_EOF1617=== CONT TestParseSingleRange/start_past_EOF1618=== CONT TestParseSingleRange/single_byte1619=== CONT TestParseSingleRange/suffix_exceeds_size1620=== CONT TestParseSingleRange/suffix1621=== CONT TestParseSingleRange/end_clamped_to_size1622=== CONT TestParseSingleRange/malformed_both_empty1623=== CONT TestParseSingleRange/closed1624=== CONT TestParseSingleRange/malformed_end_before_start1625=== CONT TestParseSingleRange/multi-range_ignored1626=== CONT TestParseSingleRange/malformed_no_dash1627=== CONT TestParseSingleRange/unknown_unit1628--- PASS: TestParseSingleRange (0.00s)1629 --- PASS: TestParseSingleRange/none (0.00s)1630 --- PASS: TestParseSingleRange/open-ended (0.00s)1631 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1632 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1633 --- PASS: TestParseSingleRange/single_byte (0.00s)1634 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1635 --- PASS: TestParseSingleRange/suffix (0.00s)1636 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1637 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1638 --- PASS: TestParseSingleRange/closed (0.00s)1639 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1640 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1641 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1642 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1643--- PASS: TestService_AuthMiddleware_OIDC (0.32s)1644 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1645 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1646 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1647 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)16482026/07/18 13:54:24 OK 20241026095416_initial_model.sql (4.52ms)1649=== NAME TestClientCADerivations1650 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket35?endpoint=http://localhost:57419®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-47566-740631855/TestClientCADerivations3600116052/001/store'1651 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 116522026/07/18 13:54:24 OK 20251210153512_drop_unused_gin_index.sql (647.13µs)1653--- PASS: TestClientCADerivations (0.81s)16542026/07/18 13:54:24 OK 20251218171726_add_pins.sql (1.45ms)16552026/07/18 13:54:24 OK 20260628120000_add_object_size_and_stats.sql (1.6ms)16562026/07/18 13:54:24 goose: successfully migrated database to version: 2026062812000016572026/07/18 13:54:24 OK 1_commit_pending_closure.sql (857.96µs)16582026/07/18 13:54:24 OK 2_object_stats_trigger.sql (201.79µs)16592026/07/18 13:54:24 goose: up to current file version: 21660--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.25s)16612026-07-18 13:54:24.607 UTC [47906] ERROR: relation "goose_db_version" does not exist at character 3616622026-07-18 13:54:24.607 UTC [47906] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16632026/07/18 13:54:24 OK 20241026095416_initial_model.sql (4.02ms)16642026/07/18 13:54:24 OK 20251210153512_drop_unused_gin_index.sql (381.5µs)16652026/07/18 13:54:24 OK 20251218171726_add_pins.sql (797.21µs)16662026/07/18 13:54:24 OK 20260628120000_add_object_size_and_stats.sql (1.12ms)16672026/07/18 13:54:24 goose: successfully migrated database to version: 2026062812000016682026/07/18 13:54:24 OK 1_commit_pending_closure.sql (898.83µs)16692026/07/18 13:54:24 OK 2_object_stats_trigger.sql (205.92µs)16702026/07/18 13:54:24 goose: up to current file version: 216712026-07-18 13:54:24.648 UTC [47911] ERROR: relation "goose_db_version" does not exist at character 3616722026-07-18 13:54:24.648 UTC [47911] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16732026/07/18 13:54:24 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16742026/07/18 13:54:24 OK 20241026095416_initial_model.sql (4.53ms)16752026/07/18 13:54:24 OK 20251210153512_drop_unused_gin_index.sql (496.13µs)16762026/07/18 13:54:24 OK 20251218171726_add_pins.sql (944.75µs)16772026/07/18 13:54:24 OK 20260628120000_add_object_size_and_stats.sql (1.52ms)16782026/07/18 13:54:24 goose: successfully migrated database to version: 2026062812000016792026/07/18 13:54:24 OK 1_commit_pending_closure.sql (1.05ms)16802026/07/18 13:54:24 OK 2_object_stats_trigger.sql (243.13µs)16812026/07/18 13:54:24 goose: up to current file version: 21682--- PASS: TestUploadHandlersRejectOversizedBody (0.05s)1683 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1684 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1685 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)16862026/07/18 13:54:24 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.638471ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16872026/07/18 13:54:24 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"16882026/07/18 13:54:24 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=390.14937ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16892026/07/18 13:54:25 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=749.828211ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16902026/07/18 13:54:25 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01691=== NAME TestPinProtectsFromGC1692 client_integration_test.go:709: Pin successfully protected closure from garbage collection16932026/07/18 13:54:25 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01694=== NAME TestClientIntegration1695 client_integration_test.go:303: Objects in database after GC:1696--- PASS: TestPinProtectsFromGC (2.92s)1697=== NAME TestClientIntegration1698 client_integration_test.go:303: Successfully deleted all objects with GC --force1699--- PASS: TestClientIntegration (2.75s)17002026/07/18 13:54:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.603889681s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17012026/07/18 13:54:27 WARN Rate limiter enabled after throttle name=s3-test rate=517022026/07/18 13:54:27 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1703=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1704 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101705 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001706--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.69s)1707--- PASS: TestClientErrorHandling (0.00s)1708 --- PASS: TestClientErrorHandling/InvalidStorePath (0.23s)1709 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.34s)1710 --- PASS: TestClientErrorHandling/ServerNotAvailable (3.24s)1711PASS1712{"timestamp":"2026-07-18T13:54:28.217267Z","level":"ERROR","fields":{"message":"Unknown connection IO error:Cancelled","peer_addr":"127.0.0.1:57493"},"target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":973,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}17132026-07-18 13:54:28.283 UTC [47603] LOG: received smart shutdown request17142026-07-18 13:54:28.284 UTC [47603] LOG: background worker "logical replication launcher" (PID 47613) exited with exit code 117152026-07-18 13:54:28.293 UTC [47608] LOG: shutting down17162026-07-18 13:54:28.293 UTC [47608] LOG: checkpoint starting: shutdown immediate17172026-07-18 13:54:29.321 UTC [47608] LOG: checkpoint complete: wrote 13367 buffers (81.6%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 13 recycled; write=0.750 s, sync=0.276 s, total=1.028 s; sync files=14838, longest=0.023 s, average=0.001 s; distance=207471 kB, estimate=207471 kB; lsn=0/E221368, redo lsn=0/E22136817182026-07-18 13:54:29.325 UTC [47603] LOG: database system is shut down1719Running OIDC tests...1720=== RUN TestGlobMatch1721=== PAUSE TestGlobMatch1722=== RUN TestAudienceForIssuer1723=== PAUSE TestAudienceForIssuer1724=== RUN TestValidateToken_ValidToken1725=== PAUSE TestValidateToken_ValidToken1726=== RUN TestValidateToken_WrongAudience1727=== PAUSE TestValidateToken_WrongAudience1728=== RUN TestValidateToken_Expired1729=== PAUSE TestValidateToken_Expired1730=== RUN TestValidateToken_BoundClaimsMismatch1731=== PAUSE TestValidateToken_BoundClaimsMismatch1732=== RUN TestValidateToken_BoundSubjectMismatch1733=== PAUSE TestValidateToken_BoundSubjectMismatch1734=== RUN TestValidateToken_MultipleProviders1735=== PAUSE TestValidateToken_MultipleProviders1736=== RUN TestValidateToken_NoMatchingProvider1737=== PAUSE TestValidateToken_NoMatchingProvider1738=== CONT TestGlobMatch1739=== RUN TestGlobMatch/foo_foo1740=== PAUSE TestGlobMatch/foo_foo1741=== RUN TestGlobMatch/foo_bar1742=== PAUSE TestGlobMatch/foo_bar1743=== RUN TestGlobMatch/*_1744=== PAUSE TestGlobMatch/*_1745=== RUN TestGlobMatch/*_anything1746=== PAUSE TestGlobMatch/*_anything1747=== RUN TestGlobMatch/foo*_foo1748=== CONT TestValidateToken_NoMatchingProvider1749=== CONT TestValidateToken_BoundClaimsMismatch1750=== CONT TestValidateToken_BoundSubjectMismatch1751=== CONT TestValidateToken_WrongAudience1752=== CONT TestValidateToken_Expired1753=== CONT TestValidateToken_ValidToken1754=== CONT TestAudienceForIssuer1755--- PASS: TestAudienceForIssuer (0.00s)1756=== CONT TestValidateToken_MultipleProviders1757=== PAUSE TestGlobMatch/foo*_foo1758=== RUN TestGlobMatch/foo*_foobar1759=== PAUSE TestGlobMatch/foo*_foobar1760=== RUN TestGlobMatch/foo*_bar1761=== PAUSE TestGlobMatch/foo*_bar1762=== RUN TestGlobMatch/*bar_bar1763=== PAUSE TestGlobMatch/*bar_bar1764=== RUN TestGlobMatch/*bar_foobar1765=== PAUSE TestGlobMatch/*bar_foobar1766=== RUN TestGlobMatch/*bar_foo1767=== PAUSE TestGlobMatch/*bar_foo1768=== RUN TestGlobMatch/foo*bar_foobar1769=== PAUSE TestGlobMatch/foo*bar_foobar1770=== RUN TestGlobMatch/foo*bar_foo123bar1771=== PAUSE TestGlobMatch/foo*bar_foo123bar1772=== RUN TestGlobMatch/foo*bar_foobarbaz1773=== PAUSE TestGlobMatch/foo*bar_foobarbaz1774=== RUN TestGlobMatch/*/*_foo/bar1775=== PAUSE TestGlobMatch/*/*_foo/bar1776=== RUN TestGlobMatch/*/*_foo1777=== PAUSE TestGlobMatch/*/*_foo1778=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1779=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1780=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01781=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01782=== RUN TestGlobMatch/refs/*/main_refs/heads/main1783=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1784=== RUN TestGlobMatch/fo?_foo1785=== PAUSE TestGlobMatch/fo?_foo1786=== RUN TestGlobMatch/fo?_fo1787=== PAUSE TestGlobMatch/fo?_fo1788=== RUN TestGlobMatch/fo?_fooo1789=== PAUSE TestGlobMatch/fo?_fooo1790=== RUN TestGlobMatch/?oo_foo1791=== PAUSE TestGlobMatch/?oo_foo1792=== RUN TestGlobMatch/?oo_boo1793=== PAUSE TestGlobMatch/?oo_boo1794=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1795=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1796=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1797=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1798=== CONT TestGlobMatch/foo_foo1799=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1800=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1801=== CONT TestGlobMatch/?oo_boo1802=== CONT TestGlobMatch/?oo_foo1803=== CONT TestGlobMatch/fo?_fooo1804=== CONT TestGlobMatch/fo?_fo1805=== CONT TestGlobMatch/fo?_foo1806=== CONT TestGlobMatch/*bar_foo1807=== CONT TestGlobMatch/*bar_foobar1808=== CONT TestGlobMatch/foo*_bar1809=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01810=== CONT TestGlobMatch/*bar_bar1811=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1812=== CONT TestGlobMatch/*/*_foo1813=== CONT TestGlobMatch/*/*_foo/bar1814=== CONT TestGlobMatch/foo*bar_foobarbaz1815=== CONT TestGlobMatch/foo*bar_foo123bar1816=== CONT TestGlobMatch/*_anything1817=== CONT TestGlobMatch/refs/*/main_refs/heads/main1818=== CONT TestGlobMatch/foo*_foobar1819=== CONT TestGlobMatch/foo_bar1820=== CONT TestGlobMatch/foo*bar_foobar1821=== CONT TestGlobMatch/*_1822=== CONT TestGlobMatch/foo*_foo1823--- PASS: TestGlobMatch (0.00s)1824 --- PASS: TestGlobMatch/foo_foo (0.00s)1825 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1826 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1827 --- PASS: TestGlobMatch/?oo_boo (0.00s)1828 --- PASS: TestGlobMatch/?oo_foo (0.00s)1829 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1830 --- PASS: TestGlobMatch/fo?_fo (0.00s)1831 --- PASS: TestGlobMatch/fo?_foo (0.00s)1832 --- PASS: TestGlobMatch/*bar_foo (0.00s)1833 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1834 --- PASS: TestGlobMatch/foo*_bar (0.00s)1835 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1836 --- PASS: TestGlobMatch/*bar_bar (0.00s)1837 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1838 --- PASS: TestGlobMatch/*/*_foo (0.00s)1839 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1840 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1841 --- PASS: TestGlobMatch/*_anything (0.00s)1842 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1843 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1844 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1845 --- PASS: TestGlobMatch/foo_bar (0.00s)1846 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1847 --- PASS: TestGlobMatch/*_ (0.00s)1848 --- PASS: TestGlobMatch/foo*_foo (0.00s)18492026/07/18 13:54:30 INFO OIDC provider initialized name=provider118502026/07/18 13:54:30 INFO OIDC provider initialized name=test18512026/07/18 13:54:30 INFO OIDC provider initialized name=provider118522026/07/18 13:54:30 INFO OIDC provider initialized name=test18532026/07/18 13:54:30 INFO OIDC provider initialized name=test18542026/07/18 13:54:30 INFO OIDC provider initialized name=test18552026/07/18 13:54:30 INFO OIDC provider initialized name=test18562026/07/18 13:54:30 INFO OIDC provider initialized name=provider21857--- PASS: TestValidateToken_Expired (0.01s)1858--- PASS: TestValidateToken_ValidToken (0.01s)1859--- PASS: TestValidateToken_WrongAudience (0.01s)1860--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1861--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1862--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1863--- PASS: TestValidateToken_MultipleProviders (0.01s)1864PASS1865Running hook tests...1866=== RUN TestSendPathsEmpty1867=== PAUSE TestSendPathsEmpty1868=== RUN TestQueueEnqueueAndFetch1869=== PAUSE TestQueueEnqueueAndFetch1870=== RUN TestQueueDeduplication1871=== PAUSE TestQueueDeduplication1872=== RUN TestQueueRemove1873=== PAUSE TestQueueRemove1874=== RUN TestQueueFetchBatchLimit1875=== PAUSE TestQueueFetchBatchLimit1876=== RUN TestQueueFetchRemoveLifecycle1877=== PAUSE TestQueueFetchRemoveLifecycle1878=== RUN TestQueueConcurrentWriters1879=== PAUSE TestQueueConcurrentWriters1880=== RUN TestServerClientIntegration1881=== PAUSE TestServerClientIntegration1882=== RUN TestServerQueueError1883=== PAUSE TestServerQueueError1884=== RUN TestGetListenerSocketActivation1885 server_test.go:210: === RUN TestGetListenerSocketActivation1886 --- PASS: TestGetListenerSocketActivation (0.00s)1887 PASS1888 1889--- PASS: TestGetListenerSocketActivation (0.01s)1890=== RUN TestWorkerUploadsAndRemoves1891=== PAUSE TestWorkerUploadsAndRemoves1892=== RUN TestWorkerSkipsGCdPaths1893=== PAUSE TestWorkerSkipsGCdPaths1894=== RUN TestWorkerPrunesClosureDeps1895=== PAUSE TestWorkerPrunesClosureDeps1896=== CONT TestSendPathsEmpty1897--- PASS: TestSendPathsEmpty (0.00s)1898=== CONT TestQueueDeduplication1899=== CONT TestQueueConcurrentWriters1900=== CONT TestWorkerSkipsGCdPaths1901=== CONT TestQueueEnqueueAndFetch1902=== CONT TestQueueRemove1903=== CONT TestQueueFetchRemoveLifecycle1904=== CONT TestQueueFetchBatchLimit1905=== CONT TestWorkerUploadsAndRemoves1906=== CONT TestWorkerPrunesClosureDeps1907=== CONT TestServerQueueError19082026/07/18 13:54:30 ERROR Failed to queue paths error="permission denied" count=11909--- PASS: TestServerQueueError (0.00s)1910=== CONT TestServerClientIntegration1911--- PASS: TestServerClientIntegration (0.00s)1912--- PASS: TestQueueEnqueueAndFetch (0.01s)19132026/07/18 13:54:30 INFO Upload queue status pending=219142026/07/18 13:54:30 INFO Uploading batch count=119152026/07/18 13:54:30 INFO Upload queue status pending=219162026/07/18 13:54:30 INFO Uploading batch count=21917--- PASS: TestQueueFetchBatchLimit (0.01s)19182026/07/18 13:54:30 INFO Upload queue status pending=219192026/07/18 13:54:30 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-47566-740631855/TestWorkerSkipsGCdPaths2627422006/002/nonexistent1920--- PASS: TestQueueFetchRemoveLifecycle (0.01s)19212026/07/18 13:54:30 INFO Uploading batch count=11922--- PASS: TestQueueRemove (0.01s)1923--- PASS: TestQueueDeduplication (0.01s)1924--- PASS: TestWorkerUploadsAndRemoves (0.06s)1925--- PASS: TestWorkerPrunesClosureDeps (0.06s)1926--- PASS: TestWorkerSkipsGCdPaths (0.06s)1927--- PASS: TestQueueConcurrentWriters (0.16s)1928PASS