niks3-go-unit-tests
aarch64-linux.go-unit-tests
· build #105
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestCaseHackSuffix6=== PAUSE TestCaseHackSuffix7=== RUN TestPartSizeForNAR8=== PAUSE TestPartSizeForNAR9=== RUN TestUploadMultipart_SupersededByPeer10=== PAUSE TestUploadMultipart_SupersededByPeer11=== RUN TestDumpPathMatchesNix12=== PAUSE TestDumpPathMatchesNix13=== RUN TestDumpPathSingleFile14=== PAUSE TestDumpPathSingleFile15=== RUN TestDumpPathWriterError16=== PAUSE TestDumpPathWriterError17=== RUN TestEncodeNixBase3218=== PAUSE TestEncodeNixBase3219=== RUN TestEncodeNixBase32WithRealHash20=== PAUSE TestEncodeNixBase32WithRealHash21=== RUN TestConvertHashToNix3222=== PAUSE TestConvertHashToNix3223=== RUN TestGetStorePathHash24=== PAUSE TestGetStorePathHash25=== RUN TestPathInfoHashCompatibility26=== PAUSE TestPathInfoHashCompatibility27=== RUN TestParsePathInfoJSON28=== PAUSE TestParsePathInfoJSON29=== RUN TestParsePathInfoJSONMultiplePaths30=== PAUSE TestParsePathInfoJSONMultiplePaths31=== RUN TestPathInfoCACompatibility32=== PAUSE TestPathInfoCACompatibility33=== RUN TestRateLimiterFeedback34=== PAUSE TestRateLimiterFeedback35=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess36=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess37=== RUN TestResolveStorePath38=== PAUSE TestResolveStorePath39=== RUN TestDoWithRetry_BodyReplayedViaGetBody40=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody41=== RUN TestShellSplit42=== PAUSE TestShellSplit43=== RUN TestShellSplitErrors44=== PAUSE TestShellSplitErrors45=== RUN TestSetClientTLS46=== PAUSE TestSetClientTLS47=== RUN TestSetClientTLSDoesNotMutateDefaultTransport48=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport49=== RUN TestSetClientTLSErrors50=== PAUSE TestSetClientTLSErrors51=== RUN TestStaticToken52=== PAUSE TestStaticToken53=== RUN TestFileTokenReadsAndCaches54=== PAUSE TestFileTokenReadsAndCaches55=== RUN TestFileTokenMissing56=== PAUSE TestFileTokenMissing57=== RUN TestFileTokenEmpty58=== PAUSE TestFileTokenEmpty59=== RUN TestScriptTokenNoExpiryRerunsEveryCall60=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall61=== RUN TestScriptTokenCachesUntilRefresh62=== PAUSE TestScriptTokenCachesUntilRefresh63=== RUN TestScriptTokenEmptyToken64=== PAUSE TestScriptTokenEmptyToken65=== RUN TestScriptTokenBadJSON66=== PAUSE TestScriptTokenBadJSON67=== RUN TestScriptTokenScriptFails68=== PAUSE TestScriptTokenScriptFails69=== RUN TestScriptTokenEmptyCommand70=== PAUSE TestScriptTokenEmptyCommand71=== CONT TestDoServerRequestAttachesToken72=== CONT TestScriptTokenNoExpiryRerunsEveryCall73=== CONT TestSetClientTLSDoesNotMutateDefaultTransport74=== CONT TestScriptTokenEmptyCommand75=== CONT TestSetClientTLS76=== CONT TestFileTokenEmpty77=== CONT TestFileTokenReadsAndCaches78=== CONT TestDumpPathSingleFile79=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess80--- PASS: TestScriptTokenEmptyCommand (0.00s)81=== CONT TestPathInfoHashCompatibility82=== CONT TestShellSplit83=== CONT TestStaticToken84--- PASS: TestStaticToken (0.00s)85=== CONT TestParsePathInfoJSON86=== RUN TestParsePathInfoJSON/Nix_format87=== PAUSE TestParsePathInfoJSON/Nix_format88=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)892026/07/19 09:59:21 WARN Rate limiter enabled after throttle name=server-test rate=590=== CONT TestDumpPathMatchesNix91=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)92=== CONT TestScriptTokenBadJSON93=== CONT TestScriptTokenEmptyToken94=== CONT TestScriptTokenCachesUntilRefresh95=== CONT TestSetClientTLSErrors96=== CONT TestFileTokenMissing97=== CONT TestUploadMultipart_SupersededByPeer98=== CONT TestShellSplitErrors99=== CONT TestResolveStorePath100=== CONT TestCaseHackSuffix101=== CONT TestScriptTokenScriptFails102=== CONT TestRateLimiterFeedback103=== RUN TestRateLimiterFeedback/429_enables_limiter104=== CONT TestPathInfoCACompatibility105=== CONT TestDumpPathWriterError106=== CONT TestParsePathInfoJSONMultiplePaths107=== CONT TestDoWithRetry_BodyReplayedViaGetBody108=== RUN TestParsePathInfoJSON/Lix_format109=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon110=== PAUSE TestParsePathInfoJSON/Lix_format111=== CONT TestEncodeNixBase32WithRealHash112=== CONT TestGetStorePathHash113=== CONT TestConvertHashToNix32114=== RUN TestUploadMultipart_SupersededByPeer/exists115=== CONT TestPartSizeForNAR116=== CONT TestEncodeNixBase32117=== RUN TestSetClientTLSErrors/missing_cert_file118=== PAUSE TestRateLimiterFeedback/429_enables_limiter119--- PASS: TestShellSplit (0.00s)120=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths121=== RUN TestSetClientTLS/rejects_connection_without_client_cert122=== RUN TestRateLimiterFeedback/503_enables_limiter123=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon124=== RUN TestParsePathInfoJSON/empty_input125=== RUN TestGetStorePathHash/valid_store_path126=== PAUSE TestUploadMultipart_SupersededByPeer/exists127=== PAUSE TestSetClientTLSErrors/missing_cert_file128=== RUN TestSetClientTLSErrors/missing_key_file129=== PAUSE TestSetClientTLSErrors/missing_key_file130=== RUN TestSetClientTLSErrors/missing_ca_file131=== RUN TestConvertHashToNix32/SRI_format_to_Nix32132=== RUN TestPartSizeForNAR/zero_stays_at_minimum133--- PASS: TestFileTokenEmpty (0.00s)1342026/07/19 09:59:21 WARN Rate limiter enabled after throttle name=server-test rate=5135--- PASS: TestFileTokenReadsAndCaches (0.00s)1362026/07/19 09:59:21 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:44101137--- PASS: TestScriptTokenEmptyToken (0.00s)138--- PASS: TestScriptTokenBadJSON (0.00s)139=== RUN TestPathInfoCACompatibility/null_ca_field140=== PAUSE TestPathInfoCACompatibility/null_ca_field141=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths142=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert143=== RUN TestEncodeNixBase32/test_string_hash1442026/07/19 09:59:21 WARN Rate limiter backed off name=server-test rate=5145=== PAUSE TestRateLimiterFeedback/503_enables_limiter1462026/07/19 09:59:21 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:44101147=== PAUSE TestEncodeNixBase32/test_string_hash148=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter149=== PAUSE TestParsePathInfoJSON/empty_input150=== RUN TestEncodeNixBase32/empty_input151=== PAUSE TestGetStorePathHash/valid_store_path152=== RUN TestUploadMultipart_SupersededByPeer/missing153=== PAUSE TestSetClientTLSErrors/missing_ca_file154=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32155=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum156--- PASS: TestDoServerRequestAttachesToken (0.00s)157--- PASS: TestShellSplitErrors (0.00s)158=== RUN TestPathInfoCACompatibility/old_string_format_-_text159--- PASS: TestFileTokenMissing (0.00s)160--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)161--- PASS: TestScriptTokenScriptFails (0.00s)162--- PASS: TestResolveStorePath (0.01s)163--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)164--- PASS: TestEncodeNixBase32WithRealHash (0.00s)165--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)166=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths167=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA168=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI169=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI170=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter171=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA172=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter173=== RUN TestParsePathInfoJSON/whitespace_only174=== RUN TestSetClientTLS/preserves_debug_logging_transport175=== PAUSE TestEncodeNixBase32/empty_input176=== CONT TestEncodeNixBase32/test_string_hash177=== RUN TestGetStorePathHash/basename_without_hyphen_should_error178=== PAUSE TestUploadMultipart_SupersededByPeer/missing179=== RUN TestSetClientTLSErrors/invalid_ca_file180=== RUN TestConvertHashToNix32/already_Nix32_format181=== RUN TestPartSizeForNAR/small_stays_at_minimum182=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text183=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths184=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512185--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)186=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter187=== PAUSE TestParsePathInfoJSON/whitespace_only188=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter189=== PAUSE TestSetClientTLS/preserves_debug_logging_transport190=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512191=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)192=== PAUSE TestPartSizeForNAR/small_stays_at_minimum193=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error194=== CONT TestUploadMultipart_SupersededByPeer/exists195=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error196=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error197=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error198=== CONT TestUploadMultipart_SupersededByPeer/missing199=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths200=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths201=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive202=== PAUSE TestSetClientTLSErrors/invalid_ca_file203=== CONT TestSetClientTLSErrors/missing_cert_file204=== PAUSE TestConvertHashToNix32/already_Nix32_format205=== RUN TestParsePathInfoJSON/invalid_JSON206=== CONT TestRateLimiterFeedback/503_enables_limiter207=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter208=== CONT TestRateLimiterFeedback/429_enables_limiter209=== CONT TestSetClientTLS/rejects_connection_without_client_cert210=== CONT TestEncodeNixBase32/empty_input211=== CONT TestSetClientTLS/preserves_debug_logging_transport212=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA213=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum214=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512215=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error216=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI217=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon218=== CONT TestGetStorePathHash/valid_store_path219=== CONT TestSetClientTLSErrors/missing_key_file220=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum221=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive222=== RUN TestConvertHashToNix32/invalid_format223=== RUN TestPathInfoCACompatibility/new_structured_format_-_text224=== PAUSE TestConvertHashToNix32/invalid_format225=== CONT TestConvertHashToNix32/SRI_format_to_Nix32226=== PAUSE TestParsePathInfoJSON/invalid_JSON227=== CONT TestParsePathInfoJSON/Nix_format228=== CONT TestParsePathInfoJSON/invalid_JSON229=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text230=== CONT TestSetClientTLSErrors/invalid_ca_file2312026/07/19 09:59:21 WARN Rate limiter enabled after throttle name=server-test rate=52322026/07/19 09:59:21 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:43155233=== CONT TestSetClientTLSErrors/missing_ca_file2342026/07/19 09:59:21 WARN Rate limiter backed off name=server-test rate=5235=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error236=== CONT TestConvertHashToNix32/already_Nix32_format237--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)238 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)239 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)240=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error241--- PASS: TestPathInfoHashCompatibility (0.03s)242 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)243 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)244 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)245 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)246=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts247=== CONT TestGetStorePathHash/basename_without_hyphen_should_error248=== CONT TestParsePathInfoJSON/empty_input249=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts2502026/07/19 09:59:21 WARN Rate limiter enabled after throttle name=server-test rate=5251=== CONT TestParsePathInfoJSON/whitespace_only2522026/07/19 09:59:21 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:33783253=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method254=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method255=== CONT TestParsePathInfoJSON/Lix_format256=== CONT TestConvertHashToNix32/invalid_format257--- PASS: TestEncodeNixBase32 (0.00s)258 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)259 --- PASS: TestEncodeNixBase32/empty_input (0.00s)260=== RUN TestPartSizeForNAR/1_TiB261=== PAUSE TestPartSizeForNAR/1_TiB262=== CONT TestPathInfoCACompatibility/null_ca_field2632026/07/19 09:59:21 WARN Rate limiter backed off name=server-test rate=5264--- PASS: TestConvertHashToNix32 (0.02s)265 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)266 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)267 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)268--- PASS: TestGetStorePathHash (0.02s)269 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)270 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)271 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)272 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)273--- PASS: TestParsePathInfoJSON (0.03s)274 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)275 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)276 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)277 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)278 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)279=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method280=== CONT TestPathInfoCACompatibility/new_structured_format_-_text281=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive282=== CONT TestPathInfoCACompatibility/old_string_format_-_text283=== RUN TestPartSizeForNAR/5_TiB_S3_max_object284=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object285--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)286 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)287 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)288=== RUN TestPartSizeForNAR/capped_at_5_GiB289=== PAUSE TestPartSizeForNAR/capped_at_5_GiB290--- PASS: TestRateLimiterFeedback (0.02s)291 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)292 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)293 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)294 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)295=== CONT TestPartSizeForNAR/zero_stays_at_minimum296=== CONT TestPartSizeForNAR/capped_at_5_GiB297=== CONT TestPartSizeForNAR/5_TiB_S3_max_object298=== CONT TestPartSizeForNAR/1_TiB299=== CONT TestPartSizeForNAR/small_stays_at_minimum300=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts301=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum302--- PASS: TestPathInfoCACompatibility (0.03s)303 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)304 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)305 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)306 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)307 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)308--- PASS: TestSetClientTLSErrors (0.03s)309 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)310 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)311 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)312 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)313--- PASS: TestPartSizeForNAR (0.02s)314 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)315 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)316 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)317 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)318 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)319 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)320 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)321--- PASS: TestDumpPathSingleFile (0.04s)3222026/07/19 09:59:21 http: TLS handshake error from 127.0.0.1:37944: remote error: tls: bad certificate323--- PASS: TestSetClientTLS (0.03s)324 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)325 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)326 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)327--- PASS: TestCaseHackSuffix (0.04s)328--- PASS: TestDumpPathWriterError (0.05s)329--- PASS: TestDumpPathMatchesNix (0.09s)330--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)331PASS332Running server tests...333The files belonging to this database system will be owned by user "nixbld".334This user must also own the server process.335336The database cluster will be initialized with locale "C".337The default database encoding has accordingly been set to "SQL_ASCII".338The default text search configuration will be set to "english".339340Data page checksums are enabled.341342creating directory /build/postgres4266745442/data ... ok343creating subdirectories ... ok344selecting dynamic shared memory implementation ... posix345selecting default "max_connections" ... 100346selecting default "shared_buffers" ... 128MB347selecting default time zone ... UTC348creating configuration files ... ok349running bootstrap script ... ok350performing post-bootstrap initialization ... ok351syncing data to disk ... ok352353initdb: warning: enabling "trust" authentication for local connections354initdb: 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.355356Success. You can now start the database server using:357358 pg_ctl -D /build/postgres4266745442/data -l logfile start359360/build/postgres4266745442:5432 - no response3612026-07-19 09:59:23.745 UTC [110] LOG: starting PostgreSQL 18.4 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit3622026-07-19 09:59:23.746 UTC [110] LOG: listening on Unix socket "/build/postgres4266745442/.s.PGSQL.5432"3632026-07-19 09:59:23.750 UTC [117] LOG: database system was shut down at 2026-07-19 09:59:23 UTC3642026-07-19 09:59:23.753 UTC [110] LOG: database system is ready to accept connections365/build/postgres4266745442:5432 - accepting connections366{"timestamp":"2026-07-19T09:59:23.979088098Z","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(384)"}367368thread 'rustfs-worker' (320) panicked at /build/rustfs-1.0.0-beta.7-vendor/source-registry-0/reqwest-0.13.4/src/async_impl/client.rs:2507:38:369Client::new(): reqwest::Error { kind: Builder, source: General("No CA certificates were loaded from the system") }370note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace371=== RUN TestService_AuthMiddleware372=== PAUSE TestService_AuthMiddleware373=== RUN TestService_AuthMiddleware_MTLSProxyHeader374=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader375=== RUN TestService_AuthMiddleware_MTLSBoundSubjects376=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects377=== RUN TestService_ReadAuthMiddleware378=== PAUSE TestService_ReadAuthMiddleware379=== RUN TestService_AuthMiddleware_OIDC380=== PAUSE TestService_AuthMiddleware_OIDC381=== RUN TestCacheConfigHandler382=== PAUSE TestCacheConfigHandler383=== RUN TestCacheStatsHandler384=== PAUSE TestCacheStatsHandler385=== RUN TestClientCADerivations386=== PAUSE TestClientCADerivations387=== RUN TestClientErrorHandling388=== PAUSE TestClientErrorHandling389=== RUN TestClientIntegration390=== PAUSE TestClientIntegration391=== RUN TestClientMultipleUploads392=== PAUSE TestClientMultipleUploads393=== RUN TestClientWithDependencies394=== PAUSE TestClientWithDependencies395=== RUN TestPinProtectsFromGC396=== PAUSE TestPinProtectsFromGC397=== RUN TestGCAdvisoryLockBlocksConcurrentRun3982026-07-19 09:59:24.157 UTC [527] ERROR: relation "goose_db_version" does not exist at character 363992026-07-19 09:59:24.157 UTC [527] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4002026/07/19 09:59:24 OK 20241026095416_initial_model.sql (9.75ms)4012026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (1.42ms)4022026/07/19 09:59:24 OK 20251218171726_add_pins.sql (3.4ms)4032026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (2.74ms)4042026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200004052026/07/19 09:59:24 OK 1_commit_pending_closure.sql (1.63ms)4062026/07/19 09:59:24 OK 2_object_stats_trigger.sql (680.69µs)4072026/07/19 09:59:24 goose: up to current file version: 2408--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.16s)409=== RUN TestGCBugBareHashReferences410=== PAUSE TestGCBugBareHashReferences411=== RUN TestGCMetrics412=== PAUSE TestGCMetrics413=== RUN TestGCTaskStore_StartNew414=== PAUSE TestGCTaskStore_StartNew415=== RUN TestGCTaskStore_DeduplicateSameParams416=== PAUSE TestGCTaskStore_DeduplicateSameParams417=== RUN TestGCTaskStore_ConflictDifferentParams418=== PAUSE TestGCTaskStore_ConflictDifferentParams419=== RUN TestGCTaskStore_GetEmpty420=== PAUSE TestGCTaskStore_GetEmpty421=== RUN TestGCTaskStore_GetReturnsLatest422=== PAUSE TestGCTaskStore_GetReturnsLatest423=== RUN TestGCTaskStore_CompletedAllowsNewTask424=== PAUSE TestGCTaskStore_CompletedAllowsNewTask425=== RUN TestGCTaskStore_PhaseUpdates426=== PAUSE TestGCTaskStore_PhaseUpdates427=== RUN TestGCTaskStore_Fail428=== PAUSE TestGCTaskStore_Fail429=== RUN TestGracefulShutdownDrainsInflight430=== PAUSE TestGracefulShutdownDrainsInflight431=== RUN TestService_healthCheckHandler432=== PAUSE TestService_healthCheckHandler433=== RUN TestGenerateLandingPage434=== PAUSE TestGenerateLandingPage435=== RUN TestNARDeduplicationMetadataUploadBug436=== PAUSE TestNARDeduplicationMetadataUploadBug437=== RUN TestMetricsInventory438=== PAUSE TestMetricsInventory439=== RUN TestService_NativeMTLS440=== PAUSE TestService_NativeMTLS441=== RUN TestServerTLSConfig442=== PAUSE TestServerTLSConfig443=== RUN TestMultipartCleanup444=== PAUSE TestMultipartCleanup445=== RUN TestObjectStatsTrigger446=== PAUSE TestObjectStatsTrigger447=== RUN TestOrphanedObjectsGC448=== PAUSE TestOrphanedObjectsGC449=== RUN TestOrphanedObjectsGCStressTest450=== PAUSE TestOrphanedObjectsGCStressTest451=== RUN TestResurrectedObjectNotDeleted452=== PAUSE TestResurrectedObjectNotDeleted453=== RUN TestParseSingleRange454=== PAUSE TestParseSingleRange455=== RUN TestIsValidCachePath456=== PAUSE TestIsValidCachePath457=== RUN TestReadProxyNarinfo458=== PAUSE TestReadProxyNarinfo459=== RUN TestReadProxyNarinfoAlreadyDecompressed460=== PAUSE TestReadProxyNarinfoAlreadyDecompressed461=== RUN TestReadProxyNarStreaming462=== PAUSE TestReadProxyNarStreaming463=== RUN TestReadProxy404464=== PAUSE TestReadProxy404465=== RUN TestReadProxyInvalidPath466=== PAUSE TestReadProxyInvalidPath467=== RUN TestReadProxyHead468=== PAUSE TestReadProxyHead469=== RUN TestReadProxyConditionalGet470=== PAUSE TestReadProxyConditionalGet471=== RUN TestReadProxyRootRedirectsToIndexHTML472=== PAUSE TestReadProxyRootRedirectsToIndexHTML473=== RUN TestReadProxyDisabled474=== PAUSE TestReadProxyDisabled475=== RUN TestReadProxyRangeRequest476=== PAUSE TestReadProxyRangeRequest477=== RUN TestRedundantMultipartUpload478=== PAUSE TestRedundantMultipartUpload479=== RUN TestCompleteMultipartUpload_ErrorButObjectExists480=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists481=== RUN TestCompletedNarNotReofferedAcrossClosures482=== PAUSE TestCompletedNarNotReofferedAcrossClosures483=== RUN TestPresignedUploadRegisteredBeforeCommit484=== PAUSE TestPresignedUploadRegisteredBeforeCommit485=== RUN TestService_Rustfstest486=== PAUSE TestService_Rustfstest487=== RUN TestSystemdListenerNotActivated488--- PASS: TestSystemdListenerNotActivated (0.00s)489=== RUN TestWatchdogBeatsWhenHealthy490--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)491=== RUN TestWatchdogSkipsWhenUnhealthy4922026/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"4972026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4982026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"4992026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5002026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5012026/07/19 09:59:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"502--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)503=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle504=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle505=== RUN TestProxyWriteTimeout506=== PAUSE TestProxyWriteTimeout507=== RUN TestIsValidUploadKey508=== PAUSE TestIsValidUploadKey509=== RUN TestUploadHandlersRejectInvalidKeys510=== PAUSE TestUploadHandlersRejectInvalidKeys511=== RUN TestUploadHandlersRejectOversizedBody512=== PAUSE TestUploadHandlersRejectOversizedBody513=== RUN TestService_cleanupPendingClosuresHandler514=== PAUSE TestService_cleanupPendingClosuresHandler515=== RUN TestService_createPendingClosureHandler516=== PAUSE TestService_createPendingClosureHandler517=== RUN TestService_verifyS3Integrity518=== PAUSE TestService_verifyS3Integrity519=== RUN TestCompleteMultipartUnregistered520=== PAUSE TestCompleteMultipartUnregistered521=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT522=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT523=== CONT TestService_AuthMiddleware524=== CONT TestObjectStatsTrigger525=== CONT TestGCTaskStore_DeduplicateSameParams526=== CONT TestClientErrorHandling527=== CONT TestPinProtectsFromGC528=== RUN TestClientErrorHandling/InvalidStorePath529=== PAUSE TestClientErrorHandling/InvalidStorePath530=== CONT TestMultipartCleanup531=== CONT TestServerTLSConfig532=== RUN TestServerTLSConfig/no_client_CA533=== PAUSE TestServerTLSConfig/no_client_CA534=== RUN TestServerTLSConfig/missing_CA_file535=== CONT TestService_NativeMTLS536=== CONT TestMetricsInventory537=== CONT TestNARDeduplicationMetadataUploadBug538=== CONT TestGenerateLandingPage539=== CONT TestService_healthCheckHandler540=== CONT TestGracefulShutdownDrainsInflight541=== CONT TestGCTaskStore_Fail542=== CONT TestService_cleanupPendingClosuresHandler543=== CONT TestGCTaskStore_PhaseUpdates544=== CONT TestUploadHandlersRejectOversizedBody5452026/07/19 09:59:24 INFO Starting HTTP server address=127.0.0.1:41365546=== CONT TestGCTaskStore_CompletedAllowsNewTask547=== CONT TestGCTaskStore_GetReturnsLatest548=== CONT TestIsValidUploadKey549=== CONT TestGCTaskStore_GetEmpty5502026/07/19 09:59:24 INFO Shutdown signal received, draining in-flight requests timeout=10s551=== RUN TestIsValidUploadKey/narinfo552=== PAUSE TestIsValidUploadKey/narinfo553=== CONT TestProxyWriteTimeout554=== RUN TestProxyWriteTimeout/narinfo555=== CONT TestRedundantMultipartUpload556=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT557=== CONT TestCompleteMultipartUnregistered558=== CONT TestService_verifyS3Integrity559=== CONT TestService_createPendingClosureHandler560=== CONT TestGCMetrics561--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)562--- PASS: TestGCTaskStore_Fail (0.00s)563--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)564--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)565--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)566--- PASS: TestGCTaskStore_GetEmpty (0.00s)567--- PASS: TestGenerateLandingPage (0.02s)568=== RUN TestClientErrorHandling/InvalidAuthToken569=== PAUSE TestClientErrorHandling/InvalidAuthToken570=== PAUSE TestServerTLSConfig/missing_CA_file571=== RUN TestServerTLSConfig/not_a_PEM_file572=== CONT TestUploadHandlersRejectInvalidKeys573=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info574=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info575=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal576=== CONT TestGCTaskStore_ConflictDifferentParams577=== RUN TestIsValidUploadKey/nar_zst578=== PAUSE TestProxyWriteTimeout/narinfo579=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle580=== RUN TestClientErrorHandling/ServerNotAvailable581--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)582=== PAUSE TestClientErrorHandling/ServerNotAvailable583=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal584=== RUN TestProxyWriteTimeout/1_GiB_nar585=== PAUSE TestProxyWriteTimeout/1_GiB_nar586=== RUN TestProxyWriteTimeout/10_GiB_nar587=== PAUSE TestProxyWriteTimeout/10_GiB_nar588=== PAUSE TestServerTLSConfig/not_a_PEM_file589=== CONT TestService_Rustfstest590=== CONT TestCompletedNarNotReofferedAcrossClosures591=== PAUSE TestIsValidUploadKey/nar_zst592=== RUN TestIsValidUploadKey/nar_xz593=== PAUSE TestIsValidUploadKey/nar_xz594=== RUN TestIsValidUploadKey/nar_plain595=== PAUSE TestIsValidUploadKey/nar_plain596=== RUN TestIsValidUploadKey/listing597=== CONT TestPresignedUploadRegisteredBeforeCommit598=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key599=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key600=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key601=== RUN TestProxyWriteTimeout/unknown_size602=== PAUSE TestIsValidUploadKey/listing603=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key604=== PAUSE TestProxyWriteTimeout/unknown_size605=== RUN TestIsValidUploadKey/build_log606=== PAUSE TestIsValidUploadKey/build_log607=== RUN TestIsValidUploadKey/build_log_home-manager_file608=== PAUSE TestIsValidUploadKey/build_log_home-manager_file609=== CONT TestCompleteMultipartUpload_ErrorButObjectExists610=== CONT TestClientMultipleUploads611=== RUN TestIsValidUploadKey/build_log_plus_in_name612=== PAUSE TestIsValidUploadKey/build_log_plus_in_name613=== RUN TestIsValidUploadKey/build_log_question_mark614=== PAUSE TestIsValidUploadKey/build_log_question_mark615=== RUN TestIsValidUploadKey/build_log_equals616=== PAUSE TestIsValidUploadKey/build_log_equals617=== RUN TestIsValidUploadKey/realisation618=== PAUSE TestIsValidUploadKey/realisation619=== RUN TestIsValidUploadKey/realisation_plus_in_output620=== PAUSE TestIsValidUploadKey/realisation_plus_in_output621=== RUN TestIsValidUploadKey/nix-cache-info622=== PAUSE TestIsValidUploadKey/nix-cache-info623=== RUN TestIsValidUploadKey/index.html624=== PAUSE TestIsValidUploadKey/index.html625=== RUN TestIsValidUploadKey/narinfo_key,_nar_type626=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type627=== RUN TestIsValidUploadKey/nar_key,_narinfo_type628=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type629=== RUN TestIsValidUploadKey/listing_key,_narinfo_type630=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type631=== RUN TestIsValidUploadKey/traversal632=== PAUSE TestIsValidUploadKey/traversal633=== RUN TestIsValidUploadKey/traversal_nar634=== PAUSE TestIsValidUploadKey/traversal_nar635=== RUN TestIsValidUploadKey/absolute636=== PAUSE TestIsValidUploadKey/absolute637=== RUN TestIsValidUploadKey/empty_key638=== PAUSE TestIsValidUploadKey/empty_key639=== RUN TestIsValidUploadKey/unknown_type640=== PAUSE TestIsValidUploadKey/unknown_type641=== CONT TestReadProxyNarStreaming642--- PASS: TestGracefulShutdownDrainsInflight (0.14s)643=== CONT TestClientWithDependencies6442026-07-19 09:59:24.597 UTC [599] ERROR: relation "goose_db_version" does not exist at character 366452026-07-19 09:59:24.597 UTC [599] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6462026-07-19 09:59:24.599 UTC [600] ERROR: relation "goose_db_version" does not exist at character 366472026-07-19 09:59:24.599 UTC [600] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6482026-07-19 09:59:24.599 UTC [601] ERROR: relation "goose_db_version" does not exist at character 366492026-07-19 09:59:24.599 UTC [601] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6502026-07-19 09:59:24.601 UTC [603] ERROR: relation "goose_db_version" does not exist at character 366512026-07-19 09:59:24.601 UTC [603] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6522026-07-19 09:59:24.601 UTC [602] ERROR: relation "goose_db_version" does not exist at character 366532026-07-19 09:59:24.601 UTC [602] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6542026-07-19 09:59:24.602 UTC [604] ERROR: relation "goose_db_version" does not exist at character 366552026-07-19 09:59:24.602 UTC [604] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC656=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts657=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts658=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure659=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure660=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart661=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart662=== CONT TestReadProxyRangeRequest6632026-07-19 09:59:24.622 UTC [605] ERROR: relation "goose_db_version" does not exist at character 366642026-07-19 09:59:24.622 UTC [605] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6652026-07-19 09:59:24.640 UTC [610] ERROR: relation "goose_db_version" does not exist at character 366662026-07-19 09:59:24.640 UTC [610] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6672026-07-19 09:59:24.644 UTC [611] ERROR: relation "goose_db_version" does not exist at character 366682026-07-19 09:59:24.644 UTC [611] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6692026/07/19 09:59:24 OK 20241026095416_initial_model.sql (26.76ms)6702026/07/19 09:59:24 OK 20241026095416_initial_model.sql (30.1ms)6712026/07/19 09:59:24 OK 20241026095416_initial_model.sql (29.93ms)6722026/07/19 09:59:24 OK 20241026095416_initial_model.sql (28.06ms)6732026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (4.15ms)6742026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (4.51ms)6752026/07/19 09:59:24 OK 20241026095416_initial_model.sql (31.95ms)6762026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (3.88ms)6772026/07/19 09:59:24 OK 20241026095416_initial_model.sql (29.87ms)6782026/07/19 09:59:24 OK 20241026095416_initial_model.sql (31.04ms)6792026-07-19 09:59:24.663 UTC [612] ERROR: relation "goose_db_version" does not exist at character 366802026-07-19 09:59:24.663 UTC [612] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6812026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (3.92ms)6822026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (4.46ms)6832026-07-19 09:59:24.665 UTC [613] ERROR: relation "goose_db_version" does not exist at character 366842026-07-19 09:59:24.665 UTC [613] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6852026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (3.54ms)6862026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (4.93ms)6872026/07/19 09:59:24 OK 20251218171726_add_pins.sql (8.26ms)6882026/07/19 09:59:24 OK 20251218171726_add_pins.sql (8.03ms)6892026/07/19 09:59:24 OK 20251218171726_add_pins.sql (7.31ms)6902026/07/19 09:59:24 OK 20251218171726_add_pins.sql (6.11ms)6912026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.61ms)6922026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.27ms)6932026-07-19 09:59:24.677 UTC [614] ERROR: relation "goose_db_version" does not exist at character 366942026-07-19 09:59:24.677 UTC [614] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6952026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (12.38ms)6962026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200006972026/07/19 09:59:24 OK 20251218171726_add_pins.sql (15.05ms)6982026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (13.79ms)6992026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200007002026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (16.15ms)7012026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (13.58ms)7022026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200007032026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200007042026/07/19 09:59:24 OK 20241026095416_initial_model.sql (24.03ms)7052026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (12.37ms)7062026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200007072026/07/19 09:59:24 OK 20241026095416_initial_model.sql (25.96ms)7082026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (16.33ms)7092026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200007102026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.99ms)7112026/07/19 09:59:24 OK 1_commit_pending_closure.sql (6.1ms)7122026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (3.88ms)7132026/07/19 09:59:24 OK 1_commit_pending_closure.sql (5.04ms)7142026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.54ms)7152026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.45ms)7162026/07/19 09:59:24 goose: up to current file version: 27172026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.9ms)7182026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (4.29ms)7192026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.44ms)7202026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (8.82ms)7212026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200007222026/07/19 09:59:24 goose: up to current file version: 27232026/07/19 09:59:24 OK 1_commit_pending_closure.sql (5.58ms)7242026/07/19 09:59:24 OK 20241026095416_initial_model.sql (20.64ms)7252026/07/19 09:59:24 OK 2_object_stats_trigger.sql (3.61ms)7262026/07/19 09:59:24 goose: up to current file version: 27272026/07/19 09:59:24 OK 2_object_stats_trigger.sql (3.98ms)7282026/07/19 09:59:24 goose: up to current file version: 27292026/07/19 09:59:24 OK 2_object_stats_trigger.sql (3.91ms)7302026/07/19 09:59:24 goose: up to current file version: 27312026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures7322026/07/19 09:59:24 OK 20241026095416_initial_model.sql (19.82ms)7332026/07/19 09:59:24 OK 20251218171726_add_pins.sql (4.97ms)7342026/07/19 09:59:24 OK 2_object_stats_trigger.sql (3.69ms)7352026/07/19 09:59:24 goose: up to current file version: 27362026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (2.88ms)7372026/07/19 09:59:24 OK 1_commit_pending_closure.sql (5.21ms)7382026/07/19 09:59:24 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"739--- PASS: TestService_AuthMiddleware (0.27s)7402026/07/19 09:59:24 OK 20251218171726_add_pins.sql (7.8ms)741=== CONT TestService_AuthMiddleware_OIDC7422026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (4.1ms)7432026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.83ms)7442026/07/19 09:59:24 goose: up to current file version: 27452026/07/19 09:59:24 INFO OIDC provider initialized name=test7462026/07/19 09:59:24 WARN mTLS auth: subject not in bound subjects subject="CN=reader"7472026/07/19 09:59:24 WARN mTLS auth: subject not in bound subjects subject="CN=writer"748--- PASS: TestService_NativeMTLS (0.27s)749=== CONT TestReadProxyDisabled750{"timestamp":"2026-07-19T09:59:24.701415586Z","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(385)"}7512026/07/19 09:59:24 INFO Created nix-cache-info in bucket bucket=bucket47522026/07/19 09:59:24 OK 20251218171726_add_pins.sql (6.96ms)7532026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (8.05ms)7542026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200007552026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures7562026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (6.91ms)7572026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200007582026/07/19 09:59:24 OK 20241026095416_initial_model.sql (13.01ms)7592026/07/19 09:59:24 OK 1_commit_pending_closure.sql (3.57ms)7602026/07/19 09:59:24 OK 20251218171726_add_pins.sql (7.84ms)761--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.26s)762=== CONT TestClientCADerivations7632026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (12.57ms)7642026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200007652026/07/19 09:59:24 OK 2_object_stats_trigger.sql (10.65ms)7662026/07/19 09:59:24 goose: up to current file version: 27672026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (11.21ms)7682026/07/19 09:59:24 OK 1_commit_pending_closure.sql (11.75ms)7692026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (11.1ms)7702026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200007712026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.09ms)7722026/07/19 09:59:24 OK 2_object_stats_trigger.sql (3.07ms)7732026/07/19 09:59:24 goose: up to current file version: 2774--- PASS: TestService_healthCheckHandler (0.29s)775=== CONT TestReadProxyRootRedirectsToIndexHTML7762026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.15ms)7772026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.53ms)7782026/07/19 09:59:24 goose: up to current file version: 27792026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.64ms)7802026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.51ms)7812026/07/19 09:59:24 goose: up to current file version: 2782--- PASS: TestMetricsInventory (0.30s)783=== CONT TestCacheStatsHandler784--- PASS: TestObjectStatsTrigger (0.30s)785=== CONT TestReadProxyConditionalGet7862026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures7872026-07-19 09:59:24.727 UTC [627] ERROR: relation "goose_db_version" does not exist at character 367882026-07-19 09:59:24.727 UTC [627] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7892026-07-19 09:59:24.727 UTC [623] ERROR: relation "goose_db_version" does not exist at character 367902026-07-19 09:59:24.727 UTC [623] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7912026-07-19 09:59:24.727 UTC [626] ERROR: relation "goose_db_version" does not exist at character 367922026-07-19 09:59:24.727 UTC [626] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7932026-07-19 09:59:24.728 UTC [625] ERROR: relation "goose_db_version" does not exist at character 367942026-07-19 09:59:24.728 UTC [625] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7952026/07/19 09:59:24 INFO Received cleanup request method=DELETE path=/api/pending_closures7962026/07/19 09:59:24 INFO Created nix-cache-info in bucket bucket=bucket107972026-07-19 09:59:24.728 UTC [628] ERROR: relation "goose_db_version" does not exist at character 367982026-07-19 09:59:24.728 UTC [628] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7992026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (6.19ms)8002026-07-19 09:59:24.729 UTC [630] ERROR: relation "goose_db_version" does not exist at character 368012026-07-19 09:59:24.729 UTC [630] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8022026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200008032026/07/19 09:59:24 INFO Aborted multipart uploads count=08042026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures8052026/07/19 09:59:24 OK 1_commit_pending_closure.sql (3.79ms)8062026-07-19 09:59:24.735 UTC [635] ERROR: relation "goose_db_version" does not exist at character 368072026-07-19 09:59:24.735 UTC [635] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8082026-07-19 09:59:24.735 UTC [632] ERROR: relation "goose_db_version" does not exist at character 368092026-07-19 09:59:24.735 UTC [632] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8102026-07-19 09:59:24.736 UTC [631] ERROR: relation "goose_db_version" does not exist at character 368112026-07-19 09:59:24.736 UTC [631] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8122026/07/19 09:59:24 OK 2_object_stats_trigger.sql (3.79ms)8132026/07/19 09:59:24 goose: up to current file version: 28142026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures8152026/07/19 09:59:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8162026/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.zst817--- PASS: TestCompleteMultipartUnregistered (0.22s)818=== CONT TestCacheConfigHandler819=== RUN TestCacheConfigHandler/full_config,_no_issuer820=== PAUSE TestCacheConfigHandler/full_config,_no_issuer821=== RUN TestCacheConfigHandler/no_cache_url_configured822=== PAUSE TestCacheConfigHandler/no_cache_url_configured823=== RUN TestCacheConfigHandler/no_signing_keys824=== PAUSE TestCacheConfigHandler/no_signing_keys825=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator826=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator827=== CONT TestReadProxyHead8282026/07/19 09:59:24 INFO Received cleanup request method=DELETE path=/api/pending_closures8292026-07-19 09:59:24.745 UTC [657] ERROR: relation "goose_db_version" does not exist at character 368302026-07-19 09:59:24.745 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8312026-07-19 09:59:24.746 UTC [641] ERROR: relation "goose_db_version" does not exist at character 368322026-07-19 09:59:24.746 UTC [641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8332026/07/19 09:59:24 INFO Aborted multipart uploads count=18342026/07/19 09:59:24 OK 20241026095416_initial_model.sql (16.48ms)8352026/07/19 09:59:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8362026-07-19 09:59:24.753 UTC [658] ERROR: relation "goose_db_version" does not exist at character 368372026-07-19 09:59:24.753 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8382026-07-19 09:59:24.753 UTC [613] ERROR: Closure does not exist: id=18392026-07-19 09:59:24.753 UTC [613] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE8402026-07-19 09:59:24.753 UTC [613] STATEMENT: -- name: CommitPendingClosure :exec841 SELECT commit_pending_closure($1::bigint)842 8432026/07/19 09:59:24 OK 20241026095416_initial_model.sql (17.14ms)8442026/07/19 09:59:24 OK 20241026095416_initial_model.sql (17.29ms)8452026/07/19 09:59:24 OK 20241026095416_initial_model.sql (15.65ms)846--- PASS: TestService_cleanupPendingClosuresHandler (0.32s)847=== CONT TestReadProxyInvalidPath8482026/07/19 09:59:24 OK 20241026095416_initial_model.sql (16.95ms)8492026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (4.01ms)8502026/07/19 09:59:24 OK 20241026095416_initial_model.sql (18.65ms)8512026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (3.38ms)8522026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (3.44ms)8532026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (4.94ms)8542026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (3.47ms)8552026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (3.3ms)8562026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.83ms)8572026/07/19 09:59:24 OK 20241026095416_initial_model.sql (17.33ms)8582026/07/19 09:59:24 OK 20241026095416_initial_model.sql (17.58ms)8592026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.64ms)8602026/07/19 09:59:24 OK 20251218171726_add_pins.sql (6.97ms)8612026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (2.87ms)862=== NAME TestNARDeduplicationMetadataUploadBug863 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2509736252/001/store/pcf8nrwphpcwjkjwwsrssrmszf0666kd-file1.txt8642026/07/19 09:59:24 OK 20251218171726_add_pins.sql (12.64ms)8652026/07/19 09:59:24 OK 20251218171726_add_pins.sql (12.82ms)8662026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (10.09ms)8672026/07/19 09:59:24 OK 20251218171726_add_pins.sql (9.27ms)8682026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (10.88ms)8692026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200008702026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (9.54ms)8712026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200008722026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (12.32ms)8732026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200008742026/07/19 09:59:24 OK 20241026095416_initial_model.sql (26.93ms)8752026/07/19 09:59:24 OK 20251218171726_add_pins.sql (13.41ms)8762026/07/19 09:59:24 OK 20241026095416_initial_model.sql (21.32ms)8772026/07/19 09:59:24 OK 20241026095416_initial_model.sql (19.51ms)8782026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.19ms)8792026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.01ms)8802026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.19ms)8812026/07/19 09:59:24 OK 20251218171726_add_pins.sql (6.65ms)8822026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (6.71ms)8832026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200008842026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (4.22ms)8852026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (8.19ms)8862026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200008872026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (2.81ms)8882026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (6.17ms)8892026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200008902026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.9ms)8912026/07/19 09:59:24 goose: up to current file version: 28922026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.84ms)8932026/07/19 09:59:24 goose: up to current file version: 28942026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.98ms)8952026/07/19 09:59:24 goose: up to current file version: 28962026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (4.49ms)8972026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (6.82ms)8982026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200008992026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.23ms)9002026/07/19 09:59:24 OK 20241026095416_initial_model.sql (20.2ms)901=== NAME TestPinProtectsFromGC902 client_integration_test.go:646: Pinned store path: /build/TestPinProtectsFromGC3946811570/001/store/6n2ismllrqa95szjskxffv574ksf3k63-pinned-file.txt903 client_integration_test.go:647: Unpinned store path: /build/TestPinProtectsFromGC3946811570/001/store/hwmmawjcgdzmsl2npv8c7wriadyv3sxq-unpinned-file.txt9042026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.06ms)9052026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.64ms)9062026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.4ms)9072026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures9082026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures9092026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.83ms)9102026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (7.47ms)9112026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200009122026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.01ms)9132026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (3.22ms)914--- PASS: TestService_Rustfstest (0.26s)915=== CONT TestReadProxy4049162026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.72ms)9172026/07/19 09:59:24 goose: up to current file version: 29182026/07/19 09:59:24 OK 2_object_stats_trigger.sql (4.38ms)9192026/07/19 09:59:24 goose: up to current file version: 29202026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.95ms)9212026/07/19 09:59:24 goose: up to current file version: 29222026/07/19 09:59:24 OK 2_object_stats_trigger.sql (3.71ms)9232026/07/19 09:59:24 goose: up to current file version: 29242026/07/19 09:59:24 OK 20251218171726_add_pins.sql (8.53ms)9252026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.13ms)9262026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures9272026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (6.77ms)9282026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200009292026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (5.27ms)9302026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200009312026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures9322026/07/19 09:59:24 OK 20251218171726_add_pins.sql (6.11ms)9332026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures9342026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.9ms)9352026/07/19 09:59:24 goose: up to current file version: 29362026/07/19 09:59:24 OK 1_commit_pending_closure.sql (3.83ms)9372026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4ms)9382026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (4.46ms)9392026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200009402026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.49ms)9412026/07/19 09:59:24 goose: up to current file version: 29422026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (7.9ms)9432026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200009442026/07/19 09:59:24 OK 2_object_stats_trigger.sql (3.54ms)9452026/07/19 09:59:24 goose: up to current file version: 29462026/07/19 09:59:24 INFO Created nix-cache-info in bucket bucket=bucket219472026-07-19 09:59:24.799 UTC [700] ERROR: relation "goose_db_version" does not exist at character 369482026-07-19 09:59:24.799 UTC [700] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9492026/07/19 09:59:24 OK 1_commit_pending_closure.sql (3.19ms)9502026/07/19 09:59:24 OK 1_commit_pending_closure.sql (3.69ms)9512026/07/19 09:59:24 OK 2_object_stats_trigger.sql (3.05ms)9522026/07/19 09:59:24 goose: up to current file version: 29532026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures9542026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures9552026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures9562026-07-19 09:59:24.805 UTC [720] ERROR: relation "goose_db_version" does not exist at character 369572026-07-19 09:59:24.805 UTC [720] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9582026/07/19 09:59:24 INFO Aborted multipart uploads count=09592026-07-19 09:59:24.808 UTC [725] ERROR: relation "goose_db_version" does not exist at character 369602026-07-19 09:59:24.808 UTC [725] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9612026/07/19 09:59:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9622026/07/19 09:59:24 WARN Force mode enabled - objects will be deleted immediately without grace period9632026/07/19 09:59:24 INFO Created nix-cache-info in bucket bucket=bucket24964{"timestamp":"2026-07-19T09:59:24.812886587Z","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(194)"}965{"timestamp":"2026-07-19T09:59:24.812948287Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket16, 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(194)"}9662026/07/19 09:59:24 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9672026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures9682026/07/19 09:59:24 OK 2_object_stats_trigger.sql (11.83ms)9692026/07/19 09:59:24 goose: up to current file version: 29702026/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=ZjI2NzdjMjMtZDk1OS00MWNkLTk0MDEtMDUyYmFkYmM4NjhhLjliY2ExY2JjLTNiYTMtNGVmYS1iM2YyLTlhYjA1ZTRiNjI0YXgxNzg0NDU1MTY0Nzk0ODAxNDkx9712026/07/19 09:59:24 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=09722026/07/19 09:59:24 INFO Vacuumed table table=pending_closures973--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.29s)974=== CONT TestService_AuthMiddleware_MTLSBoundSubjects9752026/07/19 09:59:24 INFO Vacuumed table table=pending_objects976--- PASS: TestReadProxyRangeRequest (0.20s)977=== CONT TestService_ReadAuthMiddleware9782026/07/19 09:59:24 INFO Vacuumed table table=multipart_uploads9792026/07/19 09:59:24 INFO Vacuumed table table=closures9802026/07/19 09:59:24 INFO Vacuumed table table=objects9812026/07/19 09:59:24 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjI2NzdjMjMtZDk1OS00MWNkLTk0MDEtMDUyYmFkYmM4NjhhLjliY2ExY2JjLTNiYTMtNGVmYS1iM2YyLTlhYjA1ZTRiNjI0YXgxNzg0NDU1MTY0Nzk0ODAxNDkx parts=1982--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.30s)983=== CONT TestClientIntegration9842026/07/19 09:59:24 INFO Received cleanup request method=DELETE path=/api/pending_closures985--- PASS: TestReadProxyNarStreaming (0.30s)9862026/07/19 09:59:24 OK 20241026095416_initial_model.sql (12.71ms)987=== CONT TestGCBugBareHashReferences988--- PASS: TestGCMetrics (0.30s)989=== CONT TestParseSingleRange990=== RUN TestParseSingleRange/none991=== PAUSE TestParseSingleRange/none992=== RUN TestParseSingleRange/unknown_unit993=== PAUSE TestParseSingleRange/unknown_unit994=== RUN TestParseSingleRange/multi-range_ignored995=== PAUSE TestParseSingleRange/multi-range_ignored996=== RUN TestParseSingleRange/malformed_no_dash997=== PAUSE TestParseSingleRange/malformed_no_dash998=== RUN TestParseSingleRange/malformed_both_empty999=== PAUSE TestParseSingleRange/malformed_both_empty1000=== RUN TestParseSingleRange/malformed_end_before_start1001=== PAUSE TestParseSingleRange/malformed_end_before_start1002=== RUN TestParseSingleRange/closed1003=== PAUSE TestParseSingleRange/closed1004=== RUN TestParseSingleRange/open-ended1005=== PAUSE TestParseSingleRange/open-ended1006=== RUN TestParseSingleRange/end_clamped_to_size1007=== PAUSE TestParseSingleRange/end_clamped_to_size1008=== RUN TestParseSingleRange/suffix1009=== PAUSE TestParseSingleRange/suffix1010=== RUN TestParseSingleRange/suffix_exceeds_size1011=== PAUSE TestParseSingleRange/suffix_exceeds_size1012=== RUN TestParseSingleRange/single_byte1013=== PAUSE TestParseSingleRange/single_byte1014=== RUN TestParseSingleRange/start_past_EOF1015=== PAUSE TestParseSingleRange/start_past_EOF1016=== RUN TestParseSingleRange/start_far_past_EOF1017=== PAUSE TestParseSingleRange/start_far_past_EOF1018=== CONT TestReadProxyNarinfoAlreadyDecompressed10192026/07/19 09:59:24 INFO Aborted multipart uploads count=110202026/07/19 09:59:24 OK 20241026095416_initial_model.sql (15.61ms)10212026/07/19 09:59:24 OK 20241026095416_initial_model.sql (14.01ms)10222026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (3.36ms)10232026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (3.7ms)10242026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (3.59ms)10252026/07/19 09:59:24 OK 20251218171726_add_pins.sql (3.38ms)1026--- PASS: TestMultipartCleanup (0.41s)1027=== CONT TestReadProxyNarinfo10282026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.66ms)10292026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.76ms)10302026-07-19 09:59:24.840 UTC [773] ERROR: relation "goose_db_version" does not exist at character 3610312026-07-19 09:59:24.840 UTC [773] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10322026-07-19 09:59:24.840 UTC [776] ERROR: relation "goose_db_version" does not exist at character 3610332026-07-19 09:59:24.840 UTC [776] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1034=== NAME TestClientMultipleUploads1035 client_integration_test.go:338: Created store path 0: /build/TestClientMultipleUploads514044067/001/store/7rj930w8w3dhza86822y3nzgkv30ps53-test-file-0.txt10362026-07-19 09:59:24.841 UTC [775] ERROR: relation "goose_db_version" does not exist at character 3610372026-07-19 09:59:24.841 UTC [775] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10382026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (5.88ms)10392026/07/19 09:59:24 goose: successfully migrated database to version: 2026062812000010402026/07/19 09:59:24 OK 1_commit_pending_closure.sql (3.72ms)10412026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (6.89ms)10422026/07/19 09:59:24 goose: successfully migrated database to version: 2026062812000010432026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (6.85ms)10442026/07/19 09:59:24 goose: successfully migrated database to version: 2026062812000010452026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.96ms)10462026/07/19 09:59:24 goose: up to current file version: 210472026/07/19 09:59:24 OK 1_commit_pending_closure.sql (3.93ms)10482026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.14ms)10492026-07-19 09:59:24.853 UTC [780] ERROR: relation "goose_db_version" does not exist at character 3610502026-07-19 09:59:24.853 UTC [780] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10512026/07/19 09:59:24 OK 2_object_stats_trigger.sql (3.1ms)10522026/07/19 09:59:24 goose: up to current file version: 210532026-07-19 09:59:24.857 UTC [832] ERROR: relation "goose_db_version" does not exist at character 3610542026-07-19 09:59:24.857 UTC [832] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10552026/07/19 09:59:24 INFO Created nix-cache-info in bucket bucket=bucket261056--- PASS: TestReadProxyDisabled (0.16s)1057=== CONT TestIsValidCachePath1058=== RUN TestIsValidCachePath/narinfo1059=== PAUSE TestIsValidCachePath/narinfo1060=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1061=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1062=== RUN TestIsValidCachePath/nar_zst1063=== PAUSE TestIsValidCachePath/nar_zst1064=== RUN TestIsValidCachePath/nar_xz1065=== PAUSE TestIsValidCachePath/nar_xz1066=== RUN TestIsValidCachePath/nar_bz21067=== PAUSE TestIsValidCachePath/nar_bz21068=== RUN TestIsValidCachePath/nar_uncompressed1069=== PAUSE TestIsValidCachePath/nar_uncompressed1070=== RUN TestIsValidCachePath/ls1071=== PAUSE TestIsValidCachePath/ls1072=== RUN TestIsValidCachePath/log1073=== PAUSE TestIsValidCachePath/log1074=== RUN TestIsValidCachePath/realisation1075=== PAUSE TestIsValidCachePath/realisation1076=== RUN TestIsValidCachePath/nix-cache-info1077=== PAUSE TestIsValidCachePath/nix-cache-info1078=== RUN TestIsValidCachePath/index.html1079=== PAUSE TestIsValidCachePath/index.html1080=== RUN TestIsValidCachePath/traversal_parent1081=== PAUSE TestIsValidCachePath/traversal_parent1082=== RUN TestIsValidCachePath/traversal_in_middle1083=== PAUSE TestIsValidCachePath/traversal_in_middle1084=== RUN TestIsValidCachePath/invalid_char_e1085=== PAUSE TestIsValidCachePath/invalid_char_e1086=== RUN TestIsValidCachePath/invalid_char_u1087=== PAUSE TestIsValidCachePath/invalid_char_u1088=== RUN TestIsValidCachePath/random_path1089=== PAUSE TestIsValidCachePath/random_path1090=== RUN TestIsValidCachePath/empty1091=== PAUSE TestIsValidCachePath/empty1092=== RUN TestIsValidCachePath/leading_slash1093=== PAUSE TestIsValidCachePath/leading_slash1094=== RUN TestIsValidCachePath/wrong_extension1095=== PAUSE TestIsValidCachePath/wrong_extension1096=== RUN TestIsValidCachePath/short_hash1097=== PAUSE TestIsValidCachePath/short_hash1098=== CONT TestService_AuthMiddleware_MTLSProxyHeader10992026/07/19 09:59:24 OK 2_object_stats_trigger.sql (14.91ms)11002026/07/19 09:59:24 goose: up to current file version: 211012026/07/19 09:59:24 OK 20241026095416_initial_model.sql (19.76ms)11022026/07/19 09:59:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11032026/07/19 09:59:24 OK 20241026095416_initial_model.sql (19.3ms)11042026/07/19 09:59:24 OK 20241026095416_initial_model.sql (20.05ms)1105=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1106=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1107=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1108=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1109=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1110=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1111=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1112=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1113=== CONT TestOrphanedObjectsGCStressTest11142026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (3.66ms)11152026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (4.74ms)11162026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (4.56ms)11172026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures11182026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.35ms)1119=== NAME TestClientMultipleUploads11202026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.81ms)1121 client_integration_test.go:338: Created store path 1: /build/TestClientMultipleUploads514044067/001/store/n2lw0961pi06hdqvqyg3nzp370hwc81y-test-file-1.txt11222026/07/19 09:59:24 OK 20251218171726_add_pins.sql (7.24ms)11232026-07-19 09:59:24.883 UTC [874] ERROR: relation "goose_db_version" does not exist at character 3611242026-07-19 09:59:24.883 UTC [874] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11252026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (5.85ms)11262026/07/19 09:59:24 goose: successfully migrated database to version: 2026062812000011272026/07/19 09:59:24 INFO Received uploads request method=POST path=/api/pending_closures11282026/07/19 09:59:24 OK 20241026095416_initial_model.sql (16.28ms)11292026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (5.76ms)11302026/07/19 09:59:24 goose: successfully migrated database to version: 2026062812000011312026/07/19 09:59:24 OK 20241026095416_initial_model.sql (16.05ms)11322026/07/19 09:59:24 OK 1_commit_pending_closure.sql (3.36ms)11332026/07/19 09:59:24 OK 1_commit_pending_closure.sql (3.11ms)11342026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (7.83ms)11352026/07/19 09:59:24 goose: successfully migrated database to version: 2026062812000011362026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (3.09ms)11372026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (2.87ms)11382026/07/19 09:59:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11392026/07/19 09:59:24 INFO Uploading pcf8nrwphpcwjkjwwsrssrmszf0666kd-file1.txt (160B)11402026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.47ms)11412026/07/19 09:59:24 goose: up to current file version: 211422026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.61ms)11432026/07/19 09:59:24 goose: up to current file version: 211442026/07/19 09:59:24 OK 1_commit_pending_closure.sql (3.88ms)11452026/07/19 09:59:24 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11462026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.24ms)11472026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.3ms)11482026/07/19 09:59:24 WARN Failed to register uploaded object key=pcf8nrwphpcwjkjwwsrssrmszf0666kd.ls error="server returned 404: 404 page not found\n"11492026/07/19 09:59:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11502026/07/19 09:59:24 OK 2_object_stats_trigger.sql (4.53ms)11512026/07/19 09:59:24 goose: up to current file version: 211522026/07/19 09:59:24 INFO Signed narinfos id=1 count=111532026/07/19 09:59:24 INFO Uploading 1 narinfos1154=== NAME TestClientWithDependencies1155 client_integration_test.go:593: Built derivation: /build/TestClientWithDependencies1980633039/001/store/ba0m9g2ql74116f23waaxv76n4vbddba-test-script11562026/07/19 09:59:24 WARN Failed to register uploaded object key=pcf8nrwphpcwjkjwwsrssrmszf0666kd.narinfo error="server returned 404: 404 page not found\n"11572026/07/19 09:59:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11582026-07-19 09:59:24.906 UTC [927] ERROR: relation "goose_db_version" does not exist at character 3611592026-07-19 09:59:24.906 UTC [927] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1160--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.19s)1161=== CONT TestOrphanedObjectsGC11622026/07/19 09:59:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11632026/07/19 09:59:24 INFO Uploading 6n2ismllrqa95szjskxffv574ksf3k63-pinned-file.txt (128B)11642026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (15.7ms)11652026/07/19 09:59:24 goose: successfully migrated database to version: 2026062812000011662026/07/19 09:59:24 OK 20241026095416_initial_model.sql (20.79ms)11672026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (15.87ms)11682026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200001169--- PASS: TestReadProxyHead (0.17s)1170=== CONT TestResurrectedObjectNotDeleted11712026/07/19 09:59:24 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11722026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (4.05ms)11732026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.64ms)11742026/07/19 09:59:24 OK 1_commit_pending_closure.sql (6.36ms)11752026/07/19 09:59:24 WARN Failed to register uploaded object key=6n2ismllrqa95szjskxffv574ksf3k63.ls error="server returned 404: 404 page not found\n"11762026/07/19 09:59:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11772026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.53ms)11782026/07/19 09:59:24 goose: up to current file version: 211792026/07/19 09:59:24 INFO Completed upload id=111802026/07/19 09:59:24 INFO Signed narinfos id=1 count=111812026/07/19 09:59:24 INFO Uploading 1 narinfos1182--- PASS: TestCacheStatsHandler (0.20s)1183=== CONT TestGCTaskStore_StartNew1184--- PASS: TestGCTaskStore_StartNew (0.00s)1185=== CONT TestClientErrorHandling/InvalidStorePath11862026-07-19 09:59:24.922 UTC [941] ERROR: relation "goose_db_version" does not exist at character 3611872026-07-19 09:59:24.922 UTC [941] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11882026/07/19 09:59:24 OK 20251218171726_add_pins.sql (6.22ms)11892026/07/19 09:59:24 OK 2_object_stats_trigger.sql (3.91ms)11902026/07/19 09:59:24 goose: up to current file version: 211912026/07/19 09:59:24 INFO Upload complete. (113ms)11922026/07/19 09:59:24 WARN Failed to register uploaded object key=6n2ismllrqa95szjskxffv574ksf3k63.narinfo error="server returned 404: 404 page not found\n"1193=== NAME TestNARDeduplicationMetadataUploadBug1194 metadata_upload_test.go:54: Retrieved narinfo from S3:1195 StorePath: /build/TestNARDeduplicationMetadataUploadBug2509736252/001/store/pcf8nrwphpcwjkjwwsrssrmszf0666kd-file1.txt1196 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1197 Compression: zstd1198 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1199 NarSize: 1601200 References: 1201 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12022026/07/19 09:59:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1203=== NAME TestClientMultipleUploads1204 client_integration_test.go:338: Created store path 2: /build/TestClientMultipleUploads514044067/001/store/wdrr8ri389asxrjrx61xz6qrf1hpvj9y-test-file-2.txt12052026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (5.98ms)12062026/07/19 09:59:24 goose: successfully migrated database to version: 202606281200001207--- PASS: TestReadProxyInvalidPath (0.18s)1208=== CONT TestClientErrorHandling/ServerNotAvailable1209=== NAME TestNARDeduplicationMetadataUploadBug1210 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1211 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1212 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12132026/07/19 09:59:24 OK 20241026095416_initial_model.sql (11ms)12142026/07/19 09:59:24 INFO Completed upload id=112152026/07/19 09:59:24 INFO Upload complete. (114ms)12162026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.75ms)12172026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (3.13ms)1218--- PASS: TestReadProxyConditionalGet (0.21s)1219=== CONT TestClientErrorHandling/InvalidAuthToken1220=== NAME TestClientWithDependencies1221 client_integration_test.go:595: Found 1 dependencies (including self)12222026/07/19 09:59:24 OK 2_object_stats_trigger.sql (3.06ms)12232026/07/19 09:59:24 goose: up to current file version: 212242026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.49ms)1225--- PASS: TestReadProxy404 (0.16s)1226=== CONT TestServerTLSConfig/no_client_CA1227=== CONT TestServerTLSConfig/not_a_PEM_file12282026-07-19 09:59:24.944 UTC [988] ERROR: relation "goose_db_version" does not exist at character 3612292026-07-19 09:59:24.944 UTC [988] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1230=== CONT TestServerTLSConfig/missing_CA_file1231--- PASS: TestServerTLSConfig (0.10s)1232 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1233 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1234 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1235=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info12362026/07/19 09:59:24 INFO Received uploads request method=POST path=/1237=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal12382026/07/19 09:59:24 INFO Received uploads request method=POST path=/1239=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key12402026/07/19 09:59:24 INFO Received complete multipart upload request method=POST path=/1241=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key12422026/07/19 09:59:24 INFO Received request for more parts method=POST path=/1243=== CONT TestProxyWriteTimeout/narinfo1244=== CONT TestProxyWriteTimeout/1_GiB_nar1245--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1246 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1247 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1248 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1249 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1250=== CONT TestProxyWriteTimeout/10_GiB_nar1251=== CONT TestProxyWriteTimeout/unknown_size1252=== CONT TestIsValidUploadKey/narinfo1253=== CONT TestIsValidUploadKey/realisation_plus_in_output1254=== CONT TestIsValidUploadKey/unknown_type1255--- PASS: TestProxyWriteTimeout (0.10s)1256 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1257 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1258 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1259 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1260=== CONT TestIsValidUploadKey/empty_key1261=== CONT TestIsValidUploadKey/absolute1262=== CONT TestIsValidUploadKey/traversal_nar1263=== CONT TestIsValidUploadKey/traversal1264=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1265=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1266=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1267=== CONT TestIsValidUploadKey/index.html1268=== CONT TestIsValidUploadKey/nix-cache-info1269=== CONT TestIsValidUploadKey/build_log_home-manager_file1270=== CONT TestIsValidUploadKey/realisation1271=== CONT TestIsValidUploadKey/build_log_equals1272=== CONT TestIsValidUploadKey/build_log_question_mark1273=== CONT TestIsValidUploadKey/build_log_plus_in_name1274=== CONT TestIsValidUploadKey/nar_plain1275=== CONT TestIsValidUploadKey/build_log1276=== CONT TestIsValidUploadKey/listing1277=== CONT TestIsValidUploadKey/nar_xz1278=== CONT TestIsValidUploadKey/nar_zst1279=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts12802026/07/19 09:59:24 INFO Received request for more parts method=POST path=/1281--- PASS: TestIsValidUploadKey (0.10s)1282 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1283 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1284 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1285 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1286 --- PASS: TestIsValidUploadKey/absolute (0.00s)1287 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1288 --- PASS: TestIsValidUploadKey/traversal (0.00s)1289 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1290 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1291 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1292 --- PASS: TestIsValidUploadKey/index.html (0.00s)1293 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1294 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1295 --- PASS: TestIsValidUploadKey/realisation (0.00s)1296 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1297 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1298 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1299 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1300 --- PASS: TestIsValidUploadKey/build_log (0.00s)1301 --- PASS: TestIsValidUploadKey/listing (0.00s)1302 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1303 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1304=== NAME TestClientCADerivations1305 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1724482622/001/store/0j5vsrrhm3sb57xj05idr4wqj01y3jry-ca-test13062026-07-19 09:59:24.949 UTC [994] ERROR: relation "goose_db_version" does not exist at character 3613072026-07-19 09:59:24.949 UTC [994] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13082026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (15.21ms)13092026/07/19 09:59:24 goose: successfully migrated database to version: 2026062812000013102026/07/19 09:59:24 OK 20241026095416_initial_model.sql (27.21ms)13112026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.67ms)13122026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (4.84ms)13132026/07/19 09:59:24 OK 2_object_stats_trigger.sql (2.79ms)1314=== NAME TestNARDeduplicationMetadataUploadBug13152026/07/19 09:59:24 goose: up to current file version: 21316 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2509736252/001/store/nksa33p65anb9pkfgwfvly0a79gj519h-file2.txt13172026/07/19 09:59:24 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1318--- PASS: TestService_ReadAuthMiddleware (0.15s)1319=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart13202026-07-19 09:59:24.968 UTC [1063] ERROR: relation "goose_db_version" does not exist at character 3613212026-07-19 09:59:24.968 UTC [1063] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13222026/07/19 09:59:24 INFO Received complete multipart upload request method=POST path=/13232026-07-19 09:59:24.969 UTC [1064] ERROR: relation "goose_db_version" does not exist at character 3613242026-07-19 09:59:24.969 UTC [1064] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13252026-07-19 09:59:24.969 UTC [1065] ERROR: relation "goose_db_version" does not exist at character 3613262026-07-19 09:59:24.969 UTC [1065] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13272026/07/19 09:59:24 OK 20251218171726_add_pins.sql (8.01ms)13282026/07/19 09:59:24 OK 20241026095416_initial_model.sql (16.11ms)13292026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (7.61ms)13302026/07/19 09:59:24 goose: successfully migrated database to version: 2026062812000013312026/07/19 09:59:24 OK 20241026095416_initial_model.sql (12.65ms)13322026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (3.9ms)13332026/07/19 09:59:24 OK 20251210153512_drop_unused_gin_index.sql (4.26ms)13342026-07-19 09:59:24.984 UTC [1087] ERROR: relation "goose_db_version" does not exist at character 3613352026-07-19 09:59:24.984 UTC [1087] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13362026/07/19 09:59:24 OK 1_commit_pending_closure.sql (6.13ms)1337=== NAME TestClientCADerivations1338 client_ca_test.go:139: Found 1 dependencies (including self)13392026/07/19 09:59:24 OK 20251218171726_add_pins.sql (7.82ms)13402026/07/19 09:59:24 OK 2_object_stats_trigger.sql (3.44ms)13412026/07/19 09:59:24 OK 20251218171726_add_pins.sql (5.2ms)13422026/07/19 09:59:24 goose: up to current file version: 213432026/07/19 09:59:24 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13442026/07/19 09:59:24 WARN mTLS auth: bound subjects configured but subject DN unavailable13452026/07/19 09:59:24 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1346--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.18s)1347=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure13482026/07/19 09:59:24 INFO Received uploads request method=POST path=/13492026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (7.92ms)13502026/07/19 09:59:24 goose: successfully migrated database to version: 2026062812000013512026/07/19 09:59:24 OK 20260628120000_add_object_size_and_stats.sql (7.62ms)13522026/07/19 09:59:24 goose: successfully migrated database to version: 2026062812000013532026/07/19 09:59:24 OK 20241026095416_initial_model.sql (17.75ms)13542026/07/19 09:59:24 OK 20241026095416_initial_model.sql (17.95ms)13552026/07/19 09:59:24 OK 20241026095416_initial_model.sql (20.17ms)13562026/07/19 09:59:24 OK 1_commit_pending_closure.sql (4.16ms)13572026/07/19 09:59:25 OK 1_commit_pending_closure.sql (3.93ms)13582026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.56ms)13592026/07/19 09:59:25 goose: up to current file version: 213602026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (4.03ms)13612026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (4.27ms)13622026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (4.21ms)13632026/07/19 09:59:25 OK 2_object_stats_trigger.sql (1.96ms)13642026/07/19 09:59:25 goose: up to current file version: 213652026/07/19 09:59:25 OK 20251218171726_add_pins.sql (5.65ms)13662026/07/19 09:59:25 OK 20251218171726_add_pins.sql (8.02ms)13672026/07/19 09:59:25 OK 20251218171726_add_pins.sql (8.17ms)13682026/07/19 09:59:25 OK 20241026095416_initial_model.sql (16.33ms)13692026-07-19 09:59:25.010 UTC [1178] ERROR: relation "goose_db_version" does not exist at character 3613702026-07-19 09:59:25.010 UTC [1178] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13712026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures13722026/07/19 09:59:25 INFO Created nix-cache-info in bucket bucket=bucket3813732026-07-19 09:59:25.021 UTC [1197] ERROR: relation "goose_db_version" does not exist at character 3613742026-07-19 09:59:25.021 UTC [1197] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13752026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (15.48ms)13762026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000013772026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (13.15ms)13782026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (14.61ms)13792026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000013802026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (14.54ms)13812026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000013822026/07/19 09:59:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13832026/07/19 09:59:25 INFO Uploading ba0m9g2ql74116f23waaxv76n4vbddba-test-script (136B)13842026/07/19 09:59:25 OK 1_commit_pending_closure.sql (3.77ms)13852026/07/19 09:59:25 OK 20251218171726_add_pins.sql (5.14ms)13862026/07/19 09:59:25 OK 1_commit_pending_closure.sql (5.43ms)13872026/07/19 09:59:25 OK 1_commit_pending_closure.sql (5.29ms)13882026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.97ms)13892026/07/19 09:59:25 goose: up to current file version: 213902026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures13912026/07/19 09:59:25 WARN Failed to register uploaded object key=log/sflq9zzpijf6hz4bp7dd9k4vrmiwbj69-test-script.drv error="server returned 404: 404 page not found\n"13922026/07/19 09:59:25 OK 2_object_stats_trigger.sql (3.43ms)13932026/07/19 09:59:25 goose: up to current file version: 213942026/07/19 09:59:25 OK 2_object_stats_trigger.sql (3.4ms)13952026/07/19 09:59:25 goose: up to current file version: 213962026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (6.46ms)13972026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000013982026/07/19 09:59:25 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13992026/07/19 09:59:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14002026/07/19 09:59:25 INFO Uploading hwmmawjcgdzmsl2npv8c7wriadyv3sxq-unpinned-file.txt (128B)14012026-07-19 09:59:25.037 UTC [1251] ERROR: relation "goose_db_version" does not exist at character 3614022026-07-19 09:59:25.037 UTC [1251] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14032026/07/19 09:59:25 OK 20241026095416_initial_model.sql (12.25ms)1404--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.18s)1405=== CONT TestCacheConfigHandler/full_config,_no_issuer1406=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1407=== CONT TestCacheConfigHandler/no_signing_keys1408=== CONT TestCacheConfigHandler/no_cache_url_configured1409--- PASS: TestCacheConfigHandler (0.00s)1410 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1411 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1412 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1413 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1414=== CONT TestParseSingleRange/none1415=== CONT TestParseSingleRange/start_past_EOF1416=== CONT TestParseSingleRange/single_byte1417=== CONT TestParseSingleRange/suffix_exceeds_size1418=== CONT TestParseSingleRange/suffix1419=== CONT TestParseSingleRange/end_clamped_to_size1420=== CONT TestParseSingleRange/start_far_past_EOF1421=== CONT TestParseSingleRange/open-ended1422=== CONT TestParseSingleRange/closed1423=== CONT TestParseSingleRange/malformed_end_before_start1424=== CONT TestParseSingleRange/malformed_both_empty14252026/07/19 09:59:25 WARN Failed to register uploaded object key=ba0m9g2ql74116f23waaxv76n4vbddba.ls error="server returned 404: 404 page not found\n"1426=== CONT TestParseSingleRange/malformed_no_dash1427=== CONT TestParseSingleRange/multi-range_ignored1428=== CONT TestParseSingleRange/unknown_unit1429--- PASS: TestParseSingleRange (0.00s)1430 --- PASS: TestParseSingleRange/none (0.00s)1431 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1432 --- PASS: TestParseSingleRange/single_byte (0.00s)1433 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1434 --- PASS: TestParseSingleRange/suffix (0.00s)1435 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1436 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1437 --- PASS: TestParseSingleRange/open-ended (0.00s)1438 --- PASS: TestParseSingleRange/closed (0.00s)1439 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1440 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1441 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1442 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1443 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1444=== CONT TestIsValidCachePath/narinfo1445=== CONT TestIsValidCachePath/index.html1446=== CONT TestIsValidCachePath/short_hash1447=== CONT TestIsValidCachePath/wrong_extension1448=== CONT TestIsValidCachePath/leading_slash14492026/07/19 09:59:25 OK 1_commit_pending_closure.sql (4.62ms)1450=== CONT TestIsValidCachePath/empty1451=== CONT TestIsValidCachePath/random_path1452=== CONT TestIsValidCachePath/invalid_char_u14532026/07/19 09:59:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1454=== CONT TestIsValidCachePath/invalid_char_e14552026/07/19 09:59:25 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"1456=== CONT TestIsValidCachePath/traversal_in_middle1457=== CONT TestIsValidCachePath/traversal_parent1458=== CONT TestIsValidCachePath/nar_uncompressed1459=== CONT TestIsValidCachePath/nix-cache-info1460=== CONT TestIsValidCachePath/realisation1461=== CONT TestIsValidCachePath/log1462=== CONT TestIsValidCachePath/ls1463=== CONT TestIsValidCachePath/nar_xz1464=== CONT TestIsValidCachePath/nar_bz21465=== CONT TestIsValidCachePath/nar_zst1466=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1467--- PASS: TestIsValidCachePath (0.00s)1468 --- PASS: TestIsValidCachePath/narinfo (0.00s)1469 --- PASS: TestIsValidCachePath/index.html (0.00s)1470 --- PASS: TestIsValidCachePath/short_hash (0.00s)1471 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1472 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1473 --- PASS: TestIsValidCachePath/empty (0.00s)1474 --- PASS: TestIsValidCachePath/random_path (0.00s)1475 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1476 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1477 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1478 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1479 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1480 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1481 --- PASS: TestIsValidCachePath/realisation (0.00s)1482 --- PASS: TestIsValidCachePath/log (0.00s)1483 --- PASS: TestIsValidCachePath/ls (0.00s)1484 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1485 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1486 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1487 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1488=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token14892026/07/19 09:59:25 INFO Signed narinfos id=1 count=114902026/07/19 09:59:25 INFO Uploading 1 narinfos1491--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.21s)1492=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected14932026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (4.25ms)14942026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures14952026/07/19 09:59:25 OK 2_object_stats_trigger.sql (3.4ms)14962026/07/19 09:59:25 goose: up to current file version: 214972026/07/19 09:59:25 OK 20241026095416_initial_model.sql (12.96ms)14982026/07/19 09:59:25 WARN Failed to register uploaded object key=hwmmawjcgdzmsl2npv8c7wriadyv3sxq.ls error="server returned 404: 404 page not found\n"14992026/07/19 09:59:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15002026/07/19 09:59:25 INFO OIDC auth successful provider=test1501=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected15022026/07/19 09:59:25 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]1503=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured15042026/07/19 09:59:25 INFO Signed narinfos id=2 count=115052026/07/19 09:59:25 INFO Uploading 1 narinfos15062026/07/19 09:59:25 WARN Failed to register uploaded object key=ba0m9g2ql74116f23waaxv76n4vbddba.narinfo error="server returned 404: 404 page not found\n"15072026/07/19 09:59:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15082026/07/19 09:59:25 WARN Authentication failed token_preview=eyJhbGciOi..._Vc7ZnPUwg 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]1509--- PASS: TestService_AuthMiddleware_OIDC (0.17s)1510 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1511 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1512 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1513 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1514--- PASS: TestReadProxyNarinfo (0.21s)15152026/07/19 09:59:25 WARN Failed to register uploaded object key=hwmmawjcgdzmsl2npv8c7wriadyv3sxq.narinfo error="server returned 404: 404 page not found\n"15162026/07/19 09:59:25 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15172026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (8.15ms)15182026/07/19 09:59:25 OK 20251218171726_add_pins.sql (9.49ms)15192026/07/19 09:59:25 INFO Completed upload id=215202026/07/19 09:59:25 INFO Upload complete. (88ms)15212026/07/19 09:59:25 INFO Completed upload id=115222026/07/19 09:59:25 INFO Upload complete. (78ms)15232026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures15242026-07-19 09:59:25.057 UTC [1292] ERROR: relation "goose_db_version" does not exist at character 3615252026-07-19 09:59:25.057 UTC [1292] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15262026/07/19 09:59:25 OK 20241026095416_initial_model.sql (11.97ms)15272026/07/19 09:59:25 OK 20251218171726_add_pins.sql (4.96ms)1528=== NAME TestClientWithDependencies1529 client_integration_test.go:597: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1980633039/001/store) requires matching store prefix15302026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures15312026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (5.57ms)15322026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000015332026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)1534=== NAME TestClientIntegration1535 client_integration_test.go:276: Created store path: /build/TestClientIntegration1992298309/002/store/4dkfcb9v1vg4b9argn7z9w8sjibd9q38-test-file.txt15362026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.66ms)15372026/07/19 09:59:25 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15382026/07/19 09:59:25 INFO Uploading wdrr8ri389asxrjrx61xz6qrf1hpvj9y-test-file-2.txt (160B)15392026/07/19 09:59:25 INFO Uploading 7rj930w8w3dhza86822y3nzgkv30ps53-test-file-0.txt (160B)15402026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (4.1ms)15412026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000015422026/07/19 09:59:25 INFO Uploading n2lw0961pi06hdqvqyg3nzp370hwc81y-test-file-1.txt (160B)15432026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures15442026/07/19 09:59:25 OK 20251218171726_add_pins.sql (3.2ms)1545--- PASS: TestClientWithDependencies (0.49s)15462026/07/19 09:59:25 OK 2_object_stats_trigger.sql (1.57ms)15472026/07/19 09:59:25 goose: up to current file version: 215482026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.06ms)15492026/07/19 09:59:25 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15502026/07/19 09:59:25 OK 2_object_stats_trigger.sql (2.06ms)15512026/07/19 09:59:25 goose: up to current file version: 215522026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)15532026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000015542026/07/19 09:59:25 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15552026/07/19 09:59:25 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15562026/07/19 09:59:25 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15572026/07/19 09:59:25 OK 1_commit_pending_closure.sql (2.24ms)15582026/07/19 09:59:25 OK 2_object_stats_trigger.sql (975.77µs)15592026/07/19 09:59:25 goose: up to current file version: 215602026/07/19 09:59:25 WARN Failed to register uploaded object key=nksa33p65anb9pkfgwfvly0a79gj519h.ls error="server returned 404: 404 page not found\n"15612026/07/19 09:59:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15622026/07/19 09:59:25 INFO Signed narinfos id=2 count=115632026/07/19 09:59:25 INFO Uploading 1 narinfos15642026/07/19 09:59:25 WARN Failed to register uploaded object key=wdrr8ri389asxrjrx61xz6qrf1hpvj9y.ls error="server returned 404: 404 page not found\n"15652026/07/19 09:59:25 WARN Failed to register uploaded object key=7rj930w8w3dhza86822y3nzgkv30ps53.ls error="server returned 404: 404 page not found\n"15662026/07/19 09:59:25 WARN Failed to register uploaded object key=n2lw0961pi06hdqvqyg3nzp370hwc81y.ls error="server returned 404: 404 page not found\n"15672026/07/19 09:59:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15682026/07/19 09:59:25 WARN Failed to register uploaded object key=nksa33p65anb9pkfgwfvly0a79gj519h.narinfo error="server returned 404: 404 page not found\n"15692026/07/19 09:59:25 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15702026/07/19 09:59:25 INFO Signed narinfos id=1 count=115712026/07/19 09:59:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15722026/07/19 09:59:25 OK 20241026095416_initial_model.sql (12.74ms)15732026/07/19 09:59:25 INFO Signed narinfos id=2 count=115742026/07/19 09:59:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15752026/07/19 09:59:25 INFO Signed narinfos id=3 count=115762026/07/19 09:59:25 INFO Completed upload id=215772026/07/19 09:59:25 INFO Uploading 3 narinfos15782026/07/19 09:59:25 INFO Upload complete. (82ms)15792026/07/19 09:59:25 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)1580=== NAME TestNARDeduplicationMetadataUploadBug1581 metadata_upload_test.go:76: Retrieved narinfo from S3:1582 StorePath: /build/TestNARDeduplicationMetadataUploadBug2509736252/001/store/nksa33p65anb9pkfgwfvly0a79gj519h-file2.txt1583 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1584 Compression: zstd1585 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1586 NarSize: 1601587 References: 1588 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf15892026/07/19 09:59:25 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_closures15902026/07/19 09:59:25 WARN Failed to register uploaded object key=n2lw0961pi06hdqvqyg3nzp370hwc81y.narinfo error="server returned 404: 404 page not found\n"15912026/07/19 09:59:25 WARN Failed to register uploaded object key=wdrr8ri389asxrjrx61xz6qrf1hpvj9y.narinfo error="server returned 404: 404 page not found\n"15922026/07/19 09:59:25 WARN Failed to register uploaded object key=7rj930w8w3dhza86822y3nzgkv30ps53.narinfo error="server returned 404: 404 page not found\n"15932026/07/19 09:59:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15942026/07/19 09:59:25 OK 20251218171726_add_pins.sql (4.13ms)1595 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1596 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1597 {"version":1,"root":{"type":"regular","size":44}}15982026/07/19 09:59:25 OK 20260628120000_add_object_size_and_stats.sql (3.15ms)15992026/07/19 09:59:25 goose: successfully migrated database to version: 2026062812000016002026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures16012026/07/19 09:59:25 OK 1_commit_pending_closure.sql (1.58ms)16022026/07/19 09:59:25 INFO Completed upload id=116032026/07/19 09:59:25 OK 2_object_stats_trigger.sql (1.09ms)16042026/07/19 09:59:25 goose: up to current file version: 216052026/07/19 09:59:25 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1606--- PASS: TestNARDeduplicationMetadataUploadBug (0.66s)16072026/07/19 09:59:25 INFO Completed upload id=216082026/07/19 09:59:25 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16092026/07/19 09:59:25 INFO Completed upload id=316102026/07/19 09:59:25 INFO Upload complete. (136ms)1611=== NAME TestClientMultipleUploads1612 client_integration_test.go:349: Uploaded 3 paths in 167.386563ms16132026/07/19 09:59:25 INFO Received create pin request method=POST path=/api/pins/myapp16142026/07/19 09:59:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16152026/07/19 09:59:25 INFO Uploading 0j5vsrrhm3sb57xj05idr4wqj01y3jry-ca-test (144B)16162026/07/19 09:59:25 WARN Failed to register uploaded object key=log/ji74majvjkm00l933zqdjyybcncffr4m-ca-test.drv error="server returned 404: 404 page not found\n"16172026/07/19 09:59:25 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3946811570/001/store/6n2ismllrqa95szjskxffv574ksf3k63-pinned-file.txt narinfo_key=6n2ismllrqa95szjskxffv574ksf3k63.narinfo16182026/07/19 09:59:25 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"1619--- PASS: TestResurrectedObjectNotDeleted (0.19s)16202026/07/19 09:59:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures16212026/07/19 09:59:25 INFO Garbage collection started16222026/07/19 09:59:25 WARN Failed to register uploaded object key=0j5vsrrhm3sb57xj05idr4wqj01y3jry.ls error="server returned 404: 404 page not found\n"16232026/07/19 09:59:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16242026/07/19 09:59:25 INFO Signed narinfos id=1 count=116252026/07/19 09:59:25 INFO Uploading 1 narinfos1626--- PASS: TestClientMultipleUploads (0.58s)16272026/07/19 09:59:25 WARN Failed to register uploaded object key=0j5vsrrhm3sb57xj05idr4wqj01y3jry.narinfo error="server returned 404: 404 page not found\n"16282026/07/19 09:59:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16292026/07/19 09:59:25 INFO Aborted multipart uploads count=016302026/07/19 09:59:25 INFO Completed upload id=116312026/07/19 09:59:25 INFO Upload complete. (90ms)16322026/07/19 09:59:25 WARN Force mode enabled - objects will be deleted immediately without grace period1633=== NAME TestClientCADerivations1634 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1724482622/001/store/0j5vsrrhm3sb57xj05idr4wqj01y3jry-ca-test1635 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1636 Compression: zstd1637 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1638 NarSize: 1441639 References: 1640 Deriver: /build/TestClientCADerivations1724482622/001/store/ji74majvjkm00l933zqdjyybcncffr4m-ca-test.drv1641 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1642 client_ca_test.go:185: Checking for realisation files in S3...16432026/07/19 09:59:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1644 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1645 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16462026/07/19 09:59:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16472026/07/19 09:59:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZjI2NzdjMjMtZDk1OS00MWNkLTk0MDEtMDUyYmFkYmM4NjhhLmNjMmJmMDQ5LTU4NjItNDEzNS05YzRiLTQxY2Q4NjgzZmM3ZXgxNzg0NDU1MTY0Nzk5Mjc0NjI5 parts=1016482026/07/19 09:59:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16492026/07/19 09:59:25 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZjI2NzdjMjMtZDk1OS00MWNkLTk0MDEtMDUyYmFkYmM4NjhhLmNkZGVkMDUzLWVmMjItNDg0Mi1iYjllLWVmYTI5NDMyODllM3gxNzg0NDU1MTY0ODE2NjMwMDU5 parts=1016502026/07/19 09:59:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16512026/07/19 09:59:25 INFO Completed upload id=116522026/07/19 09:59:25 INFO Completed upload id=116532026/07/19 09:59:25 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016542026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures16552026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures16562026/07/19 09:59:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures16572026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures16582026/07/19 09:59:25 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16592026/07/19 09:59:25 WARN Found objects in DB but missing from S3, will re-upload count=11660--- PASS: TestService_verifyS3Integrity (0.63s)16612026/07/19 09:59:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16622026/07/19 09:59:25 INFO Aborted multipart uploads count=016632026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures16642026/07/19 09:59:25 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZjI2NzdjMjMtZDk1OS00MWNkLTk0MDEtMDUyYmFkYmM4NjhhLmQyYWExYzRlLTA2NTctNDdhMy04YjU3LWRlNTQzMGFhOTAxZHgxNzg0NDU1MTY0NzMzMDU0NDk5 parts=121665--- PASS: TestRedundantMultipartUpload (0.74s)16662026/07/19 09:59:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16672026/07/19 09:59:25 INFO Uploading 4dkfcb9v1vg4b9argn7z9w8sjibd9q38-test-file.txt (152B)16682026/07/19 09:59:25 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=016692026/07/19 09:59:25 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16702026/07/19 09:59:25 INFO Vacuumed table table=pending_closures16712026/07/19 09:59:25 WARN Failed to register uploaded object key=4dkfcb9v1vg4b9argn7z9w8sjibd9q38.ls error="server returned 404: 404 page not found\n"16722026/07/19 09:59:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16732026/07/19 09:59:25 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.793299ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures16742026/07/19 09:59:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16752026/07/19 09:59:25 INFO Signed narinfos id=1 count=116762026/07/19 09:59:25 INFO Vacuumed table table=pending_objects16772026/07/19 09:59:25 INFO Uploading 1 narinfos16782026/07/19 09:59:25 INFO Vacuumed table table=multipart_uploads16792026/07/19 09:59:25 WARN Failed to register uploaded object key=4dkfcb9v1vg4b9argn7z9w8sjibd9q38.narinfo error="server returned 404: 404 page not found\n"16802026/07/19 09:59:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16812026/07/19 09:59:25 INFO Vacuumed table table=closures16822026/07/19 09:59:25 INFO Vacuumed table table=objects16832026/07/19 09:59:25 INFO Completed upload id=116842026/07/19 09:59:25 INFO Upload complete. (95ms)1685=== NAME TestClientIntegration1686 client_integration_test.go:292: Retrieved narinfo from S3:1687 StorePath: /build/TestClientIntegration1992298309/002/store/4dkfcb9v1vg4b9argn7z9w8sjibd9q38-test-file.txt1688 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1689 Compression: zstd1690 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11691 NarSize: 1521692 References: 1693 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11694 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1695 client_integration_test.go:293: Decompressed .ls content (64 bytes):1696 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1697 client_integration_test.go:296: Testing garbage collection...16982026/07/19 09:59:25 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZjI2NzdjMjMtZDk1OS00MWNkLTk0MDEtMDUyYmFkYmM4NjhhLmMzMTY2N2FhLWM3YzAtNDc4Yi1iZWViLTA4MDU1NmRkMGJkMHgxNzg0NDU1MTY0Nzk1MDk2MDE0 parts=1216992026/07/19 09:59:25 INFO Received uploads request method=POST path=/api/pending_closures17002026/07/19 09:59:25 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001701--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.67s)1702--- PASS: TestService_createPendingClosureHandler (0.67s)1703=== NAME TestClientCADerivations1704 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1705 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1706 error: binary cache 's3://bucket26?endpoint=http://localhost:40835®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1724482622/001/store'1707 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11708--- PASS: TestClientCADerivations (0.51s)17092026/07/19 09:59:25 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"17102026/07/19 09:59:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures17112026/07/19 09:59:25 INFO Garbage collection started17122026/07/19 09:59:25 INFO Aborted multipart uploads count=017132026/07/19 09:59:25 WARN Force mode enabled - objects will be deleted immediately without grace period1714--- PASS: TestGCBugBareHashReferences (0.42s)1715=== NAME TestOrphanedObjectsGC1716 orphaned_objects_gc_test.go:290: GC Test Summary:1717 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1718 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1719 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1720 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1721 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1722--- PASS: TestOrphanedObjectsGC (0.46s)17232026/07/19 09:59:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.20069ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17242026/07/19 09:59:25 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=821.123244ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17252026/07/19 09:59:25 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=017262026/07/19 09:59:25 INFO Vacuumed table table=pending_closures17272026/07/19 09:59:25 INFO Vacuumed table table=pending_objects17282026/07/19 09:59:25 INFO Vacuumed table table=multipart_uploads17292026/07/19 09:59:25 INFO Vacuumed table table=closures17302026/07/19 09:59:25 INFO Vacuumed table table=objects1731=== NAME TestOrphanedObjectsGCStressTest1732 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1733 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion17342026/07/19 09:59:26 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=017352026/07/19 09:59:26 INFO Vacuumed table table=pending_closures17362026/07/19 09:59:26 INFO Vacuumed table table=pending_objects17372026/07/19 09:59:26 INFO Vacuumed table table=multipart_uploads17382026/07/19 09:59:26 INFO Vacuumed table table=closures17392026/07/19 09:59:26 INFO Vacuumed table table=objects1740 orphaned_objects_gc_test.go:509: Stress test completed successfully:1741 orphaned_objects_gc_test.go:510: - Active objects preserved: 201742 orphaned_objects_gc_test.go:511: - Objects deleted: 2101743 orphaned_objects_gc_test.go:512: - Total GC'd: 2101744--- PASS: TestOrphanedObjectsGCStressTest (1.25s)1745--- PASS: TestUploadHandlersRejectOversizedBody (0.18s)1746 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.10s)1747 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.10s)1748 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.26s)17492026/07/19 09:59:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.589419556s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17502026/07/19 09:59:27 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01751=== NAME TestPinProtectsFromGC1752 client_integration_test.go:709: Pin successfully protected closure from garbage collection1753--- PASS: TestPinProtectsFromGC (2.68s)17542026/07/19 09:59:27 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01755=== NAME TestClientIntegration1756 client_integration_test.go:303: Objects in database after GC:1757 client_integration_test.go:303: Successfully deleted all objects with GC --force1758--- PASS: TestClientIntegration (2.42s)17592026/07/19 09:59:27 WARN Rate limiter enabled after throttle name=s3-test rate=517602026/07/19 09:59:27 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1761=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1762 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101763 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001764--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (2.75s)1765--- PASS: TestClientErrorHandling (0.10s)1766 --- PASS: TestClientErrorHandling/InvalidStorePath (0.19s)1767 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.29s)1768 --- PASS: TestClientErrorHandling/ServerNotAvailable (3.26s)1769PASS17702026-07-19 09:59:28.868 UTC [110] LOG: received smart shutdown request17712026-07-19 09:59:28.873 UTC [110] LOG: background worker "logical replication launcher" (PID 120) exited with exit code 117722026-07-19 09:59:28.885 UTC [115] LOG: shutting down17732026-07-19 09:59:28.885 UTC [115] LOG: checkpoint starting: shutdown immediate17742026-07-19 09:59:30.234 UTC [115] LOG: checkpoint complete: wrote 12731 buffers (77.7%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 13 recycled; write=0.241 s, sync=1.098 s, total=1.349 s; sync files=15167, longest=0.018 s, average=0.001 s; distance=208460 kB, estimate=208460 kB; lsn=0/E2F24B8, redo lsn=0/E2F24B817752026-07-19 09:59:30.342 UTC [110] LOG: database system is shut down1776Running OIDC tests...1777=== RUN TestGlobMatch1778=== PAUSE TestGlobMatch1779=== RUN TestAudienceForIssuer1780=== PAUSE TestAudienceForIssuer1781=== RUN TestValidateToken_ValidToken1782=== PAUSE TestValidateToken_ValidToken1783=== RUN TestValidateToken_WrongAudience1784=== PAUSE TestValidateToken_WrongAudience1785=== RUN TestValidateToken_Expired1786=== PAUSE TestValidateToken_Expired1787=== RUN TestValidateToken_BoundClaimsMismatch1788=== PAUSE TestValidateToken_BoundClaimsMismatch1789=== RUN TestValidateToken_BoundSubjectMismatch1790=== PAUSE TestValidateToken_BoundSubjectMismatch1791=== RUN TestValidateToken_MultipleProviders1792=== PAUSE TestValidateToken_MultipleProviders1793=== RUN TestValidateToken_NoMatchingProvider1794=== PAUSE TestValidateToken_NoMatchingProvider1795=== CONT TestGlobMatch1796=== RUN TestGlobMatch/foo_foo1797=== CONT TestValidateToken_Expired1798=== CONT TestValidateToken_BoundClaimsMismatch1799=== PAUSE TestGlobMatch/foo_foo1800=== CONT TestValidateToken_NoMatchingProvider1801=== RUN TestGlobMatch/foo_bar1802=== PAUSE TestGlobMatch/foo_bar1803=== RUN TestGlobMatch/*_1804=== PAUSE TestGlobMatch/*_1805=== RUN TestGlobMatch/*_anything1806=== PAUSE TestGlobMatch/*_anything1807=== RUN TestGlobMatch/foo*_foo1808=== CONT TestValidateToken_ValidToken1809=== CONT TestAudienceForIssuer1810--- PASS: TestAudienceForIssuer (0.00s)1811=== CONT TestValidateToken_WrongAudience1812=== CONT TestValidateToken_MultipleProviders1813=== CONT TestValidateToken_BoundSubjectMismatch1814=== PAUSE TestGlobMatch/foo*_foo1815=== RUN TestGlobMatch/foo*_foobar1816=== PAUSE TestGlobMatch/foo*_foobar1817=== RUN TestGlobMatch/foo*_bar1818=== PAUSE TestGlobMatch/foo*_bar1819=== RUN TestGlobMatch/*bar_bar1820=== PAUSE TestGlobMatch/*bar_bar1821=== RUN TestGlobMatch/*bar_foobar1822=== PAUSE TestGlobMatch/*bar_foobar1823=== RUN TestGlobMatch/*bar_foo1824=== PAUSE TestGlobMatch/*bar_foo1825=== RUN TestGlobMatch/foo*bar_foobar1826=== PAUSE TestGlobMatch/foo*bar_foobar1827=== RUN TestGlobMatch/foo*bar_foo123bar1828=== PAUSE TestGlobMatch/foo*bar_foo123bar1829=== RUN TestGlobMatch/foo*bar_foobarbaz1830=== PAUSE TestGlobMatch/foo*bar_foobarbaz1831=== RUN TestGlobMatch/*/*_foo/bar18322026/07/19 09:59:31 INFO OIDC provider initialized name=test1833=== PAUSE TestGlobMatch/*/*_foo/bar1834=== RUN TestGlobMatch/*/*_foo1835=== PAUSE TestGlobMatch/*/*_foo18362026/07/19 09:59:31 INFO OIDC provider initialized name=test1837=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1838=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1839=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01840=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.018412026/07/19 09:59:31 INFO OIDC provider initialized name=test1842=== RUN TestGlobMatch/refs/*/main_refs/heads/main1843=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1844=== RUN TestGlobMatch/fo?_foo1845=== PAUSE TestGlobMatch/fo?_foo1846=== RUN TestGlobMatch/fo?_fo1847=== PAUSE TestGlobMatch/fo?_fo1848=== RUN TestGlobMatch/fo?_fooo18492026/07/19 09:59:31 INFO OIDC provider initialized name=provider11850=== PAUSE TestGlobMatch/fo?_fooo1851=== RUN TestGlobMatch/?oo_foo1852=== PAUSE TestGlobMatch/?oo_foo1853=== RUN TestGlobMatch/?oo_boo1854=== PAUSE TestGlobMatch/?oo_boo18552026/07/19 09:59:31 INFO OIDC provider initialized name=test1856=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1857=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1858=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1859=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1860=== CONT TestGlobMatch/foo_foo18612026/07/19 09:59:31 INFO OIDC provider initialized name=provider11862=== CONT TestGlobMatch/*/*_foo/bar1863=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1864=== CONT TestGlobMatch/foo*_bar18652026/07/19 09:59:31 INFO OIDC provider initialized name=test1866=== CONT TestGlobMatch/fo?_foo1867=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1868=== CONT TestGlobMatch/*/*_foo1869=== CONT TestGlobMatch/fo?_fooo1870=== CONT TestGlobMatch/refs/*/main_refs/heads/main1871=== CONT TestGlobMatch/foo*_foobar1872=== CONT TestGlobMatch/foo*_foo1873=== CONT TestGlobMatch/*bar_bar1874=== CONT TestGlobMatch/*_anything1875=== CONT TestGlobMatch/foo*bar_foobarbaz1876=== CONT TestGlobMatch/*_1877=== CONT TestGlobMatch/foo*bar_foo123bar1878=== CONT TestGlobMatch/foo_bar1879=== CONT TestGlobMatch/foo*bar_foobar1880=== CONT TestGlobMatch/*bar_foo1881=== CONT TestGlobMatch/?oo_boo1882=== CONT TestGlobMatch/*bar_foobar1883=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1884=== CONT TestGlobMatch/fo?_fo1885=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01886=== CONT TestGlobMatch/?oo_foo1887--- PASS: TestGlobMatch (0.00s)1888 --- PASS: TestGlobMatch/foo_foo (0.00s)1889 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1890 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1891 --- PASS: TestGlobMatch/foo*_bar (0.00s)1892 --- PASS: TestGlobMatch/fo?_foo (0.00s)1893 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1894 --- PASS: TestGlobMatch/*/*_foo (0.00s)1895 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1896 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1897 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1898 --- PASS: TestGlobMatch/foo*_foo (0.00s)1899 --- PASS: TestGlobMatch/*bar_bar (0.00s)1900 --- PASS: TestGlobMatch/*_anything (0.00s)1901 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1902 --- PASS: TestGlobMatch/*_ (0.00s)1903 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1904 --- PASS: TestGlobMatch/foo_bar (0.00s)1905 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1906 --- PASS: TestGlobMatch/*bar_foo (0.00s)1907 --- PASS: TestGlobMatch/?oo_boo (0.00s)1908 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1909 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1910 --- PASS: TestGlobMatch/fo?_fo (0.00s)1911 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1912 --- PASS: TestGlobMatch/?oo_foo (0.00s)19132026/07/19 09:59:31 INFO OIDC provider initialized name=provider21914--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1915--- PASS: TestValidateToken_Expired (0.01s)1916--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1917--- PASS: TestValidateToken_WrongAudience (0.01s)1918--- PASS: TestValidateToken_ValidToken (0.01s)1919--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1920--- PASS: TestValidateToken_MultipleProviders (0.01s)1921PASS1922Running hook tests...1923=== RUN TestSendPathsEmpty1924=== PAUSE TestSendPathsEmpty1925=== RUN TestQueueEnqueueAndFetch1926=== PAUSE TestQueueEnqueueAndFetch1927=== RUN TestQueueDeduplication1928=== PAUSE TestQueueDeduplication1929=== RUN TestQueueRemove1930=== PAUSE TestQueueRemove1931=== RUN TestQueueFetchBatchLimit1932=== PAUSE TestQueueFetchBatchLimit1933=== RUN TestQueueFetchRemoveLifecycle1934=== PAUSE TestQueueFetchRemoveLifecycle1935=== RUN TestQueueConcurrentWriters1936=== PAUSE TestQueueConcurrentWriters1937=== RUN TestServerClientIntegration1938=== PAUSE TestServerClientIntegration1939=== RUN TestServerQueueError1940=== PAUSE TestServerQueueError1941=== RUN TestGetListenerSocketActivation1942 server_test.go:210: === RUN TestGetListenerSocketActivation1943 --- PASS: TestGetListenerSocketActivation (0.00s)1944 PASS1945 1946--- PASS: TestGetListenerSocketActivation (0.00s)1947=== RUN TestWorkerUploadsAndRemoves1948=== PAUSE TestWorkerUploadsAndRemoves1949=== RUN TestWorkerSkipsGCdPaths1950=== PAUSE TestWorkerSkipsGCdPaths1951=== RUN TestWorkerPrunesClosureDeps1952=== PAUSE TestWorkerPrunesClosureDeps1953=== CONT TestSendPathsEmpty1954--- PASS: TestSendPathsEmpty (0.00s)1955=== CONT TestQueueConcurrentWriters1956=== CONT TestServerQueueError1957=== CONT TestQueueFetchRemoveLifecycle1958=== CONT TestQueueFetchBatchLimit1959=== CONT TestQueueRemove1960=== CONT TestQueueDeduplication19612026/07/19 09:59:31 ERROR Failed to queue paths error="permission denied" count=11962=== CONT TestQueueEnqueueAndFetch1963=== CONT TestServerClientIntegration1964=== CONT TestWorkerPrunesClosureDeps1965=== CONT TestWorkerSkipsGCdPaths1966=== CONT TestWorkerUploadsAndRemoves1967--- PASS: TestServerQueueError (0.00s)1968--- PASS: TestServerClientIntegration (0.00s)19692026/07/19 09:59:31 INFO Upload queue status pending=219702026/07/19 09:59:31 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1430676426/002/nonexistent1971--- PASS: TestQueueRemove (0.01s)19722026/07/19 09:59:31 INFO Upload queue status pending=219732026/07/19 09:59:31 INFO Uploading batch count=11974--- PASS: TestQueueEnqueueAndFetch (0.01s)19752026/07/19 09:59:31 INFO Uploading batch count=11976--- PASS: TestQueueFetchBatchLimit (0.01s)1977--- PASS: TestQueueDeduplication (0.01s)1978--- PASS: TestQueueFetchRemoveLifecycle (0.01s)19792026/07/19 09:59:31 INFO Upload queue status pending=219802026/07/19 09:59:31 INFO Uploading batch count=21981--- PASS: TestWorkerSkipsGCdPaths (0.06s)1982--- PASS: TestWorkerPrunesClosureDeps (0.06s)1983--- PASS: TestWorkerUploadsAndRemoves (0.06s)1984--- PASS: TestQueueConcurrentWriters (0.21s)1985PASS