niks3-go-unit-tests
aarch64-darwin.go-unit-tests
· build #105
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestCaseHackSuffix5=== PAUSE TestCaseHackSuffix6=== RUN TestPartSizeForNAR7=== PAUSE TestPartSizeForNAR8=== RUN TestUploadMultipart_SupersededByPeer9=== PAUSE TestUploadMultipart_SupersededByPeer10=== RUN TestDumpPathMatchesNix11=== PAUSE TestDumpPathMatchesNix12=== RUN TestDumpPathSingleFile13=== PAUSE TestDumpPathSingleFile14=== RUN TestDumpPathWriterError15=== PAUSE TestDumpPathWriterError16=== RUN TestEncodeNixBase3217=== PAUSE TestEncodeNixBase3218=== RUN TestEncodeNixBase32WithRealHash19=== PAUSE TestEncodeNixBase32WithRealHash20=== RUN TestConvertHashToNix3221=== PAUSE TestConvertHashToNix3222=== RUN TestGetStorePathHash23=== PAUSE TestGetStorePathHash24=== RUN TestPathInfoHashCompatibility25=== PAUSE TestPathInfoHashCompatibility26=== RUN TestParsePathInfoJSON27=== PAUSE TestParsePathInfoJSON28=== RUN TestParsePathInfoJSONMultiplePaths29=== PAUSE TestParsePathInfoJSONMultiplePaths30=== RUN TestPathInfoCACompatibility31=== PAUSE TestPathInfoCACompatibility32=== RUN TestRateLimiterFeedback33=== PAUSE TestRateLimiterFeedback34=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess35=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess36=== RUN TestResolveStorePath37=== PAUSE TestResolveStorePath38=== RUN TestDoWithRetry_BodyReplayedViaGetBody39=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody40=== RUN TestShellSplit41=== PAUSE TestShellSplit42=== RUN TestShellSplitErrors43=== PAUSE TestShellSplitErrors44=== RUN TestSetClientTLS45=== PAUSE TestSetClientTLS46=== RUN TestSetClientTLSDoesNotMutateDefaultTransport47=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport48=== RUN TestSetClientTLSErrors49=== PAUSE TestSetClientTLSErrors50=== RUN TestStaticToken51=== PAUSE TestStaticToken52=== RUN TestFileTokenReadsAndCaches53=== PAUSE TestFileTokenReadsAndCaches54=== RUN TestFileTokenMissing55=== PAUSE TestFileTokenMissing56=== RUN TestFileTokenEmpty57=== PAUSE TestFileTokenEmpty58=== RUN TestScriptTokenNoExpiryRerunsEveryCall59=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall60=== RUN TestScriptTokenCachesUntilRefresh61=== PAUSE TestScriptTokenCachesUntilRefresh62=== RUN TestScriptTokenEmptyToken63=== PAUSE TestScriptTokenEmptyToken64=== RUN TestScriptTokenBadJSON65=== PAUSE TestScriptTokenBadJSON66=== RUN TestScriptTokenScriptFails67=== PAUSE TestScriptTokenScriptFails68=== RUN TestScriptTokenEmptyCommand69=== PAUSE TestScriptTokenEmptyCommand70=== CONT TestDoServerRequestAttachesToken71=== CONT TestResolveStorePath72=== CONT TestConvertHashToNix3273=== RUN TestConvertHashToNix32/SRI_format_to_Nix3274=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix3275=== RUN TestConvertHashToNix32/already_Nix32_format76=== PAUSE TestConvertHashToNix32/already_Nix32_format77=== RUN TestConvertHashToNix32/invalid_format78=== PAUSE TestConvertHashToNix32/invalid_format79=== CONT TestConvertHashToNix32/SRI_format_to_Nix3280=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess81=== CONT TestDumpPathMatchesNix822026/07/19 09:59:22 WARN Rate limiter enabled after throttle name=server-test rate=583=== CONT TestDumpPathSingleFile84=== CONT TestGetStorePathHash85=== RUN TestGetStorePathHash/valid_store_path86=== PAUSE TestGetStorePathHash/valid_store_path87=== RUN TestGetStorePathHash/basename_without_hyphen_should_error88=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error89=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error90=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error91=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error92=== CONT TestPathInfoHashCompatibility93=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)94=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)95=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon96=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon97=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI98=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI99=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512100=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512101=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)102=== CONT TestFileTokenMissing103=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error104=== CONT TestPartSizeForNAR105=== CONT TestUploadMultipart_SupersededByPeer106=== RUN TestUploadMultipart_SupersededByPeer/exists107=== CONT TestConvertHashToNix32/invalid_format108=== CONT TestScriptTokenEmptyToken109=== RUN TestPartSizeForNAR/zero_stays_at_minimum110=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum111=== CONT TestConvertHashToNix32/already_Nix32_format112=== PAUSE TestUploadMultipart_SupersededByPeer/exists113--- PASS: TestConvertHashToNix32 (0.00s)114 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)115 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)116 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)117=== CONT TestScriptTokenEmptyCommand118--- PASS: TestScriptTokenEmptyCommand (0.00s)119=== RUN TestUploadMultipart_SupersededByPeer/missing120=== RUN TestPartSizeForNAR/small_stays_at_minimum121=== PAUSE TestPartSizeForNAR/small_stays_at_minimum122=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum123=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum124=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts125=== PAUSE TestUploadMultipart_SupersededByPeer/missing126=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts127=== CONT TestScriptTokenScriptFails128=== CONT TestScriptTokenBadJSON129=== RUN TestPartSizeForNAR/1_TiB130=== PAUSE TestPartSizeForNAR/1_TiB131=== RUN TestPartSizeForNAR/5_TiB_S3_max_object132=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object133=== RUN TestPartSizeForNAR/capped_at_5_GiB134=== PAUSE TestPartSizeForNAR/capped_at_5_GiB135=== CONT TestScriptTokenNoExpiryRerunsEveryCall136--- PASS: TestDoServerRequestAttachesToken (0.00s)137=== CONT TestScriptTokenCachesUntilRefresh138--- PASS: TestFileTokenMissing (0.00s)139=== CONT TestEncodeNixBase32140=== RUN TestEncodeNixBase32/test_string_hash141=== PAUSE TestEncodeNixBase32/test_string_hash142=== RUN TestEncodeNixBase32/empty_input143=== PAUSE TestEncodeNixBase32/empty_input144=== CONT TestEncodeNixBase32WithRealHash145--- PASS: TestEncodeNixBase32WithRealHash (0.00s)146=== CONT TestParsePathInfoJSON147=== RUN TestParsePathInfoJSON/Nix_format148=== PAUSE TestParsePathInfoJSON/Nix_format149=== RUN TestParsePathInfoJSON/Lix_format150=== PAUSE TestParsePathInfoJSON/Lix_format151=== RUN TestParsePathInfoJSON/empty_input152--- PASS: TestResolveStorePath (0.00s)153=== CONT TestRateLimiterFeedback154=== PAUSE TestParsePathInfoJSON/empty_input155=== RUN TestRateLimiterFeedback/429_enables_limiter156=== PAUSE TestRateLimiterFeedback/429_enables_limiter157=== RUN TestRateLimiterFeedback/503_enables_limiter158=== PAUSE TestRateLimiterFeedback/503_enables_limiter159=== RUN TestParsePathInfoJSON/whitespace_only160=== PAUSE TestParsePathInfoJSON/whitespace_only161=== RUN TestParsePathInfoJSON/invalid_JSON162=== PAUSE TestParsePathInfoJSON/invalid_JSON163=== CONT TestPathInfoCACompatibility164=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter165=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter166=== RUN TestPathInfoCACompatibility/null_ca_field167=== PAUSE TestPathInfoCACompatibility/null_ca_field168=== RUN TestPathInfoCACompatibility/old_string_format_-_text169=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter170=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter171=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text172=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive173=== CONT TestParsePathInfoJSONMultiplePaths174=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive175=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths176=== RUN TestPathInfoCACompatibility/new_structured_format_-_text177=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths178=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text179=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method180=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths181=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method182=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths183=== CONT TestCaseHackSuffix184=== CONT TestDumpPathWriterError185--- PASS: TestScriptTokenScriptFails (0.01s)186=== CONT TestSetClientTLSDoesNotMutateDefaultTransport187--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)188=== CONT TestFileTokenReadsAndCaches189--- PASS: TestFileTokenReadsAndCaches (0.00s)190=== CONT TestStaticToken191--- PASS: TestStaticToken (0.00s)192=== CONT TestSetClientTLSErrors193=== RUN TestSetClientTLSErrors/missing_cert_file194=== PAUSE TestSetClientTLSErrors/missing_cert_file195=== RUN TestSetClientTLSErrors/missing_key_file196=== PAUSE TestSetClientTLSErrors/missing_key_file197=== RUN TestSetClientTLSErrors/missing_ca_file198=== PAUSE TestSetClientTLSErrors/missing_ca_file199=== RUN TestSetClientTLSErrors/invalid_ca_file200=== PAUSE TestSetClientTLSErrors/invalid_ca_file201=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512202=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI203=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon204--- PASS: TestPathInfoHashCompatibility (0.00s)205 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)206 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)207 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)208 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)209=== CONT TestGetStorePathHash/valid_store_path210=== CONT TestShellSplitErrors211--- PASS: TestShellSplitErrors (0.00s)212=== CONT TestSetClientTLS213=== RUN TestSetClientTLS/rejects_connection_without_client_cert214=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert215=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA216=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA217=== RUN TestSetClientTLS/preserves_debug_logging_transport218=== PAUSE TestSetClientTLS/preserves_debug_logging_transport219=== CONT TestFileTokenEmpty220--- PASS: TestFileTokenEmpty (0.00s)221=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error222=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error223=== CONT TestShellSplit224--- PASS: TestShellSplit (0.00s)225=== CONT TestGetStorePathHash/basename_without_hyphen_should_error226--- PASS: TestGetStorePathHash (0.00s)227 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)228 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)229 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)230 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)231=== CONT TestDoWithRetry_BodyReplayedViaGetBody232--- PASS: TestScriptTokenBadJSON (0.01s)233=== CONT TestUploadMultipart_SupersededByPeer/exists234--- PASS: TestScriptTokenEmptyToken (0.01s)235=== CONT TestUploadMultipart_SupersededByPeer/missing2362026/07/19 09:59:22 WARN Rate limiter enabled after throttle name=server-test rate=52372026/07/19 09:59:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:592562382026/07/19 09:59:22 WARN Rate limiter backed off name=server-test rate=52392026/07/19 09:59:22 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:59256240--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)241=== CONT TestPartSizeForNAR/1_TiB242=== CONT TestPartSizeForNAR/capped_at_5_GiB243=== CONT TestPartSizeForNAR/zero_stays_at_minimum244=== CONT TestPartSizeForNAR/5_TiB_S3_max_object245=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts246=== CONT TestPartSizeForNAR/small_stays_at_minimum247=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum248=== CONT TestEncodeNixBase32/test_string_hash249--- PASS: TestPartSizeForNAR (0.00s)250 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)251 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)252 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)253 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)254 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)255 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)256 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)257=== CONT TestEncodeNixBase32/empty_input258=== CONT TestParsePathInfoJSON/invalid_JSON259=== CONT TestParsePathInfoJSON/whitespace_only260--- PASS: TestEncodeNixBase32 (0.00s)261 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)262 --- PASS: TestEncodeNixBase32/empty_input (0.00s)263=== CONT TestParsePathInfoJSON/Nix_format264=== CONT TestParsePathInfoJSON/empty_input265=== CONT TestParsePathInfoJSON/Lix_format266--- PASS: TestParsePathInfoJSON (0.00s)267 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)268 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)269 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)270 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)271 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)272=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter273=== CONT TestRateLimiterFeedback/429_enables_limiter274=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter275=== CONT TestRateLimiterFeedback/503_enables_limiter2762026/07/19 09:59:22 WARN Rate limiter enabled after throttle name=server-test rate=52772026/07/19 09:59:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:59265278--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)279 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)280 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)2812026/07/19 09:59:22 WARN Rate limiter backed off name=server-test rate=5282=== CONT TestPathInfoCACompatibility/null_ca_field283=== CONT TestPathInfoCACompatibility/new_structured_format_-_text284=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method285=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive286=== CONT TestPathInfoCACompatibility/old_string_format_-_text287=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths288--- PASS: TestPathInfoCACompatibility (0.00s)289 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)290 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)291 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)292 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)293 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)294=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths295--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)296 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)297 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)298=== CONT TestSetClientTLSErrors/missing_cert_file299=== CONT TestSetClientTLSErrors/invalid_ca_file300=== CONT TestSetClientTLSErrors/missing_ca_file301=== CONT TestSetClientTLSErrors/missing_key_file3022026/07/19 09:59:22 WARN Rate limiter enabled after throttle name=server-test rate=53032026/07/19 09:59:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:59268304=== CONT TestSetClientTLS/rejects_connection_without_client_cert305=== CONT TestSetClientTLS/preserves_debug_logging_transport3062026/07/19 09:59:22 WARN Rate limiter backed off name=server-test rate=5307--- PASS: TestRateLimiterFeedback (0.00s)308 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)309 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)310 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)311 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)312=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA313--- PASS: TestSetClientTLSErrors (0.00s)314 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)315 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)316 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)317 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3182026/07/19 09:59:22 http: TLS handshake error from 127.0.0.1:59271: remote error: tls: bad certificate319--- PASS: TestSetClientTLS (0.00s)320 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)321 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)322 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)323--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)324--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)325--- PASS: TestDumpPathWriterError (0.03s)326--- PASS: TestDumpPathSingleFile (0.04s)327--- PASS: TestCaseHackSuffix (0.04s)328--- PASS: TestDumpPathMatchesNix (0.07s)329--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)330PASS331Running server tests...332The files belonging to this database system will be owned by user "_nixbld10".333This user must also own the server process.334335The database cluster will be initialized with locale "C".336The default database encoding has accordingly been set to "SQL_ASCII".337The default text search configuration will be set to "english".338339Data page checksums are enabled.340341creating directory /nix/var/nix/builds/nix-92310-3857150617/postgres3128613476/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-92310-3857150617/postgres3128613476/data -l logfile start358359/nix/var/nix/builds/nix-92310-3857150617/postgres3128613476:5432 - no response3602026-07-19 09:59:23.638 UTC [92556] LOG: starting PostgreSQL 18.4 on aarch64-apple-darwin25.3.0, compiled by clang version 21.1.8, 64-bit3612026-07-19 09:59:23.638 UTC [92556] LOG: listening on Unix socket "/nix/var/nix/builds/nix-92310-3857150617/postgres3128613476/.s.PGSQL.5432"3622026-07-19 09:59:23.641 UTC [92563] LOG: database system was shut down at 2026-07-19 09:59:23 UTC3632026-07-19 09:59:23.642 UTC [92556] LOG: database system is ready to accept connections364/nix/var/nix/builds/nix-92310-3857150617/postgres3128613476:5432 - accepting connections365<jemalloc>: option background_thread currently supports pthread only366{"timestamp":"2026-07-19T09:59:23.785657Z","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(9)"}367=== RUN TestService_AuthMiddleware368=== PAUSE TestService_AuthMiddleware369=== RUN TestService_AuthMiddleware_MTLSProxyHeader370=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader371=== RUN TestService_AuthMiddleware_MTLSBoundSubjects372=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects373=== RUN TestService_ReadAuthMiddleware374=== PAUSE TestService_ReadAuthMiddleware375=== RUN TestService_AuthMiddleware_OIDC376=== PAUSE TestService_AuthMiddleware_OIDC377=== RUN TestCacheConfigHandler378=== PAUSE TestCacheConfigHandler379=== RUN TestCacheStatsHandler380=== PAUSE TestCacheStatsHandler381=== RUN TestClientCADerivations382=== PAUSE TestClientCADerivations383=== RUN TestClientErrorHandling384=== PAUSE TestClientErrorHandling385=== RUN TestClientIntegration386=== PAUSE TestClientIntegration387=== RUN TestClientMultipleUploads388=== PAUSE TestClientMultipleUploads389=== RUN TestClientWithDependencies390=== PAUSE TestClientWithDependencies391=== RUN TestPinProtectsFromGC392=== PAUSE TestPinProtectsFromGC393=== RUN TestGCAdvisoryLockBlocksConcurrentRun3942026-07-19 09:59:23.929 UTC [92618] ERROR: relation "goose_db_version" does not exist at character 363952026-07-19 09:59:23.929 UTC [92618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC3962026/07/19 09:59:23 OK 20241026095416_initial_model.sql (3.37ms)3972026/07/19 09:59:23 OK 20251210153512_drop_unused_gin_index.sql (506.96µs)3982026/07/19 09:59:23 OK 20251218171726_add_pins.sql (836.46µs)3992026/07/19 09:59:23 OK 20260628120000_add_object_size_and_stats.sql (870.67µs)4002026/07/19 09:59:23 goose: successfully migrated database to version: 202606281200004012026/07/19 09:59:23 OK 1_commit_pending_closure.sql (870.96µs)4022026/07/19 09:59:23 OK 2_object_stats_trigger.sql (186.96µs)4032026/07/19 09:59:23 goose: up to current file version: 2404--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.08s)405=== RUN TestGCBugBareHashReferences406=== PAUSE TestGCBugBareHashReferences407=== RUN TestGCMetrics408=== PAUSE TestGCMetrics409=== RUN TestGCTaskStore_StartNew410=== PAUSE TestGCTaskStore_StartNew411=== RUN TestGCTaskStore_DeduplicateSameParams412=== PAUSE TestGCTaskStore_DeduplicateSameParams413=== RUN TestGCTaskStore_ConflictDifferentParams414=== PAUSE TestGCTaskStore_ConflictDifferentParams415=== RUN TestGCTaskStore_GetEmpty416=== PAUSE TestGCTaskStore_GetEmpty417=== RUN TestGCTaskStore_GetReturnsLatest418=== PAUSE TestGCTaskStore_GetReturnsLatest419=== RUN TestGCTaskStore_CompletedAllowsNewTask420=== PAUSE TestGCTaskStore_CompletedAllowsNewTask421=== RUN TestGCTaskStore_PhaseUpdates422=== PAUSE TestGCTaskStore_PhaseUpdates423=== RUN TestGCTaskStore_Fail424=== PAUSE TestGCTaskStore_Fail425=== RUN TestGracefulShutdownDrainsInflight426=== PAUSE TestGracefulShutdownDrainsInflight427=== RUN TestService_healthCheckHandler428=== PAUSE TestService_healthCheckHandler429=== RUN TestGenerateLandingPage430=== PAUSE TestGenerateLandingPage431=== RUN TestNARDeduplicationMetadataUploadBug432=== PAUSE TestNARDeduplicationMetadataUploadBug433=== RUN TestMetricsInventory434=== PAUSE TestMetricsInventory435=== RUN TestService_NativeMTLS436=== PAUSE TestService_NativeMTLS437=== RUN TestServerTLSConfig438=== PAUSE TestServerTLSConfig439=== RUN TestMultipartCleanup440=== PAUSE TestMultipartCleanup441=== RUN TestObjectStatsTrigger442=== PAUSE TestObjectStatsTrigger443=== RUN TestOrphanedObjectsGC444=== PAUSE TestOrphanedObjectsGC445=== RUN TestOrphanedObjectsGCStressTest446=== PAUSE TestOrphanedObjectsGCStressTest447=== RUN TestResurrectedObjectNotDeleted448=== PAUSE TestResurrectedObjectNotDeleted449=== RUN TestParseSingleRange450=== PAUSE TestParseSingleRange451=== RUN TestIsValidCachePath452=== PAUSE TestIsValidCachePath453=== RUN TestReadProxyNarinfo454=== PAUSE TestReadProxyNarinfo455=== RUN TestReadProxyNarinfoAlreadyDecompressed456=== PAUSE TestReadProxyNarinfoAlreadyDecompressed457=== RUN TestReadProxyNarStreaming458=== PAUSE TestReadProxyNarStreaming459=== RUN TestReadProxy404460=== PAUSE TestReadProxy404461=== RUN TestReadProxyInvalidPath462=== PAUSE TestReadProxyInvalidPath463=== RUN TestReadProxyHead464=== PAUSE TestReadProxyHead465=== RUN TestReadProxyConditionalGet466=== PAUSE TestReadProxyConditionalGet467=== RUN TestReadProxyRootRedirectsToIndexHTML468=== PAUSE TestReadProxyRootRedirectsToIndexHTML469=== RUN TestReadProxyDisabled470=== PAUSE TestReadProxyDisabled471=== RUN TestReadProxyRangeRequest472=== PAUSE TestReadProxyRangeRequest473=== RUN TestRedundantMultipartUpload474=== PAUSE TestRedundantMultipartUpload475=== RUN TestCompleteMultipartUpload_ErrorButObjectExists476=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists477=== RUN TestCompletedNarNotReofferedAcrossClosures478=== PAUSE TestCompletedNarNotReofferedAcrossClosures479=== RUN TestPresignedUploadRegisteredBeforeCommit480=== PAUSE TestPresignedUploadRegisteredBeforeCommit481=== RUN TestService_Rustfstest482=== PAUSE TestService_Rustfstest483=== RUN TestSystemdListenerNotActivated484--- PASS: TestSystemdListenerNotActivated (0.00s)485=== RUN TestWatchdogBeatsWhenHealthy486--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)487=== RUN TestWatchdogSkipsWhenUnhealthy4882026/07/19 09:59:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4892026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4902026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4912026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4922026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4932026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4942026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4952026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4962026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"497--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)498=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle499=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle500=== RUN TestProxyWriteTimeout501=== PAUSE TestProxyWriteTimeout502=== RUN TestIsValidUploadKey503=== PAUSE TestIsValidUploadKey504=== RUN TestUploadHandlersRejectInvalidKeys505=== PAUSE TestUploadHandlersRejectInvalidKeys506=== RUN TestUploadHandlersRejectOversizedBody507=== PAUSE TestUploadHandlersRejectOversizedBody508=== RUN TestService_cleanupPendingClosuresHandler509=== PAUSE TestService_cleanupPendingClosuresHandler510=== RUN TestService_createPendingClosureHandler511=== PAUSE TestService_createPendingClosureHandler512=== RUN TestService_verifyS3Integrity513=== PAUSE TestService_verifyS3Integrity514=== RUN TestCompleteMultipartUnregistered515=== PAUSE TestCompleteMultipartUnregistered516=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT517=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT518=== CONT TestService_AuthMiddleware519=== CONT TestOrphanedObjectsGC520=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT521=== CONT TestCompleteMultipartUnregistered522=== CONT TestService_verifyS3Integrity523=== CONT TestService_createPendingClosureHandler524=== CONT TestService_cleanupPendingClosuresHandler525=== CONT TestUploadHandlersRejectOversizedBody526=== CONT TestUploadHandlersRejectInvalidKeys527=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info528=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info529=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal530=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal531=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key532=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key533=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key534=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key535=== CONT TestIsValidUploadKey536=== RUN TestIsValidUploadKey/narinfo537=== PAUSE TestIsValidUploadKey/narinfo538=== RUN TestIsValidUploadKey/nar_zst539=== PAUSE TestIsValidUploadKey/nar_zst540=== RUN TestIsValidUploadKey/nar_xz541=== PAUSE TestIsValidUploadKey/nar_xz542=== RUN TestIsValidUploadKey/nar_plain543=== PAUSE TestIsValidUploadKey/nar_plain544=== RUN TestIsValidUploadKey/listing545=== PAUSE TestIsValidUploadKey/listing546=== RUN TestIsValidUploadKey/build_log547=== CONT TestProxyWriteTimeout548=== RUN TestProxyWriteTimeout/narinfo549=== PAUSE TestProxyWriteTimeout/narinfo550=== RUN TestProxyWriteTimeout/1_GiB_nar551=== PAUSE TestProxyWriteTimeout/1_GiB_nar552=== RUN TestProxyWriteTimeout/10_GiB_nar553=== PAUSE TestProxyWriteTimeout/10_GiB_nar554=== RUN TestProxyWriteTimeout/unknown_size555=== PAUSE TestProxyWriteTimeout/unknown_size556=== PAUSE TestIsValidUploadKey/build_log557=== RUN TestIsValidUploadKey/build_log_home-manager_file558=== PAUSE TestIsValidUploadKey/build_log_home-manager_file559=== RUN TestIsValidUploadKey/build_log_plus_in_name560=== PAUSE TestIsValidUploadKey/build_log_plus_in_name561=== RUN TestIsValidUploadKey/build_log_question_mark562=== PAUSE TestIsValidUploadKey/build_log_question_mark563=== RUN TestIsValidUploadKey/build_log_equals564=== PAUSE TestIsValidUploadKey/build_log_equals565=== RUN TestIsValidUploadKey/realisation566=== PAUSE TestIsValidUploadKey/realisation567=== RUN TestIsValidUploadKey/realisation_plus_in_output568=== PAUSE TestIsValidUploadKey/realisation_plus_in_output569=== RUN TestIsValidUploadKey/nix-cache-info570=== PAUSE TestIsValidUploadKey/nix-cache-info571=== RUN TestIsValidUploadKey/index.html572=== PAUSE TestIsValidUploadKey/index.html573=== RUN TestIsValidUploadKey/narinfo_key,_nar_type574=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type575=== RUN TestIsValidUploadKey/nar_key,_narinfo_type576=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type577=== RUN TestIsValidUploadKey/listing_key,_narinfo_type578=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type579=== RUN TestIsValidUploadKey/traversal580=== PAUSE TestIsValidUploadKey/traversal581=== RUN TestIsValidUploadKey/traversal_nar582=== PAUSE TestIsValidUploadKey/traversal_nar583=== RUN TestIsValidUploadKey/absolute584=== PAUSE TestIsValidUploadKey/absolute585=== RUN TestIsValidUploadKey/empty_key586=== PAUSE TestIsValidUploadKey/empty_key587=== RUN TestIsValidUploadKey/unknown_type588=== PAUSE TestIsValidUploadKey/unknown_type589=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle590=== CONT TestService_Rustfstest591=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure592=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure593=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart594=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart595=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts596=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts597=== CONT TestPresignedUploadRegisteredBeforeCommit5982026-07-19 09:59:24.365 UTC [92736] ERROR: relation "goose_db_version" does not exist at character 365992026-07-19 09:59:24.365 UTC [92736] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6002026-07-19 09:59:24.369 UTC [92737] ERROR: relation "goose_db_version" does not exist at character 366012026-07-19 09:59:24.369 UTC [92737] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6022026/07/19 09:59:24 OK 20241026095416_initial_model.sql (21.66ms)6032026-07-19 09:59:24.406 UTC [92743] ERROR: relation "goose_db_version" does not exist at character 366042026-07-19 09:59:24.406 UTC [92743] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6052026-07-19 09:59:24.407 UTC [92745] ERROR: relation "goose_db_version" does not exist at character 366062026-07-19 09:59:24.407 UTC [92745] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6072026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)6082026/07/19 09:59:24 OK 20251218171726_add_pins.sql (3.4ms)6092026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)6102026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200006112026/07/19 09:59:24 OK 20241026095416_initial_model.sql (7.45ms)6122026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (1.03ms)6132026/07/19 09:59:24 OK 20241026095416_initial_model.sql (6.19ms)6142026-07-19 09:59:24.418 UTC [92747] ERROR: relation "goose_db_version" does not exist at character 366152026-07-19 09:59:24.418 UTC [92747] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6162026-07-19 09:59:24.418 UTC [92748] ERROR: relation "goose_db_version" does not exist at character 366172026-07-19 09:59:24.418 UTC [92748] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6182026-07-19 09:59:24.418 UTC [92746] ERROR: relation "goose_db_version" does not exist at character 366192026-07-19 09:59:24.418 UTC [92746] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6202026/07/19 09:59:24 OK 1_commit_pending_closure.sql (2.51ms)6212026-07-19 09:59:24.419 UTC [92749] ERROR: relation "goose_db_version" does not exist at character 366222026-07-19 09:59:24.419 UTC [92749] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6232026/07/19 09:59:24 OK 20251218171726_add_pins.sql (2.07ms)6242026/07/19 09:59:24 OK 2_object_stats_trigger.sql (1.12ms)6252026/07/19 09:59:24 goose: up to current file version: 26262026-07-19 09:59:24.420 UTC [92750] ERROR: relation "goose_db_version" does not exist at character 366272026-07-19 09:59:24.420 UTC [92750] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6282026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)6292026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (4.49ms)6302026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200006312026/07/19 09:59:24 OK 20241026095416_initial_model.sql (8.82ms)6322026/07/19 09:59:24 OK 20251218171726_add_pins.sql (4.32ms)6332026/07/19 09:59:24 OK 1_commit_pending_closure.sql (2.18ms)6342026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures6352026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures6362026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures6372026/07/19 09:59:24 OK 2_object_stats_trigger.sql (694.17µs)6382026/07/19 09:59:24 goose: up to current file version: 26392026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (2.58ms)6402026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200006412026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)6422026/07/19 09:59:24 OK 1_commit_pending_closure.sql (3.16ms)6432026/07/19 09:59:24 OK 20251218171726_add_pins.sql (3.79ms)6442026/07/19 09:59:24 OK 2_object_stats_trigger.sql (1.75ms)6452026/07/19 09:59:24 goose: up to current file version: 26462026/07/19 09:59:24 OK 20241026095416_initial_model.sql (5.96ms)6472026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (2.03ms)6482026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200006492026/07/19 09:59:24 OK 20241026095416_initial_model.sql (7.98ms)6502026/07/19 09:59:24 OK 20241026095416_initial_model.sql (7.76ms)6512026/07/19 09:59:24 OK 20241026095416_initial_model.sql (8.13ms)6522026/07/19 09:59:24 OK 20241026095416_initial_model.sql (7.6ms)6532026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (851.88µs)6542026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (868.42µs)6552026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (841.38µs)6562026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (989.08µs)6572026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (721.38µs)6582026/07/19 09:59:24 OK 1_commit_pending_closure.sql (2.19ms)6592026/07/19 09:59:24 OK 2_object_stats_trigger.sql (549.71µs)6602026/07/19 09:59:24 goose: up to current file version: 26612026/07/19 09:59:24 OK 20251218171726_add_pins.sql (1.36ms)6622026/07/19 09:59:24 OK 20251218171726_add_pins.sql (1.98ms)6632026/07/19 09:59:24 OK 20251218171726_add_pins.sql (2.07ms)6642026/07/19 09:59:24 OK 20251218171726_add_pins.sql (3.85ms)6652026/07/19 09:59:24 INFO Received cleanup request method=DELETE path=/api/pending_closures6662026/07/19 09:59:24 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"667--- PASS: TestService_AuthMiddleware (0.27s)668=== CONT TestCompletedNarNotReofferedAcrossClosures6692026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (2.17ms)6702026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200006712026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.67ms)6722026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (4.41ms)6732026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200006742026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (5.97ms)6752026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200006762026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (3.52ms)6772026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200006782026/07/19 09:59:24 OK 1_commit_pending_closure.sql (3.16ms)6792026/07/19 09:59:24 OK 1_commit_pending_closure.sql (1.53ms)6802026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (2.13ms)6812026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200006822026/07/19 09:59:24 OK 2_object_stats_trigger.sql (495.79µs)6832026/07/19 09:59:24 goose: up to current file version: 26842026/07/19 09:59:24 OK 2_object_stats_trigger.sql (422.83µs)6852026/07/19 09:59:24 goose: up to current file version: 26862026/07/19 09:59:24 OK 1_commit_pending_closure.sql (1.44ms)6872026/07/19 09:59:24 INFO Aborted multipart uploads count=06882026/07/19 09:59:24 OK 1_commit_pending_closure.sql (2.14ms)6892026/07/19 09:59:24 OK 1_commit_pending_closure.sql (1.67ms)6902026/07/19 09:59:24 OK 2_object_stats_trigger.sql (619.21µs)6912026/07/19 09:59:24 goose: up to current file version: 26922026/07/19 09:59:24 OK 2_object_stats_trigger.sql (574.04µs)6932026/07/19 09:59:24 goose: up to current file version: 26942026/07/19 09:59:24 OK 2_object_stats_trigger.sql (725.08µs)6952026/07/19 09:59:24 goose: up to current file version: 26962026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures6972026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures6982026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures6992026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures700--- PASS: TestService_Rustfstest (0.25s)701=== CONT TestCompleteMultipartUpload_ErrorButObjectExists7022026/07/19 09:59:24 INFO Received cleanup request method=DELETE path=/api/pending_closures7032026/07/19 09:59:24 INFO Aborted multipart uploads count=1704{"timestamp":"2026-07-19T09:59:24.453074Z","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(2)"}705--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.28s)706=== CONT TestRedundantMultipartUpload7072026/07/19 09:59:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7082026-07-19 09:59:24.454 UTC [92736] ERROR: Closure does not exist: id=17092026-07-19 09:59:24.454 UTC [92736] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE7102026-07-19 09:59:24.454 UTC [92736] STATEMENT: -- name: CommitPendingClosure :exec711 SELECT commit_pending_closure($1::bigint)712 713--- PASS: TestService_cleanupPendingClosuresHandler (0.28s)714=== CONT TestReadProxyRangeRequest7152026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures7162026/07/19 09:59:24 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7172026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures718--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.24s)719=== CONT TestReadProxyDisabled7202026-07-19 09:59:24.466 UTC [92759] ERROR: relation "goose_db_version" does not exist at character 367212026-07-19 09:59:24.466 UTC [92759] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7222026/07/19 09:59:24 OK 20241026095416_initial_model.sql (15.25ms)7232026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)7242026/07/19 09:59:24 OK 20251218171726_add_pins.sql (6.49ms)7252026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)7262026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200007272026/07/19 09:59:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7282026/07/19 09:59:24 OK 1_commit_pending_closure.sql (28.11ms)7292026/07/19 09:59:24 OK 2_object_stats_trigger.sql (1.15ms)7302026/07/19 09:59:24 goose: up to current file version: 27312026/07/19 09:59:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7322026/07/19 09:59:24 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst733--- PASS: TestCompleteMultipartUnregistered (0.36s)734=== CONT TestReadProxyRootRedirectsToIndexHTML7352026-07-19 09:59:24.584 UTC [92779] ERROR: relation "goose_db_version" does not exist at character 367362026-07-19 09:59:24.584 UTC [92779] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7372026-07-19 09:59:24.596 UTC [92781] ERROR: relation "goose_db_version" does not exist at character 367382026-07-19 09:59:24.596 UTC [92781] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7392026/07/19 09:59:24 OK 20241026095416_initial_model.sql (19.44ms)7402026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (773.79µs)7412026/07/19 09:59:24 OK 20251218171726_add_pins.sql (2.14ms)7422026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (3.59ms)7432026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200007442026/07/19 09:59:24 OK 1_commit_pending_closure.sql (1.41ms)7452026/07/19 09:59:24 OK 2_object_stats_trigger.sql (571.21µs)7462026/07/19 09:59:24 goose: up to current file version: 27472026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures7482026/07/19 09:59:24 OK 20241026095416_initial_model.sql (16.49ms)7492026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (5.86ms)7502026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.34ms)7512026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures7522026-07-19 09:59:24.636 UTC [92787] ERROR: relation "goose_db_version" does not exist at character 367532026-07-19 09:59:24.636 UTC [92787] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7542026-07-19 09:59:24.636 UTC [92788] ERROR: relation "goose_db_version" does not exist at character 367552026-07-19 09:59:24.636 UTC [92788] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7562026-07-19 09:59:24.640 UTC [92789] ERROR: relation "goose_db_version" does not exist at character 367572026-07-19 09:59:24.640 UTC [92789] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7582026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (9.34ms)7592026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200007602026/07/19 09:59:24 OK 1_commit_pending_closure.sql (2.06ms)7612026/07/19 09:59:24 OK 2_object_stats_trigger.sql (674.92µs)7622026/07/19 09:59:24 goose: up to current file version: 27632026/07/19 09:59:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7642026/07/19 09:59:24 OK 20241026095416_initial_model.sql (19.78ms)7652026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (875µs)7662026/07/19 09:59:24 OK 20251218171726_add_pins.sql (2.21ms)767--- PASS: TestReadProxyRangeRequest (0.22s)768=== CONT TestReadProxyConditionalGet7692026/07/19 09:59:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7702026/07/19 09:59:24 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZDc3ODNjMDEtZTZhZS00NDY3LTljZjUtNzU5ZDEzMjBhNDgxLjNkODkxMTY3LWIwMmYtNDg4Ny1hNTQ1LWUzMjE2OTMyZDQzYXgxNzg0NDU1MTY0NDMyNzYyMDAw parts=107712026/07/19 09:59:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7722026/07/19 09:59:24 INFO Completed upload id=17732026/07/19 09:59:24 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000007742026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (16.19ms)7752026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200007762026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures7772026/07/19 09:59:24 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZDc3ODNjMDEtZTZhZS00NDY3LTljZjUtNzU5ZDEzMjBhNDgxLjk2ODA0MzcxLWVmNWItNGY3OC05NTQ3LTA0ZDc0YWY3ZGQ2NngxNzg0NDU1MTY0NDUwMjk1MDAw parts=107782026/07/19 09:59:24 OK 20241026095416_initial_model.sql (39.74ms)7792026/07/19 09:59:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7802026/07/19 09:59:24 OK 20241026095416_initial_model.sql (40.06ms)7812026/07/19 09:59:24 INFO Starting cleanup of old closures method=DELETE path=/api/closures7822026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (648.17µs)7832026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (688.21µs)7842026/07/19 09:59:24 OK 1_commit_pending_closure.sql (1.78ms)7852026/07/19 09:59:24 OK 2_object_stats_trigger.sql (530.08µs)7862026/07/19 09:59:24 goose: up to current file version: 27872026/07/19 09:59:24 OK 20251218171726_add_pins.sql (1.69ms)7882026/07/19 09:59:24 OK 20251218171726_add_pins.sql (2.23ms)7892026/07/19 09:59:24 INFO Aborted multipart uploads count=07902026/07/19 09:59:24 INFO Completed upload id=17912026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (2.76ms)7922026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200007932026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (2.23ms)7942026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200007952026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures7962026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures7972026/07/19 09:59:24 OK 1_commit_pending_closure.sql (1.23ms)7982026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures7992026/07/19 09:59:24 OK 1_commit_pending_closure.sql (1.44ms)8002026/07/19 09:59:24 OK 2_object_stats_trigger.sql (623.13µs)8012026/07/19 09:59:24 goose: up to current file version: 28022026/07/19 09:59:24 OK 2_object_stats_trigger.sql (542.13µs)8032026/07/19 09:59:24 goose: up to current file version: 28042026/07/19 09:59:24 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8052026/07/19 09:59:24 WARN Found objects in DB but missing from S3, will re-upload count=1806--- PASS: TestService_verifyS3Integrity (0.52s)807=== CONT TestReadProxyHead8082026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures8092026/07/19 09:59:24 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=0810--- PASS: TestReadProxyDisabled (0.24s)811=== CONT TestReadProxyInvalidPath8122026/07/19 09:59:24 INFO Vacuumed table table=pending_closures8132026/07/19 09:59:24 INFO Vacuumed table table=pending_objects8142026/07/19 09:59:24 INFO Vacuumed table table=multipart_uploads8152026/07/19 09:59:24 INFO Vacuumed table table=closures8162026/07/19 09:59:24 INFO Vacuumed table table=objects8172026/07/19 09:59:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete818{"timestamp":"2026-07-19T09:59:24.70959Z","level":"ERROR","fields":{"message":"complete_multipart_upload part error: \"part.1 not found\""},"target":"rustfs_ecstore::set_disk","filename":"crates/ecstore/src/set_disk.rs","line_number":3463,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}819{"timestamp":"2026-07-19T09:59:24.709611Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket14, object=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst"},"target":"rustfs_ecstore::set_disk","filename":"crates/ecstore/src/set_disk.rs","line_number":3534,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}8202026/07/19 09:59:24 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=ZDc3ODNjMDEtZTZhZS00NDY3LTljZjUtNzU5ZDEzMjBhNDgxLjI4YmU0ZGQ4LTAwYzgtNGYxMC04NDFiLWVjNGVhMzM5MGJlYngxNzg0NDU1MTY0Njk2MzMzMDAw8212026/07/19 09:59:24 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDc3ODNjMDEtZTZhZS00NDY3LTljZjUtNzU5ZDEzMjBhNDgxLjI4YmU0ZGQ4LTAwYzgtNGYxMC04NDFiLWVjNGVhMzM5MGJlYngxNzg0NDU1MTY0Njk2MzMzMDAw parts=1822--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.26s)823=== CONT TestReadProxy4048242026/07/19 09:59:24 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000825--- PASS: TestService_createPendingClosureHandler (0.56s)826=== CONT TestReadProxyNarStreaming827=== NAME TestOrphanedObjectsGC828 orphaned_objects_gc_test.go:290: GC Test Summary:829 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A830 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B831 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)832 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)833 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects834--- PASS: TestOrphanedObjectsGC (0.60s)835=== CONT TestReadProxyNarinfoAlreadyDecompressed8362026/07/19 09:59:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8372026/07/19 09:59:24 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZDc3ODNjMDEtZTZhZS00NDY3LTljZjUtNzU5ZDEzMjBhNDgxLjIzYjgyY2ZkLTQyZWEtNDFjZS04ZmU2LTNkYmEwNDQ3MjlhYXgxNzg0NDU1MTY0NjMyMjg1MDAw parts=12838--- PASS: TestRedundantMultipartUpload (0.40s)839=== CONT TestReadProxyNarinfo8402026/07/19 09:59:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8412026/07/19 09:59:24 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZDc3ODNjMDEtZTZhZS00NDY3LTljZjUtNzU5ZDEzMjBhNDgxLjE4YWNiY2ZlLTkwNTMtNDk0Yy1hMmQyLWIzZDE4NzIxMDI5NngxNzg0NDU1MTY0NzAyNzQ0MDAw parts=128422026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures843--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.45s)844=== CONT TestIsValidCachePath845=== RUN TestIsValidCachePath/narinfo846=== PAUSE TestIsValidCachePath/narinfo847=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars848=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars849=== RUN TestIsValidCachePath/nar_zst850=== PAUSE TestIsValidCachePath/nar_zst851=== RUN TestIsValidCachePath/nar_xz852=== PAUSE TestIsValidCachePath/nar_xz853=== RUN TestIsValidCachePath/nar_bz2854=== PAUSE TestIsValidCachePath/nar_bz2855=== RUN TestIsValidCachePath/nar_uncompressed856=== PAUSE TestIsValidCachePath/nar_uncompressed857=== RUN TestIsValidCachePath/ls858=== PAUSE TestIsValidCachePath/ls859=== RUN TestIsValidCachePath/log860=== PAUSE TestIsValidCachePath/log861=== RUN TestIsValidCachePath/realisation862=== PAUSE TestIsValidCachePath/realisation863=== RUN TestIsValidCachePath/nix-cache-info864=== PAUSE TestIsValidCachePath/nix-cache-info865=== RUN TestIsValidCachePath/index.html866=== PAUSE TestIsValidCachePath/index.html867=== RUN TestIsValidCachePath/traversal_parent868=== PAUSE TestIsValidCachePath/traversal_parent869=== RUN TestIsValidCachePath/traversal_in_middle870=== PAUSE TestIsValidCachePath/traversal_in_middle871=== RUN TestIsValidCachePath/invalid_char_e872=== PAUSE TestIsValidCachePath/invalid_char_e873=== RUN TestIsValidCachePath/invalid_char_u874=== PAUSE TestIsValidCachePath/invalid_char_u875=== RUN TestIsValidCachePath/random_path876=== PAUSE TestIsValidCachePath/random_path877=== RUN TestIsValidCachePath/empty878=== PAUSE TestIsValidCachePath/empty879=== RUN TestIsValidCachePath/leading_slash880=== PAUSE TestIsValidCachePath/leading_slash881=== RUN TestIsValidCachePath/wrong_extension882=== PAUSE TestIsValidCachePath/wrong_extension883=== RUN TestIsValidCachePath/short_hash884=== PAUSE TestIsValidCachePath/short_hash885=== CONT TestParseSingleRange886=== RUN TestParseSingleRange/none887=== PAUSE TestParseSingleRange/none888=== RUN TestParseSingleRange/unknown_unit889=== PAUSE TestParseSingleRange/unknown_unit890=== RUN TestParseSingleRange/multi-range_ignored891=== PAUSE TestParseSingleRange/multi-range_ignored892=== RUN TestParseSingleRange/malformed_no_dash893=== PAUSE TestParseSingleRange/malformed_no_dash894=== RUN TestParseSingleRange/malformed_both_empty895=== PAUSE TestParseSingleRange/malformed_both_empty896=== RUN TestParseSingleRange/malformed_end_before_start897=== PAUSE TestParseSingleRange/malformed_end_before_start898=== RUN TestParseSingleRange/closed899=== PAUSE TestParseSingleRange/closed900=== RUN TestParseSingleRange/open-ended901=== PAUSE TestParseSingleRange/open-ended902=== RUN TestParseSingleRange/end_clamped_to_size903=== PAUSE TestParseSingleRange/end_clamped_to_size904=== RUN TestParseSingleRange/suffix905=== PAUSE TestParseSingleRange/suffix906=== RUN TestParseSingleRange/suffix_exceeds_size907=== PAUSE TestParseSingleRange/suffix_exceeds_size908=== RUN TestParseSingleRange/single_byte909=== PAUSE TestParseSingleRange/single_byte910=== RUN TestParseSingleRange/start_past_EOF911=== PAUSE TestParseSingleRange/start_past_EOF912=== RUN TestParseSingleRange/start_far_past_EOF913=== PAUSE TestParseSingleRange/start_far_past_EOF914=== CONT TestResurrectedObjectNotDeleted9152026-07-19 09:59:25.043 UTC [92894] ERROR: relation "goose_db_version" does not exist at character 369162026-07-19 09:59:25.043 UTC [92894] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9172026/07/19 09:59:25 OK 20241026095416_initial_model.sql (20.7ms)9182026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)9192026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.34ms)9202026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (11.15ms)9212026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200009222026/07/19 09:59:25 OK 1_commit_pending_closure.sql (1.92ms)9232026/07/19 09:59:25 OK 2_object_stats_trigger.sql (528.21µs)9242026/07/19 09:59:25 goose: up to current file version: 2925--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.57s)926=== CONT TestOrphanedObjectsGCStressTest9272026-07-19 09:59:25.118 UTC [92914] ERROR: relation "goose_db_version" does not exist at character 369282026-07-19 09:59:25.118 UTC [92914] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9292026/07/19 09:59:25 OK 20241026095416_initial_model.sql (22.6ms)9302026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (1.17ms)9312026/07/19 09:59:25 OK 20251218171726_add_pins.sql (1.36ms)9322026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (18.98ms)9332026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200009342026/07/19 09:59:25 OK 1_commit_pending_closure.sql (1.76ms)9352026/07/19 09:59:25 OK 2_object_stats_trigger.sql (1.31ms)9362026/07/19 09:59:25 goose: up to current file version: 2937--- PASS: TestReadProxyConditionalGet (0.54s)938=== CONT TestObjectStatsTrigger9392026-07-19 09:59:25.234 UTC [92961] ERROR: relation "goose_db_version" does not exist at character 369402026-07-19 09:59:25.234 UTC [92961] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9412026-07-19 09:59:25.246 UTC [92966] ERROR: relation "goose_db_version" does not exist at character 369422026-07-19 09:59:25.246 UTC [92966] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9432026-07-19 09:59:25.246 UTC [92964] ERROR: relation "goose_db_version" does not exist at character 369442026-07-19 09:59:25.246 UTC [92964] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9452026-07-19 09:59:25.260 UTC [92968] ERROR: relation "goose_db_version" does not exist at character 369462026-07-19 09:59:25.260 UTC [92968] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9472026-07-19 09:59:25.266 UTC [92969] ERROR: relation "goose_db_version" does not exist at character 369482026-07-19 09:59:25.266 UTC [92969] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9492026/07/19 09:59:25 OK 20241026095416_initial_model.sql (22.12ms)9502026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (827.17µs)9512026/07/19 09:59:25 OK 20251218171726_add_pins.sql (2.03ms)9522026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (5.79ms)9532026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200009542026/07/19 09:59:25 OK 20241026095416_initial_model.sql (18.97ms)9552026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (918.79µs)9562026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.61ms)9572026/07/19 09:59:25 OK 2_object_stats_trigger.sql (644.96µs)9582026/07/19 09:59:25 goose: up to current file version: 29592026/07/19 09:59:25 OK 20241026095416_initial_model.sql (15.89ms)9602026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (929.96µs)961--- PASS: TestReadProxyInvalidPath (0.59s)962=== CONT TestMultipartCleanup9632026-07-19 09:59:25.288 UTC [92970] ERROR: relation "goose_db_version" does not exist at character 369642026-07-19 09:59:25.288 UTC [92970] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9652026/07/19 09:59:25 OK 20251218171726_add_pins.sql (11.09ms)9662026/07/19 09:59:25 OK 20251218171726_add_pins.sql (9.25ms)9672026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (3.2ms)9682026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200009692026/07/19 09:59:25 OK 20241026095416_initial_model.sql (20.32ms)9702026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.19ms)9712026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (6.42ms)9722026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200009732026/07/19 09:59:25 OK 2_object_stats_trigger.sql (3.1ms)9742026/07/19 09:59:25 goose: up to current file version: 29752026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)9762026/07/19 09:59:25 OK 20241026095416_initial_model.sql (21.19ms)9772026/07/19 09:59:25 OK 1_commit_pending_closure.sql (3.97ms)9782026/07/19 09:59:25 OK 2_object_stats_trigger.sql (1.43ms)9792026/07/19 09:59:25 goose: up to current file version: 29802026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)9812026/07/19 09:59:25 OK 20251218171726_add_pins.sql (2.58ms)9822026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.88ms)9832026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (6.04ms)9842026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200009852026/07/19 09:59:25 OK 20241026095416_initial_model.sql (10.36ms)9862026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.88ms)9872026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (4.69ms)9882026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (7.96ms)9892026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200009902026/07/19 09:59:25 OK 1_commit_pending_closure.sql (1.54ms)9912026/07/19 09:59:25 OK 20251218171726_add_pins.sql (1.82ms)9922026/07/19 09:59:25 OK 2_object_stats_trigger.sql (516.96µs)9932026/07/19 09:59:25 goose: up to current file version: 2994--- PASS: TestReadProxyHead (0.63s)995--- PASS: TestReadProxyNarStreaming (0.58s)996=== CONT TestService_NativeMTLS997=== CONT TestServerTLSConfig998=== RUN TestServerTLSConfig/no_client_CA999=== PAUSE TestServerTLSConfig/no_client_CA1000=== RUN TestServerTLSConfig/missing_CA_file1001=== PAUSE TestServerTLSConfig/missing_CA_file1002=== RUN TestServerTLSConfig/not_a_PEM_file1003=== PAUSE TestServerTLSConfig/not_a_PEM_file1004=== CONT TestMetricsInventory10052026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (7.07ms)10062026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000010072026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.59ms)10082026/07/19 09:59:25 OK 2_object_stats_trigger.sql (790.5µs)10092026/07/19 09:59:25 goose: up to current file version: 21010--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.55s)1011=== CONT TestNARDeduplicationMetadataUploadBug10122026/07/19 09:59:25 OK 2_object_stats_trigger.sql (21.67ms)10132026/07/19 09:59:25 goose: up to current file version: 21014--- PASS: TestReadProxyNarinfo (0.48s)1015=== CONT TestGenerateLandingPage1016--- PASS: TestReadProxy404 (0.62s)1017=== CONT TestService_healthCheckHandler1018--- PASS: TestGenerateLandingPage (0.00s)1019=== CONT TestGracefulShutdownDrainsInflight10202026/07/19 09:59:25 INFO Starting HTTP server address=127.0.0.1:5936610212026/07/19 09:59:25 INFO Shutdown signal received, draining in-flight requests timeout=10s10222026-07-19 09:59:25.342 UTC [92983] ERROR: relation "goose_db_version" does not exist at character 3610232026-07-19 09:59:25.342 UTC [92983] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10242026/07/19 09:59:25 OK 20241026095416_initial_model.sql (10.26ms)10252026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (1.37ms)10262026/07/19 09:59:25 OK 20251218171726_add_pins.sql (4.15ms)10272026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (7.08ms)10282026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000010292026/07/19 09:59:25 OK 1_commit_pending_closure.sql (1.11ms)10302026/07/19 09:59:25 OK 2_object_stats_trigger.sql (262.17µs)10312026/07/19 09:59:25 goose: up to current file version: 21032--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1033=== CONT TestGCTaskStore_Fail1034--- PASS: TestGCTaskStore_Fail (0.00s)1035=== CONT TestGCTaskStore_PhaseUpdates1036--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1037=== CONT TestGCTaskStore_CompletedAllowsNewTask1038--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1039=== CONT TestGCTaskStore_GetReturnsLatest1040--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1041=== CONT TestGCTaskStore_GetEmpty1042--- PASS: TestGCTaskStore_GetEmpty (0.00s)1043=== CONT TestGCTaskStore_ConflictDifferentParams1044--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1045=== CONT TestGCTaskStore_DeduplicateSameParams1046--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1047=== CONT TestGCTaskStore_StartNew1048--- PASS: TestGCTaskStore_StartNew (0.00s)1049=== CONT TestGCMetrics1050--- PASS: TestResurrectedObjectNotDeleted (0.53s)1051=== CONT TestGCBugBareHashReferences10522026-07-19 09:59:25.620 UTC [93056] ERROR: relation "goose_db_version" does not exist at character 3610532026-07-19 09:59:25.620 UTC [93056] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10542026/07/19 09:59:25 OK 20241026095416_initial_model.sql (15.57ms)10552026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)10562026/07/19 09:59:25 OK 20251218171726_add_pins.sql (972.38µs)10572026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (3.34ms)10582026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000010592026/07/19 09:59:25 OK 1_commit_pending_closure.sql (1.07ms)10602026/07/19 09:59:25 OK 2_object_stats_trigger.sql (416.96µs)10612026/07/19 09:59:25 goose: up to current file version: 210622026-07-19 09:59:25.683 UTC [93073] ERROR: relation "goose_db_version" does not exist at character 3610632026-07-19 09:59:25.683 UTC [93073] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10642026/07/19 09:59:25 OK 20241026095416_initial_model.sql (26.27ms)10652026-07-19 09:59:25.729 UTC [93086] ERROR: relation "goose_db_version" does not exist at character 3610662026-07-19 09:59:25.729 UTC [93086] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10672026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (13.53ms)10682026-07-19 09:59:25.758 UTC [93088] ERROR: relation "goose_db_version" does not exist at character 3610692026-07-19 09:59:25.758 UTC [93088] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10702026/07/19 09:59:25 OK 20251218171726_add_pins.sql (28.44ms)10712026-07-19 09:59:25.784 UTC [93093] ERROR: relation "goose_db_version" does not exist at character 3610722026-07-19 09:59:25.784 UTC [93093] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10732026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (25.21ms)10742026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000010752026/07/19 09:59:25 OK 1_commit_pending_closure.sql (21.3ms)10762026/07/19 09:59:25 OK 20241026095416_initial_model.sql (38.45ms)10772026/07/19 09:59:25 OK 2_object_stats_trigger.sql (13.47ms)10782026/07/19 09:59:25 goose: up to current file version: 210792026-07-19 09:59:25.833 UTC [93099] ERROR: relation "goose_db_version" does not exist at character 3610802026-07-19 09:59:25.833 UTC [93099] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10812026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (15.2ms)10822026/07/19 09:59:25 OK 20251218171726_add_pins.sql (4.19ms)10832026-07-19 09:59:25.840 UTC [93100] ERROR: relation "goose_db_version" does not exist at character 3610842026-07-19 09:59:25.840 UTC [93100] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10852026/07/19 09:59:25 OK 20241026095416_initial_model.sql (25.53ms)10862026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)10872026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (5.58ms)10882026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000010892026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.46ms)10902026/07/19 09:59:25 OK 1_commit_pending_closure.sql (1.94ms)10912026/07/19 09:59:25 OK 2_object_stats_trigger.sql (1.47ms)10922026/07/19 09:59:25 goose: up to current file version: 210932026/07/19 09:59:25 OK 20241026095416_initial_model.sql (11.25ms)10942026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)1095--- PASS: TestService_healthCheckHandler (0.51s)1096=== CONT TestPinProtectsFromGC10972026/07/19 09:59:25 OK 20251218171726_add_pins.sql (1.33ms)10982026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (6.45ms)10992026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000011002026/07/19 09:59:25 OK 20241026095416_initial_model.sql (10.2ms)1101--- PASS: TestObjectStatsTrigger (0.64s)1102=== CONT TestClientWithDependencies11032026/07/19 09:59:25 OK 1_commit_pending_closure.sql (4.88ms)11042026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (3.81ms)11052026/07/19 09:59:25 OK 20241026095416_initial_model.sql (11.82ms)11062026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.07ms)11072026/07/19 09:59:25 goose: up to current file version: 211082026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (8.39ms)11092026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000011102026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.5ms)11112026/07/19 09:59:25 OK 1_commit_pending_closure.sql (3.47ms)11122026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.99ms)11132026/07/19 09:59:25 OK 2_object_stats_trigger.sql (1.96ms)11142026/07/19 09:59:25 goose: up to current file version: 211152026/07/19 09:59:25 OK 20251218171726_add_pins.sql (8.87ms)11162026-07-19 09:59:25.867 UTC [93105] ERROR: relation "goose_db_version" does not exist at character 3611172026-07-19 09:59:25.867 UTC [93105] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11182026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures11192026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (13.98ms)11202026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000011212026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (12.17ms)11222026/07/19 09:59:25 goose: successfully migrated database to version: 202606281200001123--- PASS: TestMetricsInventory (0.56s)1124=== CONT TestClientMultipleUploads11252026/07/19 09:59:25 OK 1_commit_pending_closure.sql (1.98ms)11262026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.28ms)11272026/07/19 09:59:25 OK 2_object_stats_trigger.sql (544.04µs)11282026/07/19 09:59:25 goose: up to current file version: 211292026/07/19 09:59:25 OK 2_object_stats_trigger.sql (1.43ms)11302026/07/19 09:59:25 goose: up to current file version: 211312026/07/19 09:59:25 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11322026/07/19 09:59:25 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1133--- PASS: TestService_NativeMTLS (0.57s)1134=== CONT TestClientIntegration11352026/07/19 09:59:25 INFO Created nix-cache-info in bucket bucket=bucket3111362026/07/19 09:59:25 OK 20241026095416_initial_model.sql (22.26ms)11372026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (1.1ms)11382026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.5ms)11392026-07-19 09:59:25.914 UTC [93117] ERROR: relation "goose_db_version" does not exist at character 3611402026-07-19 09:59:25.914 UTC [93117] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11412026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (17.68ms)11422026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000011432026/07/19 09:59:25 OK 1_commit_pending_closure.sql (1.08ms)11442026/07/19 09:59:25 OK 2_object_stats_trigger.sql (289.75µs)11452026/07/19 09:59:25 goose: up to current file version: 211462026/07/19 09:59:25 OK 20241026095416_initial_model.sql (12.54ms)11472026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (851.33µs)11482026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.29ms)11492026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (6.04ms)11502026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000011512026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.07ms)11522026/07/19 09:59:25 OK 2_object_stats_trigger.sql (746.13µs)11532026/07/19 09:59:25 goose: up to current file version: 211542026/07/19 09:59:25 INFO Aborted multipart uploads count=011552026/07/19 09:59:25 WARN Force mode enabled - objects will be deleted immediately without grace period11562026/07/19 09:59:25 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=011572026/07/19 09:59:25 INFO Vacuumed table table=pending_closures11582026/07/19 09:59:25 INFO Vacuumed table table=pending_objects11592026/07/19 09:59:25 INFO Vacuumed table table=multipart_uploads11602026/07/19 09:59:25 INFO Vacuumed table table=closures11612026/07/19 09:59:25 INFO Vacuumed table table=objects1162--- PASS: TestGCMetrics (0.57s)1163=== CONT TestClientErrorHandling1164=== RUN TestClientErrorHandling/InvalidStorePath1165=== PAUSE TestClientErrorHandling/InvalidStorePath1166=== RUN TestClientErrorHandling/InvalidAuthToken1167=== PAUSE TestClientErrorHandling/InvalidAuthToken1168=== RUN TestClientErrorHandling/ServerNotAvailable1169=== PAUSE TestClientErrorHandling/ServerNotAvailable1170=== CONT TestClientCADerivations11712026/07/19 09:59:25 INFO Received cleanup request method=DELETE path=/api/pending_closures11722026/07/19 09:59:25 INFO Aborted multipart uploads count=11173--- PASS: TestMultipartCleanup (0.72s)1174=== CONT TestCacheStatsHandler1175=== NAME TestNARDeduplicationMetadataUploadBug1176 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-92310-3857150617/TestNARDeduplicationMetadataUploadBug2255404408/001/store/sny2zbq0f4hcnygkvb1rnk90py7xrs57-file1.txt11772026-07-19 09:59:26.145 UTC [93133] ERROR: relation "goose_db_version" does not exist at character 3611782026-07-19 09:59:26.145 UTC [93133] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1179--- PASS: TestGCBugBareHashReferences (0.74s)1180=== CONT TestCacheConfigHandler1181=== RUN TestCacheConfigHandler/full_config,_no_issuer1182=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1183=== RUN TestCacheConfigHandler/no_cache_url_configured1184=== PAUSE TestCacheConfigHandler/no_cache_url_configured1185=== RUN TestCacheConfigHandler/no_signing_keys1186=== PAUSE TestCacheConfigHandler/no_signing_keys1187=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1188=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1189=== CONT TestService_AuthMiddleware_OIDC11902026/07/19 09:59:26 INFO OIDC provider initialized name=test11912026-07-19 09:59:26.167 UTC [93137] ERROR: relation "goose_db_version" does not exist at character 3611922026-07-19 09:59:26.167 UTC [93137] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11932026-07-19 09:59:26.182 UTC [93139] ERROR: relation "goose_db_version" does not exist at character 3611942026-07-19 09:59:26.182 UTC [93139] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11952026/07/19 09:59:26 OK 20241026095416_initial_model.sql (20.22ms)11962026/07/19 09:59:26 OK 20251210153512_drop_unused_gin_index.sql (806µs)11972026/07/19 09:59:26 OK 20241026095416_initial_model.sql (22.63ms)11982026-07-19 09:59:26.196 UTC [93140] ERROR: relation "goose_db_version" does not exist at character 3611992026-07-19 09:59:26.196 UTC [93140] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12002026/07/19 09:59:26 OK 20251210153512_drop_unused_gin_index.sql (878µs)12012026/07/19 09:59:26 OK 20251218171726_add_pins.sql (9.3ms)12022026/07/19 09:59:26 OK 20251218171726_add_pins.sql (2.38ms)12032026/07/19 09:59:26 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)12042026/07/19 09:59:26 goose: successfully migrated database to version: 2026062812000012052026/07/19 09:59:26 OK 1_commit_pending_closure.sql (3.66ms)12062026/07/19 09:59:26 OK 20260628120000_add_object_size_and_stats.sql (11.16ms)12072026/07/19 09:59:26 goose: successfully migrated database to version: 2026062812000012082026/07/19 09:59:26 OK 2_object_stats_trigger.sql (1.69ms)12092026/07/19 09:59:26 goose: up to current file version: 212102026/07/19 09:59:26 OK 20241026095416_initial_model.sql (9.77ms)12112026/07/19 09:59:26 OK 20241026095416_initial_model.sql (13.57ms)12122026/07/19 09:59:26 OK 1_commit_pending_closure.sql (2.53ms)12132026/07/19 09:59:26 OK 2_object_stats_trigger.sql (549.79µs)12142026/07/19 09:59:26 goose: up to current file version: 212152026/07/19 09:59:26 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)12162026/07/19 09:59:26 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)12172026/07/19 09:59:26 OK 20251218171726_add_pins.sql (3.23ms)12182026/07/19 09:59:26 OK 20251218171726_add_pins.sql (4.05ms)12192026/07/19 09:59:26 OK 20260628120000_add_object_size_and_stats.sql (2.33ms)12202026/07/19 09:59:26 goose: successfully migrated database to version: 2026062812000012212026/07/19 09:59:26 INFO Created nix-cache-info in bucket bucket=bucket3612222026/07/19 09:59:26 INFO Created nix-cache-info in bucket bucket=bucket3512232026/07/19 09:59:26 OK 1_commit_pending_closure.sql (2.16ms)12242026/07/19 09:59:26 OK 20260628120000_add_object_size_and_stats.sql (4.23ms)12252026/07/19 09:59:26 goose: successfully migrated database to version: 2026062812000012262026/07/19 09:59:26 OK 2_object_stats_trigger.sql (1.2ms)12272026/07/19 09:59:26 goose: up to current file version: 212282026/07/19 09:59:26 OK 1_commit_pending_closure.sql (2.88ms)12292026/07/19 09:59:26 OK 2_object_stats_trigger.sql (617.38µs)12302026/07/19 09:59:26 goose: up to current file version: 212312026/07/19 09:59:26 INFO Created nix-cache-info in bucket bucket=bucket3712322026/07/19 09:59:26 INFO Created nix-cache-info in bucket bucket=bucket3812332026-07-19 09:59:26.270 UTC [93146] ERROR: relation "goose_db_version" does not exist at character 3612342026-07-19 09:59:26.270 UTC [93146] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12352026/07/19 09:59:26 OK 20241026095416_initial_model.sql (9.4ms)12362026/07/19 09:59:26 OK 20251210153512_drop_unused_gin_index.sql (924.83µs)12372026/07/19 09:59:26 OK 20251218171726_add_pins.sql (2.06ms)12382026/07/19 09:59:26 OK 20260628120000_add_object_size_and_stats.sql (4.04ms)12392026/07/19 09:59:26 goose: successfully migrated database to version: 2026062812000012402026/07/19 09:59:26 OK 1_commit_pending_closure.sql (2.48ms)12412026/07/19 09:59:26 OK 2_object_stats_trigger.sql (569.25µs)12422026/07/19 09:59:26 goose: up to current file version: 212432026/07/19 09:59:26 INFO Created nix-cache-info in bucket bucket=bucket3912442026-07-19 09:59:26.327 UTC [93154] ERROR: relation "goose_db_version" does not exist at character 3612452026-07-19 09:59:26.327 UTC [93154] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12462026/07/19 09:59:26 OK 20241026095416_initial_model.sql (8.46ms)12472026/07/19 09:59:26 OK 20251210153512_drop_unused_gin_index.sql (967.29µs)12482026/07/19 09:59:26 OK 20251218171726_add_pins.sql (2.61ms)12492026/07/19 09:59:26 OK 20260628120000_add_object_size_and_stats.sql (11.66ms)12502026/07/19 09:59:26 goose: successfully migrated database to version: 2026062812000012512026/07/19 09:59:26 OK 1_commit_pending_closure.sql (2.27ms)12522026/07/19 09:59:26 OK 2_object_stats_trigger.sql (627.92µs)12532026/07/19 09:59:26 goose: up to current file version: 212542026-07-19 09:59:26.362 UTC [93159] ERROR: relation "goose_db_version" does not exist at character 3612552026-07-19 09:59:26.362 UTC [93159] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1256--- PASS: TestCacheStatsHandler (0.37s)1257=== CONT TestService_ReadAuthMiddleware12582026/07/19 09:59:26 OK 20241026095416_initial_model.sql (4.48ms)12592026/07/19 09:59:26 OK 20251210153512_drop_unused_gin_index.sql (950.63µs)12602026/07/19 09:59:26 OK 20251218171726_add_pins.sql (2.18ms)12612026/07/19 09:59:26 OK 20260628120000_add_object_size_and_stats.sql (2.77ms)12622026/07/19 09:59:26 goose: successfully migrated database to version: 2026062812000012632026/07/19 09:59:26 OK 1_commit_pending_closure.sql (1.86ms)12642026/07/19 09:59:26 OK 2_object_stats_trigger.sql (626.54µs)12652026/07/19 09:59:26 goose: up to current file version: 21266=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1267=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1268=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1269=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1270=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1271=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1272=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1273=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1274=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1275=== NAME TestClientIntegration1276 client_integration_test.go:276: Created store path: /nix/var/nix/builds/nix-92310-3857150617/TestClientIntegration3443601219/002/store/kfl3d25fmqaq0l4k7r08k52m6j9l7dzy-test-file.txt1277=== NAME TestClientMultipleUploads1278 client_integration_test.go:338: Created store path 0: /nix/var/nix/builds/nix-92310-3857150617/TestClientMultipleUploads3557604097/001/store/s2nn3y65g96lf3vpv9mnl0fkiifxdpsy-test-file-0.txt12792026-07-19 09:59:26.613 UTC [93197] ERROR: relation "goose_db_version" does not exist at character 3612802026-07-19 09:59:26.613 UTC [93197] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1281=== NAME TestOrphanedObjectsGCStressTest1282 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains12832026/07/19 09:59:26 OK 20241026095416_initial_model.sql (6.38ms)1284 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion12852026/07/19 09:59:26 OK 20251210153512_drop_unused_gin_index.sql (904.71µs)12862026/07/19 09:59:26 OK 20251218171726_add_pins.sql (2.29ms)12872026/07/19 09:59:26 OK 20260628120000_add_object_size_and_stats.sql (2.19ms)12882026/07/19 09:59:26 goose: successfully migrated database to version: 2026062812000012892026/07/19 09:59:26 OK 1_commit_pending_closure.sql (2.1ms)12902026/07/19 09:59:26 OK 2_object_stats_trigger.sql (593µs)12912026/07/19 09:59:26 goose: up to current file version: 212922026/07/19 09:59:26 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"12932026/07/19 09:59:26 WARN mTLS auth: bound subjects configured but subject DN unavailable12942026/07/19 09:59:26 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1295--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.25s)1296=== CONT TestService_AuthMiddleware_MTLSProxyHeader1297=== NAME TestClientMultipleUploads1298 client_integration_test.go:338: Created store path 1: /nix/var/nix/builds/nix-92310-3857150617/TestClientMultipleUploads3557604097/001/store/i54drwn2bmrifqaq5w8bvcjrjalgcihl-test-file-1.txt1299 client_integration_test.go:338: Created store path 2: /nix/var/nix/builds/nix-92310-3857150617/TestClientMultipleUploads3557604097/001/store/68d0iszbrifxjfgg33jwh6k9jahr6w21-test-file-2.txt1300=== NAME TestPinProtectsFromGC1301 client_integration_test.go:646: Pinned store path: /nix/var/nix/builds/nix-92310-3857150617/TestPinProtectsFromGC300840418/001/store/ffajggw7p271nwf6vl63wlyj3r51px4b-pinned-file.txt1302 client_integration_test.go:647: Unpinned store path: /nix/var/nix/builds/nix-92310-3857150617/TestPinProtectsFromGC300840418/001/store/5dyzymkkrsy37p8r3pk8rj0hzq00vp7q-unpinned-file.txt13032026/07/19 09:59:26 INFO Received uploads request method=POST path=/api/pending_closures13042026-07-19 09:59:26.748 UTC [93219] ERROR: relation "goose_db_version" does not exist at character 3613052026-07-19 09:59:26.748 UTC [93219] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13062026-07-19 09:59:26.755 UTC [93224] ERROR: relation "goose_db_version" does not exist at character 3613072026-07-19 09:59:26.755 UTC [93224] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13082026/07/19 09:59:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13092026/07/19 09:59:26 INFO Uploading sny2zbq0f4hcnygkvb1rnk90py7xrs57-file1.txt (160B)13102026/07/19 09:59:26 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"13112026/07/19 09:59:26 OK 20241026095416_initial_model.sql (6.52ms)13122026/07/19 09:59:26 WARN Failed to register uploaded object key=sny2zbq0f4hcnygkvb1rnk90py7xrs57.ls error="server returned 404: 404 page not found\n"13132026/07/19 09:59:26 OK 20251210153512_drop_unused_gin_index.sql (797.75µs)13142026/07/19 09:59:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13152026/07/19 09:59:26 INFO Signed narinfos id=1 count=113162026/07/19 09:59:26 INFO Uploading 1 narinfos13172026/07/19 09:59:26 OK 20241026095416_initial_model.sql (6.96ms)13182026/07/19 09:59:26 WARN Failed to register uploaded object key=sny2zbq0f4hcnygkvb1rnk90py7xrs57.narinfo error="server returned 404: 404 page not found\n"13192026/07/19 09:59:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13202026/07/19 09:59:26 OK 20251210153512_drop_unused_gin_index.sql (772.5µs)13212026/07/19 09:59:26 OK 20251218171726_add_pins.sql (2.39ms)13222026/07/19 09:59:26 OK 20251218171726_add_pins.sql (1.64ms)13232026/07/19 09:59:26 OK 20260628120000_add_object_size_and_stats.sql (2.09ms)13242026/07/19 09:59:26 goose: successfully migrated database to version: 2026062812000013252026/07/19 09:59:26 INFO Completed upload id=113262026/07/19 09:59:26 INFO Upload complete. (488ms)1327=== NAME TestNARDeduplicationMetadataUploadBug1328 metadata_upload_test.go:54: Retrieved narinfo from S3:1329 StorePath: /nix/var/nix/builds/nix-92310-3857150617/TestNARDeduplicationMetadataUploadBug2255404408/001/store/sny2zbq0f4hcnygkvb1rnk90py7xrs57-file1.txt1330 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1331 Compression: zstd1332 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1333 NarSize: 1601334 References: 1335 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13362026/07/19 09:59:26 OK 1_commit_pending_closure.sql (1.79ms)13372026/07/19 09:59:26 OK 20260628120000_add_object_size_and_stats.sql (2.71ms)13382026/07/19 09:59:26 goose: successfully migrated database to version: 2026062812000013392026/07/19 09:59:26 OK 2_object_stats_trigger.sql (620.25µs)13402026/07/19 09:59:26 goose: up to current file version: 213412026/07/19 09:59:26 OK 1_commit_pending_closure.sql (954.58µs)13422026/07/19 09:59:26 OK 2_object_stats_trigger.sql (762.25µs)13432026/07/19 09:59:26 goose: up to current file version: 213442026/07/19 09:59:26 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1345--- PASS: TestService_ReadAuthMiddleware (0.42s)1346=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info13472026/07/19 09:59:26 INFO Received uploads request method=POST path=/1348=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key13492026/07/19 09:59:26 INFO Received request for more parts method=POST path=/1350=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key13512026/07/19 09:59:26 INFO Received complete multipart upload request method=POST path=/1352=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal13532026/07/19 09:59:26 INFO Received uploads request method=POST path=/1354--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1355 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1356 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1357 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1358 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1359=== CONT TestProxyWriteTimeout/narinfo1360=== CONT TestProxyWriteTimeout/unknown_size1361=== CONT TestProxyWriteTimeout/1_GiB_nar1362=== CONT TestProxyWriteTimeout/10_GiB_nar1363--- PASS: TestProxyWriteTimeout (0.00s)1364 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1365 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1366 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1367 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1368=== CONT TestIsValidUploadKey/narinfo1369=== CONT TestIsValidUploadKey/nix-cache-info1370=== CONT TestIsValidUploadKey/traversal1371=== CONT TestIsValidUploadKey/unknown_type1372=== CONT TestIsValidUploadKey/empty_key1373=== CONT TestIsValidUploadKey/absolute1374=== CONT TestIsValidUploadKey/traversal_nar1375=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1376=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1377=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1378=== CONT TestIsValidUploadKey/index.html1379=== CONT TestIsValidUploadKey/build_log_home-manager_file1380=== CONT TestIsValidUploadKey/realisation_plus_in_output1381=== CONT TestIsValidUploadKey/realisation1382=== CONT TestIsValidUploadKey/build_log_equals1383=== CONT TestIsValidUploadKey/build_log_question_mark1384=== CONT TestIsValidUploadKey/build_log_plus_in_name1385=== CONT TestIsValidUploadKey/nar_plain1386=== CONT TestIsValidUploadKey/build_log1387=== CONT TestIsValidUploadKey/listing1388=== CONT TestIsValidUploadKey/nar_xz1389=== CONT TestIsValidUploadKey/nar_zst1390--- PASS: TestIsValidUploadKey (0.01s)1391 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1392 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1393 --- PASS: TestIsValidUploadKey/traversal (0.00s)1394 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1395 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1396 --- PASS: TestIsValidUploadKey/absolute (0.00s)1397 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1398 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1399 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1400 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1401 --- PASS: TestIsValidUploadKey/index.html (0.00s)1402 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1403 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1404 --- PASS: TestIsValidUploadKey/realisation (0.00s)1405 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1406 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1407 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1408 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1409 --- PASS: TestIsValidUploadKey/build_log (0.00s)1410 --- PASS: TestIsValidUploadKey/listing (0.00s)1411 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1412 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1413=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14142026/07/19 09:59:26 INFO Received uploads request method=POST path=/1415--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.16s)1416=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14172026/07/19 09:59:26 INFO Received request for more parts method=POST path=/1418=== NAME TestNARDeduplicationMetadataUploadBug1419 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1420 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1421 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1422=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14232026/07/19 09:59:26 INFO Received complete multipart upload request method=POST path=/1424=== CONT TestIsValidCachePath/narinfo1425=== CONT TestIsValidCachePath/index.html1426=== CONT TestIsValidCachePath/short_hash1427=== CONT TestIsValidCachePath/wrong_extension1428=== CONT TestIsValidCachePath/leading_slash1429=== CONT TestIsValidCachePath/empty1430=== CONT TestIsValidCachePath/random_path1431=== CONT TestIsValidCachePath/invalid_char_u1432=== CONT TestIsValidCachePath/invalid_char_e1433=== CONT TestIsValidCachePath/traversal_in_middle1434=== CONT TestIsValidCachePath/traversal_parent1435=== CONT TestIsValidCachePath/nar_uncompressed1436=== CONT TestIsValidCachePath/nix-cache-info1437=== CONT TestIsValidCachePath/realisation1438=== CONT TestIsValidCachePath/log1439=== CONT TestIsValidCachePath/ls1440=== CONT TestIsValidCachePath/nar_xz1441=== CONT TestIsValidCachePath/nar_bz21442=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1443=== CONT TestIsValidCachePath/nar_zst1444--- PASS: TestIsValidCachePath (0.00s)1445 --- PASS: TestIsValidCachePath/narinfo (0.00s)1446 --- PASS: TestIsValidCachePath/index.html (0.00s)1447 --- PASS: TestIsValidCachePath/short_hash (0.00s)1448 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1449 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1450 --- PASS: TestIsValidCachePath/empty (0.00s)1451 --- PASS: TestIsValidCachePath/random_path (0.00s)1452 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1453 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1454 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1455 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1456 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1457 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1458 --- PASS: TestIsValidCachePath/realisation (0.00s)1459 --- PASS: TestIsValidCachePath/log (0.00s)1460 --- PASS: TestIsValidCachePath/ls (0.00s)1461 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1462 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1463 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1464 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1465=== CONT TestParseSingleRange/none1466=== CONT TestParseSingleRange/open-ended1467=== CONT TestParseSingleRange/start_far_past_EOF1468=== CONT TestParseSingleRange/start_past_EOF1469=== CONT TestParseSingleRange/single_byte1470=== CONT TestParseSingleRange/suffix_exceeds_size1471=== CONT TestParseSingleRange/suffix1472=== CONT TestParseSingleRange/end_clamped_to_size1473=== CONT TestParseSingleRange/malformed_both_empty1474=== CONT TestParseSingleRange/closed1475=== CONT TestParseSingleRange/malformed_end_before_start1476=== CONT TestParseSingleRange/multi-range_ignored1477=== CONT TestParseSingleRange/malformed_no_dash1478=== CONT TestParseSingleRange/unknown_unit1479--- PASS: TestParseSingleRange (0.00s)1480 --- PASS: TestParseSingleRange/none (0.00s)1481 --- PASS: TestParseSingleRange/open-ended (0.00s)1482 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1483 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1484 --- PASS: TestParseSingleRange/single_byte (0.00s)1485 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1486 --- PASS: TestParseSingleRange/suffix (0.00s)1487 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1488 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1489 --- PASS: TestParseSingleRange/closed (0.00s)1490 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1491 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1492 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1493 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1494=== CONT TestServerTLSConfig/no_client_CA1495=== CONT TestServerTLSConfig/not_a_PEM_file1496=== CONT TestServerTLSConfig/missing_CA_file1497=== CONT TestClientErrorHandling/InvalidStorePath1498--- PASS: TestServerTLSConfig (0.00s)1499 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1500 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1501 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)15022026/07/19 09:59:26 INFO Received uploads request method=POST path=/api/pending_closures15032026/07/19 09:59:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15042026/07/19 09:59:26 INFO Uploading kfl3d25fmqaq0l4k7r08k52m6j9l7dzy-test-file.txt (152B)15052026/07/19 09:59:26 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15062026/07/19 09:59:26 WARN Failed to register uploaded object key=kfl3d25fmqaq0l4k7r08k52m6j9l7dzy.ls error="server returned 404: 404 page not found\n"15072026/07/19 09:59:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15082026/07/19 09:59:26 INFO Signed narinfos id=1 count=115092026/07/19 09:59:26 INFO Uploading 1 narinfos15102026/07/19 09:59:26 WARN Failed to register uploaded object key=kfl3d25fmqaq0l4k7r08k52m6j9l7dzy.narinfo error="server returned 404: 404 page not found\n"15112026/07/19 09:59:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15122026/07/19 09:59:26 INFO Completed upload id=115132026/07/19 09:59:26 INFO Upload complete. (218ms)1514=== NAME TestClientIntegration1515 client_integration_test.go:292: Retrieved narinfo from S3:1516 StorePath: /nix/var/nix/builds/nix-92310-3857150617/TestClientIntegration3443601219/002/store/kfl3d25fmqaq0l4k7r08k52m6j9l7dzy-test-file.txt1517 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1518 Compression: zstd1519 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11520 NarSize: 1521521 References: 1522 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11523 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1524 client_integration_test.go:293: Decompressed .ls content (64 bytes):1525 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1526 client_integration_test.go:296: Testing garbage collection...15272026-07-19 09:59:26.971 UTC [93257] ERROR: relation "goose_db_version" does not exist at character 3615282026-07-19 09:59:26.971 UTC [93257] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15292026/07/19 09:59:26 OK 20241026095416_initial_model.sql (5.37ms)15302026/07/19 09:59:26 OK 20251210153512_drop_unused_gin_index.sql (845.96µs)15312026/07/19 09:59:26 OK 20251218171726_add_pins.sql (2.29ms)15322026/07/19 09:59:26 OK 20260628120000_add_object_size_and_stats.sql (2.71ms)15332026/07/19 09:59:26 goose: successfully migrated database to version: 2026062812000015342026/07/19 09:59:26 OK 1_commit_pending_closure.sql (2.1ms)15352026/07/19 09:59:26 OK 2_object_stats_trigger.sql (433.46µs)15362026/07/19 09:59:26 goose: up to current file version: 21537=== NAME TestNARDeduplicationMetadataUploadBug1538 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-92310-3857150617/TestNARDeduplicationMetadataUploadBug2255404408/001/store/rs5d2vmaq56h222sz4hsvj4pgibhiyls-file2.txt1539=== NAME TestOrphanedObjectsGCStressTest1540 orphaned_objects_gc_test.go:509: Stress test completed successfully:1541 orphaned_objects_gc_test.go:510: - Active objects preserved: 201542 orphaned_objects_gc_test.go:511: - Objects deleted: 2101543 orphaned_objects_gc_test.go:512: - Total GC'd: 2101544--- PASS: TestOrphanedObjectsGCStressTest (1.96s)1545=== CONT TestClientErrorHandling/ServerNotAvailable15462026/07/19 09:59:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures15472026/07/19 09:59:27 INFO Garbage collection started15482026/07/19 09:59:27 INFO Received uploads request method=POST path=/api/pending_closures15492026/07/19 09:59:27 INFO Aborted multipart uploads count=015502026/07/19 09:59:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15512026/07/19 09:59:27 INFO Uploading ffajggw7p271nwf6vl63wlyj3r51px4b-pinned-file.txt (128B)15522026/07/19 09:59:27 WARN Force mode enabled - objects will be deleted immediately without grace period15532026/07/19 09:59:27 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15542026/07/19 09:59:27 WARN Failed to register uploaded object key=ffajggw7p271nwf6vl63wlyj3r51px4b.ls error="server returned 404: 404 page not found\n"15552026/07/19 09:59:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15562026/07/19 09:59:27 INFO Signed narinfos id=1 count=115572026/07/19 09:59:27 INFO Uploading 1 narinfos15582026/07/19 09:59:27 WARN Failed to register uploaded object key=ffajggw7p271nwf6vl63wlyj3r51px4b.narinfo error="server returned 404: 404 page not found\n"15592026/07/19 09:59:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15602026/07/19 09:59:27 INFO Completed upload id=115612026/07/19 09:59:27 INFO Upload complete. (264ms)1562=== CONT TestClientErrorHandling/InvalidAuthToken15632026/07/19 09:59:27 INFO Received uploads request method=POST path=/api/pending_closures15642026/07/19 09:59:27 INFO Received uploads request method=POST path=/api/pending_closures15652026/07/19 09:59:27 INFO Received uploads request method=POST path=/api/pending_closures15662026/07/19 09:59:27 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15672026/07/19 09:59:27 INFO Uploading 68d0iszbrifxjfgg33jwh6k9jahr6w21-test-file-2.txt (160B)15682026/07/19 09:59:27 INFO Uploading s2nn3y65g96lf3vpv9mnl0fkiifxdpsy-test-file-0.txt (160B)15692026/07/19 09:59:27 INFO Uploading i54drwn2bmrifqaq5w8bvcjrjalgcihl-test-file-1.txt (160B)15702026/07/19 09:59:27 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15712026/07/19 09:59:27 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15722026/07/19 09:59:27 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15732026/07/19 09:59:27 WARN Failed to register uploaded object key=i54drwn2bmrifqaq5w8bvcjrjalgcihl.ls error="server returned 404: 404 page not found\n"15742026/07/19 09:59:27 WARN Failed to register uploaded object key=68d0iszbrifxjfgg33jwh6k9jahr6w21.ls error="server returned 404: 404 page not found\n"15752026/07/19 09:59:27 WARN Failed to register uploaded object key=s2nn3y65g96lf3vpv9mnl0fkiifxdpsy.ls error="server returned 404: 404 page not found\n"15762026/07/19 09:59:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15772026/07/19 09:59:27 INFO Signed narinfos id=1 count=115782026/07/19 09:59:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15792026/07/19 09:59:27 INFO Signed narinfos id=2 count=115802026/07/19 09:59:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15812026/07/19 09:59:27 INFO Signed narinfos id=3 count=115822026/07/19 09:59:27 INFO Uploading 3 narinfos15832026/07/19 09:59:27 WARN Failed to register uploaded object key=s2nn3y65g96lf3vpv9mnl0fkiifxdpsy.narinfo error="server returned 404: 404 page not found\n"15842026/07/19 09:59:27 WARN Failed to register uploaded object key=i54drwn2bmrifqaq5w8bvcjrjalgcihl.narinfo error="server returned 404: 404 page not found\n"15852026/07/19 09:59:27 WARN Failed to register uploaded object key=68d0iszbrifxjfgg33jwh6k9jahr6w21.narinfo error="server returned 404: 404 page not found\n"15862026/07/19 09:59:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15872026/07/19 09:59:27 INFO Completed upload id=115882026/07/19 09:59:27 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15892026/07/19 09:59:27 INFO Completed upload id=215902026/07/19 09:59:27 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete15912026/07/19 09:59:27 INFO Completed upload id=315922026/07/19 09:59:27 INFO Upload complete. (328ms)1593=== NAME TestClientMultipleUploads1594 client_integration_test.go:349: Uploaded 3 paths in 543.040459ms1595--- PASS: TestClientMultipleUploads (1.41s)1596=== CONT TestCacheConfigHandler/full_config,_no_issuer1597=== CONT TestCacheConfigHandler/no_signing_keys1598=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1599=== CONT TestCacheConfigHandler/no_cache_url_configured1600--- PASS: TestCacheConfigHandler (0.00s)1601 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1602 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1603 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1604 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1605=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token16062026/07/19 09:59:27 INFO OIDC auth successful provider=test1607=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected16082026/07/19 09:59:27 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1609=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1610=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16112026/07/19 09:59:27 WARN Authentication failed token_preview=eyJhbGciOi...vdfrtX-C_Q 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]1612--- PASS: TestService_AuthMiddleware_OIDC (0.23s)1613 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1614 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1615 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1616 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)16172026/07/19 09:59:27 INFO Received uploads request method=POST path=/api/pending_closures16182026/07/19 09:59:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16192026/07/19 09:59:27 INFO Uploading 5dyzymkkrsy37p8r3pk8rj0hzq00vp7q-unpinned-file.txt (128B)16202026/07/19 09:59:27 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16212026-07-19 09:59:27.362 UTC [93307] ERROR: relation "goose_db_version" does not exist at character 3616222026-07-19 09:59:27.362 UTC [93307] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16232026/07/19 09:59:27 WARN Failed to register uploaded object key=5dyzymkkrsy37p8r3pk8rj0hzq00vp7q.ls error="server returned 404: 404 page not found\n"16242026/07/19 09:59:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16252026/07/19 09:59:27 INFO Signed narinfos id=2 count=116262026/07/19 09:59:27 INFO Uploading 1 narinfos16272026/07/19 09:59:27 OK 20241026095416_initial_model.sql (6.38ms)16282026/07/19 09:59:27 OK 20251210153512_drop_unused_gin_index.sql (804.63µs)16292026/07/19 09:59:27 WARN Failed to register uploaded object key=5dyzymkkrsy37p8r3pk8rj0hzq00vp7q.narinfo error="server returned 404: 404 page not found\n"16302026/07/19 09:59:27 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16312026/07/19 09:59:27 OK 20251218171726_add_pins.sql (2.31ms)16322026/07/19 09:59:27 INFO Completed upload id=216332026/07/19 09:59:27 INFO Upload complete. (210ms)16342026/07/19 09:59:27 OK 20260628120000_add_object_size_and_stats.sql (3.33ms)16352026/07/19 09:59:27 goose: successfully migrated database to version: 2026062812000016362026/07/19 09:59:27 OK 1_commit_pending_closure.sql (2ms)16372026/07/19 09:59:27 OK 2_object_stats_trigger.sql (590.5µs)16382026/07/19 09:59:27 goose: up to current file version: 216392026/07/19 09:59:27 INFO Received uploads request method=POST path=/api/pending_closures16402026/07/19 09:59:27 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16412026/07/19 09:59:27 WARN Failed to register uploaded object key=rs5d2vmaq56h222sz4hsvj4pgibhiyls.ls error="server returned 404: 404 page not found\n"16422026/07/19 09:59:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16432026/07/19 09:59:27 INFO Signed narinfos id=2 count=116442026/07/19 09:59:27 INFO Uploading 1 narinfos16452026/07/19 09:59:27 WARN Failed to register uploaded object key=rs5d2vmaq56h222sz4hsvj4pgibhiyls.narinfo error="server returned 404: 404 page not found\n"16462026/07/19 09:59:27 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16472026/07/19 09:59:27 INFO Completed upload id=216482026/07/19 09:59:27 INFO Upload complete. (327ms)1649=== NAME TestNARDeduplicationMetadataUploadBug1650 metadata_upload_test.go:76: Retrieved narinfo from S3:1651 StorePath: /nix/var/nix/builds/nix-92310-3857150617/TestNARDeduplicationMetadataUploadBug2255404408/001/store/rs5d2vmaq56h222sz4hsvj4pgibhiyls-file2.txt1652 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1653 Compression: zstd1654 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1655 NarSize: 1601656 References: 1657 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf16582026/07/19 09:59:27 INFO Received create pin request method=POST path=/api/pins/myapp1659 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1660 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1661 {"version":1,"root":{"type":"regular","size":44}}1662--- PASS: TestNARDeduplicationMetadataUploadBug (2.18s)16632026/07/19 09:59:27 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-92310-3857150617/TestPinProtectsFromGC300840418/001/store/ffajggw7p271nwf6vl63wlyj3r51px4b-pinned-file.txt narinfo_key=ffajggw7p271nwf6vl63wlyj3r51px4b.narinfo16642026/07/19 09:59:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures16652026/07/19 09:59:27 INFO Garbage collection started16662026/07/19 09:59:27 INFO Aborted multipart uploads count=016672026/07/19 09:59:27 WARN Force mode enabled - objects will be deleted immediately without grace period16682026/07/19 09:59:27 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_closures1669=== NAME TestClientWithDependencies1670 client_integration_test.go:593: Built derivation: /nix/var/nix/builds/nix-92310-3857150617/TestClientWithDependencies2140681457/001/store/1azwggqpzqqcqk3xgaggr6bc3z1p0jsv-test-script16712026/07/19 09:59:27 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=186.214681ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16722026/07/19 09:59:27 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1673=== NAME TestClientCADerivations1674 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-92310-3857150617/TestClientCADerivations418614150/001/store/mqyy29zdn6vmhkd6jz4fl790gxwvjal0-ca-test1675 client_ca_test.go:139: Found 1 dependencies (including self)1676=== NAME TestClientWithDependencies1677 client_integration_test.go:595: Found 1 dependencies (including self)16782026/07/19 09:59:28 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=368.473809ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16792026/07/19 09:59:28 WARN Rate limiter enabled after throttle name=s3-test rate=516802026/07/19 09:59:28 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1681=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1682 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101683 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001684--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.88s)16852026/07/19 09:59:28 INFO Received uploads request method=POST path=/api/pending_closures16862026/07/19 09:59:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16872026/07/19 09:59:28 INFO Uploading 1azwggqpzqqcqk3xgaggr6bc3z1p0jsv-test-script (136B)16882026/07/19 09:59:28 INFO Received uploads request method=POST path=/api/pending_closures16892026/07/19 09:59:28 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16902026/07/19 09:59:28 WARN Failed to register uploaded object key=log/9cybwb3arf4kdhkn6a6687hbyins1m5b-test-script.drv error="server returned 404: 404 page not found\n"16912026/07/19 09:59:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16922026/07/19 09:59:28 INFO Uploading mqyy29zdn6vmhkd6jz4fl790gxwvjal0-ca-test (144B)16932026/07/19 09:59:28 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16942026/07/19 09:59:28 WARN Failed to register uploaded object key=1azwggqpzqqcqk3xgaggr6bc3z1p0jsv.ls error="server returned 404: 404 page not found\n"16952026/07/19 09:59:28 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16962026/07/19 09:59:28 INFO Signed narinfos id=1 count=116972026/07/19 09:59:28 INFO Uploading 1 narinfos16982026/07/19 09:59:28 WARN Failed to register uploaded object key=log/4d4m44hx1j6pcw9k01qxfdc4y5g8qzk2-ca-test.drv error="server returned 404: 404 page not found\n"16992026/07/19 09:59:28 WARN Failed to register uploaded object key=mqyy29zdn6vmhkd6jz4fl790gxwvjal0.ls error="server returned 404: 404 page not found\n"17002026/07/19 09:59:28 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17012026/07/19 09:59:28 WARN Failed to register uploaded object key=1azwggqpzqqcqk3xgaggr6bc3z1p0jsv.narinfo error="server returned 404: 404 page not found\n"17022026/07/19 09:59:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17032026/07/19 09:59:28 INFO Signed narinfos id=1 count=117042026/07/19 09:59:28 INFO Uploading 1 narinfos17052026/07/19 09:59:28 INFO Completed upload id=117062026/07/19 09:59:28 INFO Upload complete. (52ms)17072026/07/19 09:59:28 WARN Failed to register uploaded object key=mqyy29zdn6vmhkd6jz4fl790gxwvjal0.narinfo error="server returned 404: 404 page not found\n"17082026/07/19 09:59:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17092026/07/19 09:59:28 INFO Completed upload id=117102026/07/19 09:59:28 INFO Upload complete. (151ms)1711=== NAME TestClientCADerivations1712 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-92310-3857150617/TestClientCADerivations418614150/001/store/mqyy29zdn6vmhkd6jz4fl790gxwvjal0-ca-test1713 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1714 Compression: zstd1715 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1716 NarSize: 1441717 References: 1718 Deriver: /nix/var/nix/builds/nix-92310-3857150617/TestClientCADerivations418614150/001/store/4d4m44hx1j6pcw9k01qxfdc4y5g8qzk2-ca-test.drv1719 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1720 client_ca_test.go:185: Checking for realisation files in S3...1721=== NAME TestClientWithDependencies1722 client_integration_test.go:597: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-92310-3857150617/TestClientWithDependencies2140681457/001/store) requires matching store prefix1723=== NAME TestClientCADerivations1724 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1725 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1726--- PASS: TestClientWithDependencies (2.29s)1727=== NAME TestClientCADerivations1728 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket39?endpoint=http://localhost:59274®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-92310-3857150617/TestClientCADerivations418614150/001/store'1729 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11730--- PASS: TestClientCADerivations (2.24s)1731--- PASS: TestUploadHandlersRejectOversizedBody (0.05s)1732 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1733 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)1734 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.53s)17352026/07/19 09:59:28 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=818.17362ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17362026/07/19 09:59:28 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=017372026/07/19 09:59:28 INFO Vacuumed table table=pending_closures17382026/07/19 09:59:28 INFO Vacuumed table table=pending_objects17392026/07/19 09:59:28 INFO Vacuumed table table=multipart_uploads17402026/07/19 09:59:28 INFO Vacuumed table table=closures17412026/07/19 09:59:28 INFO Vacuumed table table=objects17422026/07/19 09:59:28 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=017432026/07/19 09:59:28 INFO Vacuumed table table=pending_closures17442026/07/19 09:59:28 INFO Vacuumed table table=pending_objects17452026/07/19 09:59:28 INFO Vacuumed table table=multipart_uploads17462026/07/19 09:59:28 INFO Vacuumed table table=closures17472026/07/19 09:59:28 INFO Vacuumed table table=objects17482026/07/19 09:59:29 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01749=== NAME TestClientIntegration1750 client_integration_test.go:303: Objects in database after GC:1751 client_integration_test.go:303: Successfully deleted all objects with GC --force1752--- PASS: TestClientIntegration (3.19s)17532026/07/19 09:59:29 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.489369902s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17542026/07/19 09:59:29 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01755=== NAME TestPinProtectsFromGC1756 client_integration_test.go:709: Pin successfully protected closure from garbage collection1757--- PASS: TestPinProtectsFromGC (3.66s)1758--- PASS: TestClientErrorHandling (0.00s)1759 --- PASS: TestClientErrorHandling/InvalidStorePath (0.29s)1760 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.69s)1761 --- PASS: TestClientErrorHandling/ServerNotAvailable (3.66s)1762PASS17632026-07-19 09:59:31.257 UTC [92556] LOG: received smart shutdown request17642026-07-19 09:59:31.258 UTC [92556] LOG: background worker "logical replication launcher" (PID 92566) exited with exit code 117652026-07-19 09:59:31.287 UTC [92561] LOG: shutting down17662026-07-19 09:59:31.287 UTC [92561] LOG: checkpoint starting: shutdown immediate17672026-07-19 09:59:32.548 UTC [92561] LOG: checkpoint complete: wrote 13253 buffers (80.9%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 13 recycled; write=0.959 s, sync=0.301 s, total=1.262 s; sync files=15167, longest=0.001 s, average=0.001 s; distance=212069 kB, estimate=212069 kB; lsn=0/E69EC18, redo lsn=0/E69EC1817682026-07-19 09:59:32.553 UTC [92556] LOG: database system is shut down1769Running OIDC tests...1770=== RUN TestGlobMatch1771=== PAUSE TestGlobMatch1772=== RUN TestAudienceForIssuer1773=== PAUSE TestAudienceForIssuer1774=== RUN TestValidateToken_ValidToken1775=== PAUSE TestValidateToken_ValidToken1776=== RUN TestValidateToken_WrongAudience1777=== PAUSE TestValidateToken_WrongAudience1778=== RUN TestValidateToken_Expired1779=== PAUSE TestValidateToken_Expired1780=== RUN TestValidateToken_BoundClaimsMismatch1781=== PAUSE TestValidateToken_BoundClaimsMismatch1782=== RUN TestValidateToken_BoundSubjectMismatch1783=== PAUSE TestValidateToken_BoundSubjectMismatch1784=== RUN TestValidateToken_MultipleProviders1785=== PAUSE TestValidateToken_MultipleProviders1786=== RUN TestValidateToken_NoMatchingProvider1787=== PAUSE TestValidateToken_NoMatchingProvider1788=== CONT TestGlobMatch1789=== RUN TestGlobMatch/foo_foo1790=== CONT TestValidateToken_WrongAudience1791=== CONT TestValidateToken_ValidToken1792=== PAUSE TestGlobMatch/foo_foo1793=== RUN TestGlobMatch/foo_bar1794=== PAUSE TestGlobMatch/foo_bar1795=== RUN TestGlobMatch/*_1796=== PAUSE TestGlobMatch/*_1797=== RUN TestGlobMatch/*_anything1798=== PAUSE TestGlobMatch/*_anything1799=== RUN TestGlobMatch/foo*_foo1800=== PAUSE TestGlobMatch/foo*_foo1801=== RUN TestGlobMatch/foo*_foobar1802=== PAUSE TestGlobMatch/foo*_foobar1803=== RUN TestGlobMatch/foo*_bar1804=== PAUSE TestGlobMatch/foo*_bar1805=== RUN TestGlobMatch/*bar_bar1806=== PAUSE TestGlobMatch/*bar_bar1807=== RUN TestGlobMatch/*bar_foobar1808=== PAUSE TestGlobMatch/*bar_foobar1809=== RUN TestGlobMatch/*bar_foo1810=== PAUSE TestGlobMatch/*bar_foo1811=== RUN TestGlobMatch/foo*bar_foobar1812=== PAUSE TestGlobMatch/foo*bar_foobar1813=== RUN TestGlobMatch/foo*bar_foo123bar1814=== PAUSE TestGlobMatch/foo*bar_foo123bar1815=== RUN TestGlobMatch/foo*bar_foobarbaz1816=== PAUSE TestGlobMatch/foo*bar_foobarbaz1817=== RUN TestGlobMatch/*/*_foo/bar1818=== PAUSE TestGlobMatch/*/*_foo/bar1819=== RUN TestGlobMatch/*/*_foo1820=== PAUSE TestGlobMatch/*/*_foo1821=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1822=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1823=== CONT TestAudienceForIssuer1824=== CONT TestValidateToken_Expired1825=== CONT TestValidateToken_MultipleProviders1826=== CONT TestValidateToken_NoMatchingProvider1827=== CONT TestValidateToken_BoundClaimsMismatch1828=== CONT TestValidateToken_BoundSubjectMismatch1829=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01830=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01831=== RUN TestGlobMatch/refs/*/main_refs/heads/main1832=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1833=== RUN TestGlobMatch/fo?_foo1834=== PAUSE TestGlobMatch/fo?_foo1835=== RUN TestGlobMatch/fo?_fo1836=== PAUSE TestGlobMatch/fo?_fo1837=== RUN TestGlobMatch/fo?_fooo1838=== PAUSE TestGlobMatch/fo?_fooo1839=== RUN TestGlobMatch/?oo_foo1840=== PAUSE TestGlobMatch/?oo_foo1841=== RUN TestGlobMatch/?oo_boo1842=== PAUSE TestGlobMatch/?oo_boo1843=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1844=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1845=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1846=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1847=== CONT TestGlobMatch/foo_foo1848=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1849=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1850=== CONT TestGlobMatch/?oo_boo1851=== CONT TestGlobMatch/?oo_foo1852=== CONT TestGlobMatch/fo?_fooo1853=== CONT TestGlobMatch/fo?_fo1854=== CONT TestGlobMatch/fo?_foo1855=== CONT TestGlobMatch/refs/*/main_refs/heads/main1856=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01857=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1858=== CONT TestGlobMatch/*/*_foo1859=== CONT TestGlobMatch/*/*_foo/bar1860=== CONT TestGlobMatch/foo*bar_foobarbaz1861=== CONT TestGlobMatch/foo*bar_foo123bar1862=== CONT TestGlobMatch/foo*bar_foobar1863=== CONT TestGlobMatch/*bar_foo1864=== CONT TestGlobMatch/*bar_foobar1865=== CONT TestGlobMatch/*bar_bar1866=== CONT TestGlobMatch/*_anything1867=== CONT TestGlobMatch/*_1868=== CONT TestGlobMatch/foo_bar1869=== CONT TestGlobMatch/foo*_bar1870=== CONT TestGlobMatch/foo*_foo1871--- PASS: TestAudienceForIssuer (0.00s)1872=== CONT TestGlobMatch/foo*_foobar1873--- PASS: TestGlobMatch (0.00s)1874 --- PASS: TestGlobMatch/foo_foo (0.00s)1875 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1876 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1877 --- PASS: TestGlobMatch/?oo_boo (0.00s)1878 --- PASS: TestGlobMatch/?oo_foo (0.00s)1879 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1880 --- PASS: TestGlobMatch/fo?_fo (0.00s)1881 --- PASS: TestGlobMatch/fo?_foo (0.00s)1882 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1883 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1884 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1885 --- PASS: TestGlobMatch/*/*_foo (0.00s)1886 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1887 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1888 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1889 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1890 --- PASS: TestGlobMatch/*bar_foo (0.00s)1891 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1892 --- PASS: TestGlobMatch/*bar_bar (0.00s)1893 --- PASS: TestGlobMatch/*_anything (0.00s)1894 --- PASS: TestGlobMatch/*_ (0.00s)1895 --- PASS: TestGlobMatch/foo_bar (0.00s)1896 --- PASS: TestGlobMatch/foo*_bar (0.00s)1897 --- PASS: TestGlobMatch/foo*_foo (0.00s)1898 --- PASS: TestGlobMatch/foo*_foobar (0.00s)18992026/07/19 09:59:33 INFO OIDC provider initialized name=test19002026/07/19 09:59:33 INFO OIDC provider initialized name=test19012026/07/19 09:59:33 INFO OIDC provider initialized name=test19022026/07/19 09:59:33 INFO OIDC provider initialized name=test19032026/07/19 09:59:33 INFO OIDC provider initialized name=test19042026/07/19 09:59:33 INFO OIDC provider initialized name=provider119052026/07/19 09:59:33 INFO OIDC provider initialized name=provider119062026/07/19 09:59:33 INFO OIDC provider initialized name=provider21907--- PASS: TestValidateToken_ValidToken (0.00s)1908--- PASS: TestValidateToken_BoundClaimsMismatch (0.00s)1909--- PASS: TestValidateToken_NoMatchingProvider (0.00s)1910--- PASS: TestValidateToken_BoundSubjectMismatch (0.00s)1911--- PASS: TestValidateToken_Expired (0.00s)1912--- PASS: TestValidateToken_WrongAudience (0.01s)1913--- PASS: TestValidateToken_MultipleProviders (0.01s)1914PASS1915Running hook tests...1916=== RUN TestSendPathsEmpty1917=== PAUSE TestSendPathsEmpty1918=== RUN TestQueueEnqueueAndFetch1919=== PAUSE TestQueueEnqueueAndFetch1920=== RUN TestQueueDeduplication1921=== PAUSE TestQueueDeduplication1922=== RUN TestQueueRemove1923=== PAUSE TestQueueRemove1924=== RUN TestQueueFetchBatchLimit1925=== PAUSE TestQueueFetchBatchLimit1926=== RUN TestQueueFetchRemoveLifecycle1927=== PAUSE TestQueueFetchRemoveLifecycle1928=== RUN TestQueueConcurrentWriters1929=== PAUSE TestQueueConcurrentWriters1930=== RUN TestServerClientIntegration1931=== PAUSE TestServerClientIntegration1932=== RUN TestServerQueueError1933=== PAUSE TestServerQueueError1934=== RUN TestGetListenerSocketActivation1935 server_test.go:210: === RUN TestGetListenerSocketActivation1936 --- PASS: TestGetListenerSocketActivation (0.00s)1937 PASS1938 1939--- PASS: TestGetListenerSocketActivation (0.01s)1940=== RUN TestWorkerUploadsAndRemoves1941=== PAUSE TestWorkerUploadsAndRemoves1942=== RUN TestWorkerSkipsGCdPaths1943=== PAUSE TestWorkerSkipsGCdPaths1944=== RUN TestWorkerPrunesClosureDeps1945=== PAUSE TestWorkerPrunesClosureDeps1946=== CONT TestSendPathsEmpty1947=== CONT TestQueueConcurrentWriters1948=== CONT TestQueueRemove1949=== CONT TestServerQueueError1950=== CONT TestWorkerUploadsAndRemoves1951=== CONT TestQueueDeduplication1952=== CONT TestQueueFetchRemoveLifecycle1953=== CONT TestQueueFetchBatchLimit1954=== CONT TestQueueEnqueueAndFetch1955=== CONT TestServerClientIntegration1956=== CONT TestWorkerSkipsGCdPaths19572026/07/19 09:59:33 ERROR Failed to queue paths error="permission denied" count=11958--- PASS: TestSendPathsEmpty (0.00s)1959--- PASS: TestServerQueueError (0.00s)1960=== CONT TestWorkerPrunesClosureDeps1961--- PASS: TestServerClientIntegration (0.00s)19622026/07/19 09:59:33 INFO Upload queue status pending=219632026/07/19 09:59:33 INFO Uploading batch count=219642026/07/19 09:59:33 INFO Upload queue status pending=219652026/07/19 09:59:33 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-92310-3857150617/TestWorkerSkipsGCdPaths828603553/002/nonexistent1966--- PASS: TestQueueFetchBatchLimit (0.00s)1967--- PASS: TestQueueRemove (0.01s)19682026/07/19 09:59:33 INFO Uploading batch count=11969--- PASS: TestQueueDeduplication (0.01s)19702026/07/19 09:59:33 INFO Upload queue status pending=219712026/07/19 09:59:33 INFO Uploading batch count=11972--- PASS: TestQueueEnqueueAndFetch (0.01s)1973--- PASS: TestQueueFetchRemoveLifecycle (0.01s)1974--- PASS: TestWorkerUploadsAndRemoves (0.06s)1975--- PASS: TestWorkerSkipsGCdPaths (0.06s)1976--- PASS: TestWorkerPrunesClosureDeps (0.06s)1977--- PASS: TestQueueConcurrentWriters (0.12s)1978PASS