niks3-go-unit-tests
aarch64-darwin.go-unit-tests
· build #92
· 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 TestConvertHashToNix3272=== RUN TestConvertHashToNix32/SRI_format_to_Nix3273=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix3274=== RUN TestConvertHashToNix32/already_Nix32_format75=== PAUSE TestConvertHashToNix32/already_Nix32_format76=== RUN TestConvertHashToNix32/invalid_format77=== PAUSE TestConvertHashToNix32/invalid_format78=== CONT TestResolveStorePath79=== CONT TestFileTokenMissing80=== CONT TestScriptTokenEmptyCommand81--- PASS: TestScriptTokenEmptyCommand (0.00s)82=== CONT TestFileTokenReadsAndCaches83=== CONT TestScriptTokenScriptFails84--- PASS: TestFileTokenMissing (0.00s)85=== CONT TestStaticToken86--- PASS: TestStaticToken (0.00s)87=== CONT TestSetClientTLSErrors88=== CONT TestScriptTokenBadJSON89=== CONT TestScriptTokenEmptyToken90=== CONT TestScriptTokenCachesUntilRefresh91=== CONT TestScriptTokenNoExpiryRerunsEveryCall92=== CONT TestFileTokenEmpty93--- PASS: TestFileTokenReadsAndCaches (0.00s)94=== CONT TestSetClientTLSDoesNotMutateDefaultTransport95--- PASS: TestResolveStorePath (0.00s)96=== CONT TestSetClientTLS97--- PASS: TestFileTokenEmpty (0.00s)98=== CONT TestShellSplitErrors99--- PASS: TestShellSplitErrors (0.00s)100=== CONT TestShellSplit101--- PASS: TestShellSplit (0.00s)102=== CONT TestDoWithRetry_BodyReplayedViaGetBody103=== RUN TestSetClientTLSErrors/missing_cert_file104=== PAUSE TestSetClientTLSErrors/missing_cert_file105=== RUN TestSetClientTLSErrors/missing_key_file106--- PASS: TestDoServerRequestAttachesToken (0.01s)107=== PAUSE TestSetClientTLSErrors/missing_key_file108=== RUN TestSetClientTLSErrors/missing_ca_file109=== PAUSE TestSetClientTLSErrors/missing_ca_file110=== RUN TestSetClientTLSErrors/invalid_ca_file111=== PAUSE TestSetClientTLSErrors/invalid_ca_file112=== CONT TestParsePathInfoJSONMultiplePaths113=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths114=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths115=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths116=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths117=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess118=== CONT TestRateLimiterFeedback119=== RUN TestRateLimiterFeedback/429_enables_limiter120=== PAUSE TestRateLimiterFeedback/429_enables_limiter121=== RUN TestRateLimiterFeedback/503_enables_limiter122=== PAUSE TestRateLimiterFeedback/503_enables_limiter123=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter124=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter125=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter126=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter127=== CONT TestPathInfoCACompatibility128=== RUN TestPathInfoCACompatibility/null_ca_field129=== PAUSE TestPathInfoCACompatibility/null_ca_field130=== RUN TestPathInfoCACompatibility/old_string_format_-_text131=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text132=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive133=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive134=== RUN TestPathInfoCACompatibility/new_structured_format_-_text135=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text136=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method137=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method138=== CONT TestUploadMultipart_SupersededByPeer139=== RUN TestUploadMultipart_SupersededByPeer/exists140=== PAUSE TestUploadMultipart_SupersededByPeer/exists141=== RUN TestUploadMultipart_SupersededByPeer/missing142=== PAUSE TestUploadMultipart_SupersededByPeer/missing143=== CONT TestDumpPathMatchesNix144--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)145=== CONT TestPartSizeForNAR146=== RUN TestPartSizeForNAR/zero_stays_at_minimum147=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum148=== RUN TestPartSizeForNAR/small_stays_at_minimum149=== PAUSE TestPartSizeForNAR/small_stays_at_minimum150=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum151=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum152=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts153=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts154=== RUN TestPartSizeForNAR/1_TiB155=== PAUSE TestPartSizeForNAR/1_TiB156=== RUN TestPartSizeForNAR/5_TiB_S3_max_object157=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object158=== RUN TestPartSizeForNAR/capped_at_5_GiB159=== PAUSE TestPartSizeForNAR/capped_at_5_GiB160=== CONT TestCaseHackSuffix1612026/07/09 07:19:46 WARN Rate limiter enabled after throttle name=server-test rate=5162--- PASS: TestScriptTokenScriptFails (0.01s)163=== CONT TestEncodeNixBase32164=== RUN TestEncodeNixBase32/test_string_hash165=== PAUSE TestEncodeNixBase32/test_string_hash166=== RUN TestEncodeNixBase32/empty_input167=== PAUSE TestEncodeNixBase32/empty_input168=== CONT TestEncodeNixBase32WithRealHash169--- PASS: TestEncodeNixBase32WithRealHash (0.00s)170=== CONT TestPathInfoHashCompatibility171=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)172=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)173=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon174=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon1752026/07/09 07:19:46 WARN Rate limiter enabled after throttle name=server-test rate=5176=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI177=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI178=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512179=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha5121802026/07/09 07:19:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:51920181=== CONT TestParsePathInfoJSON182=== RUN TestParsePathInfoJSON/Nix_format183=== PAUSE TestParsePathInfoJSON/Nix_format184=== RUN TestParsePathInfoJSON/Lix_format185=== PAUSE TestParsePathInfoJSON/Lix_format186=== RUN TestParsePathInfoJSON/empty_input187=== PAUSE TestParsePathInfoJSON/empty_input188=== RUN TestParsePathInfoJSON/whitespace_only189=== PAUSE TestParsePathInfoJSON/whitespace_only190=== RUN TestParsePathInfoJSON/invalid_JSON191=== PAUSE TestParsePathInfoJSON/invalid_JSON192=== CONT TestDumpPathWriterError1932026/07/09 07:19:46 WARN Rate limiter backed off name=server-test rate=51942026/07/09 07:19:46 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:51920195--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)196=== CONT TestGetStorePathHash197=== RUN TestGetStorePathHash/valid_store_path198=== PAUSE TestGetStorePathHash/valid_store_path199=== RUN TestGetStorePathHash/basename_without_hyphen_should_error200=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error201=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error202=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error203=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error204=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error205=== CONT TestConvertHashToNix32/SRI_format_to_Nix32206=== CONT TestDumpPathSingleFile207=== RUN TestSetClientTLS/rejects_connection_without_client_cert208=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert209=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA210=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA211=== RUN TestSetClientTLS/preserves_debug_logging_transport212=== PAUSE TestSetClientTLS/preserves_debug_logging_transport213=== CONT TestConvertHashToNix32/invalid_format214=== CONT TestConvertHashToNix32/already_Nix32_format215--- PASS: TestConvertHashToNix32 (0.00s)216 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)217 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)218 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)219=== CONT TestSetClientTLSErrors/missing_cert_file220=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths221=== CONT TestSetClientTLSErrors/invalid_ca_file222=== CONT TestSetClientTLSErrors/missing_ca_file223=== CONT TestSetClientTLSErrors/missing_key_file224=== CONT TestRateLimiterFeedback/429_enables_limiter225--- PASS: TestSetClientTLSErrors (0.01s)226 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)227 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)228 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)229 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)2302026/07/09 07:19:46 WARN Rate limiter enabled after throttle name=server-test rate=52312026/07/09 07:19:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:519252322026/07/09 07:19:46 WARN Rate limiter backed off name=server-test rate=5233=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths234--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)235 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)236 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)237=== CONT TestPathInfoCACompatibility/null_ca_field238=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter239=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter240=== CONT TestRateLimiterFeedback/503_enables_limiter241--- PASS: TestScriptTokenBadJSON (0.02s)242=== CONT TestUploadMultipart_SupersededByPeer/exists243--- PASS: TestScriptTokenEmptyToken (0.02s)244=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method2452026/07/09 07:19:46 WARN Rate limiter enabled after throttle name=server-test rate=52462026/07/09 07:19:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:51931247=== CONT TestPathInfoCACompatibility/new_structured_format_-_text248=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive249=== CONT TestPathInfoCACompatibility/old_string_format_-_text250--- PASS: TestPathInfoCACompatibility (0.00s)251 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)252 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)253 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)254 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)255 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)256=== CONT TestUploadMultipart_SupersededByPeer/missing2572026/07/09 07:19:46 WARN Rate limiter backed off name=server-test rate=5258--- PASS: TestRateLimiterFeedback (0.00s)259 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)260 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)261 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)262 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)263=== CONT TestPartSizeForNAR/zero_stays_at_minimum264=== CONT TestPartSizeForNAR/1_TiB265=== CONT TestPartSizeForNAR/capped_at_5_GiB266=== CONT TestPartSizeForNAR/5_TiB_S3_max_object267=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum268=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts269=== CONT TestPartSizeForNAR/small_stays_at_minimum270--- PASS: TestPartSizeForNAR (0.00s)271 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)272 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)273 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)274 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)275 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)276 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)277 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)278=== CONT TestEncodeNixBase32/test_string_hash279=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)280=== CONT TestEncodeNixBase32/empty_input281=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI282=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512283=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon284--- PASS: TestPathInfoHashCompatibility (0.00s)285 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)286 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)287 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)288 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)289=== CONT TestParsePathInfoJSON/Nix_format290=== CONT TestParsePathInfoJSON/whitespace_only291=== CONT TestParsePathInfoJSON/invalid_JSON292=== CONT TestParsePathInfoJSON/empty_input293=== CONT TestParsePathInfoJSON/Lix_format294--- PASS: TestEncodeNixBase32 (0.00s)295 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)296 --- PASS: TestEncodeNixBase32/empty_input (0.00s)297--- PASS: TestParsePathInfoJSON (0.00s)298 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)299 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)300 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)301 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)302 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)303=== CONT TestGetStorePathHash/valid_store_path304=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error305=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error306=== CONT TestGetStorePathHash/basename_without_hyphen_should_error307--- PASS: TestGetStorePathHash (0.00s)308 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)309 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)310 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)311 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)312=== CONT TestSetClientTLS/rejects_connection_without_client_cert313=== CONT TestSetClientTLS/preserves_debug_logging_transport314--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)315 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)316 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)317=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3182026/07/09 07:19:46 http: TLS handshake error from 127.0.0.1:51937: read tcp 127.0.0.1:51924->127.0.0.1:51937: use of closed network connection319--- PASS: TestSetClientTLS (0.01s)320 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)321 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)322 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)323--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)324--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)325--- PASS: TestDumpPathWriterError (0.04s)326--- PASS: TestDumpPathSingleFile (0.31s)327--- PASS: TestCaseHackSuffix (0.31s)328--- PASS: TestDumpPathMatchesNix (0.32s)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 disabled.340341creating directory /nix/var/nix/builds/nix-84864-1761111497/postgres3171649900/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-84864-1761111497/postgres3171649900/data -l logfile start358359/nix/var/nix/builds/nix-84864-1761111497/postgres3171649900:5432 - no response3602026-07-09 07:19:48.861 UTC [85065] LOG: starting PostgreSQL 17.10 on aarch64-apple-darwin25.3.0, compiled by clang version 21.1.8, 64-bit3612026-07-09 07:19:48.862 UTC [85065] LOG: listening on Unix socket "/nix/var/nix/builds/nix-84864-1761111497/postgres3171649900/.s.PGSQL.5432"3622026-07-09 07:19:48.867 UTC [85073] LOG: database system was shut down at 2026-07-09 07:19:48 UTC3632026-07-09 07:19:48.872 UTC [85065] LOG: database system is ready to accept connections364/nix/var/nix/builds/nix-84864-1761111497/postgres3171649900:5432 - accepting connections365<jemalloc>: option background_thread currently supports pthread only366=== RUN TestService_AuthMiddleware367=== PAUSE TestService_AuthMiddleware368=== RUN TestService_AuthMiddleware_MTLSProxyHeader369=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader370=== RUN TestService_AuthMiddleware_MTLSBoundSubjects371=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects372=== RUN TestService_ReadAuthMiddleware373=== PAUSE TestService_ReadAuthMiddleware374=== RUN TestService_AuthMiddleware_OIDC375=== PAUSE TestService_AuthMiddleware_OIDC376=== RUN TestCacheConfigHandler377=== PAUSE TestCacheConfigHandler378=== RUN TestCacheStatsHandler379=== PAUSE TestCacheStatsHandler380=== RUN TestClientCADerivations381=== PAUSE TestClientCADerivations382=== RUN TestClientErrorHandling383=== PAUSE TestClientErrorHandling384=== RUN TestClientIntegration385=== PAUSE TestClientIntegration386=== RUN TestClientMultipleUploads387=== PAUSE TestClientMultipleUploads388=== RUN TestClientWithDependencies389=== PAUSE TestClientWithDependencies390=== RUN TestPinProtectsFromGC391=== PAUSE TestPinProtectsFromGC392=== RUN TestGCAdvisoryLockBlocksConcurrentRun393{"timestamp":"2026-07-09T07:19:49.130547Z","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(10)"}3942026-07-09 07:19:49.176 UTC [85128] ERROR: relation "goose_db_version" does not exist at character 363952026-07-09 07:19:49.176 UTC [85128] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC3962026/07/09 07:19:49 OK 20241026095416_initial_model.sql (8.16ms)3972026/07/09 07:19:49 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)3982026/07/09 07:19:49 OK 20251218171726_add_pins.sql (2.49ms)3992026/07/09 07:19:49 OK 20260628120000_add_object_size_and_stats.sql (2.58ms)4002026/07/09 07:19:49 goose: successfully migrated database to version: 202606281200004012026/07/09 07:19:49 OK 1_commit_pending_closure.sql (3.17ms)4022026/07/09 07:19:49 OK 2_object_stats_trigger.sql (662.92µs)4032026/07/09 07:19:49 goose: up to current file version: 2404--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.15s)405=== RUN TestGCBugBareHashReferences406=== PAUSE TestGCBugBareHashReferences407=== RUN TestGCMetrics408=== PAUSE TestGCMetrics409=== RUN TestGCTaskStore_StartNew410=== PAUSE TestGCTaskStore_StartNew411=== RUN TestGCTaskStore_DeduplicateSameParams412=== PAUSE TestGCTaskStore_DeduplicateSameParams413=== RUN TestGCTaskStore_ConflictDifferentParams414=== PAUSE TestGCTaskStore_ConflictDifferentParams415=== RUN TestGCTaskStore_GetEmpty416=== PAUSE TestGCTaskStore_GetEmpty417=== RUN TestGCTaskStore_GetReturnsLatest418=== PAUSE TestGCTaskStore_GetReturnsLatest419=== RUN TestGCTaskStore_CompletedAllowsNewTask420=== PAUSE TestGCTaskStore_CompletedAllowsNewTask421=== RUN TestGCTaskStore_PhaseUpdates422=== PAUSE TestGCTaskStore_PhaseUpdates423=== RUN TestGCTaskStore_Fail424=== PAUSE TestGCTaskStore_Fail425=== RUN TestGracefulShutdownDrainsInflight426=== PAUSE TestGracefulShutdownDrainsInflight427=== RUN TestService_healthCheckHandler428=== PAUSE TestService_healthCheckHandler429=== RUN TestGenerateLandingPage430=== PAUSE TestGenerateLandingPage431=== RUN TestNARDeduplicationMetadataUploadBug432=== PAUSE TestNARDeduplicationMetadataUploadBug433=== RUN TestMetricsInventory434=== PAUSE TestMetricsInventory435=== RUN TestService_NativeMTLS436=== PAUSE TestService_NativeMTLS437=== RUN TestServerTLSConfig438=== PAUSE TestServerTLSConfig439=== RUN TestMultipartCleanup440=== PAUSE TestMultipartCleanup441=== RUN TestObjectStatsTrigger442=== PAUSE TestObjectStatsTrigger443=== RUN TestOrphanedObjectsGC444=== PAUSE TestOrphanedObjectsGC445=== RUN TestOrphanedObjectsGCStressTest446=== PAUSE TestOrphanedObjectsGCStressTest447=== RUN TestResurrectedObjectNotDeleted448=== PAUSE TestResurrectedObjectNotDeleted449=== RUN TestParseSingleRange450=== PAUSE TestParseSingleRange451=== RUN TestIsValidCachePath452=== PAUSE TestIsValidCachePath453=== RUN TestReadProxyNarinfo454=== PAUSE TestReadProxyNarinfo455=== RUN TestReadProxyNarinfoAlreadyDecompressed456=== PAUSE TestReadProxyNarinfoAlreadyDecompressed457=== RUN TestReadProxyNarStreaming458=== PAUSE TestReadProxyNarStreaming459=== RUN TestReadProxy404460=== PAUSE TestReadProxy404461=== RUN TestReadProxyInvalidPath462=== PAUSE TestReadProxyInvalidPath463=== RUN TestReadProxyHead464=== PAUSE TestReadProxyHead465=== RUN TestReadProxyConditionalGet466=== PAUSE TestReadProxyConditionalGet467=== RUN TestReadProxyRootRedirectsToIndexHTML468=== PAUSE TestReadProxyRootRedirectsToIndexHTML469=== RUN TestReadProxyDisabled470=== PAUSE TestReadProxyDisabled471=== RUN TestReadProxyRangeRequest472=== PAUSE TestReadProxyRangeRequest473=== RUN TestRedundantMultipartUpload474=== PAUSE TestRedundantMultipartUpload475=== RUN TestCompleteMultipartUpload_ErrorButObjectExists476=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists477=== RUN TestService_Rustfstest478=== PAUSE TestService_Rustfstest479=== RUN TestSystemdListenerNotActivated480--- PASS: TestSystemdListenerNotActivated (0.00s)481=== RUN TestWatchdogBeatsWhenHealthy482--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)483=== RUN TestWatchdogSkipsWhenUnhealthy4842026/07/09 07:19:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4852026/07/09 07:19:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4862026/07/09 07:19:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4872026/07/09 07:19:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4882026/07/09 07:19:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4892026/07/09 07:19:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4902026/07/09 07:19:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4912026/07/09 07:19:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4922026/07/09 07:19:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4932026/07/09 07:19:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"494--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)495=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle496=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle497=== RUN TestProxyWriteTimeout498=== PAUSE TestProxyWriteTimeout499=== RUN TestIsValidUploadKey500=== PAUSE TestIsValidUploadKey501=== RUN TestUploadHandlersRejectInvalidKeys502=== PAUSE TestUploadHandlersRejectInvalidKeys503=== RUN TestUploadHandlersRejectOversizedBody504=== PAUSE TestUploadHandlersRejectOversizedBody505=== RUN TestService_cleanupPendingClosuresHandler506=== PAUSE TestService_cleanupPendingClosuresHandler507=== RUN TestService_createPendingClosureHandler508=== PAUSE TestService_createPendingClosureHandler509=== RUN TestService_verifyS3Integrity510=== PAUSE TestService_verifyS3Integrity511=== RUN TestCompleteMultipartUnregistered512=== PAUSE TestCompleteMultipartUnregistered513=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT514=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT515=== CONT TestService_AuthMiddleware516=== CONT TestMultipartCleanup517=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT518=== CONT TestCompleteMultipartUnregistered519=== CONT TestGCTaskStore_StartNew520--- PASS: TestGCTaskStore_StartNew (0.00s)521=== CONT TestServerTLSConfig522=== RUN TestServerTLSConfig/no_client_CA523=== PAUSE TestServerTLSConfig/no_client_CA524=== RUN TestServerTLSConfig/missing_CA_file525=== PAUSE TestServerTLSConfig/missing_CA_file526=== RUN TestServerTLSConfig/not_a_PEM_file527=== PAUSE TestServerTLSConfig/not_a_PEM_file528=== CONT TestServerTLSConfig/no_client_CA529=== CONT TestService_NativeMTLS530=== CONT TestClientErrorHandling531=== RUN TestClientErrorHandling/InvalidStorePath532=== PAUSE TestClientErrorHandling/InvalidStorePath533=== RUN TestClientErrorHandling/InvalidAuthToken534=== PAUSE TestClientErrorHandling/InvalidAuthToken535=== RUN TestClientErrorHandling/ServerNotAvailable536=== PAUSE TestClientErrorHandling/ServerNotAvailable537=== CONT TestClientErrorHandling/InvalidStorePath538=== CONT TestGCMetrics539=== CONT TestGCTaskStore_PhaseUpdates540--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)541=== CONT TestMetricsInventory542=== CONT TestNARDeduplicationMetadataUploadBug543=== CONT TestGenerateLandingPage544--- PASS: TestGenerateLandingPage (0.00s)545=== CONT TestService_healthCheckHandler5462026-07-09 07:19:49.667 UTC [85164] ERROR: relation "goose_db_version" does not exist at character 365472026-07-09 07:19:49.667 UTC [85164] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5482026/07/09 07:19:49 OK 20241026095416_initial_model.sql (53.95ms)5492026/07/09 07:19:49 OK 20251210153512_drop_unused_gin_index.sql (3.59ms)5502026/07/09 07:19:49 OK 20251218171726_add_pins.sql (5.87ms)5512026/07/09 07:19:49 OK 20260628120000_add_object_size_and_stats.sql (9.07ms)5522026/07/09 07:19:49 goose: successfully migrated database to version: 202606281200005532026-07-09 07:19:49.761 UTC [85168] ERROR: relation "goose_db_version" does not exist at character 365542026-07-09 07:19:49.761 UTC [85168] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5552026-07-09 07:19:49.762 UTC [85169] ERROR: relation "goose_db_version" does not exist at character 365562026-07-09 07:19:49.762 UTC [85169] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5572026/07/09 07:19:49 OK 1_commit_pending_closure.sql (3.09ms)5582026/07/09 07:19:49 OK 2_object_stats_trigger.sql (739.63µs)5592026/07/09 07:19:49 goose: up to current file version: 25602026-07-09 07:19:49.764 UTC [85170] ERROR: relation "goose_db_version" does not exist at character 365612026-07-09 07:19:49.764 UTC [85170] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5622026-07-09 07:19:49.765 UTC [85171] ERROR: relation "goose_db_version" does not exist at character 365632026-07-09 07:19:49.765 UTC [85171] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5642026-07-09 07:19:49.770 UTC [85172] ERROR: relation "goose_db_version" does not exist at character 365652026-07-09 07:19:49.770 UTC [85172] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5662026-07-09 07:19:49.771 UTC [85173] ERROR: relation "goose_db_version" does not exist at character 365672026-07-09 07:19:49.771 UTC [85173] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5682026-07-09 07:19:49.771 UTC [85174] ERROR: relation "goose_db_version" does not exist at character 365692026-07-09 07:19:49.771 UTC [85174] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5702026/07/09 07:19:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete5712026/07/09 07:19:49 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst572--- PASS: TestCompleteMultipartUnregistered (0.31s)573=== CONT TestGracefulShutdownDrainsInflight5742026/07/09 07:19:49 INFO Starting HTTP server address=127.0.0.1:519535752026/07/09 07:19:49 INFO Shutdown signal received, draining in-flight requests timeout=10s5762026/07/09 07:19:49 OK 20241026095416_initial_model.sql (9.35ms)5772026/07/09 07:19:49 OK 20241026095416_initial_model.sql (10.94ms)5782026/07/09 07:19:49 OK 20241026095416_initial_model.sql (10.02ms)5792026/07/09 07:19:49 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)5802026/07/09 07:19:49 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)5812026/07/09 07:19:49 OK 20241026095416_initial_model.sql (11.48ms)5822026/07/09 07:19:49 OK 20251210153512_drop_unused_gin_index.sql (981.33µs)5832026/07/09 07:19:49 OK 20251210153512_drop_unused_gin_index.sql (953.63µs)5842026/07/09 07:19:49 OK 20241026095416_initial_model.sql (9.33ms)5852026-07-09 07:19:49.786 UTC [85175] ERROR: relation "goose_db_version" does not exist at character 365862026-07-09 07:19:49.786 UTC [85175] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5872026/07/09 07:19:49 OK 20241026095416_initial_model.sql (9.42ms)5882026/07/09 07:19:49 OK 20251218171726_add_pins.sql (1.94ms)5892026/07/09 07:19:49 OK 20251218171726_add_pins.sql (2.13ms)5902026/07/09 07:19:49 OK 20241026095416_initial_model.sql (10.29ms)5912026/07/09 07:19:49 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)5922026/07/09 07:19:49 OK 20251218171726_add_pins.sql (2.32ms)5932026-07-09 07:19:49.787 UTC [85176] ERROR: relation "goose_db_version" does not exist at character 365942026-07-09 07:19:49.787 UTC [85176] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5952026/07/09 07:19:49 OK 20251218171726_add_pins.sql (3.03ms)5962026/07/09 07:19:49 OK 20251210153512_drop_unused_gin_index.sql (1.82ms)5972026/07/09 07:19:49 OK 20251210153512_drop_unused_gin_index.sql (1.13ms)5982026/07/09 07:19:49 OK 20260628120000_add_object_size_and_stats.sql (2.84ms)5992026/07/09 07:19:49 goose: successfully migrated database to version: 202606281200006002026/07/09 07:19:49 OK 20260628120000_add_object_size_and_stats.sql (2.74ms)6012026/07/09 07:19:49 goose: successfully migrated database to version: 202606281200006022026/07/09 07:19:49 OK 20251218171726_add_pins.sql (2.46ms)6032026/07/09 07:19:49 OK 20251218171726_add_pins.sql (2.05ms)6042026/07/09 07:19:49 OK 20260628120000_add_object_size_and_stats.sql (2.5ms)6052026/07/09 07:19:49 goose: successfully migrated database to version: 202606281200006062026/07/09 07:19:49 OK 20251218171726_add_pins.sql (1.87ms)6072026/07/09 07:19:49 OK 20260628120000_add_object_size_and_stats.sql (2.73ms)6082026/07/09 07:19:49 goose: successfully migrated database to version: 202606281200006092026/07/09 07:19:49 OK 1_commit_pending_closure.sql (2.02ms)6102026/07/09 07:19:49 OK 1_commit_pending_closure.sql (2.12ms)6112026/07/09 07:19:49 OK 20260628120000_add_object_size_and_stats.sql (1.76ms)6122026/07/09 07:19:49 goose: successfully migrated database to version: 202606281200006132026/07/09 07:19:49 OK 2_object_stats_trigger.sql (510.63µs)6142026/07/09 07:19:49 goose: up to current file version: 26152026/07/09 07:19:49 OK 1_commit_pending_closure.sql (1.6ms)6162026/07/09 07:19:49 OK 2_object_stats_trigger.sql (681.88µs)6172026/07/09 07:19:49 goose: up to current file version: 26182026/07/09 07:19:49 OK 20260628120000_add_object_size_and_stats.sql (2.1ms)6192026/07/09 07:19:49 goose: successfully migrated database to version: 202606281200006202026/07/09 07:19:49 OK 1_commit_pending_closure.sql (1.7ms)6212026/07/09 07:19:49 OK 20260628120000_add_object_size_and_stats.sql (1.92ms)6222026/07/09 07:19:49 goose: successfully migrated database to version: 202606281200006232026/07/09 07:19:49 OK 2_object_stats_trigger.sql (589µs)6242026/07/09 07:19:49 goose: up to current file version: 26252026/07/09 07:19:49 OK 2_object_stats_trigger.sql (635.88µs)6262026/07/09 07:19:49 goose: up to current file version: 26272026/07/09 07:19:49 OK 1_commit_pending_closure.sql (1.42ms)6282026/07/09 07:19:49 OK 1_commit_pending_closure.sql (1.43ms)6292026/07/09 07:19:49 OK 2_object_stats_trigger.sql (574.29µs)6302026/07/09 07:19:49 goose: up to current file version: 26312026/07/09 07:19:49 OK 1_commit_pending_closure.sql (1.8ms)6322026/07/09 07:19:49 OK 2_object_stats_trigger.sql (576.42µs)6332026/07/09 07:19:49 goose: up to current file version: 26342026/07/09 07:19:49 OK 2_object_stats_trigger.sql (1.05ms)6352026/07/09 07:19:49 goose: up to current file version: 26362026/07/09 07:19:49 INFO Received uploads request method=POST path=/api/pending_closures6372026/07/09 07:19:49 INFO Received uploads request method=POST path=/api/pending_closures6382026/07/09 07:19:49 WARN mTLS auth: subject not in bound subjects subject="CN=reader"6392026/07/09 07:19:49 WARN mTLS auth: subject not in bound subjects subject="CN=writer"640--- PASS: TestService_NativeMTLS (0.32s)641=== CONT TestGCTaskStore_Fail642--- PASS: TestGCTaskStore_Fail (0.00s)643=== CONT TestService_AuthMiddleware_OIDC6442026/07/09 07:19:49 OK 20241026095416_initial_model.sql (8.38ms)6452026/07/09 07:19:49 INFO OIDC provider initialized name=test6462026/07/09 07:19:49 OK 20241026095416_initial_model.sql (7.89ms)6472026/07/09 07:19:49 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)6482026/07/09 07:19:49 OK 20251210153512_drop_unused_gin_index.sql (940.67µs)6492026/07/09 07:19:49 OK 20251218171726_add_pins.sql (2.27ms)6502026/07/09 07:19:49 OK 20251218171726_add_pins.sql (2.47ms)6512026/07/09 07:19:49 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"652--- PASS: TestService_AuthMiddleware (0.33s)653=== CONT TestClientCADerivations6542026/07/09 07:19:49 INFO Aborted multipart uploads count=06552026/07/09 07:19:49 OK 20260628120000_add_object_size_and_stats.sql (2.7ms)6562026/07/09 07:19:49 goose: successfully migrated database to version: 202606281200006572026/07/09 07:19:49 OK 20260628120000_add_object_size_and_stats.sql (2.34ms)6582026/07/09 07:19:49 goose: successfully migrated database to version: 202606281200006592026/07/09 07:19:49 OK 1_commit_pending_closure.sql (1.84ms)6602026/07/09 07:19:49 WARN Force mode enabled - objects will be deleted immediately without grace period6612026/07/09 07:19:49 OK 1_commit_pending_closure.sql (1.77ms)6622026/07/09 07:19:49 OK 2_object_stats_trigger.sql (539.25µs)6632026/07/09 07:19:49 goose: up to current file version: 26642026/07/09 07:19:49 OK 2_object_stats_trigger.sql (552.58µs)6652026/07/09 07:19:49 goose: up to current file version: 26662026/07/09 07:19:49 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=06672026/07/09 07:19:49 INFO Vacuumed table table=pending_closures6682026/07/09 07:19:49 INFO Vacuumed table table=pending_objects6692026/07/09 07:19:49 INFO Vacuumed table table=multipart_uploads6702026/07/09 07:19:49 INFO Vacuumed table table=closures6712026/07/09 07:19:49 INFO Vacuumed table table=objects672--- PASS: TestGCMetrics (0.34s)673=== CONT TestCacheStatsHandler674--- PASS: TestService_healthCheckHandler (0.37s)675=== CONT TestCacheConfigHandler676=== RUN TestCacheConfigHandler/full_config,_no_issuer677=== PAUSE TestCacheConfigHandler/full_config,_no_issuer678=== RUN TestCacheConfigHandler/no_cache_url_configured679=== PAUSE TestCacheConfigHandler/no_cache_url_configured680=== RUN TestCacheConfigHandler/no_signing_keys681=== PAUSE TestCacheConfigHandler/no_signing_keys682=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator683=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator684=== CONT TestReadProxyRootRedirectsToIndexHTML685--- PASS: TestGracefulShutdownDrainsInflight (0.07s)686=== CONT TestService_verifyS3Integrity687--- PASS: TestMetricsInventory (0.38s)688=== CONT TestService_createPendingClosureHandler689--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.39s)690=== CONT TestService_cleanupPendingClosuresHandler691{"timestamp":"2026-07-09T07:19:49.862342Z","level":"ERROR","fields":{"message":"system path read failed","path_kind":"data_usage","operation":"read_primary","reason":"config_not_found","object":"buckets/.usage.json","error":"Config not found"},"target":"rustfs_ecstore::data_usage","filename":"crates/ecstore/src/data_usage.rs","line_number":126,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}6922026/07/09 07:19:49 INFO Created nix-cache-info in bucket bucket=bucket96932026-07-09 07:19:49.891 UTC [85196] ERROR: relation "goose_db_version" does not exist at character 366942026-07-09 07:19:49.891 UTC [85196] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC695=== CONT TestUploadHandlersRejectOversizedBody6962026-07-09 07:19:49.894 UTC [85197] ERROR: relation "goose_db_version" does not exist at character 366972026-07-09 07:19:49.894 UTC [85197] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6982026-07-09 07:19:49.916 UTC [85198] ERROR: relation "goose_db_version" does not exist at character 366992026-07-09 07:19:49.916 UTC [85198] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7002026/07/09 07:19:49 OK 20241026095416_initial_model.sql (12.96ms)7012026/07/09 07:19:49 OK 20241026095416_initial_model.sql (14.03ms)7022026/07/09 07:19:49 OK 20251210153512_drop_unused_gin_index.sql (957.71µs)7032026/07/09 07:19:49 OK 20251210153512_drop_unused_gin_index.sql (934.54µs)704=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure705=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure706=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart707=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart708=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts709=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts710=== CONT TestUploadHandlersRejectInvalidKeys711=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info712=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info713=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal714=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal715=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key716=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key717=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key718=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key719=== CONT TestIsValidUploadKey720=== RUN TestIsValidUploadKey/narinfo721=== PAUSE TestIsValidUploadKey/narinfo722=== RUN TestIsValidUploadKey/nar_zst723=== PAUSE TestIsValidUploadKey/nar_zst724=== RUN TestIsValidUploadKey/nar_xz725=== PAUSE TestIsValidUploadKey/nar_xz726=== RUN TestIsValidUploadKey/nar_plain727=== PAUSE TestIsValidUploadKey/nar_plain728=== RUN TestIsValidUploadKey/listing729=== PAUSE TestIsValidUploadKey/listing730=== RUN TestIsValidUploadKey/build_log731=== PAUSE TestIsValidUploadKey/build_log732=== RUN TestIsValidUploadKey/build_log_home-manager_file733=== PAUSE TestIsValidUploadKey/build_log_home-manager_file734=== RUN TestIsValidUploadKey/build_log_plus_in_name735=== PAUSE TestIsValidUploadKey/build_log_plus_in_name736=== RUN TestIsValidUploadKey/build_log_question_mark737=== PAUSE TestIsValidUploadKey/build_log_question_mark738=== RUN TestIsValidUploadKey/build_log_equals739=== PAUSE TestIsValidUploadKey/build_log_equals740=== RUN TestIsValidUploadKey/realisation741=== PAUSE TestIsValidUploadKey/realisation742=== RUN TestIsValidUploadKey/realisation_plus_in_output743=== PAUSE TestIsValidUploadKey/realisation_plus_in_output744=== RUN TestIsValidUploadKey/nix-cache-info745=== PAUSE TestIsValidUploadKey/nix-cache-info746=== RUN TestIsValidUploadKey/index.html747=== PAUSE TestIsValidUploadKey/index.html748=== RUN TestIsValidUploadKey/narinfo_key,_nar_type749=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type750=== RUN TestIsValidUploadKey/nar_key,_narinfo_type751=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type752=== RUN TestIsValidUploadKey/listing_key,_narinfo_type753=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type754=== RUN TestIsValidUploadKey/traversal755=== PAUSE TestIsValidUploadKey/traversal756=== RUN TestIsValidUploadKey/traversal_nar757=== PAUSE TestIsValidUploadKey/traversal_nar758=== RUN TestIsValidUploadKey/absolute759=== PAUSE TestIsValidUploadKey/absolute760=== RUN TestIsValidUploadKey/empty_key761=== PAUSE TestIsValidUploadKey/empty_key762=== RUN TestIsValidUploadKey/unknown_type763=== PAUSE TestIsValidUploadKey/unknown_type764=== CONT TestProxyWriteTimeout765=== RUN TestProxyWriteTimeout/narinfo766=== PAUSE TestProxyWriteTimeout/narinfo767=== RUN TestProxyWriteTimeout/1_GiB_nar768=== PAUSE TestProxyWriteTimeout/1_GiB_nar769=== RUN TestProxyWriteTimeout/10_GiB_nar770=== PAUSE TestProxyWriteTimeout/10_GiB_nar771=== RUN TestProxyWriteTimeout/unknown_size772=== PAUSE TestProxyWriteTimeout/unknown_size773=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle7742026/07/09 07:19:49 OK 20251218171726_add_pins.sql (2.58ms)7752026/07/09 07:19:49 OK 20251218171726_add_pins.sql (3.6ms)7762026/07/09 07:19:49 OK 20260628120000_add_object_size_and_stats.sql (4.23ms)7772026/07/09 07:19:49 goose: successfully migrated database to version: 202606281200007782026/07/09 07:19:49 OK 20260628120000_add_object_size_and_stats.sql (2.7ms)7792026/07/09 07:19:49 goose: successfully migrated database to version: 202606281200007802026/07/09 07:19:49 OK 1_commit_pending_closure.sql (1.86ms)7812026/07/09 07:19:49 OK 1_commit_pending_closure.sql (1.99ms)7822026/07/09 07:19:49 OK 2_object_stats_trigger.sql (561.13µs)7832026/07/09 07:19:49 goose: up to current file version: 27842026/07/09 07:19:49 OK 2_object_stats_trigger.sql (607.96µs)7852026/07/09 07:19:49 goose: up to current file version: 27862026/07/09 07:19:49 OK 20241026095416_initial_model.sql (12.54ms)7872026/07/09 07:19:49 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)7882026/07/09 07:19:49 OK 20251218171726_add_pins.sql (2.53ms)789=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token790=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token791=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected792=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected793=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected794=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected795=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured796=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured797=== CONT TestService_Rustfstest7982026/07/09 07:19:49 INFO Created nix-cache-info in bucket bucket=bucket127992026/07/09 07:19:49 OK 20260628120000_add_object_size_and_stats.sql (4.56ms)8002026/07/09 07:19:49 goose: successfully migrated database to version: 202606281200008012026/07/09 07:19:49 OK 1_commit_pending_closure.sql (1.86ms)8022026/07/09 07:19:49 OK 2_object_stats_trigger.sql (393.42µs)8032026/07/09 07:19:49 goose: up to current file version: 28042026/07/09 07:19:49 INFO Received cleanup request method=DELETE path=/api/pending_closures8052026/07/09 07:19:49 INFO Aborted multipart uploads count=1806--- PASS: TestCacheStatsHandler (0.18s)807=== CONT TestCompleteMultipartUpload_ErrorButObjectExists808--- PASS: TestMultipartCleanup (0.52s)809=== CONT TestRedundantMultipartUpload810=== NAME TestNARDeduplicationMetadataUploadBug811 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-84864-1761111497/TestNARDeduplicationMetadataUploadBug681800468/001/store/02l77r5x23661bqhhn6jq18i9k985jsv-file1.txt8122026-07-09 07:19:50.009 UTC [85209] ERROR: relation "goose_db_version" does not exist at character 368132026-07-09 07:19:50.009 UTC [85209] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8142026-07-09 07:19:50.009 UTC [85210] ERROR: relation "goose_db_version" does not exist at character 368152026-07-09 07:19:50.009 UTC [85210] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026/07/09 07:19:50 OK 20241026095416_initial_model.sql (12.88ms)8172026/07/09 07:19:50 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)8182026/07/09 07:19:50 OK 20251218171726_add_pins.sql (3.02ms)8192026/07/09 07:19:50 OK 20241026095416_initial_model.sql (20.41ms)8202026/07/09 07:19:50 OK 20251210153512_drop_unused_gin_index.sql (923.42µs)8212026/07/09 07:19:50 OK 20260628120000_add_object_size_and_stats.sql (4.22ms)8222026/07/09 07:19:50 goose: successfully migrated database to version: 202606281200008232026/07/09 07:19:50 OK 20251218171726_add_pins.sql (2.17ms)8242026/07/09 07:19:50 OK 1_commit_pending_closure.sql (1.94ms)8252026/07/09 07:19:50 OK 2_object_stats_trigger.sql (409.21µs)8262026/07/09 07:19:50 goose: up to current file version: 2827--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.20s)828=== CONT TestReadProxyRangeRequest8292026/07/09 07:19:50 OK 20260628120000_add_object_size_and_stats.sql (18.19ms)8302026/07/09 07:19:50 goose: successfully migrated database to version: 202606281200008312026/07/09 07:19:50 OK 1_commit_pending_closure.sql (2.93ms)8322026/07/09 07:19:50 OK 2_object_stats_trigger.sql (619.75µs)8332026/07/09 07:19:50 goose: up to current file version: 28342026/07/09 07:19:50 INFO Received uploads request method=POST path=/api/pending_closures8352026-07-09 07:19:50.116 UTC [85219] ERROR: relation "goose_db_version" does not exist at character 368362026-07-09 07:19:50.116 UTC [85219] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8372026-07-09 07:19:50.118 UTC [85220] ERROR: relation "goose_db_version" does not exist at character 368382026-07-09 07:19:50.118 UTC [85220] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8392026/07/09 07:19:50 OK 20241026095416_initial_model.sql (15.37ms)8402026/07/09 07:19:50 OK 20241026095416_initial_model.sql (11.75ms)8412026/07/09 07:19:50 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)8422026/07/09 07:19:50 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)8432026/07/09 07:19:50 OK 20251218171726_add_pins.sql (2.2ms)8442026/07/09 07:19:50 OK 20251218171726_add_pins.sql (2.49ms)8452026/07/09 07:19:50 OK 20260628120000_add_object_size_and_stats.sql (3.29ms)8462026/07/09 07:19:50 goose: successfully migrated database to version: 202606281200008472026/07/09 07:19:50 OK 20260628120000_add_object_size_and_stats.sql (4.59ms)8482026/07/09 07:19:50 goose: successfully migrated database to version: 202606281200008492026/07/09 07:19:50 OK 1_commit_pending_closure.sql (2.18ms)8502026/07/09 07:19:50 OK 1_commit_pending_closure.sql (2.04ms)8512026/07/09 07:19:50 OK 2_object_stats_trigger.sql (940.46µs)8522026/07/09 07:19:50 goose: up to current file version: 28532026/07/09 07:19:50 OK 2_object_stats_trigger.sql (820.83µs)8542026/07/09 07:19:50 goose: up to current file version: 28552026/07/09 07:19:50 INFO Received cleanup request method=DELETE path=/api/pending_closures8562026/07/09 07:19:50 INFO Received uploads request method=POST path=/api/pending_closures8572026/07/09 07:19:50 INFO Received uploads request method=POST path=/api/pending_closures8582026/07/09 07:19:50 INFO Received uploads request method=POST path=/api/pending_closures8592026/07/09 07:19:50 INFO Aborted multipart uploads count=08602026/07/09 07:19:50 INFO Received uploads request method=POST path=/api/pending_closures8612026/07/09 07:19:50 INFO Received cleanup request method=DELETE path=/api/pending_closures8622026/07/09 07:19:50 INFO Aborted multipart uploads count=18632026/07/09 07:19:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8642026-07-09 07:19:50.187 UTC [85219] ERROR: Closure does not exist: id=18652026-07-09 07:19:50.187 UTC [85219] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE8662026-07-09 07:19:50.187 UTC [85219] STATEMENT: -- name: CommitPendingClosure :exec867 SELECT commit_pending_closure($1::bigint)868 869--- PASS: TestService_cleanupPendingClosuresHandler (0.33s)870=== CONT TestReadProxyDisabled8712026/07/09 07:19:50 INFO Received uploads request method=POST path=/api/pending_closures8722026/07/09 07:19:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8732026/07/09 07:19:50 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8742026/07/09 07:19:50 INFO Uploading 02l77r5x23661bqhhn6jq18i9k985jsv-file1.txt (160B)8752026/07/09 07:19:50 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MGYzOGI1MTQtNDcxNi00MjAxLTg2MzUtNWQ3MTUzMzgyMDg3LjMyNzAzMDY0LTNlNTAtNDc2ZS04MWZkLTRhOGYyMjkzNjM2NXgxNzgzNTgxNTkwMDc2OTIwMDAw parts=108762026/07/09 07:19:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8772026/07/09 07:19:50 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8782026/07/09 07:19:50 INFO Signed narinfos id=1 count=18792026/07/09 07:19:50 INFO Uploading 1 narinfos8802026/07/09 07:19:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8812026/07/09 07:19:50 INFO Completed upload id=18822026/07/09 07:19:50 INFO Completed upload id=18832026/07/09 07:19:50 INFO Upload complete. (225ms)8842026/07/09 07:19:50 INFO Received uploads request method=POST path=/api/pending_closures8852026/07/09 07:19:50 INFO Received uploads request method=POST path=/api/pending_closures8862026/07/09 07:19:50 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8872026/07/09 07:19:50 WARN Found objects in DB but missing from S3, will re-upload count=1888--- PASS: TestService_verifyS3Integrity (0.45s)889=== CONT TestReadProxyNarinfo890=== NAME TestNARDeduplicationMetadataUploadBug891 metadata_upload_test.go:54: Retrieved narinfo from S3:892 StorePath: /nix/var/nix/builds/nix-84864-1761111497/TestNARDeduplicationMetadataUploadBug681800468/001/store/02l77r5x23661bqhhn6jq18i9k985jsv-file1.txt893 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst894 Compression: zstd895 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf896 NarSize: 160897 References: 898 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf899 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)900 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):901 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}9022026/07/09 07:19:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9032026/07/09 07:19:50 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MGYzOGI1MTQtNDcxNi00MjAxLTg2MzUtNWQ3MTUzMzgyMDg3LmNlY2E4ZjQwLWY1YmItNGYzNy1hYWU3LTY5MjkyYzFhNDliOXgxNzgzNTgxNTkwMTc0Mzc1MDAw parts=109042026/07/09 07:19:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9052026-07-09 07:19:50.368 UTC [85255] ERROR: relation "goose_db_version" does not exist at character 369062026-07-09 07:19:50.368 UTC [85255] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9072026/07/09 07:19:50 INFO Completed upload id=19082026/07/09 07:19:50 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009092026/07/09 07:19:50 INFO Received uploads request method=POST path=/api/pending_closures9102026/07/09 07:19:50 INFO Starting cleanup of old closures method=DELETE path=/api/closures9112026/07/09 07:19:50 INFO Aborted multipart uploads count=0912 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-84864-1761111497/TestNARDeduplicationMetadataUploadBug681800468/001/store/421wspn5s6m3ci4s06x0w4wqrskc3jhm-file2.txt9132026/07/09 07:19:50 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=09142026/07/09 07:19:50 INFO Vacuumed table table=pending_closures9152026/07/09 07:19:50 OK 20241026095416_initial_model.sql (14.63ms)9162026/07/09 07:19:50 INFO Vacuumed table table=pending_objects9172026/07/09 07:19:50 OK 20251210153512_drop_unused_gin_index.sql (1.2ms)9182026/07/09 07:19:50 OK 20251218171726_add_pins.sql (4.66ms)9192026/07/09 07:19:50 INFO Vacuumed table table=multipart_uploads9202026/07/09 07:19:50 INFO Vacuumed table table=closures9212026-07-09 07:19:50.417 UTC [85259] ERROR: relation "goose_db_version" does not exist at character 369222026-07-09 07:19:50.417 UTC [85259] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9232026-07-09 07:19:50.420 UTC [85260] ERROR: relation "goose_db_version" does not exist at character 369242026-07-09 07:19:50.420 UTC [85260] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9252026-07-09 07:19:50.424 UTC [85261] ERROR: relation "goose_db_version" does not exist at character 369262026-07-09 07:19:50.424 UTC [85261] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9272026/07/09 07:19:50 INFO Vacuumed table table=objects9282026/07/09 07:19:50 OK 20260628120000_add_object_size_and_stats.sql (38.19ms)9292026/07/09 07:19:50 goose: successfully migrated database to version: 202606281200009302026/07/09 07:19:50 OK 1_commit_pending_closure.sql (5.55ms)9312026/07/09 07:19:50 OK 2_object_stats_trigger.sql (5.31ms)9322026/07/09 07:19:50 goose: up to current file version: 29332026/07/09 07:19:50 OK 20241026095416_initial_model.sql (20.06ms)9342026/07/09 07:19:50 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000935--- PASS: TestService_Rustfstest (0.54s)936=== CONT TestReadProxyConditionalGet9372026-07-09 07:19:50.479 UTC [85263] ERROR: relation "goose_db_version" does not exist at character 369382026-07-09 07:19:50.479 UTC [85263] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9392026/07/09 07:19:50 OK 20241026095416_initial_model.sql (29.53ms)940--- PASS: TestService_createPendingClosureHandler (0.62s)941=== CONT TestReadProxyHead9422026/07/09 07:19:50 OK 20251210153512_drop_unused_gin_index.sql (11.68ms)9432026/07/09 07:19:50 OK 20241026095416_initial_model.sql (37.89ms)9442026/07/09 07:19:50 OK 20251210153512_drop_unused_gin_index.sql (12.2ms)9452026/07/09 07:19:50 OK 20251210153512_drop_unused_gin_index.sql (9.65ms)9462026/07/09 07:19:50 OK 20251218171726_add_pins.sql (13.89ms)9472026/07/09 07:19:50 OK 20251218171726_add_pins.sql (7.34ms)948=== NAME TestClientCADerivations949 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-84864-1761111497/TestClientCADerivations3465123559/001/store/vzi5kcgys13k4iccrpp4v018xjza0d3d-ca-test9502026/07/09 07:19:50 OK 20260628120000_add_object_size_and_stats.sql (13.87ms)9512026/07/09 07:19:50 goose: successfully migrated database to version: 202606281200009522026/07/09 07:19:50 OK 20251218171726_add_pins.sql (22.94ms)9532026/07/09 07:19:50 OK 1_commit_pending_closure.sql (14.73ms)9542026/07/09 07:19:50 OK 20260628120000_add_object_size_and_stats.sql (27.71ms)9552026/07/09 07:19:50 goose: successfully migrated database to version: 202606281200009562026/07/09 07:19:50 OK 2_object_stats_trigger.sql (12.8ms)9572026/07/09 07:19:50 goose: up to current file version: 29582026/07/09 07:19:50 OK 1_commit_pending_closure.sql (13.64ms)9592026/07/09 07:19:50 OK 2_object_stats_trigger.sql (6.02ms)9602026/07/09 07:19:50 goose: up to current file version: 29612026/07/09 07:19:50 OK 20260628120000_add_object_size_and_stats.sql (26.64ms)9622026/07/09 07:19:50 goose: successfully migrated database to version: 202606281200009632026/07/09 07:19:50 OK 1_commit_pending_closure.sql (2.5ms)9642026/07/09 07:19:50 OK 20241026095416_initial_model.sql (39.17ms)9652026/07/09 07:19:50 OK 2_object_stats_trigger.sql (1.11ms)9662026/07/09 07:19:50 goose: up to current file version: 29672026-07-09 07:19:50.552 UTC [85271] ERROR: relation "goose_db_version" does not exist at character 369682026-07-09 07:19:50.552 UTC [85271] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9692026/07/09 07:19:50 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)9702026/07/09 07:19:50 OK 20251218171726_add_pins.sql (2.24ms)9712026/07/09 07:19:50 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)9722026/07/09 07:19:50 goose: successfully migrated database to version: 202606281200009732026/07/09 07:19:50 OK 1_commit_pending_closure.sql (2.4ms)9742026/07/09 07:19:50 OK 2_object_stats_trigger.sql (502.63µs)9752026/07/09 07:19:50 goose: up to current file version: 29762026/07/09 07:19:50 INFO Received uploads request method=POST path=/api/pending_closures9772026/07/09 07:19:50 INFO Received uploads request method=POST path=/api/pending_closures9782026/07/09 07:19:50 INFO Received uploads request method=POST path=/api/pending_closures9792026/07/09 07:19:50 OK 20241026095416_initial_model.sql (9.61ms)9802026/07/09 07:19:50 OK 20251210153512_drop_unused_gin_index.sql (666.63µs)9812026/07/09 07:19:50 OK 20251218171726_add_pins.sql (1.23ms)9822026/07/09 07:19:50 INFO Received uploads request method=POST path=/api/pending_closures9832026/07/09 07:19:50 OK 20260628120000_add_object_size_and_stats.sql (1.91ms)9842026/07/09 07:19:50 goose: successfully migrated database to version: 202606281200009852026/07/09 07:19:50 OK 1_commit_pending_closure.sql (2.59ms)9862026/07/09 07:19:50 OK 2_object_stats_trigger.sql (1.01ms)9872026/07/09 07:19:50 goose: up to current file version: 2988--- PASS: TestReadProxyDisabled (0.40s)989=== CONT TestReadProxyInvalidPath9902026/07/09 07:19:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete991--- PASS: TestReadProxyRangeRequest (0.54s)992=== CONT TestReadProxy404993{"timestamp":"2026-07-09T07:19:50.599235Z","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(4)"}994{"timestamp":"2026-07-09T07:19:50.599272Z","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(4)"}9952026/07/09 07:19:50 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=MGYzOGI1MTQtNDcxNi00MjAxLTg2MzUtNWQ3MTUzMzgyMDg3LjE1ZDBkNTQ0LTc0ZjgtNGI5ZS1iODlkLWZmYjVlOTdjYjA1OHgxNzgzNTgxNTkwNTY4MTM1MDAw9962026/07/09 07:19:50 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MGYzOGI1MTQtNDcxNi00MjAxLTg2MzUtNWQ3MTUzMzgyMDg3LjE1ZDBkNTQ0LTc0ZjgtNGI5ZS1iODlkLWZmYjVlOTdjYjA1OHgxNzgzNTgxNTkwNTY4MTM1MDAw parts=1997--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.61s)998=== CONT TestReadProxyNarStreaming999=== NAME TestClientCADerivations1000 client_ca_test.go:139: Found 1 dependencies (including self)10012026-07-09 07:19:50.610 UTC [85280] ERROR: relation "goose_db_version" does not exist at character 3610022026-07-09 07:19:50.610 UTC [85280] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10032026/07/09 07:19:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10042026/07/09 07:19:50 OK 20241026095416_initial_model.sql (16.65ms)10052026/07/09 07:19:50 OK 20251210153512_drop_unused_gin_index.sql (901.04µs)10062026/07/09 07:19:50 OK 20251218171726_add_pins.sql (1.3ms)10072026/07/09 07:19:50 OK 20260628120000_add_object_size_and_stats.sql (1.6ms)10082026/07/09 07:19:50 goose: successfully migrated database to version: 2026062812000010092026/07/09 07:19:50 OK 1_commit_pending_closure.sql (2.21ms)10102026/07/09 07:19:50 OK 2_object_stats_trigger.sql (998.58µs)10112026/07/09 07:19:50 goose: up to current file version: 21012--- PASS: TestReadProxyNarinfo (0.36s)1013=== CONT TestReadProxyNarinfoAlreadyDecompressed10142026/07/09 07:19:50 INFO Received uploads request method=POST path=/api/pending_closures10152026/07/09 07:19:50 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)10162026/07/09 07:19:50 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10172026/07/09 07:19:50 INFO Signed narinfos id=2 count=110182026/07/09 07:19:50 INFO Uploading 1 narinfos10192026/07/09 07:19:50 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10202026/07/09 07:19:50 INFO Completed upload id=210212026/07/09 07:19:50 INFO Upload complete. (197ms)1022=== NAME TestNARDeduplicationMetadataUploadBug1023 metadata_upload_test.go:76: Retrieved narinfo from S3:1024 StorePath: /nix/var/nix/builds/nix-84864-1761111497/TestNARDeduplicationMetadataUploadBug681800468/001/store/421wspn5s6m3ci4s06x0w4wqrskc3jhm-file2.txt1025 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1026 Compression: zstd1027 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1028 NarSize: 1601029 References: 1030 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1031 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1032 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1033 {"version":1,"root":{"type":"regular","size":44}}1034--- PASS: TestNARDeduplicationMetadataUploadBug (1.23s)1035=== CONT TestResurrectedObjectNotDeleted10362026/07/09 07:19:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10372026-07-09 07:19:50.787 UTC [85293] ERROR: relation "goose_db_version" does not exist at character 3610382026-07-09 07:19:50.787 UTC [85293] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10392026-07-09 07:19:50.789 UTC [85294] ERROR: relation "goose_db_version" does not exist at character 3610402026-07-09 07:19:50.789 UTC [85294] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10412026/07/09 07:19:50 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MGYzOGI1MTQtNDcxNi00MjAxLTg2MzUtNWQ3MTUzMzgyMDg3LjUwZGQzZjEyLTQ2MDEtNDU3OC1hYTE1LWU3ZmJhNzY3ZmNjMXgxNzgzNTgxNTkwNTY4ODkxMDAw parts=121042--- PASS: TestRedundantMultipartUpload (0.80s)1043=== CONT TestIsValidCachePath1044=== RUN TestIsValidCachePath/narinfo1045=== PAUSE TestIsValidCachePath/narinfo1046=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1047=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1048=== RUN TestIsValidCachePath/nar_zst1049=== PAUSE TestIsValidCachePath/nar_zst1050=== RUN TestIsValidCachePath/nar_xz1051=== PAUSE TestIsValidCachePath/nar_xz1052=== RUN TestIsValidCachePath/nar_bz21053=== PAUSE TestIsValidCachePath/nar_bz21054=== RUN TestIsValidCachePath/nar_uncompressed1055=== PAUSE TestIsValidCachePath/nar_uncompressed1056=== RUN TestIsValidCachePath/ls1057=== PAUSE TestIsValidCachePath/ls1058=== RUN TestIsValidCachePath/log1059=== PAUSE TestIsValidCachePath/log1060=== RUN TestIsValidCachePath/realisation1061=== PAUSE TestIsValidCachePath/realisation1062=== RUN TestIsValidCachePath/nix-cache-info1063=== PAUSE TestIsValidCachePath/nix-cache-info1064=== RUN TestIsValidCachePath/index.html1065=== PAUSE TestIsValidCachePath/index.html1066=== RUN TestIsValidCachePath/traversal_parent1067=== PAUSE TestIsValidCachePath/traversal_parent1068=== RUN TestIsValidCachePath/traversal_in_middle1069=== PAUSE TestIsValidCachePath/traversal_in_middle1070=== RUN TestIsValidCachePath/invalid_char_e1071=== PAUSE TestIsValidCachePath/invalid_char_e1072=== RUN TestIsValidCachePath/invalid_char_u1073=== PAUSE TestIsValidCachePath/invalid_char_u1074=== RUN TestIsValidCachePath/random_path1075=== PAUSE TestIsValidCachePath/random_path1076=== RUN TestIsValidCachePath/empty1077=== PAUSE TestIsValidCachePath/empty1078=== RUN TestIsValidCachePath/leading_slash1079=== PAUSE TestIsValidCachePath/leading_slash1080=== RUN TestIsValidCachePath/wrong_extension1081=== PAUSE TestIsValidCachePath/wrong_extension1082=== RUN TestIsValidCachePath/short_hash1083=== PAUSE TestIsValidCachePath/short_hash1084=== CONT TestParseSingleRange1085=== RUN TestParseSingleRange/none1086=== PAUSE TestParseSingleRange/none1087=== RUN TestParseSingleRange/unknown_unit1088=== PAUSE TestParseSingleRange/unknown_unit1089=== RUN TestParseSingleRange/multi-range_ignored1090=== PAUSE TestParseSingleRange/multi-range_ignored1091=== RUN TestParseSingleRange/malformed_no_dash1092=== PAUSE TestParseSingleRange/malformed_no_dash1093=== RUN TestParseSingleRange/malformed_both_empty1094=== PAUSE TestParseSingleRange/malformed_both_empty1095=== RUN TestParseSingleRange/malformed_end_before_start1096=== PAUSE TestParseSingleRange/malformed_end_before_start1097=== RUN TestParseSingleRange/closed1098=== PAUSE TestParseSingleRange/closed1099=== RUN TestParseSingleRange/open-ended1100=== PAUSE TestParseSingleRange/open-ended1101=== RUN TestParseSingleRange/end_clamped_to_size1102=== PAUSE TestParseSingleRange/end_clamped_to_size1103=== RUN TestParseSingleRange/suffix1104=== PAUSE TestParseSingleRange/suffix1105=== RUN TestParseSingleRange/suffix_exceeds_size1106=== PAUSE TestParseSingleRange/suffix_exceeds_size1107=== RUN TestParseSingleRange/single_byte1108=== PAUSE TestParseSingleRange/single_byte1109=== RUN TestParseSingleRange/start_past_EOF1110=== PAUSE TestParseSingleRange/start_past_EOF1111=== RUN TestParseSingleRange/start_far_past_EOF1112=== PAUSE TestParseSingleRange/start_far_past_EOF1113=== CONT TestGCTaskStore_ConflictDifferentParams1114--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1115=== CONT TestGCTaskStore_CompletedAllowsNewTask1116--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1117=== CONT TestGCTaskStore_GetReturnsLatest1118--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1119=== CONT TestGCTaskStore_GetEmpty1120--- PASS: TestGCTaskStore_GetEmpty (0.00s)1121=== CONT TestService_AuthMiddleware_MTLSBoundSubjects11222026/07/09 07:19:50 OK 20241026095416_initial_model.sql (13.64ms)11232026/07/09 07:19:50 OK 20251210153512_drop_unused_gin_index.sql (1.11ms)11242026/07/09 07:19:50 OK 20241026095416_initial_model.sql (9.94ms)11252026/07/09 07:19:50 OK 20251210153512_drop_unused_gin_index.sql (867.08µs)11262026/07/09 07:19:50 OK 20251218171726_add_pins.sql (2.27ms)11272026/07/09 07:19:50 OK 20251218171726_add_pins.sql (4.7ms)11282026/07/09 07:19:50 OK 20260628120000_add_object_size_and_stats.sql (3.06ms)11292026/07/09 07:19:50 goose: successfully migrated database to version: 2026062812000011302026/07/09 07:19:50 OK 20260628120000_add_object_size_and_stats.sql (3.54ms)11312026/07/09 07:19:50 goose: successfully migrated database to version: 2026062812000011322026/07/09 07:19:50 OK 1_commit_pending_closure.sql (2.1ms)11332026/07/09 07:19:50 OK 1_commit_pending_closure.sql (2.2ms)11342026/07/09 07:19:50 OK 2_object_stats_trigger.sql (625.46µs)11352026/07/09 07:19:50 goose: up to current file version: 211362026/07/09 07:19:50 OK 2_object_stats_trigger.sql (714.13µs)11372026/07/09 07:19:50 goose: up to current file version: 21138--- PASS: TestReadProxyHead (0.38s)1139=== CONT TestService_ReadAuthMiddleware11402026/07/09 07:19:50 INFO Received uploads request method=POST path=/api/pending_closures1141--- PASS: TestReadProxyConditionalGet (0.39s)1142=== CONT TestClientMultipleUploads11432026/07/09 07:19:50 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11442026/07/09 07:19:50 INFO Uploading vzi5kcgys13k4iccrpp4v018xjza0d3d-ca-test (144B)11452026/07/09 07:19:50 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11462026/07/09 07:19:50 INFO Signed narinfos id=1 count=111472026/07/09 07:19:50 INFO Uploading 1 narinfos11482026/07/09 07:19:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11492026/07/09 07:19:50 INFO Completed upload id=111502026/07/09 07:19:50 INFO Upload complete. (219ms)1151=== NAME TestClientCADerivations1152 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-84864-1761111497/TestClientCADerivations3465123559/001/store/vzi5kcgys13k4iccrpp4v018xjza0d3d-ca-test1153 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1154 Compression: zstd1155 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1156 NarSize: 1441157 References: 1158 Deriver: /nix/var/nix/builds/nix-84864-1761111497/TestClientCADerivations3465123559/001/store/maylywmr1x1dvabb29jhs8xmz4jz7gsa-ca-test.drv1159 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1160 client_ca_test.go:185: Checking for realisation files in S3...1161 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1162 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache11632026-07-09 07:19:50.980 UTC [85307] ERROR: relation "goose_db_version" does not exist at character 3611642026-07-09 07:19:50.980 UTC [85307] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11652026-07-09 07:19:50.982 UTC [85308] ERROR: relation "goose_db_version" does not exist at character 3611662026-07-09 07:19:50.982 UTC [85308] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11672026-07-09 07:19:50.997 UTC [85309] ERROR: relation "goose_db_version" does not exist at character 3611682026-07-09 07:19:50.997 UTC [85309] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11692026/07/09 07:19:51 OK 20241026095416_initial_model.sql (14.31ms)11702026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)11712026/07/09 07:19:51 OK 20251218171726_add_pins.sql (3.05ms)11722026/07/09 07:19:51 OK 20241026095416_initial_model.sql (14.56ms)11732026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (4.17ms)11742026/07/09 07:19:51 goose: successfully migrated database to version: 2026062812000011752026/07/09 07:19:51 OK 20241026095416_initial_model.sql (15.2ms)11762026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)11772026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (795.08µs)11782026/07/09 07:19:51 OK 1_commit_pending_closure.sql (2.12ms)11792026/07/09 07:19:51 OK 2_object_stats_trigger.sql (571.71µs)11802026/07/09 07:19:51 goose: up to current file version: 211812026/07/09 07:19:51 OK 20251218171726_add_pins.sql (2.32ms)11822026/07/09 07:19:51 OK 20251218171726_add_pins.sql (2.48ms)1183--- PASS: TestReadProxyInvalidPath (0.45s)1184=== CONT TestGCBugBareHashReferences11852026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (6.15ms)11862026/07/09 07:19:51 goose: successfully migrated database to version: 2026062812000011872026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (6.02ms)11882026/07/09 07:19:51 goose: successfully migrated database to version: 202606281200001189=== NAME TestClientCADerivations1190 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket12?endpoint=http://localhost:51940®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-84864-1761111497/TestClientCADerivations3465123559/001/store'1191 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 111922026/07/09 07:19:51 OK 1_commit_pending_closure.sql (2.87ms)11932026/07/09 07:19:51 OK 2_object_stats_trigger.sql (1.05ms)1194--- PASS: TestClientCADerivations (1.24s)11952026/07/09 07:19:51 goose: up to current file version: 21196=== CONT TestPinProtectsFromGC11972026/07/09 07:19:51 OK 1_commit_pending_closure.sql (4.71ms)11982026/07/09 07:19:51 OK 2_object_stats_trigger.sql (1.52ms)11992026/07/09 07:19:51 goose: up to current file version: 21200--- PASS: TestReadProxy404 (0.46s)1201=== CONT TestClientWithDependencies1202--- PASS: TestReadProxyNarStreaming (0.45s)1203=== CONT TestOrphanedObjectsGC12042026-07-09 07:19:51.071 UTC [85318] ERROR: relation "goose_db_version" does not exist at character 3612052026-07-09 07:19:51.071 UTC [85318] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12062026-07-09 07:19:51.104 UTC [85319] ERROR: relation "goose_db_version" does not exist at character 3612072026-07-09 07:19:51.104 UTC [85319] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12082026/07/09 07:19:51 OK 20241026095416_initial_model.sql (26.34ms)12092026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)12102026/07/09 07:19:51 OK 20251218171726_add_pins.sql (2.65ms)12112026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (5.06ms)12122026/07/09 07:19:51 goose: successfully migrated database to version: 2026062812000012132026/07/09 07:19:51 OK 1_commit_pending_closure.sql (2.6ms)12142026/07/09 07:19:51 OK 2_object_stats_trigger.sql (521.29µs)12152026/07/09 07:19:51 goose: up to current file version: 21216--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.46s)1217=== CONT TestOrphanedObjectsGCStressTest12182026/07/09 07:19:51 OK 20241026095416_initial_model.sql (16.25ms)12192026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (1.08ms)12202026/07/09 07:19:51 OK 20251218171726_add_pins.sql (2.86ms)12212026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (7.28ms)12222026/07/09 07:19:51 goose: successfully migrated database to version: 2026062812000012232026/07/09 07:19:51 OK 1_commit_pending_closure.sql (1.4ms)12242026/07/09 07:19:51 OK 2_object_stats_trigger.sql (327.04µs)12252026/07/09 07:19:51 goose: up to current file version: 21226--- PASS: TestResurrectedObjectNotDeleted (0.47s)1227=== CONT TestService_AuthMiddleware_MTLSProxyHeader12282026-07-09 07:19:51.192 UTC [85323] ERROR: relation "goose_db_version" does not exist at character 3612292026-07-09 07:19:51.192 UTC [85323] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12302026/07/09 07:19:51 OK 20241026095416_initial_model.sql (20.47ms)12312026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)12322026/07/09 07:19:51 OK 20251218171726_add_pins.sql (2.67ms)12332026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (22.95ms)12342026/07/09 07:19:51 goose: successfully migrated database to version: 2026062812000012352026/07/09 07:19:51 OK 1_commit_pending_closure.sql (2.28ms)12362026/07/09 07:19:51 OK 2_object_stats_trigger.sql (619.92µs)12372026/07/09 07:19:51 goose: up to current file version: 212382026/07/09 07:19:51 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"12392026/07/09 07:19:51 WARN mTLS auth: bound subjects configured but subject DN unavailable12402026/07/09 07:19:51 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1241--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.46s)1242=== CONT TestClientErrorHandling/ServerNotAvailable12432026-07-09 07:19:51.268 UTC [85326] ERROR: relation "goose_db_version" does not exist at character 3612442026-07-09 07:19:51.268 UTC [85326] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12452026-07-09 07:19:51.287 UTC [85327] ERROR: relation "goose_db_version" does not exist at character 3612462026-07-09 07:19:51.287 UTC [85327] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12472026/07/09 07:19:51 OK 20241026095416_initial_model.sql (9.12ms)12482026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (822.92µs)12492026/07/09 07:19:51 OK 20251218171726_add_pins.sql (2.15ms)12502026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (3.46ms)12512026/07/09 07:19:51 goose: successfully migrated database to version: 2026062812000012522026/07/09 07:19:51 OK 1_commit_pending_closure.sql (2.12ms)12532026/07/09 07:19:51 OK 20241026095416_initial_model.sql (9.43ms)12542026/07/09 07:19:51 OK 2_object_stats_trigger.sql (449.63µs)12552026/07/09 07:19:51 goose: up to current file version: 212562026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (987.04µs)12572026/07/09 07:19:51 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1258--- PASS: TestService_ReadAuthMiddleware (0.45s)1259=== CONT TestClientIntegration12602026/07/09 07:19:51 OK 20251218171726_add_pins.sql (2.49ms)12612026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (2.94ms)12622026/07/09 07:19:51 goose: successfully migrated database to version: 2026062812000012632026/07/09 07:19:51 OK 1_commit_pending_closure.sql (2.13ms)12642026/07/09 07:19:51 OK 2_object_stats_trigger.sql (702.71µs)12652026/07/09 07:19:51 goose: up to current file version: 212662026/07/09 07:19:51 INFO Created nix-cache-info in bucket bucket=bucket351267=== NAME TestClientMultipleUploads1268 client_integration_test.go:338: Created store path 0: /nix/var/nix/builds/nix-84864-1761111497/TestClientMultipleUploads2118336446/001/store/936316f0mzh149fr1kkmd0f71v77hcb2-test-file-0.txt12692026-07-09 07:19:51.424 UTC [85336] ERROR: relation "goose_db_version" does not exist at character 3612702026-07-09 07:19:51.424 UTC [85336] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12712026-07-09 07:19:51.448 UTC [85338] ERROR: relation "goose_db_version" does not exist at character 3612722026-07-09 07:19:51.448 UTC [85338] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12732026-07-09 07:19:51.450 UTC [85339] ERROR: relation "goose_db_version" does not exist at character 3612742026-07-09 07:19:51.450 UTC [85339] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12752026/07/09 07:19:51 OK 20241026095416_initial_model.sql (21.74ms)12762026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (839.33µs)12772026/07/09 07:19:51 OK 20251218171726_add_pins.sql (2.8ms)12782026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (9.87ms)12792026/07/09 07:19:51 goose: successfully migrated database to version: 2026062812000012802026-07-09 07:19:51.472 UTC [85341] ERROR: relation "goose_db_version" does not exist at character 3612812026-07-09 07:19:51.472 UTC [85341] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12822026/07/09 07:19:51 OK 1_commit_pending_closure.sql (2.09ms)12832026/07/09 07:19:51 OK 2_object_stats_trigger.sql (491.71µs)12842026/07/09 07:19:51 goose: up to current file version: 212852026/07/09 07:19:51 OK 20241026095416_initial_model.sql (16.44ms)12862026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (850.25µs)12872026/07/09 07:19:51 OK 20241026095416_initial_model.sql (17.81ms)12882026/07/09 07:19:51 INFO Created nix-cache-info in bucket bucket=bucket3612892026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (689.46µs)12902026/07/09 07:19:51 OK 20251218171726_add_pins.sql (2.17ms)12912026/07/09 07:19:51 OK 20251218171726_add_pins.sql (4.86ms)12922026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (3.01ms)12932026/07/09 07:19:51 goose: successfully migrated database to version: 2026062812000012942026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)12952026/07/09 07:19:51 goose: successfully migrated database to version: 2026062812000012962026/07/09 07:19:51 OK 1_commit_pending_closure.sql (2.89ms)12972026/07/09 07:19:51 OK 2_object_stats_trigger.sql (567.83µs)12982026/07/09 07:19:51 goose: up to current file version: 212992026/07/09 07:19:51 OK 1_commit_pending_closure.sql (1.94ms)1300 client_integration_test.go:338: Created store path 1: /nix/var/nix/builds/nix-84864-1761111497/TestClientMultipleUploads2118336446/001/store/wr1d3iialngjprw6l70z8dj6r7abd3cj-test-file-1.txt13012026/07/09 07:19:51 OK 2_object_stats_trigger.sql (672.21µs)13022026/07/09 07:19:51 goose: up to current file version: 213032026/07/09 07:19:51 OK 20241026095416_initial_model.sql (12.27ms)13042026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)13052026/07/09 07:19:51 INFO Created nix-cache-info in bucket bucket=bucket3813062026/07/09 07:19:51 OK 20251218171726_add_pins.sql (3.32ms)13072026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (5.39ms)13082026/07/09 07:19:51 goose: successfully migrated database to version: 2026062812000013092026/07/09 07:19:51 OK 1_commit_pending_closure.sql (1.83ms)13102026/07/09 07:19:51 OK 2_object_stats_trigger.sql (513.13µs)13112026/07/09 07:19:51 goose: up to current file version: 213122026-07-09 07:19:51.532 UTC [85347] ERROR: relation "goose_db_version" does not exist at character 3613132026-07-09 07:19:51.532 UTC [85347] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1314 client_integration_test.go:338: Created store path 2: /nix/var/nix/builds/nix-84864-1761111497/TestClientMultipleUploads2118336446/001/store/030s53p0phmllawzmdm87nji4wqrh287-test-file-2.txt13152026-07-09 07:19:51.551 UTC [85353] ERROR: relation "goose_db_version" does not exist at character 3613162026-07-09 07:19:51.551 UTC [85353] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13172026/07/09 07:19:51 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_closures13182026/07/09 07:19:51 OK 20241026095416_initial_model.sql (43.56ms)13192026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (1.2ms)13202026/07/09 07:19:51 OK 20241026095416_initial_model.sql (17.58ms)13212026/07/09 07:19:51 OK 20251218171726_add_pins.sql (2.64ms)13222026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (879.17µs)13232026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (2.18ms)13242026/07/09 07:19:51 goose: successfully migrated database to version: 2026062812000013252026/07/09 07:19:51 OK 20251218171726_add_pins.sql (2.41ms)13262026/07/09 07:19:51 OK 1_commit_pending_closure.sql (1.93ms)13272026/07/09 07:19:51 OK 2_object_stats_trigger.sql (587.29µs)13282026/07/09 07:19:51 goose: up to current file version: 213292026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (2.68ms)13302026/07/09 07:19:51 goose: successfully migrated database to version: 2026062812000013312026/07/09 07:19:51 OK 1_commit_pending_closure.sql (1.96ms)13322026/07/09 07:19:51 OK 2_object_stats_trigger.sql (534.58µs)13332026/07/09 07:19:51 goose: up to current file version: 21334--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.43s)1335=== CONT TestObjectStatsTrigger13362026-07-09 07:19:51.649 UTC [85362] ERROR: relation "goose_db_version" does not exist at character 3613372026-07-09 07:19:51.649 UTC [85362] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1338=== NAME TestPinProtectsFromGC1339 client_integration_test.go:646: Pinned store path: /nix/var/nix/builds/nix-84864-1761111497/TestPinProtectsFromGC3044337267/001/store/rbjlw7ql6awq6in6k1vn8lchcf2kljyi-pinned-file.txt1340 client_integration_test.go:647: Unpinned store path: /nix/var/nix/builds/nix-84864-1761111497/TestPinProtectsFromGC3044337267/001/store/yp97hs2l3ypw7d24b70xmpi84288mwqp-unpinned-file.txt13412026/07/09 07:19:51 OK 20241026095416_initial_model.sql (5.92ms)13422026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)13432026/07/09 07:19:51 OK 20251218171726_add_pins.sql (2.59ms)13442026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (3.5ms)13452026/07/09 07:19:51 goose: successfully migrated database to version: 2026062812000013462026/07/09 07:19:51 OK 1_commit_pending_closure.sql (2.88ms)13472026/07/09 07:19:51 OK 2_object_stats_trigger.sql (597.17µs)13482026/07/09 07:19:51 goose: up to current file version: 213492026/07/09 07:19:51 INFO Created nix-cache-info in bucket bucket=bucket4213502026/07/09 07:19:51 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.695265ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1351--- PASS: TestGCBugBareHashReferences (0.68s)1352=== CONT TestServerTLSConfig/not_a_PEM_file1353=== CONT TestGCTaskStore_DeduplicateSameParams1354--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1355=== CONT TestServerTLSConfig/missing_CA_file1356--- PASS: TestServerTLSConfig (0.00s)1357 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1358 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1359 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1360=== CONT TestClientErrorHandling/InvalidAuthToken13612026/07/09 07:19:51 INFO Received uploads request method=POST path=/api/pending_closures13622026/07/09 07:19:51 INFO Received uploads request method=POST path=/api/pending_closures13632026/07/09 07:19:51 INFO Received uploads request method=POST path=/api/pending_closures13642026/07/09 07:19:51 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13652026/07/09 07:19:51 INFO Uploading wr1d3iialngjprw6l70z8dj6r7abd3cj-test-file-1.txt (160B)13662026/07/09 07:19:51 INFO Uploading 030s53p0phmllawzmdm87nji4wqrh287-test-file-2.txt (160B)13672026/07/09 07:19:51 INFO Uploading 936316f0mzh149fr1kkmd0f71v77hcb2-test-file-0.txt (160B)13682026/07/09 07:19:51 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13692026/07/09 07:19:51 INFO Signed narinfos id=2 count=113702026/07/09 07:19:51 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign13712026/07/09 07:19:51 INFO Signed narinfos id=3 count=113722026/07/09 07:19:51 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13732026/07/09 07:19:51 INFO Signed narinfos id=1 count=113742026/07/09 07:19:51 INFO Uploading 3 narinfos13752026/07/09 07:19:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13762026/07/09 07:19:51 INFO Completed upload id=113772026/07/09 07:19:51 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13782026/07/09 07:19:51 INFO Completed upload id=213792026/07/09 07:19:51 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete13802026/07/09 07:19:51 INFO Completed upload id=313812026/07/09 07:19:51 INFO Upload complete. (158ms)1382=== NAME TestClientMultipleUploads1383 client_integration_test.go:349: Uploaded 3 paths in 222.018541ms1384=== NAME TestClientIntegration1385 client_integration_test.go:276: Created store path: /nix/var/nix/builds/nix-84864-1761111497/TestClientIntegration1226919046/002/store/p4ai63rbp7ri7l6hjwlf93wl1q8lbv65-test-file.txt1386--- PASS: TestClientMultipleUploads (0.91s)1387=== CONT TestCacheConfigHandler/full_config,_no_issuer1388=== CONT TestCacheConfigHandler/no_signing_keys1389=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1390=== CONT TestCacheConfigHandler/no_cache_url_configured1391--- PASS: TestCacheConfigHandler (0.00s)1392 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1393 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1394 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1395 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1396=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure13972026/07/09 07:19:51 INFO Received uploads request method=POST path=/1398=== NAME TestOrphanedObjectsGC1399 orphaned_objects_gc_test.go:290: GC Test Summary:1400 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1401 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1402 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1403 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1404 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1405--- PASS: TestOrphanedObjectsGC (0.73s)1406=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14072026/07/09 07:19:51 INFO Received request for more parts method=POST path=/14082026-07-09 07:19:51.788 UTC [85377] ERROR: relation "goose_db_version" does not exist at character 3614092026-07-09 07:19:51.788 UTC [85377] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14102026/07/09 07:19:51 OK 20241026095416_initial_model.sql (10.17ms)14112026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (1.08ms)14122026/07/09 07:19:51 OK 20251218171726_add_pins.sql (2.49ms)1413=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14142026/07/09 07:19:51 INFO Received complete multipart upload request method=POST path=/14152026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (2.74ms)14162026/07/09 07:19:51 goose: successfully migrated database to version: 2026062812000014172026/07/09 07:19:51 OK 1_commit_pending_closure.sql (2.09ms)14182026/07/09 07:19:51 OK 2_object_stats_trigger.sql (692.38µs)14192026/07/09 07:19:51 goose: up to current file version: 21420--- PASS: TestObjectStatsTrigger (0.21s)1421=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14222026/07/09 07:19:51 INFO Received uploads request method=POST path=/1423=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14242026/07/09 07:19:51 INFO Received complete multipart upload request method=POST path=/1425=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14262026/07/09 07:19:51 INFO Received request for more parts method=POST path=/1427=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14282026/07/09 07:19:51 INFO Received uploads request method=POST path=/1429--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1430 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1431 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1432 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1433 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1434=== CONT TestIsValidUploadKey/narinfo1435=== CONT TestProxyWriteTimeout/narinfo1436=== CONT TestIsValidUploadKey/realisation1437=== CONT TestIsValidUploadKey/build_log_equals1438=== CONT TestIsValidUploadKey/build_log_question_mark1439=== CONT TestIsValidUploadKey/build_log_plus_in_name1440=== CONT TestIsValidUploadKey/build_log_home-manager_file1441=== CONT TestIsValidUploadKey/build_log1442=== CONT TestIsValidUploadKey/listing1443=== CONT TestIsValidUploadKey/realisation_plus_in_output1444=== CONT TestIsValidUploadKey/nar_plain1445=== CONT TestIsValidUploadKey/unknown_type1446=== CONT TestIsValidUploadKey/nar_xz1447=== CONT TestIsValidUploadKey/empty_key1448=== CONT TestIsValidUploadKey/nar_zst1449=== CONT TestIsValidUploadKey/absolute1450=== CONT TestIsValidUploadKey/traversal_nar1451=== CONT TestIsValidUploadKey/traversal1452=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1453=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1454=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1455=== CONT TestIsValidUploadKey/index.html1456=== CONT TestIsValidUploadKey/nix-cache-info1457--- PASS: TestIsValidUploadKey (0.00s)1458 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1459 --- PASS: TestIsValidUploadKey/realisation (0.00s)1460 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1461 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1462 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1463 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1464 --- PASS: TestIsValidUploadKey/build_log (0.00s)1465 --- PASS: TestIsValidUploadKey/listing (0.00s)1466 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1467 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1468 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1469 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1470 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1471 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1472 --- PASS: TestIsValidUploadKey/absolute (0.00s)1473 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1474 --- PASS: TestIsValidUploadKey/traversal (0.00s)1475 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1476 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1477 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1478 --- PASS: TestIsValidUploadKey/index.html (0.00s)1479 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1480=== CONT TestProxyWriteTimeout/10_GiB_nar1481=== CONT TestProxyWriteTimeout/unknown_size1482=== CONT TestProxyWriteTimeout/1_GiB_nar1483--- PASS: TestProxyWriteTimeout (0.00s)1484 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1485 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1486 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1487 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1488=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token14892026/07/09 07:19:51 INFO OIDC auth successful provider=test1490=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected14912026/07/09 07:19:51 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]1492=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1493=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected14942026/07/09 07:19:51 WARN Authentication failed token_preview=eyJhbGciOi...K2-MCzpdOQ 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]1495=== CONT TestIsValidCachePath/narinfo1496=== CONT TestIsValidCachePath/index.html1497=== CONT TestIsValidCachePath/short_hash1498=== CONT TestIsValidCachePath/wrong_extension1499=== CONT TestIsValidCachePath/leading_slash1500=== CONT TestIsValidCachePath/empty1501=== CONT TestIsValidCachePath/random_path1502=== CONT TestIsValidCachePath/invalid_char_u1503=== CONT TestIsValidCachePath/invalid_char_e1504=== CONT TestIsValidCachePath/traversal_in_middle1505=== CONT TestIsValidCachePath/traversal_parent1506=== CONT TestIsValidCachePath/nar_uncompressed1507=== CONT TestIsValidCachePath/nix-cache-info1508=== CONT TestIsValidCachePath/realisation1509=== CONT TestIsValidCachePath/log1510=== CONT TestIsValidCachePath/ls1511=== CONT TestIsValidCachePath/nar_xz1512=== CONT TestIsValidCachePath/nar_bz21513=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1514=== CONT TestIsValidCachePath/nar_zst1515--- PASS: TestIsValidCachePath (0.00s)1516 --- PASS: TestIsValidCachePath/narinfo (0.00s)1517 --- PASS: TestIsValidCachePath/index.html (0.00s)1518 --- PASS: TestIsValidCachePath/short_hash (0.00s)1519 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1520 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1521 --- PASS: TestIsValidCachePath/empty (0.00s)1522 --- PASS: TestIsValidCachePath/random_path (0.00s)1523 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1524 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1525 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1526 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1527 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1528 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1529 --- PASS: TestIsValidCachePath/realisation (0.00s)1530 --- PASS: TestIsValidCachePath/log (0.00s)1531 --- PASS: TestIsValidCachePath/ls (0.00s)1532 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1533 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1534 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1535 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1536=== CONT TestParseSingleRange/none1537=== CONT TestParseSingleRange/open-ended1538=== CONT TestParseSingleRange/start_far_past_EOF1539=== CONT TestParseSingleRange/start_past_EOF1540=== CONT TestParseSingleRange/single_byte1541=== CONT TestParseSingleRange/suffix_exceeds_size1542=== CONT TestParseSingleRange/suffix1543=== CONT TestParseSingleRange/end_clamped_to_size1544=== CONT TestParseSingleRange/malformed_both_empty1545=== CONT TestParseSingleRange/closed1546=== CONT TestParseSingleRange/malformed_end_before_start1547=== CONT TestParseSingleRange/multi-range_ignored1548=== CONT TestParseSingleRange/malformed_no_dash1549=== CONT TestParseSingleRange/unknown_unit1550--- PASS: TestParseSingleRange (0.00s)1551 --- PASS: TestParseSingleRange/none (0.00s)1552 --- PASS: TestParseSingleRange/open-ended (0.00s)1553 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1554 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1555 --- PASS: TestParseSingleRange/single_byte (0.00s)1556 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1557 --- PASS: TestParseSingleRange/suffix (0.00s)1558 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1559 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1560 --- PASS: TestParseSingleRange/closed (0.00s)1561 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1562 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1563 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1564 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1565--- PASS: TestService_AuthMiddleware_OIDC (0.15s)1566 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1567 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1568 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1569 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)15702026-07-09 07:19:51.865 UTC [85382] ERROR: relation "goose_db_version" does not exist at character 3615712026-07-09 07:19:51.865 UTC [85382] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15722026/07/09 07:19:51 INFO Received uploads request method=POST path=/api/pending_closures15732026/07/09 07:19:51 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15742026/07/09 07:19:51 INFO Uploading rbjlw7ql6awq6in6k1vn8lchcf2kljyi-pinned-file.txt (128B)15752026/07/09 07:19:51 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15762026/07/09 07:19:51 INFO Signed narinfos id=1 count=115772026/07/09 07:19:51 INFO Uploading 1 narinfos15782026/07/09 07:19:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15792026/07/09 07:19:51 INFO Completed upload id=115802026/07/09 07:19:51 INFO Upload complete. (155ms)15812026/07/09 07:19:51 OK 20241026095416_initial_model.sql (10.73ms)15822026/07/09 07:19:51 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)15832026/07/09 07:19:51 OK 20251218171726_add_pins.sql (2.45ms)15842026/07/09 07:19:51 OK 20260628120000_add_object_size_and_stats.sql (3.01ms)15852026/07/09 07:19:51 goose: successfully migrated database to version: 2026062812000015862026/07/09 07:19:51 OK 1_commit_pending_closure.sql (2.1ms)15872026/07/09 07:19:51 OK 2_object_stats_trigger.sql (586.13µs)15882026/07/09 07:19:51 goose: up to current file version: 215892026/07/09 07:19:51 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=390.592385ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures15902026/07/09 07:19:51 INFO Received uploads request method=POST path=/api/pending_closures1591=== NAME TestClientWithDependencies1592 client_integration_test.go:593: Built derivation: /nix/var/nix/builds/nix-84864-1761111497/TestClientWithDependencies819867453/001/store/9wkvav1gggxjjnbj7dsxr81fsprvkczb-test-script15932026/07/09 07:19:51 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15942026/07/09 07:19:51 INFO Uploading p4ai63rbp7ri7l6hjwlf93wl1q8lbv65-test-file.txt (152B)15952026/07/09 07:19:51 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15962026/07/09 07:19:51 INFO Signed narinfos id=1 count=115972026/07/09 07:19:51 INFO Uploading 1 narinfos15982026/07/09 07:19:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15992026/07/09 07:19:51 INFO Completed upload id=116002026/07/09 07:19:51 INFO Upload complete. (147ms)1601=== NAME TestClientIntegration1602 client_integration_test.go:292: Retrieved narinfo from S3:1603 StorePath: /nix/var/nix/builds/nix-84864-1761111497/TestClientIntegration1226919046/002/store/p4ai63rbp7ri7l6hjwlf93wl1q8lbv65-test-file.txt1604 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1605 Compression: zstd1606 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11607 NarSize: 1521608 References: 1609 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11610 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1611 client_integration_test.go:293: Decompressed .ls content (64 bytes):1612 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1613 client_integration_test.go:296: Testing garbage collection...1614=== NAME TestClientWithDependencies1615 client_integration_test.go:595: Found 1 dependencies (including self)16162026/07/09 07:19:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures16172026/07/09 07:19:52 INFO Garbage collection started16182026/07/09 07:19:52 INFO Aborted multipart uploads count=016192026/07/09 07:19:52 WARN Force mode enabled - objects will be deleted immediately without grace period16202026/07/09 07:19:52 INFO Received uploads request method=POST path=/api/pending_closures16212026/07/09 07:19:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16222026/07/09 07:19:52 INFO Uploading yp97hs2l3ypw7d24b70xmpi84288mwqp-unpinned-file.txt (128B)16232026/07/09 07:19:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16242026/07/09 07:19:52 INFO Signed narinfos id=2 count=116252026/07/09 07:19:52 INFO Uploading 1 narinfos16262026/07/09 07:19:52 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16272026/07/09 07:19:52 INFO Completed upload id=216282026/07/09 07:19:52 INFO Upload complete. (133ms)16292026/07/09 07:19:52 INFO Received create pin request method=POST path=/api/pins/myapp16302026/07/09 07:19:52 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-84864-1761111497/TestPinProtectsFromGC3044337267/001/store/rbjlw7ql6awq6in6k1vn8lchcf2kljyi-pinned-file.txt narinfo_key=rbjlw7ql6awq6in6k1vn8lchcf2kljyi.narinfo16312026/07/09 07:19:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures16322026/07/09 07:19:52 INFO Garbage collection started16332026/07/09 07:19:52 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"16342026/07/09 07:19:52 INFO Aborted multipart uploads count=016352026/07/09 07:19:52 WARN Force mode enabled - objects will be deleted immediately without grace period16362026/07/09 07:19:52 INFO Received uploads request method=POST path=/api/pending_closures16372026/07/09 07:19:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16382026/07/09 07:19:52 INFO Uploading 9wkvav1gggxjjnbj7dsxr81fsprvkczb-test-script (136B)16392026/07/09 07:19:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16402026/07/09 07:19:52 INFO Signed narinfos id=1 count=116412026/07/09 07:19:52 INFO Uploading 1 narinfos16422026/07/09 07:19:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16432026/07/09 07:19:52 INFO Completed upload id=116442026/07/09 07:19:52 INFO Upload complete. (67ms)1645 client_integration_test.go:597: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-84864-1761111497/TestClientWithDependencies819867453/001/store) requires matching store prefix1646--- PASS: TestClientWithDependencies (1.12s)1647=== NAME TestOrphanedObjectsGCStressTest1648 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains16492026/07/09 07:19:52 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=793.68517ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1650 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1651--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)1652 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)1653 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)1654 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.69s)1655=== NAME TestOrphanedObjectsGCStressTest1656 orphaned_objects_gc_test.go:509: Stress test completed successfully:1657 orphaned_objects_gc_test.go:510: - Active objects preserved: 201658 orphaned_objects_gc_test.go:511: - Objects deleted: 2101659 orphaned_objects_gc_test.go:512: - Total GC'd: 2101660--- PASS: TestOrphanedObjectsGCStressTest (1.40s)16612026/07/09 07:19:52 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=016622026/07/09 07:19:52 INFO Vacuumed table table=pending_closures16632026/07/09 07:19:52 INFO Vacuumed table table=pending_objects16642026/07/09 07:19:52 INFO Vacuumed table table=multipart_uploads16652026/07/09 07:19:52 INFO Vacuumed table table=closures16662026/07/09 07:19:52 INFO Vacuumed table table=objects16672026/07/09 07:19:52 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=016682026/07/09 07:19:52 INFO Vacuumed table table=pending_closures16692026/07/09 07:19:52 INFO Vacuumed table table=pending_objects16702026/07/09 07:19:52 INFO Vacuumed table table=multipart_uploads16712026/07/09 07:19:52 INFO Vacuumed table table=closures16722026/07/09 07:19:52 INFO Vacuumed table table=objects16732026/07/09 07:19:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.471921095s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16742026/07/09 07:19:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01675=== NAME TestClientIntegration1676 client_integration_test.go:303: Objects in database after GC:1677 client_integration_test.go:303: Successfully deleted all objects with GC --force1678--- PASS: TestClientIntegration (2.75s)16792026/07/09 07:19:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01680=== NAME TestPinProtectsFromGC1681 client_integration_test.go:709: Pin successfully protected closure from garbage collection1682--- PASS: TestPinProtectsFromGC (3.11s)16832026/07/09 07:19:54 WARN Rate limiter enabled after throttle name=s3-test rate=516842026/07/09 07:19:54 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1685=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1686 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101687 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001688--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.44s)1689--- PASS: TestClientErrorHandling (0.00s)1690 --- PASS: TestClientErrorHandling/InvalidStorePath (0.42s)1691 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.43s)1692 --- PASS: TestClientErrorHandling/ServerNotAvailable (3.31s)1693PASS16942026-07-09 07:19:55.134 UTC [85065] LOG: received smart shutdown request16952026-07-09 07:19:55.138 UTC [85065] LOG: background worker "logical replication launcher" (PID 85076) exited with exit code 116962026-07-09 07:19:55.147 UTC [85071] LOG: shutting down16972026-07-09 07:19:55.148 UTC [85071] LOG: checkpoint starting: shutdown immediate16982026-07-09 07:19:56.534 UTC [85071] LOG: checkpoint complete: wrote 13677 buffers (83.5%); 0 WAL file(s) added, 0 removed, 12 recycled; write=0.837 s, sync=0.540 s, total=1.387 s; sync files=14421, longest=0.009 s, average=0.001 s; distance=197511 kB, estimate=197511 kB; lsn=0/D5F49A8, redo lsn=0/D5F49A816992026-07-09 07:19:56.539 UTC [85065] LOG: database system is shut down1700Running OIDC tests...1701=== RUN TestGlobMatch1702=== PAUSE TestGlobMatch1703=== RUN TestAudienceForIssuer1704=== PAUSE TestAudienceForIssuer1705=== RUN TestValidateToken_ValidToken1706=== PAUSE TestValidateToken_ValidToken1707=== RUN TestValidateToken_WrongAudience1708=== PAUSE TestValidateToken_WrongAudience1709=== RUN TestValidateToken_Expired1710=== PAUSE TestValidateToken_Expired1711=== RUN TestValidateToken_BoundClaimsMismatch1712=== PAUSE TestValidateToken_BoundClaimsMismatch1713=== RUN TestValidateToken_BoundSubjectMismatch1714=== PAUSE TestValidateToken_BoundSubjectMismatch1715=== RUN TestValidateToken_MultipleProviders1716=== PAUSE TestValidateToken_MultipleProviders1717=== RUN TestValidateToken_NoMatchingProvider1718=== PAUSE TestValidateToken_NoMatchingProvider1719=== CONT TestGlobMatch1720=== RUN TestGlobMatch/foo_foo1721=== PAUSE TestGlobMatch/foo_foo1722=== RUN TestGlobMatch/foo_bar1723=== PAUSE TestGlobMatch/foo_bar1724=== RUN TestGlobMatch/*_1725=== PAUSE TestGlobMatch/*_1726=== RUN TestGlobMatch/*_anything1727=== PAUSE TestGlobMatch/*_anything1728=== RUN TestGlobMatch/foo*_foo1729=== PAUSE TestGlobMatch/foo*_foo1730=== RUN TestGlobMatch/foo*_foobar1731=== PAUSE TestGlobMatch/foo*_foobar1732=== RUN TestGlobMatch/foo*_bar1733=== PAUSE TestGlobMatch/foo*_bar1734=== RUN TestGlobMatch/*bar_bar1735=== PAUSE TestGlobMatch/*bar_bar1736=== RUN TestGlobMatch/*bar_foobar1737=== PAUSE TestGlobMatch/*bar_foobar1738=== RUN TestGlobMatch/*bar_foo1739=== PAUSE TestGlobMatch/*bar_foo1740=== RUN TestGlobMatch/foo*bar_foobar1741=== PAUSE TestGlobMatch/foo*bar_foobar1742=== RUN TestGlobMatch/foo*bar_foo123bar1743=== PAUSE TestGlobMatch/foo*bar_foo123bar1744=== RUN TestGlobMatch/foo*bar_foobarbaz1745=== PAUSE TestGlobMatch/foo*bar_foobarbaz1746=== RUN TestGlobMatch/*/*_foo/bar1747=== PAUSE TestGlobMatch/*/*_foo/bar1748=== RUN TestGlobMatch/*/*_foo1749=== PAUSE TestGlobMatch/*/*_foo1750=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1751=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1752=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01753=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01754=== RUN TestGlobMatch/refs/*/main_refs/heads/main1755=== CONT TestValidateToken_BoundClaimsMismatch1756=== CONT TestValidateToken_NoMatchingProvider1757=== CONT TestValidateToken_MultipleProviders1758=== CONT TestValidateToken_BoundSubjectMismatch1759=== CONT TestValidateToken_WrongAudience1760=== CONT TestValidateToken_Expired1761=== CONT TestValidateToken_ValidToken1762=== CONT TestAudienceForIssuer1763--- PASS: TestAudienceForIssuer (0.00s)1764=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1765=== RUN TestGlobMatch/fo?_foo1766=== PAUSE TestGlobMatch/fo?_foo1767=== RUN TestGlobMatch/fo?_fo1768=== PAUSE TestGlobMatch/fo?_fo1769=== RUN TestGlobMatch/fo?_fooo1770=== PAUSE TestGlobMatch/fo?_fooo1771=== RUN TestGlobMatch/?oo_foo1772=== PAUSE TestGlobMatch/?oo_foo1773=== RUN TestGlobMatch/?oo_boo1774=== PAUSE TestGlobMatch/?oo_boo1775=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1776=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1777=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1778=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1779=== CONT TestGlobMatch/foo_foo1780=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1781=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1782=== CONT TestGlobMatch/?oo_boo1783=== CONT TestGlobMatch/?oo_foo1784=== CONT TestGlobMatch/fo?_fooo1785=== CONT TestGlobMatch/fo?_fo1786=== CONT TestGlobMatch/fo?_foo1787=== CONT TestGlobMatch/refs/*/main_refs/heads/main1788=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01789=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1790=== CONT TestGlobMatch/*/*_foo1791=== CONT TestGlobMatch/*/*_foo/bar1792=== CONT TestGlobMatch/foo*bar_foobarbaz1793=== CONT TestGlobMatch/foo*bar_foo123bar1794=== CONT TestGlobMatch/foo*bar_foobar1795=== CONT TestGlobMatch/*bar_foo1796=== CONT TestGlobMatch/*bar_foobar1797=== CONT TestGlobMatch/*bar_bar1798=== CONT TestGlobMatch/foo*_bar1799=== CONT TestGlobMatch/foo*_foobar1800=== CONT TestGlobMatch/foo*_foo1801=== CONT TestGlobMatch/*_anything1802=== CONT TestGlobMatch/*_1803=== CONT TestGlobMatch/foo_bar1804--- PASS: TestGlobMatch (0.00s)1805 --- PASS: TestGlobMatch/foo_foo (0.00s)1806 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1807 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1808 --- PASS: TestGlobMatch/?oo_boo (0.00s)1809 --- PASS: TestGlobMatch/?oo_foo (0.00s)1810 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1811 --- PASS: TestGlobMatch/fo?_fo (0.00s)1812 --- PASS: TestGlobMatch/fo?_foo (0.00s)1813 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1814 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1815 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1816 --- PASS: TestGlobMatch/*/*_foo (0.00s)1817 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1818 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1819 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1820 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1821 --- PASS: TestGlobMatch/*bar_foo (0.00s)1822 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1823 --- PASS: TestGlobMatch/*bar_bar (0.00s)1824 --- PASS: TestGlobMatch/foo*_bar (0.00s)1825 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1826 --- PASS: TestGlobMatch/foo*_foo (0.00s)1827 --- PASS: TestGlobMatch/*_anything (0.00s)1828 --- PASS: TestGlobMatch/*_ (0.00s)1829 --- PASS: TestGlobMatch/foo_bar (0.00s)18302026/07/09 07:19:57 INFO OIDC provider initialized name=test18312026/07/09 07:19:57 INFO OIDC provider initialized name=test18322026/07/09 07:19:57 INFO OIDC provider initialized name=test18332026/07/09 07:19:57 INFO OIDC provider initialized name=test18342026/07/09 07:19:57 INFO OIDC provider initialized name=provider118352026/07/09 07:19:57 INFO OIDC provider initialized name=test18362026/07/09 07:19:57 INFO OIDC provider initialized name=provider11837--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1838--- PASS: TestValidateToken_WrongAudience (0.01s)1839--- PASS: TestValidateToken_Expired (0.01s)1840--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1841--- PASS: TestValidateToken_ValidToken (0.01s)18422026/07/09 07:19:57 INFO OIDC provider initialized name=provider21843--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1844--- PASS: TestValidateToken_MultipleProviders (0.01s)1845PASS1846Running hook tests...1847=== RUN TestSendPathsEmpty1848=== PAUSE TestSendPathsEmpty1849=== RUN TestQueueEnqueueAndFetch1850=== PAUSE TestQueueEnqueueAndFetch1851=== RUN TestQueueDeduplication1852=== PAUSE TestQueueDeduplication1853=== RUN TestQueueRemove1854=== PAUSE TestQueueRemove1855=== RUN TestQueueFetchBatchLimit1856=== PAUSE TestQueueFetchBatchLimit1857=== RUN TestQueueFetchRemoveLifecycle1858=== PAUSE TestQueueFetchRemoveLifecycle1859=== RUN TestQueueConcurrentWriters1860=== PAUSE TestQueueConcurrentWriters1861=== RUN TestServerClientIntegration1862=== PAUSE TestServerClientIntegration1863=== RUN TestServerQueueError1864=== PAUSE TestServerQueueError1865=== RUN TestGetListenerSocketActivation1866 server_test.go:210: === RUN TestGetListenerSocketActivation1867 --- PASS: TestGetListenerSocketActivation (0.00s)1868 PASS1869 1870--- PASS: TestGetListenerSocketActivation (0.02s)1871=== RUN TestWorkerUploadsAndRemoves1872=== PAUSE TestWorkerUploadsAndRemoves1873=== RUN TestWorkerSkipsGCdPaths1874=== PAUSE TestWorkerSkipsGCdPaths1875=== RUN TestWorkerPrunesClosureDeps1876=== PAUSE TestWorkerPrunesClosureDeps1877=== CONT TestSendPathsEmpty1878--- PASS: TestSendPathsEmpty (0.00s)1879=== CONT TestWorkerPrunesClosureDeps1880=== CONT TestQueueConcurrentWriters1881=== CONT TestQueueRemove1882=== CONT TestWorkerSkipsGCdPaths1883=== CONT TestWorkerUploadsAndRemoves1884=== CONT TestQueueFetchRemoveLifecycle1885=== CONT TestServerQueueError1886=== CONT TestQueueFetchBatchLimit1887=== CONT TestQueueDeduplication1888=== CONT TestServerClientIntegration18892026/07/09 07:19:57 ERROR Failed to queue paths error="permission denied" count=11890--- PASS: TestServerQueueError (0.00s)1891=== CONT TestQueueEnqueueAndFetch1892--- PASS: TestServerClientIntegration (0.00s)1893--- PASS: TestQueueDeduplication (0.01s)18942026/07/09 07:19:58 INFO Upload queue status pending=218952026/07/09 07:19:58 INFO Uploading batch count=11896--- PASS: TestQueueEnqueueAndFetch (0.01s)18972026/07/09 07:19:58 INFO Upload queue status pending=218982026/07/09 07:19:58 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-84864-1761111497/TestWorkerSkipsGCdPaths3809131875/002/nonexistent18992026/07/09 07:19:58 INFO Uploading batch count=11900--- PASS: TestQueueFetchBatchLimit (0.01s)1901--- PASS: TestQueueRemove (0.01s)1902--- PASS: TestQueueFetchRemoveLifecycle (0.01s)19032026/07/09 07:19:58 INFO Upload queue status pending=219042026/07/09 07:19:58 INFO Uploading batch count=21905--- PASS: TestWorkerPrunesClosureDeps (0.06s)1906--- PASS: TestWorkerSkipsGCdPaths (0.06s)1907--- PASS: TestWorkerUploadsAndRemoves (0.07s)1908--- PASS: TestQueueConcurrentWriters (0.17s)1909PASS