niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #136
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestCaseHackSuffix5=== PAUSE TestCaseHackSuffix6=== RUN TestFilterOversizedClosures7=== PAUSE TestFilterOversizedClosures8=== RUN TestPartSizeForNAR9=== PAUSE TestPartSizeForNAR10=== RUN TestUploadMultipart_SupersededByPeer11=== PAUSE TestUploadMultipart_SupersededByPeer12=== RUN TestDumpPathMatchesNix13=== PAUSE TestDumpPathMatchesNix14=== RUN TestDumpPathSingleFile15=== PAUSE TestDumpPathSingleFile16=== RUN TestDumpPathWriterError17=== PAUSE TestDumpPathWriterError18=== RUN TestEncodeNixBase3219=== PAUSE TestEncodeNixBase3220=== RUN TestEncodeNixBase32WithRealHash21=== PAUSE TestEncodeNixBase32WithRealHash22=== RUN TestConvertHashToNix3223=== PAUSE TestConvertHashToNix3224=== RUN TestGetStorePathHash25=== PAUSE TestGetStorePathHash26=== RUN TestPathInfoHashCompatibility27=== PAUSE TestPathInfoHashCompatibility28=== RUN TestParsePathInfoJSON29=== PAUSE TestParsePathInfoJSON30=== RUN TestParsePathInfoJSONMultiplePaths31=== PAUSE TestParsePathInfoJSONMultiplePaths32=== RUN TestPathInfoCACompatibility33=== PAUSE TestPathInfoCACompatibility34=== RUN TestRateLimiterFeedback35=== PAUSE TestRateLimiterFeedback36=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess37=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess38=== RUN TestResolveStorePath39=== PAUSE TestResolveStorePath40=== RUN TestDoWithRetry_BodyReplayedViaGetBody41=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody42=== RUN TestShellSplit43=== PAUSE TestShellSplit44=== RUN TestShellSplitErrors45=== PAUSE TestShellSplitErrors46=== RUN TestSetClientTLS47=== PAUSE TestSetClientTLS48=== RUN TestSetClientTLSDoesNotMutateDefaultTransport49=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport50=== RUN TestSetClientTLSErrors51=== PAUSE TestSetClientTLSErrors52=== RUN TestStaticToken53=== PAUSE TestStaticToken54=== RUN TestFileTokenReadsAndCaches55=== PAUSE TestFileTokenReadsAndCaches56=== RUN TestFileTokenMissing57=== PAUSE TestFileTokenMissing58=== RUN TestFileTokenEmpty59=== PAUSE TestFileTokenEmpty60=== RUN TestScriptTokenNoExpiryRerunsEveryCall61=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall62=== RUN TestScriptTokenCachesUntilRefresh63=== PAUSE TestScriptTokenCachesUntilRefresh64=== RUN TestScriptTokenEmptyToken65=== PAUSE TestScriptTokenEmptyToken66=== RUN TestScriptTokenBadJSON67=== PAUSE TestScriptTokenBadJSON68=== RUN TestScriptTokenScriptFails69=== PAUSE TestScriptTokenScriptFails70=== RUN TestScriptTokenEmptyCommand71=== PAUSE TestScriptTokenEmptyCommand72=== CONT TestDoServerRequestAttachesToken73=== CONT TestResolveStorePath74=== CONT TestEncodeNixBase32WithRealHash75=== CONT TestParsePathInfoJSONMultiplePaths76=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths77--- PASS: TestEncodeNixBase32WithRealHash (0.00s)78=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths79=== CONT TestParsePathInfoJSON80=== CONT TestDumpPathMatchesNix81=== CONT TestRateLimiterFeedback82=== RUN TestRateLimiterFeedback/429_enables_limiter83=== PAUSE TestRateLimiterFeedback/429_enables_limiter84=== RUN TestParsePathInfoJSON/Nix_format85=== RUN TestRateLimiterFeedback/503_enables_limiter86=== PAUSE TestRateLimiterFeedback/503_enables_limiter87=== PAUSE TestParsePathInfoJSON/Nix_format88=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter89=== RUN TestParsePathInfoJSON/Lix_format90=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter91=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter92=== PAUSE TestParsePathInfoJSON/Lix_format93=== CONT TestDumpPathWriterError94=== RUN TestParsePathInfoJSON/empty_input95=== PAUSE TestParsePathInfoJSON/empty_input96=== RUN TestParsePathInfoJSON/whitespace_only97=== PAUSE TestParsePathInfoJSON/whitespace_only98=== RUN TestParsePathInfoJSON/invalid_JSON99=== PAUSE TestParsePathInfoJSON/invalid_JSON100=== CONT TestParsePathInfoJSON/Nix_format101=== CONT TestGetStorePathHash102=== RUN TestGetStorePathHash/valid_store_path103=== PAUSE TestGetStorePathHash/valid_store_path104=== RUN TestGetStorePathHash/basename_without_hyphen_should_error105=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error106=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error107=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error108=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error109=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error110=== CONT TestGetStorePathHash/valid_store_path111=== CONT TestPathInfoHashCompatibility112=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)113=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)114=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon115=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon116=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI117=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI118=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512119=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512120=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)121=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter122=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess123=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error124=== CONT TestDumpPathSingleFile125=== CONT TestFilterOversizedClosures126=== RUN TestFilterOversizedClosures/no_limit_keeps_everything1272026/08/25 08:16:46 WARN Rate limiter enabled after throttle name=server-test rate=5128=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything129=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped130=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped131=== RUN TestFilterOversizedClosures/all_closures_skipped132=== PAUSE TestFilterOversizedClosures/all_closures_skipped133=== CONT TestUploadMultipart_SupersededByPeer134=== RUN TestUploadMultipart_SupersededByPeer/exists135=== PAUSE TestUploadMultipart_SupersededByPeer/exists136=== RUN TestUploadMultipart_SupersededByPeer/missing137=== PAUSE TestUploadMultipart_SupersededByPeer/missing138=== CONT TestPartSizeForNAR139=== RUN TestPartSizeForNAR/zero_stays_at_minimum140=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum141=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error142=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512143=== CONT TestGetStorePathHash/basename_without_hyphen_should_error144=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI145=== CONT TestPathInfoCACompatibility146=== CONT TestParsePathInfoJSON/invalid_JSON147=== RUN TestPathInfoCACompatibility/null_ca_field148=== PAUSE TestPathInfoCACompatibility/null_ca_field149=== RUN TestPathInfoCACompatibility/old_string_format_-_text150=== CONT TestConvertHashToNix32151=== RUN TestConvertHashToNix32/SRI_format_to_Nix32152=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32153=== RUN TestConvertHashToNix32/already_Nix32_format154=== PAUSE TestConvertHashToNix32/already_Nix32_format155=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text156=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive157=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive158=== RUN TestPathInfoCACompatibility/new_structured_format_-_text159=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text160=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method161=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method162=== CONT TestCaseHackSuffix163=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths164=== RUN TestPartSizeForNAR/small_stays_at_minimum165=== CONT TestRateLimiterFeedback/429_enables_limiter166--- PASS: TestResolveStorePath (0.00s)167--- PASS: TestGetStorePathHash (0.00s)168 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)169 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)170 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)171 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)172=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths173=== CONT TestParsePathInfoJSON/whitespace_only174--- PASS: TestDoServerRequestAttachesToken (0.00s)175=== CONT TestParsePathInfoJSON/empty_input176=== PAUSE TestPartSizeForNAR/small_stays_at_minimum177=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum178=== RUN TestConvertHashToNix32/invalid_format179=== PAUSE TestConvertHashToNix32/invalid_format180=== CONT TestParsePathInfoJSON/Lix_format181=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum1822026/08/25 08:16:46 WARN Rate limiter enabled after throttle name=server-test rate=51832026/08/25 08:16:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:52109184=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts185=== CONT TestFilterOversizedClosures/no_limit_keeps_everything186=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon187=== CONT TestUploadMultipart_SupersededByPeer/exists188=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts189=== RUN TestPartSizeForNAR/1_TiB190=== PAUSE TestPartSizeForNAR/1_TiB191=== RUN TestPartSizeForNAR/5_TiB_S3_max_object192=== CONT TestFilterOversizedClosures/all_closures_skipped193=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object194=== RUN TestPartSizeForNAR/capped_at_5_GiB195=== PAUSE TestPartSizeForNAR/capped_at_5_GiB1962026/08/25 08:16:46 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50197=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter198--- PASS: TestPathInfoHashCompatibility (0.00s)199 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)200 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)201 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)202 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)203=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2042026/08/25 08:16:46 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000205--- PASS: TestFilterOversizedClosures (0.00s)206 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)207 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)208 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)209=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter210--- PASS: TestParsePathInfoJSON (0.00s)211 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)212 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)213 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)214 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)215 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)216=== CONT TestRateLimiterFeedback/503_enables_limiter2172026/08/25 08:16:46 WARN Rate limiter backed off name=server-test rate=5218=== CONT TestScriptTokenEmptyCommand219--- PASS: TestScriptTokenEmptyCommand (0.00s)220=== CONT TestScriptTokenScriptFails221=== CONT TestScriptTokenBadJSON222=== CONT TestScriptTokenEmptyToken2232026/08/25 08:16:46 WARN Rate limiter enabled after throttle name=server-test rate=52242026/08/25 08:16:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:52117225=== CONT TestScriptTokenCachesUntilRefresh2262026/08/25 08:16:46 WARN Rate limiter backed off name=server-test rate=5227=== CONT TestScriptTokenNoExpiryRerunsEveryCall228--- PASS: TestRateLimiterFeedback (0.00s)229 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)230 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)231 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)232 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)233--- PASS: TestScriptTokenScriptFails (0.01s)234=== CONT TestFileTokenEmpty235--- PASS: TestFileTokenEmpty (0.00s)236=== CONT TestFileTokenMissing237--- PASS: TestFileTokenMissing (0.00s)238=== CONT TestFileTokenReadsAndCaches239--- PASS: TestFileTokenReadsAndCaches (0.00s)240=== CONT TestStaticToken241--- PASS: TestStaticToken (0.00s)242=== CONT TestSetClientTLSErrors243=== RUN TestSetClientTLSErrors/missing_cert_file244=== PAUSE TestSetClientTLSErrors/missing_cert_file245=== RUN TestSetClientTLSErrors/missing_key_file246=== PAUSE TestSetClientTLSErrors/missing_key_file247=== RUN TestSetClientTLSErrors/missing_ca_file248=== PAUSE TestSetClientTLSErrors/missing_ca_file249=== RUN TestSetClientTLSErrors/invalid_ca_file250=== PAUSE TestSetClientTLSErrors/invalid_ca_file251=== CONT TestSetClientTLSDoesNotMutateDefaultTransport252--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)253=== CONT TestSetClientTLS254=== RUN TestSetClientTLS/rejects_connection_without_client_cert255=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert256=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA257=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA258=== RUN TestSetClientTLS/preserves_debug_logging_transport259=== PAUSE TestSetClientTLS/preserves_debug_logging_transport260=== CONT TestShellSplitErrors261--- PASS: TestShellSplitErrors (0.00s)262=== CONT TestShellSplit263--- PASS: TestShellSplit (0.00s)264=== CONT TestDoWithRetry_BodyReplayedViaGetBody265--- PASS: TestScriptTokenEmptyToken (0.01s)266=== CONT TestUploadMultipart_SupersededByPeer/missing267--- PASS: TestScriptTokenBadJSON (0.01s)268=== CONT TestEncodeNixBase32269=== RUN TestEncodeNixBase32/test_string_hash270=== PAUSE TestEncodeNixBase32/test_string_hash271=== RUN TestEncodeNixBase32/empty_input272=== PAUSE TestEncodeNixBase32/empty_input273=== CONT TestPathInfoCACompatibility/null_ca_field274=== CONT TestPathInfoCACompatibility/new_structured_format_-_text275=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method276=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive277=== CONT TestPathInfoCACompatibility/old_string_format_-_text278--- PASS: TestPathInfoCACompatibility (0.00s)279 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)280 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)281 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)282 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)283 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)284=== CONT TestConvertHashToNix32/SRI_format_to_Nix32285=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths286=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths287--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)288 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)289 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)290=== CONT TestConvertHashToNix32/invalid_format291=== CONT TestConvertHashToNix32/already_Nix32_format292--- PASS: TestConvertHashToNix32 (0.00s)293 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)294 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)295 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)296=== CONT TestPartSizeForNAR/zero_stays_at_minimum297=== CONT TestPartSizeForNAR/5_TiB_S3_max_object298=== CONT TestPartSizeForNAR/capped_at_5_GiB299=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts300=== CONT TestPartSizeForNAR/1_TiB301=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum302=== CONT TestPartSizeForNAR/small_stays_at_minimum3032026/08/25 08:16:46 WARN Rate limiter enabled after throttle name=server-test rate=5304--- PASS: TestPartSizeForNAR (0.00s)305 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)306 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)307 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)308 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)309 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)310 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)311 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)312=== CONT TestSetClientTLSErrors/missing_cert_file3132026/08/25 08:16:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:52121314=== CONT TestSetClientTLSErrors/missing_ca_file3152026/08/25 08:16:46 WARN Rate limiter backed off name=server-test rate=53162026/08/25 08:16:46 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:52121317--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)318 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)319 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)320=== CONT TestSetClientTLSErrors/missing_key_file321=== CONT TestSetClientTLSErrors/invalid_ca_file322=== CONT TestSetClientTLS/rejects_connection_without_client_cert323--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)324=== CONT TestSetClientTLS/preserves_debug_logging_transport325=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA326--- PASS: TestSetClientTLSErrors (0.00s)327 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)328 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)329 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)330 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)331=== CONT TestEncodeNixBase32/test_string_hash332=== CONT TestEncodeNixBase32/empty_input333--- PASS: TestEncodeNixBase32 (0.00s)334 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)335 --- PASS: TestEncodeNixBase32/empty_input (0.00s)3362026/08/25 08:16:46 http: TLS handshake error from 127.0.0.1:52125: remote error: tls: bad certificate337--- PASS: TestSetClientTLS (0.00s)338 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)339 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)340 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)341--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)342--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)343--- PASS: TestDumpPathWriterError (0.04s)344--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)345--- PASS: TestDumpPathSingleFile (8.79s)346--- PASS: TestCaseHackSuffix (8.78s)347--- PASS: TestDumpPathMatchesNix (8.80s)348PASS349Running server tests...350The files belonging to this database system will be owned by user "_nixbld10".351This user must also own the server process.352353The database cluster will be initialized with locale "C".354The default database encoding has accordingly been set to "SQL_ASCII".355The default text search configuration will be set to "english".356357Data page checksums are enabled.358359creating directory /nix/var/nix/builds/nix-88322-2630525197/postgres2829311753/data ... ok360creating subdirectories ... ok361selecting dynamic shared memory implementation ... posix362selecting default "max_connections" ... 100363selecting default "shared_buffers" ... 128MB364selecting default time zone ... UTC365creating configuration files ... ok366running bootstrap script ... ok367performing post-bootstrap initialization ... ok368syncing data to disk ... ok369370initdb: warning: enabling "trust" authentication for local connections371initdb: 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.372373Success. You can now start the database server using:374375 pg_ctl -D /nix/var/nix/builds/nix-88322-2630525197/postgres2829311753/data -l logfile start3763772026-08-25 08:16:57.483 UTC [89598] LOG: starting PostgreSQL 18.4 on aarch64-apple-darwin25.5.0, compiled by clang version 21.1.8, 64-bit3782026-08-25 08:16:57.483 UTC [89598] LOG: listening on Unix socket "/nix/var/nix/builds/nix-88322-2630525197/postgres2829311753/.s.PGSQL.5432"3792026-08-25 08:16:57.486 UTC [89605] LOG: database system was shut down at 2026-08-25 08:16:57 UTC3802026-08-25 08:16:57.487 UTC [89598] LOG: database system is ready to accept connections381/nix/var/nix/builds/nix-88322-2630525197/postgres2829311753:5432 - accepting connections382=== RUN TestService_AuthMiddleware383=== PAUSE TestService_AuthMiddleware384=== RUN TestService_AuthMiddleware_MTLSProxyHeader385=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader386=== RUN TestService_AuthMiddleware_MTLSBoundSubjects387=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects388=== RUN TestService_ReadAuthMiddleware389=== PAUSE TestService_ReadAuthMiddleware390=== RUN TestService_AuthMiddleware_OIDC391=== PAUSE TestService_AuthMiddleware_OIDC392=== RUN TestCacheConfigHandler393=== PAUSE TestCacheConfigHandler394=== RUN TestCacheStatsHandler395=== PAUSE TestCacheStatsHandler396=== RUN TestClientCADerivations397=== PAUSE TestClientCADerivations398=== RUN TestClientErrorHandling399=== PAUSE TestClientErrorHandling400=== RUN TestClientIntegration401=== PAUSE TestClientIntegration402=== RUN TestClientMultipleUploads403=== PAUSE TestClientMultipleUploads404=== RUN TestClientWithDependencies405=== PAUSE TestClientWithDependencies406=== RUN TestPinProtectsFromGC407=== PAUSE TestPinProtectsFromGC408=== RUN TestGCAdvisoryLockBlocksConcurrentRun4092026-08-25 08:16:59.605 UTC [89719] ERROR: relation "goose_db_version" does not exist at character 364102026-08-25 08:16:59.605 UTC [89719] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4112026/08/25 08:16:59 OK 20241026095416_initial_model.sql (3.54ms)4122026/08/25 08:16:59 OK 20251210153512_drop_unused_gin_index.sql (522.21µs)4132026/08/25 08:16:59 OK 20251218171726_add_pins.sql (882.67µs)4142026/08/25 08:16:59 OK 20260628120000_add_object_size_and_stats.sql (867.38µs)4152026/08/25 08:16:59 goose: successfully migrated database to version: 202606281200004162026/08/25 08:16:59 OK 1_commit_pending_closure.sql (927.54µs)4172026/08/25 08:16:59 OK 2_object_stats_trigger.sql (213.92µs)4182026/08/25 08:16:59 goose: up to current file version: 2419--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.35s)420=== RUN TestGCBugBareHashReferences421=== PAUSE TestGCBugBareHashReferences422=== RUN TestGCMetrics423=== PAUSE TestGCMetrics424=== RUN TestGCTaskStore_StartNew425=== PAUSE TestGCTaskStore_StartNew426=== RUN TestGCTaskStore_DeduplicateSameParams427=== PAUSE TestGCTaskStore_DeduplicateSameParams428=== RUN TestGCTaskStore_ConflictDifferentParams429=== PAUSE TestGCTaskStore_ConflictDifferentParams430=== RUN TestGCTaskStore_GetEmpty431=== PAUSE TestGCTaskStore_GetEmpty432=== RUN TestGCTaskStore_GetReturnsLatest433=== PAUSE TestGCTaskStore_GetReturnsLatest434=== RUN TestGCTaskStore_CompletedAllowsNewTask435=== PAUSE TestGCTaskStore_CompletedAllowsNewTask436=== RUN TestGCTaskStore_PhaseUpdates437=== PAUSE TestGCTaskStore_PhaseUpdates438=== RUN TestGCTaskStore_Fail439=== PAUSE TestGCTaskStore_Fail440=== RUN TestGracefulShutdownDrainsInflight441=== PAUSE TestGracefulShutdownDrainsInflight442=== RUN TestService_healthCheckHandler443=== PAUSE TestService_healthCheckHandler444=== RUN TestGenerateLandingPage445=== PAUSE TestGenerateLandingPage446=== RUN TestCacheConfigHandlerMaxNarSize447=== PAUSE TestCacheConfigHandlerMaxNarSize448=== RUN TestCreatePendingClosureRejectsOversizedNAR449=== PAUSE TestCreatePendingClosureRejectsOversizedNAR450=== RUN TestNARDeduplicationMetadataUploadBug451=== PAUSE TestNARDeduplicationMetadataUploadBug452=== RUN TestMetricsInventory453=== PAUSE TestMetricsInventory454=== RUN TestService_NativeMTLS455=== PAUSE TestService_NativeMTLS456=== RUN TestServerTLSConfig457=== PAUSE TestServerTLSConfig458=== RUN TestMultipartCleanup459=== PAUSE TestMultipartCleanup460=== RUN TestObjectStatsTrigger461=== PAUSE TestObjectStatsTrigger462=== RUN TestOrphanedObjectsGC463=== PAUSE TestOrphanedObjectsGC464=== RUN TestOrphanedObjectsGCStressTest465=== PAUSE TestOrphanedObjectsGCStressTest466=== RUN TestResurrectedObjectNotDeleted467=== PAUSE TestResurrectedObjectNotDeleted468=== RUN TestParseSingleRange469=== PAUSE TestParseSingleRange470=== RUN TestIsValidCachePath471=== PAUSE TestIsValidCachePath472=== RUN TestReadProxyNarinfo473=== PAUSE TestReadProxyNarinfo474=== RUN TestReadProxyNarinfoAlreadyDecompressed475=== PAUSE TestReadProxyNarinfoAlreadyDecompressed476=== RUN TestReadProxyNarStreaming477=== PAUSE TestReadProxyNarStreaming478=== RUN TestReadProxy404479=== PAUSE TestReadProxy404480=== RUN TestReadProxyInvalidPath481=== PAUSE TestReadProxyInvalidPath482=== RUN TestReadProxyHead483=== PAUSE TestReadProxyHead484=== RUN TestReadProxyConditionalGet485=== PAUSE TestReadProxyConditionalGet486=== RUN TestReadProxyRootRedirectsToIndexHTML487=== PAUSE TestReadProxyRootRedirectsToIndexHTML488=== RUN TestReadProxyDisabled489=== PAUSE TestReadProxyDisabled490=== RUN TestReadProxyRangeRequest491=== PAUSE TestReadProxyRangeRequest492=== RUN TestRedundantMultipartUpload493=== PAUSE TestRedundantMultipartUpload494=== RUN TestCompleteMultipartUpload_ErrorButObjectExists495=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists496=== RUN TestCompletedNarNotReofferedAcrossClosures497=== PAUSE TestCompletedNarNotReofferedAcrossClosures498=== RUN TestPresignedUploadRegisteredBeforeCommit499=== PAUSE TestPresignedUploadRegisteredBeforeCommit500=== RUN TestService_Rustfstest501=== PAUSE TestService_Rustfstest502=== RUN TestParseSize503=== PAUSE TestParseSize504=== RUN TestSkippedUploadsHandler505=== PAUSE TestSkippedUploadsHandler506=== RUN TestSystemdListenerNotActivated507--- PASS: TestSystemdListenerNotActivated (0.00s)508=== RUN TestWatchdogBeatsWhenHealthy509--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)510=== RUN TestWatchdogSkipsWhenUnhealthy5112026/08/25 08:16:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5122026/08/25 08:16:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5132026/08/25 08:16:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5142026/08/25 08:16:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5152026/08/25 08:16:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5162026/08/25 08:16:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5172026/08/25 08:16:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5182026/08/25 08:16:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5192026/08/25 08:16:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5202026/08/25 08:16:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"521--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)522=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle523=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle524=== RUN TestProxyWriteTimeout525=== PAUSE TestProxyWriteTimeout526=== RUN TestIsValidUploadKey527=== PAUSE TestIsValidUploadKey528=== RUN TestUploadHandlersRejectInvalidKeys529=== PAUSE TestUploadHandlersRejectInvalidKeys530=== RUN TestUploadHandlersRejectOversizedBody531=== PAUSE TestUploadHandlersRejectOversizedBody532=== RUN TestService_cleanupPendingClosuresHandler533=== PAUSE TestService_cleanupPendingClosuresHandler534=== RUN TestService_createPendingClosureHandler535=== PAUSE TestService_createPendingClosureHandler536=== RUN TestService_verifyS3Integrity537=== PAUSE TestService_verifyS3Integrity538=== RUN TestCompleteMultipartUnregistered539=== PAUSE TestCompleteMultipartUnregistered540=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT541=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT542=== CONT TestService_AuthMiddleware543=== CONT TestObjectStatsTrigger544=== CONT TestCompleteMultipartUpload_ErrorButObjectExists545=== CONT TestReadProxy404546=== CONT TestIsValidUploadKey547=== RUN TestIsValidUploadKey/narinfo548=== CONT TestGCTaskStore_ConflictDifferentParams549=== PAUSE TestIsValidUploadKey/narinfo550--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)551=== RUN TestIsValidUploadKey/nar_zst552=== CONT TestService_NativeMTLS553=== PAUSE TestIsValidUploadKey/nar_zst554=== CONT TestMultipartCleanup555=== CONT TestProxyWriteTimeout556=== RUN TestProxyWriteTimeout/narinfo557=== PAUSE TestProxyWriteTimeout/narinfo558=== RUN TestProxyWriteTimeout/1_GiB_nar559=== PAUSE TestProxyWriteTimeout/1_GiB_nar560=== CONT TestServerTLSConfig561=== RUN TestServerTLSConfig/no_client_CA562=== RUN TestIsValidUploadKey/nar_xz563=== RUN TestProxyWriteTimeout/10_GiB_nar564=== PAUSE TestServerTLSConfig/no_client_CA565=== PAUSE TestProxyWriteTimeout/10_GiB_nar566=== RUN TestServerTLSConfig/missing_CA_file567=== PAUSE TestIsValidUploadKey/nar_xz568=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle569=== PAUSE TestServerTLSConfig/missing_CA_file570=== RUN TestProxyWriteTimeout/unknown_size571=== PAUSE TestProxyWriteTimeout/unknown_size572=== RUN TestIsValidUploadKey/nar_plain573=== PAUSE TestIsValidUploadKey/nar_plain574=== RUN TestIsValidUploadKey/listing575=== PAUSE TestIsValidUploadKey/listing576=== RUN TestIsValidUploadKey/build_log577=== PAUSE TestIsValidUploadKey/build_log578=== RUN TestIsValidUploadKey/build_log_home-manager_file579=== PAUSE TestIsValidUploadKey/build_log_home-manager_file580=== RUN TestIsValidUploadKey/build_log_plus_in_name581=== PAUSE TestIsValidUploadKey/build_log_plus_in_name582=== RUN TestIsValidUploadKey/build_log_question_mark583=== PAUSE TestIsValidUploadKey/build_log_question_mark584=== RUN TestIsValidUploadKey/build_log_equals585=== PAUSE TestIsValidUploadKey/build_log_equals586=== RUN TestIsValidUploadKey/realisation587=== PAUSE TestIsValidUploadKey/realisation588=== RUN TestIsValidUploadKey/realisation_plus_in_output589=== PAUSE TestIsValidUploadKey/realisation_plus_in_output590=== RUN TestIsValidUploadKey/nix-cache-info591=== PAUSE TestIsValidUploadKey/nix-cache-info592=== RUN TestIsValidUploadKey/index.html593=== PAUSE TestIsValidUploadKey/index.html594=== RUN TestIsValidUploadKey/narinfo_key,_nar_type595=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type596=== RUN TestIsValidUploadKey/nar_key,_narinfo_type597=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type598=== RUN TestIsValidUploadKey/listing_key,_narinfo_type599=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type600=== RUN TestIsValidUploadKey/traversal601=== PAUSE TestIsValidUploadKey/traversal602=== RUN TestIsValidUploadKey/traversal_nar603=== PAUSE TestIsValidUploadKey/traversal_nar604=== RUN TestIsValidUploadKey/absolute605=== PAUSE TestIsValidUploadKey/absolute606=== RUN TestIsValidUploadKey/empty_key607=== PAUSE TestIsValidUploadKey/empty_key608=== RUN TestIsValidUploadKey/unknown_type609=== PAUSE TestIsValidUploadKey/unknown_type610=== RUN TestServerTLSConfig/not_a_PEM_file611=== PAUSE TestServerTLSConfig/not_a_PEM_file612=== CONT TestSkippedUploadsHandler613=== CONT TestParseSize614=== CONT TestService_Rustfstest615--- PASS: TestParseSize (0.00s)616=== CONT TestPresignedUploadRegisteredBeforeCommit6172026/08/25 08:16:59 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000618--- PASS: TestSkippedUploadsHandler (0.01s)619=== CONT TestCompletedNarNotReofferedAcrossClosures6202026-08-25 08:17:00.198 UTC [89744] ERROR: relation "goose_db_version" does not exist at character 366212026-08-25 08:17:00.198 UTC [89744] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6222026-08-25 08:17:00.203 UTC [89745] ERROR: relation "goose_db_version" does not exist at character 366232026-08-25 08:17:00.203 UTC [89745] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6242026-08-25 08:17:00.205 UTC [89746] ERROR: relation "goose_db_version" does not exist at character 366252026-08-25 08:17:00.205 UTC [89746] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6262026-08-25 08:17:00.206 UTC [89747] ERROR: relation "goose_db_version" does not exist at character 366272026-08-25 08:17:00.206 UTC [89747] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6282026-08-25 08:17:00.208 UTC [89748] ERROR: relation "goose_db_version" does not exist at character 366292026-08-25 08:17:00.208 UTC [89748] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6302026-08-25 08:17:00.208 UTC [89750] ERROR: relation "goose_db_version" does not exist at character 366312026-08-25 08:17:00.208 UTC [89750] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6322026-08-25 08:17:00.208 UTC [89749] ERROR: relation "goose_db_version" does not exist at character 366332026-08-25 08:17:00.208 UTC [89749] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6342026-08-25 08:17:00.209 UTC [89752] ERROR: relation "goose_db_version" does not exist at character 366352026-08-25 08:17:00.209 UTC [89752] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6362026-08-25 08:17:00.210 UTC [89751] ERROR: relation "goose_db_version" does not exist at character 366372026-08-25 08:17:00.210 UTC [89751] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6382026/08/25 08:17:00 OK 20241026095416_initial_model.sql (5.91ms)6392026-08-25 08:17:00.212 UTC [89753] ERROR: relation "goose_db_version" does not exist at character 366402026-08-25 08:17:00.212 UTC [89753] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6412026/08/25 08:17:00 OK 20251210153512_drop_unused_gin_index.sql (820.75µs)6422026/08/25 08:17:00 OK 20251218171726_add_pins.sql (2.41ms)6432026/08/25 08:17:00 OK 20241026095416_initial_model.sql (6.49ms)6442026/08/25 08:17:00 OK 20241026095416_initial_model.sql (7.4ms)6452026/08/25 08:17:00 OK 20251210153512_drop_unused_gin_index.sql (820.46µs)6462026/08/25 08:17:00 OK 20251210153512_drop_unused_gin_index.sql (786.21µs)6472026/08/25 08:17:00 OK 20260628120000_add_object_size_and_stats.sql (1.89ms)6482026/08/25 08:17:00 goose: successfully migrated database to version: 202606281200006492026/08/25 08:17:00 OK 20241026095416_initial_model.sql (8.19ms)6502026/08/25 08:17:00 OK 20251218171726_add_pins.sql (1.94ms)6512026/08/25 08:17:00 OK 20241026095416_initial_model.sql (6.91ms)6522026/08/25 08:17:00 OK 1_commit_pending_closure.sql (1.65ms)6532026/08/25 08:17:00 OK 20251218171726_add_pins.sql (2.04ms)6542026/08/25 08:17:00 OK 20251210153512_drop_unused_gin_index.sql (1.11ms)6552026/08/25 08:17:00 OK 20241026095416_initial_model.sql (7.74ms)6562026/08/25 08:17:00 OK 2_object_stats_trigger.sql (460.75µs)6572026/08/25 08:17:00 goose: up to current file version: 26582026/08/25 08:17:00 OK 20251210153512_drop_unused_gin_index.sql (1.08ms)6592026/08/25 08:17:00 OK 20241026095416_initial_model.sql (6.73ms)6602026/08/25 08:17:00 OK 20241026095416_initial_model.sql (7.57ms)6612026/08/25 08:17:00 OK 20260628120000_add_object_size_and_stats.sql (1.52ms)6622026/08/25 08:17:00 goose: successfully migrated database to version: 202606281200006632026/08/25 08:17:00 OK 20260628120000_add_object_size_and_stats.sql (1.13ms)6642026/08/25 08:17:00 goose: successfully migrated database to version: 202606281200006652026/08/25 08:17:00 OK 20251210153512_drop_unused_gin_index.sql (974.04µs)6662026/08/25 08:17:00 OK 20251210153512_drop_unused_gin_index.sql (782µs)6672026/08/25 08:17:00 OK 20251210153512_drop_unused_gin_index.sql (803.58µs)6682026/08/25 08:17:00 OK 20251218171726_add_pins.sql (1.18ms)6692026/08/25 08:17:00 OK 20251218171726_add_pins.sql (2.09ms)6702026/08/25 08:17:00 OK 20241026095416_initial_model.sql (8.49ms)6712026/08/25 08:17:00 OK 1_commit_pending_closure.sql (1.54ms)6722026/08/25 08:17:00 OK 1_commit_pending_closure.sql (1.53ms)6732026/08/25 08:17:00 OK 2_object_stats_trigger.sql (397.17µs)6742026/08/25 08:17:00 goose: up to current file version: 26752026/08/25 08:17:00 OK 2_object_stats_trigger.sql (619.29µs)6762026/08/25 08:17:00 goose: up to current file version: 26772026/08/25 08:17:00 OK 20251218171726_add_pins.sql (1.53ms)6782026/08/25 08:17:00 OK 20260628120000_add_object_size_and_stats.sql (1.47ms)6792026/08/25 08:17:00 goose: successfully migrated database to version: 202606281200006802026/08/25 08:17:00 OK 20241026095416_initial_model.sql (6.85ms)6812026/08/25 08:17:00 OK 20251218171726_add_pins.sql (1.76ms)6822026/08/25 08:17:00 OK 20251218171726_add_pins.sql (2.19ms)6832026/08/25 08:17:00 OK 20251210153512_drop_unused_gin_index.sql (7.17ms)6842026/08/25 08:17:00 OK 20251210153512_drop_unused_gin_index.sql (6.45ms)6852026/08/25 08:17:00 OK 20260628120000_add_object_size_and_stats.sql (8.04ms)6862026/08/25 08:17:00 goose: successfully migrated database to version: 202606281200006872026/08/25 08:17:00 OK 1_commit_pending_closure.sql (7.56ms)6882026/08/25 08:17:00 OK 2_object_stats_trigger.sql (207.08µs)6892026/08/25 08:17:00 goose: up to current file version: 26902026/08/25 08:17:00 OK 20260628120000_add_object_size_and_stats.sql (42.03ms)6912026/08/25 08:17:00 goose: successfully migrated database to version: 202606281200006922026/08/25 08:17:00 OK 20251218171726_add_pins.sql (36.13ms)6932026/08/25 08:17:00 OK 20260628120000_add_object_size_and_stats.sql (42.96ms)6942026/08/25 08:17:00 goose: successfully migrated database to version: 202606281200006952026/08/25 08:17:00 OK 20260628120000_add_object_size_and_stats.sql (42.79ms)6962026/08/25 08:17:00 goose: successfully migrated database to version: 202606281200006972026/08/25 08:17:00 OK 1_commit_pending_closure.sql (36.18ms)6982026/08/25 08:17:00 OK 2_object_stats_trigger.sql (199.92µs)6992026/08/25 08:17:00 goose: up to current file version: 27002026/08/25 08:17:00 OK 1_commit_pending_closure.sql (1.08ms)7012026/08/25 08:17:00 OK 2_object_stats_trigger.sql (199.25µs)7022026/08/25 08:17:00 goose: up to current file version: 27032026/08/25 08:17:00 OK 20251218171726_add_pins.sql (41.83ms)7042026/08/25 08:17:00 OK 1_commit_pending_closure.sql (5.55ms)7052026/08/25 08:17:00 OK 2_object_stats_trigger.sql (178.42µs)7062026/08/25 08:17:00 goose: up to current file version: 27072026/08/25 08:17:00 OK 1_commit_pending_closure.sql (5.9ms)7082026/08/25 08:17:00 OK 2_object_stats_trigger.sql (180.54µs)7092026/08/25 08:17:00 goose: up to current file version: 27102026/08/25 08:17:00 OK 20260628120000_add_object_size_and_stats.sql (11.64ms)7112026/08/25 08:17:00 goose: successfully migrated database to version: 202606281200007122026/08/25 08:17:00 OK 1_commit_pending_closure.sql (1.21ms)7132026/08/25 08:17:00 OK 2_object_stats_trigger.sql (177.13µs)7142026/08/25 08:17:00 goose: up to current file version: 2715{"timestamp":"2026-08-25T08:17:00.279144Z","level":"ERROR","duration":"119.458µs","resp":"Response { status: 503, version: HTTP/1.1, headers: {\"content-type\": \"application/xml\"}, body: Body { once: b\"<?xml version=\\\"1.0\\\" encoding=\\\"UTF-8\\\"?><Error><Code>SlowDown</Code><Message>bucket creation concurrency limit reached; retry later</Message></Error>\" } }","target":"s3s::service","filename":"/nix/var/nix/builds/nix-57705-2947227838/rustfs-1.0.0-beta.12-vendor/source-git-1/s3s-0.14.1/src/service.rs","line_number":640,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}716{"timestamp":"2026-08-25T08:17:00.279344Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"79fd430a-4099-4a5f-8f5c-897ac99f5f82","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket10/","status_code":503,"duration_ms":0,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}7172026/08/25 08:17:00 OK 20260628120000_add_object_size_and_stats.sql (12.56ms)7182026/08/25 08:17:00 goose: successfully migrated database to version: 202606281200007192026/08/25 08:17:00 OK 1_commit_pending_closure.sql (1.42ms)7202026/08/25 08:17:00 OK 2_object_stats_trigger.sql (196.38µs)7212026/08/25 08:17:00 goose: up to current file version: 2722{"timestamp":"2026-08-25T08:17:00.286208Z","level":"ERROR","duration":"64.5µs","resp":"Response { status: 503, version: HTTP/1.1, headers: {\"content-type\": \"application/xml\"}, body: Body { once: b\"<?xml version=\\\"1.0\\\" encoding=\\\"UTF-8\\\"?><Error><Code>SlowDown</Code><Message>bucket creation concurrency limit reached; retry later</Message></Error>\" } }","target":"s3s::service","filename":"/nix/var/nix/builds/nix-57705-2947227838/rustfs-1.0.0-beta.12-vendor/source-git-1/s3s-0.14.1/src/service.rs","line_number":640,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}723{"timestamp":"2026-08-25T08:17:00.286223Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"85adacf4-efa0-4481-a9bd-7a8bf8bf72e5","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket11/","status_code":503,"duration_ms":0,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}724--- PASS: TestObjectStatsTrigger (0.44s)725=== CONT TestCompleteMultipartUnregistered7262026/08/25 08:17:00 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"727--- PASS: TestService_AuthMiddleware (0.49s)728=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT7292026/08/25 08:17:00 INFO Received uploads request method=POST path=/api/pending_closures7302026/08/25 08:17:00 INFO Received uploads request method=POST path=/api/pending_closures731--- PASS: TestService_Rustfstest (0.67s)732=== CONT TestUploadHandlersRejectOversizedBody733=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure734=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure735=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart736=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart737=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts738=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts739=== CONT TestService_cleanupPendingClosuresHandler7402026/08/25 08:17:00 INFO Received cleanup request method=DELETE path=/api/pending_closures7412026/08/25 08:17:00 INFO Aborted multipart uploads count=1742--- PASS: TestMultipartCleanup (0.74s)743=== CONT TestClientIntegration744--- PASS: TestReadProxy404 (0.75s)745=== CONT TestGCTaskStore_DeduplicateSameParams746--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)747=== CONT TestGCTaskStore_StartNew748--- PASS: TestGCTaskStore_StartNew (0.00s)749=== CONT TestGCMetrics7502026/08/25 08:17:00 INFO Received uploads request method=POST path=/api/pending_closures7512026/08/25 08:17:00 INFO Received uploads request method=POST path=/api/pending_closures7522026/08/25 08:17:00 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7532026/08/25 08:17:00 INFO Received uploads request method=POST path=/api/pending_closures754--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.89s)755=== CONT TestGCBugBareHashReferences7562026/08/25 08:17:00 INFO Received uploads request method=POST path=/api/pending_closures7572026/08/25 08:17:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"7582026/08/25 08:17:01 WARN mTLS auth: subject not in bound subjects subject="CN=writer"759--- PASS: TestService_NativeMTLS (1.12s)760=== CONT TestPinProtectsFromGC7612026/08/25 08:17:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7622026/08/25 08:17:01 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmQxZjM4MzQtNzZmMy00MzEzLWE0NGYtYjg1OGE0NTdiYjBmLmEyZTdjZWZhLWYwNjQtNDU0ZS05YmVmLTFmNzNlMzIxZmM2NXgxNzg3NjQ1ODIwNzg2OTA2MDAw7632026/08/25 08:17:01 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmQxZjM4MzQtNzZmMy00MzEzLWE0NGYtYjg1OGE0NTdiYjBmLmEyZTdjZWZhLWYwNjQtNDU0ZS05YmVmLTFmNzNlMzIxZmM2NXgxNzg3NjQ1ODIwNzg2OTA2MDAw parts=1764--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.22s)765=== CONT TestClientWithDependencies7662026/08/25 08:17:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7672026-08-25 08:17:01.846 UTC [89770] ERROR: relation "goose_db_version" does not exist at character 367682026-08-25 08:17:01.846 UTC [89770] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7692026-08-25 08:17:01.950 UTC [89771] ERROR: relation "goose_db_version" does not exist at character 367702026-08-25 08:17:01.950 UTC [89771] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7712026/08/25 08:17:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7722026/08/25 08:17:02 OK 20241026095416_initial_model.sql (175.26ms)7732026/08/25 08:17:02 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZmQxZjM4MzQtNzZmMy00MzEzLWE0NGYtYjg1OGE0NTdiYjBmLmQzNTg5M2YzLTQ2MWYtNGNjMi04OWIwLWI1ZWVmY2Q0OThlZHgxNzg3NjQ1ODIwNTIwNzAyMDAw parts=127742026/08/25 08:17:02 INFO Received uploads request method=POST path=/api/pending_closures775--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.18s)776=== CONT TestClientMultipleUploads7772026/08/25 08:17:02 OK 20251210153512_drop_unused_gin_index.sql (9.64ms)7782026/08/25 08:17:02 OK 20251218171726_add_pins.sql (13.26ms)7792026/08/25 08:17:02 OK 20241026095416_initial_model.sql (83.94ms)7802026/08/25 08:17:02 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)7812026/08/25 08:17:02 OK 20251218171726_add_pins.sql (3.24ms)7822026/08/25 08:17:02 OK 20260628120000_add_object_size_and_stats.sql (20.09ms)7832026/08/25 08:17:02 goose: successfully migrated database to version: 202606281200007842026/08/25 08:17:02 OK 1_commit_pending_closure.sql (2.38ms)7852026/08/25 08:17:02 OK 2_object_stats_trigger.sql (383.13µs)7862026/08/25 08:17:02 goose: up to current file version: 27872026/08/25 08:17:02 OK 20260628120000_add_object_size_and_stats.sql (32.41ms)7882026/08/25 08:17:02 goose: successfully migrated database to version: 202606281200007892026/08/25 08:17:02 OK 1_commit_pending_closure.sql (6.57ms)7902026/08/25 08:17:02 OK 2_object_stats_trigger.sql (388.13µs)7912026/08/25 08:17:02 goose: up to current file version: 27922026-08-25 08:17:02.190 UTC [89774] ERROR: relation "goose_db_version" does not exist at character 367932026-08-25 08:17:02.190 UTC [89774] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7942026-08-25 08:17:02.206 UTC [89776] ERROR: relation "goose_db_version" does not exist at character 367952026-08-25 08:17:02.206 UTC [89776] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7962026-08-25 08:17:02.223 UTC [89775] ERROR: relation "goose_db_version" does not exist at character 367972026-08-25 08:17:02.223 UTC [89775] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7982026-08-25 08:17:02.286 UTC [89777] ERROR: relation "goose_db_version" does not exist at character 367992026-08-25 08:17:02.286 UTC [89777] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8002026/08/25 08:17:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8012026/08/25 08:17:02 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst802--- PASS: TestCompleteMultipartUnregistered (1.95s)803=== CONT TestUploadHandlersRejectInvalidKeys804=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info805=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info806=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal807=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal808=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key809=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key810=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key811=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key812=== CONT TestCacheConfigHandler813=== RUN TestCacheConfigHandler/full_config,_no_issuer814=== PAUSE TestCacheConfigHandler/full_config,_no_issuer815=== RUN TestCacheConfigHandler/no_cache_url_configured816=== PAUSE TestCacheConfigHandler/no_cache_url_configured817=== RUN TestCacheConfigHandler/no_signing_keys818=== PAUSE TestCacheConfigHandler/no_signing_keys819=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator820=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator821=== CONT TestClientErrorHandling822=== RUN TestClientErrorHandling/InvalidStorePath823=== PAUSE TestClientErrorHandling/InvalidStorePath824=== RUN TestClientErrorHandling/InvalidAuthToken825=== PAUSE TestClientErrorHandling/InvalidAuthToken826=== RUN TestClientErrorHandling/ServerNotAvailable827=== PAUSE TestClientErrorHandling/ServerNotAvailable828=== CONT TestClientCADerivations8292026/08/25 08:17:02 INFO Received uploads request method=POST path=/api/pending_closures8302026/08/25 08:17:02 OK 20241026095416_initial_model.sql (130.48ms)8312026/08/25 08:17:02 OK 20251210153512_drop_unused_gin_index.sql (12.48ms)832--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.02s)833=== CONT TestCacheStatsHandler8342026/08/25 08:17:02 OK 20241026095416_initial_model.sql (121.25ms)8352026/08/25 08:17:02 OK 20241026095416_initial_model.sql (136.1ms)8362026/08/25 08:17:02 OK 20251218171726_add_pins.sql (21.93ms)8372026/08/25 08:17:02 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)8382026/08/25 08:17:02 OK 20251210153512_drop_unused_gin_index.sql (1.54ms)8392026/08/25 08:17:02 OK 20241026095416_initial_model.sql (82.52ms)8402026/08/25 08:17:02 OK 20251210153512_drop_unused_gin_index.sql (9.07ms)8412026/08/25 08:17:02 OK 20251218171726_add_pins.sql (11.51ms)8422026/08/25 08:17:02 OK 20251218171726_add_pins.sql (18.45ms)8432026/08/25 08:17:02 OK 20260628120000_add_object_size_and_stats.sql (19.89ms)8442026/08/25 08:17:02 goose: successfully migrated database to version: 202606281200008452026/08/25 08:17:02 OK 1_commit_pending_closure.sql (6.95ms)8462026/08/25 08:17:02 OK 2_object_stats_trigger.sql (487.17µs)8472026/08/25 08:17:02 goose: up to current file version: 28482026/08/25 08:17:02 OK 20251218171726_add_pins.sql (21.55ms)8492026/08/25 08:17:02 OK 20260628120000_add_object_size_and_stats.sql (29.2ms)8502026/08/25 08:17:02 goose: successfully migrated database to version: 202606281200008512026/08/25 08:17:02 OK 20260628120000_add_object_size_and_stats.sql (23.59ms)8522026/08/25 08:17:02 goose: successfully migrated database to version: 202606281200008532026/08/25 08:17:02 OK 1_commit_pending_closure.sql (2.85ms)8542026/08/25 08:17:02 OK 2_object_stats_trigger.sql (470.17µs)8552026/08/25 08:17:02 goose: up to current file version: 28562026/08/25 08:17:02 OK 1_commit_pending_closure.sql (10.52ms)8572026/08/25 08:17:02 OK 2_object_stats_trigger.sql (829.25µs)8582026/08/25 08:17:02 goose: up to current file version: 28592026/08/25 08:17:02 OK 20260628120000_add_object_size_and_stats.sql (39.53ms)8602026/08/25 08:17:02 goose: successfully migrated database to version: 202606281200008612026/08/25 08:17:02 OK 1_commit_pending_closure.sql (6.75ms)8622026/08/25 08:17:02 OK 2_object_stats_trigger.sql (632.75µs)8632026/08/25 08:17:02 goose: up to current file version: 28642026/08/25 08:17:02 INFO Received cleanup request method=DELETE path=/api/pending_closures8652026/08/25 08:17:02 INFO Aborted multipart uploads count=08662026/08/25 08:17:02 INFO Received uploads request method=POST path=/api/pending_closures8672026/08/25 08:17:02 INFO Aborted multipart uploads count=08682026/08/25 08:17:02 WARN Force mode enabled - objects will be deleted immediately without grace period8692026/08/25 08:17:02 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=08702026/08/25 08:17:02 INFO Vacuumed table table=pending_closures8712026/08/25 08:17:02 INFO Vacuumed table table=pending_objects8722026/08/25 08:17:02 INFO Vacuumed table table=multipart_uploads8732026/08/25 08:17:02 INFO Vacuumed table table=closures8742026/08/25 08:17:02 INFO Vacuumed table table=objects875--- PASS: TestGCMetrics (2.11s)876=== CONT TestService_AuthMiddleware_OIDC8772026/08/25 08:17:02 INFO Received cleanup request method=DELETE path=/api/pending_closures8782026/08/25 08:17:02 INFO OIDC provider initialized name=test8792026/08/25 08:17:02 INFO Aborted multipart uploads count=18802026/08/25 08:17:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8812026-08-25 08:17:02.808 UTC [89774] ERROR: Closure does not exist: id=18822026-08-25 08:17:02.808 UTC [89774] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE8832026-08-25 08:17:02.808 UTC [89774] STATEMENT: -- name: CommitPendingClosure :exec884 SELECT commit_pending_closure($1::bigint)885 886--- PASS: TestService_cleanupPendingClosuresHandler (2.20s)887=== CONT TestService_AuthMiddleware_MTLSBoundSubjects8882026/08/25 08:17:02 INFO Created nix-cache-info in bucket bucket=bucket158892026-08-25 08:17:02.972 UTC [89787] ERROR: relation "goose_db_version" does not exist at character 368902026-08-25 08:17:02.972 UTC [89787] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8912026-08-25 08:17:02.974 UTC [89789] ERROR: relation "goose_db_version" does not exist at character 368922026-08-25 08:17:02.974 UTC [89789] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8932026/08/25 08:17:03 OK 20241026095416_initial_model.sql (45.56ms)8942026/08/25 08:17:03 OK 20241026095416_initial_model.sql (51.87ms)895=== NAME TestClientIntegration896 client_integration_test.go:276: Created store path: /nix/var/nix/builds/nix-88322-2630525197/TestClientIntegration4107016632/002/store/234qf6757nf1gm6w4fi0zamv34bq6bvc-test-file.txt8972026/08/25 08:17:03 OK 20251210153512_drop_unused_gin_index.sql (625.92µs)8982026/08/25 08:17:03 OK 20251210153512_drop_unused_gin_index.sql (569.04µs)8992026/08/25 08:17:03 OK 20251218171726_add_pins.sql (1.07ms)9002026/08/25 08:17:03 OK 20251218171726_add_pins.sql (1.09ms)9012026/08/25 08:17:03 OK 20260628120000_add_object_size_and_stats.sql (4.18ms)9022026/08/25 08:17:03 goose: successfully migrated database to version: 202606281200009032026/08/25 08:17:03 OK 20260628120000_add_object_size_and_stats.sql (4.36ms)9042026/08/25 08:17:03 goose: successfully migrated database to version: 202606281200009052026/08/25 08:17:03 OK 1_commit_pending_closure.sql (1.13ms)9062026/08/25 08:17:03 OK 1_commit_pending_closure.sql (1.14ms)9072026/08/25 08:17:03 OK 2_object_stats_trigger.sql (494.21µs)9082026/08/25 08:17:03 goose: up to current file version: 29092026/08/25 08:17:03 OK 2_object_stats_trigger.sql (384.17µs)9102026/08/25 08:17:03 goose: up to current file version: 2911--- PASS: TestGCBugBareHashReferences (2.27s)912=== CONT TestService_AuthMiddleware_MTLSProxyHeader9132026/08/25 08:17:03 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9142026/08/25 08:17:03 INFO Created nix-cache-info in bucket bucket=bucket189152026/08/25 08:17:03 INFO Received uploads request method=POST path=/api/pending_closures9162026/08/25 08:17:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9172026/08/25 08:17:03 INFO Uploading 234qf6757nf1gm6w4fi0zamv34bq6bvc-test-file.txt (152B)9182026/08/25 08:17:03 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"9192026/08/25 08:17:03 WARN Failed to register uploaded object key=234qf6757nf1gm6w4fi0zamv34bq6bvc.ls error="server returned 404: 404 page not found\n"9202026/08/25 08:17:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9212026/08/25 08:17:03 INFO Signed narinfos id=1 count=19222026/08/25 08:17:03 INFO Uploading 1 narinfos9232026/08/25 08:17:03 INFO Created nix-cache-info in bucket bucket=bucket199242026/08/25 08:17:03 WARN Failed to register uploaded object key=234qf6757nf1gm6w4fi0zamv34bq6bvc.narinfo error="server returned 404: 404 page not found\n"9252026/08/25 08:17:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9262026/08/25 08:17:03 INFO Completed upload id=19272026/08/25 08:17:03 INFO Upload complete. (254ms)928=== NAME TestClientIntegration929 client_integration_test.go:292: Retrieved narinfo from S3:930 StorePath: /nix/var/nix/builds/nix-88322-2630525197/TestClientIntegration4107016632/002/store/234qf6757nf1gm6w4fi0zamv34bq6bvc-test-file.txt931 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst932 Compression: zstd933 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1934 NarSize: 152935 References: 936 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1937 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)938 client_integration_test.go:293: Decompressed .ls content (64 bytes):939 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}940 client_integration_test.go:296: Testing garbage collection...9412026/08/25 08:17:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures9422026/08/25 08:17:03 INFO Garbage collection started9432026/08/25 08:17:03 INFO Aborted multipart uploads count=09442026/08/25 08:17:03 WARN Force mode enabled - objects will be deleted immediately without grace period945=== NAME TestPinProtectsFromGC946 client_integration_test.go:646: Pinned store path: /nix/var/nix/builds/nix-88322-2630525197/TestPinProtectsFromGC2106837784/001/store/l7g3kdppxc7n0hjc2kll5mapg647h56q-pinned-file.txt947 client_integration_test.go:647: Unpinned store path: /nix/var/nix/builds/nix-88322-2630525197/TestPinProtectsFromGC2106837784/001/store/y0lgjn463q36xih3kxbis27yy7nnqcm0-unpinned-file.txt9482026-08-25 08:17:03.434 UTC [89814] ERROR: relation "goose_db_version" does not exist at character 369492026-08-25 08:17:03.434 UTC [89814] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9502026-08-25 08:17:03.434 UTC [89813] ERROR: relation "goose_db_version" does not exist at character 369512026-08-25 08:17:03.434 UTC [89813] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9522026/08/25 08:17:03 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=09532026/08/25 08:17:03 INFO Vacuumed table table=pending_closures9542026/08/25 08:17:03 INFO Vacuumed table table=pending_objects9552026/08/25 08:17:03 INFO Vacuumed table table=multipart_uploads9562026/08/25 08:17:03 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9572026/08/25 08:17:03 INFO Vacuumed table table=closures9582026/08/25 08:17:03 INFO Vacuumed table table=objects9592026/08/25 08:17:03 OK 20241026095416_initial_model.sql (37.21ms)9602026/08/25 08:17:03 OK 20241026095416_initial_model.sql (30.52ms)9612026/08/25 08:17:03 OK 20251210153512_drop_unused_gin_index.sql (517.88µs)9622026/08/25 08:17:03 OK 20251210153512_drop_unused_gin_index.sql (551.79µs)9632026/08/25 08:17:03 OK 20251218171726_add_pins.sql (977.79µs)9642026/08/25 08:17:03 OK 20251218171726_add_pins.sql (837.04µs)9652026/08/25 08:17:03 OK 20260628120000_add_object_size_and_stats.sql (1.23ms)9662026/08/25 08:17:03 goose: successfully migrated database to version: 202606281200009672026/08/25 08:17:03 OK 20260628120000_add_object_size_and_stats.sql (1.54ms)9682026/08/25 08:17:03 goose: successfully migrated database to version: 202606281200009692026/08/25 08:17:03 OK 1_commit_pending_closure.sql (954.17µs)9702026/08/25 08:17:03 OK 2_object_stats_trigger.sql (217.92µs)9712026/08/25 08:17:03 goose: up to current file version: 29722026/08/25 08:17:03 OK 1_commit_pending_closure.sql (852.63µs)9732026/08/25 08:17:03 OK 2_object_stats_trigger.sql (222.25µs)9742026/08/25 08:17:03 goose: up to current file version: 29752026-08-25 08:17:03.525 UTC [89819] ERROR: relation "goose_db_version" does not exist at character 369762026-08-25 08:17:03.525 UTC [89819] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC977=== NAME TestClientWithDependencies978 client_integration_test.go:593: Built derivation: /nix/var/nix/builds/nix-88322-2630525197/TestClientWithDependencies2102880501/001/store/w7rqynh6f9fs0lqy95qv5mdybriq05pr-test-script9792026/08/25 08:17:03 INFO Received uploads request method=POST path=/api/pending_closures9802026/08/25 08:17:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9812026/08/25 08:17:03 INFO Uploading l7g3kdppxc7n0hjc2kll5mapg647h56q-pinned-file.txt (128B)982 client_integration_test.go:595: Found 1 dependencies (including self)9832026/08/25 08:17:03 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"9842026/08/25 08:17:03 INFO Created nix-cache-info in bucket bucket=bucket219852026/08/25 08:17:03 WARN Failed to register uploaded object key=l7g3kdppxc7n0hjc2kll5mapg647h56q.ls error="server returned 404: 404 page not found\n"9862026/08/25 08:17:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9872026/08/25 08:17:03 INFO Signed narinfos id=1 count=19882026/08/25 08:17:03 INFO Uploading 1 narinfos9892026/08/25 08:17:03 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9902026/08/25 08:17:03 INFO Received uploads request method=POST path=/api/pending_closures9912026/08/25 08:17:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9922026/08/25 08:17:03 INFO Uploading w7rqynh6f9fs0lqy95qv5mdybriq05pr-test-script (136B)9932026/08/25 08:17:03 WARN Failed to register uploaded object key=l7g3kdppxc7n0hjc2kll5mapg647h56q.narinfo error="server returned 404: 404 page not found\n"9942026/08/25 08:17:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9952026/08/25 08:17:03 OK 20241026095416_initial_model.sql (127.16ms)9962026/08/25 08:17:03 OK 20251210153512_drop_unused_gin_index.sql (12.56ms)9972026/08/25 08:17:03 INFO Completed upload id=19982026/08/25 08:17:03 INFO Upload complete. (237ms)9992026/08/25 08:17:03 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"10002026/08/25 08:17:03 WARN Failed to register uploaded object key=log/7w53m6yxndvvw24rz3z0gj7n26hp99f6-test-script.drv error="server returned 404: 404 page not found\n"10012026/08/25 08:17:03 INFO Created nix-cache-info in bucket bucket=bucket2010022026/08/25 08:17:03 OK 20251218171726_add_pins.sql (35.75ms)10032026/08/25 08:17:03 WARN Failed to register uploaded object key=w7rqynh6f9fs0lqy95qv5mdybriq05pr.ls error="server returned 404: 404 page not found\n"10042026/08/25 08:17:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10052026/08/25 08:17:03 INFO Signed narinfos id=1 count=110062026/08/25 08:17:03 INFO Uploading 1 narinfos10072026/08/25 08:17:03 OK 20260628120000_add_object_size_and_stats.sql (25.05ms)10082026/08/25 08:17:03 goose: successfully migrated database to version: 2026062812000010092026/08/25 08:17:03 OK 1_commit_pending_closure.sql (10.28ms)10102026/08/25 08:17:03 OK 2_object_stats_trigger.sql (296.54µs)10112026/08/25 08:17:03 goose: up to current file version: 210122026/08/25 08:17:03 WARN Failed to register uploaded object key=w7rqynh6f9fs0lqy95qv5mdybriq05pr.narinfo error="server returned 404: 404 page not found\n"10132026/08/25 08:17:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10142026/08/25 08:17:03 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10152026/08/25 08:17:03 INFO Completed upload id=110162026/08/25 08:17:03 INFO Upload complete. (221ms)1017 client_integration_test.go:597: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-88322-2630525197/TestClientWithDependencies2102880501/001/store) requires matching store prefix10182026/08/25 08:17:03 INFO Received uploads request method=POST path=/api/pending_closures10192026/08/25 08:17:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10202026/08/25 08:17:03 INFO Uploading y0lgjn463q36xih3kxbis27yy7nnqcm0-unpinned-file.txt (128B)1021=== NAME TestClientMultipleUploads1022 client_integration_test.go:338: Created store path 0: /nix/var/nix/builds/nix-88322-2630525197/TestClientMultipleUploads4193933450/001/store/n3f78rcypns2rp8w7qriy3p0pipc727c-test-file-0.txt10232026/08/25 08:17:03 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"1024--- PASS: TestClientWithDependencies (2.76s)1025=== CONT TestService_ReadAuthMiddleware10262026/08/25 08:17:03 WARN Failed to register uploaded object key=y0lgjn463q36xih3kxbis27yy7nnqcm0.ls error="server returned 404: 404 page not found\n"10272026/08/25 08:17:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10282026/08/25 08:17:03 INFO Signed narinfos id=2 count=110292026/08/25 08:17:03 INFO Uploading 1 narinfos10302026/08/25 08:17:03 WARN Failed to register uploaded object key=y0lgjn463q36xih3kxbis27yy7nnqcm0.narinfo error="server returned 404: 404 page not found\n"10312026/08/25 08:17:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10322026/08/25 08:17:03 INFO Completed upload id=210332026/08/25 08:17:03 INFO Upload complete. (207ms)1034=== NAME TestClientMultipleUploads1035 client_integration_test.go:338: Created store path 1: /nix/var/nix/builds/nix-88322-2630525197/TestClientMultipleUploads4193933450/001/store/7lqhbima07jqkyczqwczvgw0plb3xkcw-test-file-1.txt1036--- PASS: TestCacheStatsHandler (1.56s)1037=== CONT TestService_healthCheckHandler10382026/08/25 08:17:03 INFO Received create pin request method=POST path=/api/pins/myapp10392026-08-25 08:17:04.005 UTC [89850] ERROR: relation "goose_db_version" does not exist at character 3610402026-08-25 08:17:04.005 UTC [89850] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10412026/08/25 08:17:04 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-88322-2630525197/TestPinProtectsFromGC2106837784/001/store/l7g3kdppxc7n0hjc2kll5mapg647h56q-pinned-file.txt narinfo_key=l7g3kdppxc7n0hjc2kll5mapg647h56q.narinfo1042=== NAME TestClientMultipleUploads1043 client_integration_test.go:338: Created store path 2: /nix/var/nix/builds/nix-88322-2630525197/TestClientMultipleUploads4193933450/001/store/n7w0aq160j61b8bi1d1xmcxplrf8agz6-test-file-2.txt10442026/08/25 08:17:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures10452026/08/25 08:17:04 INFO Garbage collection started10462026-08-25 08:17:04.009 UTC [89851] ERROR: relation "goose_db_version" does not exist at character 3610472026-08-25 08:17:04.009 UTC [89851] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10482026/08/25 08:17:04 INFO Aborted multipart uploads count=010492026/08/25 08:17:04 WARN Force mode enabled - objects will be deleted immediately without grace period10502026/08/25 08:17:04 OK 20241026095416_initial_model.sql (46.45ms)10512026/08/25 08:17:04 OK 20251210153512_drop_unused_gin_index.sql (821.54µs)10522026/08/25 08:17:04 OK 20241026095416_initial_model.sql (30.45ms)10532026/08/25 08:17:04 OK 20251210153512_drop_unused_gin_index.sql (498.17µs)10542026/08/25 08:17:04 OK 20251218171726_add_pins.sql (2.79ms)10552026/08/25 08:17:04 OK 20251218171726_add_pins.sql (11.52ms)10562026/08/25 08:17:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10572026/08/25 08:17:04 OK 20260628120000_add_object_size_and_stats.sql (11.58ms)10582026/08/25 08:17:04 goose: successfully migrated database to version: 2026062812000010592026/08/25 08:17:04 OK 20260628120000_add_object_size_and_stats.sql (20.24ms)10602026/08/25 08:17:04 goose: successfully migrated database to version: 2026062812000010612026/08/25 08:17:04 OK 1_commit_pending_closure.sql (1.66ms)10622026/08/25 08:17:04 OK 2_object_stats_trigger.sql (410.75µs)10632026/08/25 08:17:04 goose: up to current file version: 210642026/08/25 08:17:04 OK 1_commit_pending_closure.sql (7.13ms)10652026/08/25 08:17:04 OK 2_object_stats_trigger.sql (661.92µs)10662026/08/25 08:17:04 goose: up to current file version: 210672026-08-25 08:17:04.105 UTC [89857] ERROR: relation "goose_db_version" does not exist at character 3610682026-08-25 08:17:04.105 UTC [89857] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10692026/08/25 08:17:04 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=010702026/08/25 08:17:04 INFO Vacuumed table table=pending_closures10712026/08/25 08:17:04 INFO Received uploads request method=POST path=/api/pending_closures1072=== NAME TestClientCADerivations1073 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-88322-2630525197/TestClientCADerivations3589123502/001/store/vh3qxsmng84dy022zcrwva4zx12zyzsh-ca-test10742026/08/25 08:17:04 INFO Vacuumed table table=pending_objects10752026/08/25 08:17:04 INFO Vacuumed table table=multipart_uploads10762026/08/25 08:17:04 INFO Received uploads request method=POST path=/api/pending_closures10772026/08/25 08:17:04 INFO Vacuumed table table=closures10782026/08/25 08:17:04 INFO Received uploads request method=POST path=/api/pending_closures10792026/08/25 08:17:04 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)10802026/08/25 08:17:04 INFO Uploading n7w0aq160j61b8bi1d1xmcxplrf8agz6-test-file-2.txt (160B)10812026/08/25 08:17:04 INFO Uploading n3f78rcypns2rp8w7qriy3p0pipc727c-test-file-0.txt (160B)10822026/08/25 08:17:04 INFO Uploading 7lqhbima07jqkyczqwczvgw0plb3xkcw-test-file-1.txt (160B)10832026/08/25 08:17:04 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"10842026/08/25 08:17:04 INFO Vacuumed table table=objects10852026/08/25 08:17:04 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"10862026/08/25 08:17:04 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"1087 client_ca_test.go:139: Found 1 dependencies (including self)1088=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1089=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1090=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1091=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1092=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1093=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1094=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1095=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1096=== CONT TestMetricsInventory10972026/08/25 08:17:04 WARN Failed to register uploaded object key=n7w0aq160j61b8bi1d1xmcxplrf8agz6.ls error="server returned 404: 404 page not found\n"10982026/08/25 08:17:04 WARN Failed to register uploaded object key=n3f78rcypns2rp8w7qriy3p0pipc727c.ls error="server returned 404: 404 page not found\n"10992026/08/25 08:17:04 WARN Failed to register uploaded object key=7lqhbima07jqkyczqwczvgw0plb3xkcw.ls error="server returned 404: 404 page not found\n"11002026/08/25 08:17:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11012026/08/25 08:17:04 INFO Signed narinfos id=1 count=111022026/08/25 08:17:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11032026/08/25 08:17:04 INFO Signed narinfos id=2 count=111042026/08/25 08:17:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign11052026/08/25 08:17:04 INFO Signed narinfos id=3 count=111062026/08/25 08:17:04 INFO Uploading 3 narinfos11072026/08/25 08:17:04 WARN Failed to register uploaded object key=7lqhbima07jqkyczqwczvgw0plb3xkcw.narinfo error="server returned 404: 404 page not found\n"11082026/08/25 08:17:04 WARN Failed to register uploaded object key=n7w0aq160j61b8bi1d1xmcxplrf8agz6.narinfo error="server returned 404: 404 page not found\n"11092026/08/25 08:17:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11102026/08/25 08:17:04 WARN Failed to register uploaded object key=n3f78rcypns2rp8w7qriy3p0pipc727c.narinfo error="server returned 404: 404 page not found\n"11112026/08/25 08:17:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11122026/08/25 08:17:04 INFO Completed upload id=111132026/08/25 08:17:04 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11142026/08/25 08:17:04 INFO Completed upload id=211152026/08/25 08:17:04 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete11162026/08/25 08:17:04 INFO Completed upload id=311172026/08/25 08:17:04 INFO Upload complete. (273ms)1118=== NAME TestClientMultipleUploads1119 client_integration_test.go:349: Uploaded 3 paths in 306.739042ms11202026/08/25 08:17:04 OK 20241026095416_initial_model.sql (187.92ms)11212026/08/25 08:17:04 OK 20251210153512_drop_unused_gin_index.sql (9.69ms)11222026/08/25 08:17:04 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"11232026/08/25 08:17:04 WARN mTLS auth: bound subjects configured but subject DN unavailable11242026/08/25 08:17:04 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1125--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.54s)1126=== CONT TestNARDeduplicationMetadataUploadBug11272026/08/25 08:17:04 INFO Received uploads request method=POST path=/api/pending_closures11282026/08/25 08:17:04 OK 20251218171726_add_pins.sql (18.71ms)1129--- PASS: TestClientMultipleUploads (2.27s)1130=== CONT TestCreatePendingClosureRejectsOversizedNAR11312026/08/25 08:17:04 INFO Received uploads request method=POST path=/api/pending_closures1132--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1133=== CONT TestCacheConfigHandlerMaxNarSize1134--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1135=== CONT TestGenerateLandingPage11362026/08/25 08:17:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11372026/08/25 08:17:04 INFO Uploading vh3qxsmng84dy022zcrwva4zx12zyzsh-ca-test (144B)1138--- PASS: TestGenerateLandingPage (0.00s)1139=== CONT TestReadProxyRootRedirectsToIndexHTML11402026/08/25 08:17:04 OK 20260628120000_add_object_size_and_stats.sql (24.93ms)11412026/08/25 08:17:04 goose: successfully migrated database to version: 2026062812000011422026/08/25 08:17:04 OK 1_commit_pending_closure.sql (5.13ms)11432026/08/25 08:17:04 OK 2_object_stats_trigger.sql (262.33µs)11442026/08/25 08:17:04 goose: up to current file version: 211452026/08/25 08:17:04 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"11462026/08/25 08:17:04 WARN Failed to register uploaded object key=log/fcng0v7b1mhxl0v15s60mdp21v489s0m-ca-test.drv error="server returned 404: 404 page not found\n"11472026/08/25 08:17:04 WARN Failed to register uploaded object key=vh3qxsmng84dy022zcrwva4zx12zyzsh.ls error="server returned 404: 404 page not found\n"11482026/08/25 08:17:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11492026/08/25 08:17:04 INFO Signed narinfos id=1 count=111502026/08/25 08:17:04 INFO Uploading 1 narinfos11512026/08/25 08:17:04 WARN Failed to register uploaded object key=vh3qxsmng84dy022zcrwva4zx12zyzsh.narinfo error="server returned 404: 404 page not found\n"11522026/08/25 08:17:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11532026/08/25 08:17:04 INFO Completed upload id=111542026/08/25 08:17:04 INFO Upload complete. (254ms)1155=== NAME TestClientCADerivations1156 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-88322-2630525197/TestClientCADerivations3589123502/001/store/vh3qxsmng84dy022zcrwva4zx12zyzsh-ca-test1157 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1158 Compression: zstd1159 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1160 NarSize: 1441161 References: 1162 Deriver: /nix/var/nix/builds/nix-88322-2630525197/TestClientCADerivations3589123502/001/store/fcng0v7b1mhxl0v15s60mdp21v489s0m-ca-test.drv1163 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1164 client_ca_test.go:185: Checking for realisation files in S3...1165 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1166 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1167--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.46s)1168=== CONT TestRedundantMultipartUpload1169=== NAME TestClientCADerivations1170 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket20?endpoint=http://localhost:52132®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-88322-2630525197/TestClientCADerivations3589123502/001/store'1171 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11172--- PASS: TestClientCADerivations (2.25s)1173=== CONT TestReadProxyRangeRequest11742026-08-25 08:17:04.712 UTC [89881] ERROR: relation "goose_db_version" does not exist at character 3611752026-08-25 08:17:04.712 UTC [89881] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11762026/08/25 08:17:04 OK 20241026095416_initial_model.sql (15.49ms)11772026/08/25 08:17:04 OK 20251210153512_drop_unused_gin_index.sql (425.46µs)11782026-08-25 08:17:04.735 UTC [89882] ERROR: relation "goose_db_version" does not exist at character 3611792026-08-25 08:17:04.735 UTC [89882] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11802026/08/25 08:17:04 OK 20251218171726_add_pins.sql (1.6ms)11812026/08/25 08:17:04 OK 20260628120000_add_object_size_and_stats.sql (8.51ms)11822026/08/25 08:17:04 goose: successfully migrated database to version: 2026062812000011832026/08/25 08:17:04 OK 1_commit_pending_closure.sql (1.59ms)11842026/08/25 08:17:04 OK 2_object_stats_trigger.sql (583.83µs)11852026/08/25 08:17:04 goose: up to current file version: 211862026/08/25 08:17:04 OK 20241026095416_initial_model.sql (34.24ms)11872026/08/25 08:17:04 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)11882026/08/25 08:17:04 OK 20251218171726_add_pins.sql (24.47ms)11892026/08/25 08:17:04 OK 20260628120000_add_object_size_and_stats.sql (24.95ms)11902026/08/25 08:17:04 goose: successfully migrated database to version: 2026062812000011912026/08/25 08:17:04 OK 1_commit_pending_closure.sql (2.27ms)11922026/08/25 08:17:04 OK 2_object_stats_trigger.sql (339.63µs)11932026/08/25 08:17:04 goose: up to current file version: 211942026/08/25 08:17:04 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1195--- PASS: TestService_ReadAuthMiddleware (0.97s)1196=== CONT TestReadProxyDisabled1197--- PASS: TestService_healthCheckHandler (0.97s)1198=== CONT TestIsValidCachePath1199=== RUN TestIsValidCachePath/narinfo1200=== PAUSE TestIsValidCachePath/narinfo1201=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1202=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1203=== RUN TestIsValidCachePath/nar_zst1204=== PAUSE TestIsValidCachePath/nar_zst1205=== RUN TestIsValidCachePath/nar_xz1206=== PAUSE TestIsValidCachePath/nar_xz1207=== RUN TestIsValidCachePath/nar_bz21208=== PAUSE TestIsValidCachePath/nar_bz21209=== RUN TestIsValidCachePath/nar_uncompressed1210=== PAUSE TestIsValidCachePath/nar_uncompressed1211=== RUN TestIsValidCachePath/ls1212=== PAUSE TestIsValidCachePath/ls1213=== RUN TestIsValidCachePath/log1214=== PAUSE TestIsValidCachePath/log1215=== RUN TestIsValidCachePath/realisation1216=== PAUSE TestIsValidCachePath/realisation1217=== RUN TestIsValidCachePath/nix-cache-info1218=== PAUSE TestIsValidCachePath/nix-cache-info1219=== RUN TestIsValidCachePath/index.html1220=== PAUSE TestIsValidCachePath/index.html1221=== RUN TestIsValidCachePath/traversal_parent1222=== PAUSE TestIsValidCachePath/traversal_parent1223=== RUN TestIsValidCachePath/traversal_in_middle1224=== PAUSE TestIsValidCachePath/traversal_in_middle1225=== RUN TestIsValidCachePath/invalid_char_e1226=== PAUSE TestIsValidCachePath/invalid_char_e1227=== RUN TestIsValidCachePath/invalid_char_u1228=== PAUSE TestIsValidCachePath/invalid_char_u1229=== RUN TestIsValidCachePath/random_path1230=== PAUSE TestIsValidCachePath/random_path1231=== RUN TestIsValidCachePath/empty1232=== PAUSE TestIsValidCachePath/empty1233=== RUN TestIsValidCachePath/leading_slash1234=== PAUSE TestIsValidCachePath/leading_slash1235=== RUN TestIsValidCachePath/wrong_extension1236=== PAUSE TestIsValidCachePath/wrong_extension1237=== RUN TestIsValidCachePath/short_hash1238=== PAUSE TestIsValidCachePath/short_hash1239=== CONT TestResurrectedObjectNotDeleted12402026-08-25 08:17:05.019 UTC [89887] ERROR: relation "goose_db_version" does not exist at character 3612412026-08-25 08:17:05.019 UTC [89887] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12422026/08/25 08:17:05 OK 20241026095416_initial_model.sql (33.16ms)12432026/08/25 08:17:05 OK 20251210153512_drop_unused_gin_index.sql (686.04µs)12442026/08/25 08:17:05 OK 20251218171726_add_pins.sql (1.48ms)12452026-08-25 08:17:05.094 UTC [89888] ERROR: relation "goose_db_version" does not exist at character 3612462026-08-25 08:17:05.094 UTC [89888] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12472026-08-25 08:17:05.097 UTC [89889] ERROR: relation "goose_db_version" does not exist at character 3612482026-08-25 08:17:05.097 UTC [89889] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12492026/08/25 08:17:05 OK 20260628120000_add_object_size_and_stats.sql (10.52ms)12502026/08/25 08:17:05 goose: successfully migrated database to version: 2026062812000012512026/08/25 08:17:05 OK 1_commit_pending_closure.sql (2.03ms)12522026/08/25 08:17:05 OK 2_object_stats_trigger.sql (377.88µs)12532026/08/25 08:17:05 goose: up to current file version: 212542026/08/25 08:17:05 OK 20241026095416_initial_model.sql (100.72ms)12552026/08/25 08:17:05 OK 20241026095416_initial_model.sql (106.05ms)12562026/08/25 08:17:05 OK 20251210153512_drop_unused_gin_index.sql (5.65ms)12572026/08/25 08:17:05 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)12582026/08/25 08:17:05 OK 20251218171726_add_pins.sql (20.67ms)12592026/08/25 08:17:05 OK 20251218171726_add_pins.sql (25.57ms)12602026/08/25 08:17:05 OK 20260628120000_add_object_size_and_stats.sql (6.16ms)12612026/08/25 08:17:05 goose: successfully migrated database to version: 2026062812000012622026/08/25 08:17:05 OK 20260628120000_add_object_size_and_stats.sql (11.24ms)12632026/08/25 08:17:05 goose: successfully migrated database to version: 2026062812000012642026/08/25 08:17:05 OK 1_commit_pending_closure.sql (3.26ms)12652026/08/25 08:17:05 OK 1_commit_pending_closure.sql (3.5ms)12662026/08/25 08:17:05 OK 2_object_stats_trigger.sql (1.07ms)12672026/08/25 08:17:05 goose: up to current file version: 212682026/08/25 08:17:05 OK 2_object_stats_trigger.sql (1.25ms)12692026/08/25 08:17:05 goose: up to current file version: 21270--- PASS: TestMetricsInventory (1.04s)1271=== CONT TestReadProxyNarStreaming12722026/08/25 08:17:05 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01273=== NAME TestClientIntegration1274 client_integration_test.go:303: Objects in database after GC:1275 client_integration_test.go:303: Successfully deleted all objects with GC --force12762026/08/25 08:17:05 INFO Created nix-cache-info in bucket bucket=bucket291277--- PASS: TestClientIntegration (4.83s)1278=== CONT TestParseSingleRange1279=== RUN TestParseSingleRange/none1280=== PAUSE TestParseSingleRange/none1281=== RUN TestParseSingleRange/unknown_unit1282=== PAUSE TestParseSingleRange/unknown_unit1283=== RUN TestParseSingleRange/multi-range_ignored1284=== PAUSE TestParseSingleRange/multi-range_ignored1285=== RUN TestParseSingleRange/malformed_no_dash1286=== PAUSE TestParseSingleRange/malformed_no_dash1287=== RUN TestParseSingleRange/malformed_both_empty1288=== PAUSE TestParseSingleRange/malformed_both_empty1289=== RUN TestParseSingleRange/malformed_end_before_start1290=== PAUSE TestParseSingleRange/malformed_end_before_start1291=== RUN TestParseSingleRange/closed1292=== PAUSE TestParseSingleRange/closed1293=== RUN TestParseSingleRange/open-ended1294=== PAUSE TestParseSingleRange/open-ended1295=== RUN TestParseSingleRange/end_clamped_to_size1296=== PAUSE TestParseSingleRange/end_clamped_to_size1297=== RUN TestParseSingleRange/suffix1298=== PAUSE TestParseSingleRange/suffix1299=== RUN TestParseSingleRange/suffix_exceeds_size1300=== PAUSE TestParseSingleRange/suffix_exceeds_size1301=== RUN TestParseSingleRange/single_byte1302=== PAUSE TestParseSingleRange/single_byte1303=== RUN TestParseSingleRange/start_past_EOF1304=== PAUSE TestParseSingleRange/start_past_EOF1305=== RUN TestParseSingleRange/start_far_past_EOF1306=== PAUSE TestParseSingleRange/start_far_past_EOF1307=== CONT TestReadProxyNarinfoAlreadyDecompressed1308--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.14s)1309=== CONT TestGCTaskStore_PhaseUpdates1310--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1311=== CONT TestReadProxyNarinfo13122026-08-25 08:17:05.521 UTC [89894] ERROR: relation "goose_db_version" does not exist at character 3613132026-08-25 08:17:05.521 UTC [89894] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1314=== NAME TestNARDeduplicationMetadataUploadBug1315 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-88322-2630525197/TestNARDeduplicationMetadataUploadBug845721457/001/store/jcx2kacixn8lv9r415njc14nlnpaa64g-file1.txt13162026-08-25 08:17:05.590 UTC [89899] ERROR: relation "goose_db_version" does not exist at character 3613172026-08-25 08:17:05.590 UTC [89899] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13182026/08/25 08:17:05 OK 20241026095416_initial_model.sql (72.5ms)13192026/08/25 08:17:05 OK 20251210153512_drop_unused_gin_index.sql (451.29µs)13202026/08/25 08:17:05 OK 20251218171726_add_pins.sql (866.79µs)13212026/08/25 08:17:05 OK 20260628120000_add_object_size_and_stats.sql (22.5ms)13222026/08/25 08:17:05 goose: successfully migrated database to version: 2026062812000013232026/08/25 08:17:05 OK 1_commit_pending_closure.sql (4.4ms)13242026/08/25 08:17:05 OK 2_object_stats_trigger.sql (226.42µs)13252026/08/25 08:17:05 goose: up to current file version: 213262026/08/25 08:17:05 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13272026/08/25 08:17:05 OK 20241026095416_initial_model.sql (99.36ms)13282026/08/25 08:17:05 OK 20251210153512_drop_unused_gin_index.sql (13.65ms)13292026/08/25 08:17:05 INFO Received uploads request method=POST path=/api/pending_closures13302026/08/25 08:17:05 OK 20251218171726_add_pins.sql (16.2ms)13312026/08/25 08:17:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13322026/08/25 08:17:05 INFO Uploading jcx2kacixn8lv9r415njc14nlnpaa64g-file1.txt (160B)13332026/08/25 08:17:05 OK 20260628120000_add_object_size_and_stats.sql (22.23ms)13342026/08/25 08:17:05 goose: successfully migrated database to version: 2026062812000013352026/08/25 08:17:05 OK 1_commit_pending_closure.sql (5.89ms)13362026/08/25 08:17:05 OK 2_object_stats_trigger.sql (219.79µs)13372026/08/25 08:17:05 goose: up to current file version: 213382026/08/25 08:17:05 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"1339--- PASS: TestReadProxyRangeRequest (1.27s)1340=== CONT TestGracefulShutdownDrainsInflight13412026/08/25 08:17:05 INFO Starting HTTP server address=127.0.0.1:5228313422026/08/25 08:17:05 INFO Shutdown signal received, draining in-flight requests timeout=10s13432026/08/25 08:17:05 WARN Failed to register uploaded object key=jcx2kacixn8lv9r415njc14nlnpaa64g.ls error="server returned 404: 404 page not found\n"13442026/08/25 08:17:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13452026/08/25 08:17:05 INFO Signed narinfos id=1 count=113462026/08/25 08:17:05 INFO Uploading 1 narinfos13472026/08/25 08:17:05 WARN Failed to register uploaded object key=jcx2kacixn8lv9r415njc14nlnpaa64g.narinfo error="server returned 404: 404 page not found\n"13482026/08/25 08:17:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1349--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1350=== CONT TestGCTaskStore_Fail1351--- PASS: TestGCTaskStore_Fail (0.00s)1352=== CONT TestService_verifyS3Integrity13532026/08/25 08:17:05 INFO Completed upload id=113542026/08/25 08:17:05 INFO Upload complete. (266ms)1355=== NAME TestNARDeduplicationMetadataUploadBug1356 metadata_upload_test.go:54: Retrieved narinfo from S3:1357 StorePath: /nix/var/nix/builds/nix-88322-2630525197/TestNARDeduplicationMetadataUploadBug845721457/001/store/jcx2kacixn8lv9r415njc14nlnpaa64g-file1.txt1358 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1359 Compression: zstd1360 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1361 NarSize: 1601362 References: 1363 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13642026/08/25 08:17:05 WARN Rate limiter enabled after throttle name=s3-test rate=513652026/08/25 08:17:05 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1366=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1367 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101368 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001369=== NAME TestNARDeduplicationMetadataUploadBug1370 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1371--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.00s)1372=== NAME TestNARDeduplicationMetadataUploadBug1373 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1374 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1375=== CONT TestReadProxyHead13762026/08/25 08:17:05 INFO Received uploads request method=POST path=/api/pending_closures1377=== NAME TestNARDeduplicationMetadataUploadBug1378 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-88322-2630525197/TestNARDeduplicationMetadataUploadBug845721457/001/store/kdarl5ysnrnlv4xj29wknp4v2jyg638i-file2.txt13792026/08/25 08:17:05 INFO Received uploads request method=POST path=/api/pending_closures13802026/08/25 08:17:06 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01381=== NAME TestPinProtectsFromGC1382 client_integration_test.go:709: Pin successfully protected closure from garbage collection1383--- PASS: TestPinProtectsFromGC (5.01s)1384=== CONT TestReadProxyConditionalGet13852026-08-25 08:17:06.043 UTC [89915] ERROR: relation "goose_db_version" does not exist at character 3613862026-08-25 08:17:06.043 UTC [89915] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13872026/08/25 08:17:06 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13882026/08/25 08:17:06 INFO Received uploads request method=POST path=/api/pending_closures13892026/08/25 08:17:06 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13902026/08/25 08:17:06 WARN Failed to register uploaded object key=kdarl5ysnrnlv4xj29wknp4v2jyg638i.ls error="server returned 404: 404 page not found\n"13912026/08/25 08:17:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13922026/08/25 08:17:06 INFO Signed narinfos id=2 count=113932026/08/25 08:17:06 INFO Uploading 1 narinfos13942026-08-25 08:17:06.119 UTC [89921] ERROR: relation "goose_db_version" does not exist at character 3613952026-08-25 08:17:06.119 UTC [89921] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13962026/08/25 08:17:06 WARN Failed to register uploaded object key=kdarl5ysnrnlv4xj29wknp4v2jyg638i.narinfo error="server returned 404: 404 page not found\n"13972026/08/25 08:17:06 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13982026/08/25 08:17:06 INFO Completed upload id=213992026/08/25 08:17:06 INFO Upload complete. (133ms)1400=== NAME TestNARDeduplicationMetadataUploadBug1401 metadata_upload_test.go:76: Retrieved narinfo from S3:1402 StorePath: /nix/var/nix/builds/nix-88322-2630525197/TestNARDeduplicationMetadataUploadBug845721457/001/store/kdarl5ysnrnlv4xj29wknp4v2jyg638i-file2.txt1403 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1404 Compression: zstd1405 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1406 NarSize: 1601407 References: 1408 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1409 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1410 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1411 {"version":1,"root":{"type":"regular","size":44}}1412--- PASS: TestNARDeduplicationMetadataUploadBug (1.79s)1413=== CONT TestOrphanedObjectsGCStressTest14142026/08/25 08:17:06 OK 20241026095416_initial_model.sql (43.54ms)14152026/08/25 08:17:06 OK 20251210153512_drop_unused_gin_index.sql (1ms)14162026/08/25 08:17:06 OK 20251218171726_add_pins.sql (2.61ms)14172026/08/25 08:17:06 OK 20260628120000_add_object_size_and_stats.sql (41.83ms)14182026/08/25 08:17:06 goose: successfully migrated database to version: 2026062812000014192026/08/25 08:17:06 OK 1_commit_pending_closure.sql (6.43ms)14202026/08/25 08:17:06 OK 2_object_stats_trigger.sql (256.17µs)14212026/08/25 08:17:06 goose: up to current file version: 214222026/08/25 08:17:06 OK 20241026095416_initial_model.sql (86.21ms)14232026/08/25 08:17:06 OK 20251210153512_drop_unused_gin_index.sql (10.57ms)14242026/08/25 08:17:06 OK 20251218171726_add_pins.sql (9.58ms)14252026/08/25 08:17:06 OK 20260628120000_add_object_size_and_stats.sql (104.45ms)14262026/08/25 08:17:06 goose: successfully migrated database to version: 202606281200001427--- PASS: TestReadProxyDisabled (1.50s)1428=== CONT TestOrphanedObjectsGC14292026/08/25 08:17:06 OK 1_commit_pending_closure.sql (6.3ms)14302026/08/25 08:17:06 OK 2_object_stats_trigger.sql (352.96µs)14312026/08/25 08:17:06 goose: up to current file version: 21432--- PASS: TestResurrectedObjectNotDeleted (1.74s)1433=== CONT TestReadProxyInvalidPath14342026-08-25 08:17:06.816 UTC [89928] ERROR: relation "goose_db_version" does not exist at character 3614352026-08-25 08:17:06.816 UTC [89928] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14362026-08-25 08:17:06.899 UTC [89929] ERROR: relation "goose_db_version" does not exist at character 3614372026-08-25 08:17:06.899 UTC [89929] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14382026/08/25 08:17:06 OK 20241026095416_initial_model.sql (134.64ms)14392026/08/25 08:17:07 OK 20251210153512_drop_unused_gin_index.sql (3.71ms)14402026/08/25 08:17:07 OK 20251218171726_add_pins.sql (30.34ms)14412026/08/25 08:17:07 OK 20260628120000_add_object_size_and_stats.sql (37.08ms)14422026/08/25 08:17:07 goose: successfully migrated database to version: 2026062812000014432026/08/25 08:17:07 OK 1_commit_pending_closure.sql (7.91ms)14442026/08/25 08:17:07 OK 2_object_stats_trigger.sql (660.29µs)14452026/08/25 08:17:07 goose: up to current file version: 214462026-08-25 08:17:07.141 UTC [89930] ERROR: relation "goose_db_version" does not exist at character 3614472026-08-25 08:17:07.141 UTC [89930] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14482026/08/25 08:17:07 OK 20241026095416_initial_model.sql (212.91ms)14492026/08/25 08:17:07 OK 20251210153512_drop_unused_gin_index.sql (13.12ms)14502026/08/25 08:17:07 OK 20251218171726_add_pins.sql (25.75ms)14512026/08/25 08:17:07 OK 20260628120000_add_object_size_and_stats.sql (49.76ms)14522026/08/25 08:17:07 goose: successfully migrated database to version: 2026062812000014532026/08/25 08:17:07 OK 1_commit_pending_closure.sql (21.39ms)14542026/08/25 08:17:07 OK 2_object_stats_trigger.sql (1.35ms)14552026/08/25 08:17:07 goose: up to current file version: 21456--- PASS: TestReadProxyNarStreaming (2.03s)1457=== CONT TestGCTaskStore_GetReturnsLatest1458--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1459=== CONT TestGCTaskStore_GetEmpty1460--- PASS: TestGCTaskStore_GetEmpty (0.00s)1461=== CONT TestGCTaskStore_CompletedAllowsNewTask1462--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1463=== CONT TestService_createPendingClosureHandler14642026/08/25 08:17:07 OK 20241026095416_initial_model.sql (240.72ms)14652026/08/25 08:17:07 OK 20251210153512_drop_unused_gin_index.sql (11.49ms)14662026/08/25 08:17:07 OK 20251218171726_add_pins.sql (48.04ms)1467--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.06s)1468=== CONT TestProxyWriteTimeout/narinfo1469=== CONT TestProxyWriteTimeout/10_GiB_nar1470=== CONT TestIsValidUploadKey/narinfo1471=== CONT TestProxyWriteTimeout/1_GiB_nar1472=== CONT TestProxyWriteTimeout/unknown_size1473--- PASS: TestProxyWriteTimeout (0.00s)1474 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1475 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1476 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1477 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1478=== CONT TestIsValidUploadKey/nix-cache-info1479=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1480=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1481=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1482=== CONT TestIsValidUploadKey/index.html1483=== CONT TestIsValidUploadKey/build_log_home-manager_file1484=== CONT TestIsValidUploadKey/realisation_plus_in_output1485=== CONT TestIsValidUploadKey/realisation1486=== CONT TestIsValidUploadKey/build_log_equals1487=== CONT TestIsValidUploadKey/build_log_question_mark1488=== CONT TestIsValidUploadKey/build_log_plus_in_name1489=== CONT TestIsValidUploadKey/traversal1490=== CONT TestIsValidUploadKey/unknown_type1491=== CONT TestIsValidUploadKey/empty_key1492=== CONT TestIsValidUploadKey/absolute1493=== CONT TestIsValidUploadKey/traversal_nar1494=== CONT TestIsValidUploadKey/build_log1495=== CONT TestIsValidUploadKey/nar_plain1496=== CONT TestIsValidUploadKey/listing1497=== CONT TestIsValidUploadKey/nar_zst1498=== CONT TestIsValidUploadKey/nar_xz1499--- PASS: TestIsValidUploadKey (0.00s)1500 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1501 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1502 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1503 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1504 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1505 --- PASS: TestIsValidUploadKey/index.html (0.00s)1506 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1507 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1508 --- PASS: TestIsValidUploadKey/realisation (0.00s)1509 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1510 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1511 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1512 --- PASS: TestIsValidUploadKey/traversal (0.00s)1513 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1514 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1515 --- PASS: TestIsValidUploadKey/absolute (0.00s)1516 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1517 --- PASS: TestIsValidUploadKey/build_log (0.00s)1518 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1519 --- PASS: TestIsValidUploadKey/listing (0.00s)1520 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1521 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1522=== CONT TestServerTLSConfig/no_client_CA1523=== CONT TestServerTLSConfig/not_a_PEM_file15242026/08/25 08:17:07 OK 20260628120000_add_object_size_and_stats.sql (37.93ms)15252026/08/25 08:17:07 goose: successfully migrated database to version: 2026062812000015262026/08/25 08:17:07 OK 1_commit_pending_closure.sql (10.85ms)15272026/08/25 08:17:07 OK 2_object_stats_trigger.sql (642.33µs)15282026/08/25 08:17:07 goose: up to current file version: 21529=== CONT TestServerTLSConfig/missing_CA_file1530--- PASS: TestServerTLSConfig (0.00s)1531 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1532 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1533 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1534=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15352026/08/25 08:17:07 INFO Received uploads request method=POST path=/15362026/08/25 08:17:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15372026/08/25 08:17:07 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZmQxZjM4MzQtNzZmMy00MzEzLWE0NGYtYjg1OGE0NTdiYjBmLmU0MjVlNzE0LTgxZGMtNDIxOC1hNWEyLTcxOTQ1ZmIyNTc0M3gxNzg3NjQ1ODI1OTQ1MDg3MDAw parts=121538--- PASS: TestRedundantMultipartUpload (3.21s)1539=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15402026/08/25 08:17:07 INFO Received request for more parts method=POST path=/1541=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15422026/08/25 08:17:07 INFO Received complete multipart upload request method=POST path=/1543=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15442026/08/25 08:17:07 INFO Received uploads request method=POST path=/1545=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15462026/08/25 08:17:07 INFO Received complete multipart upload request method=POST path=/1547=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15482026/08/25 08:17:07 INFO Received request for more parts method=POST path=/1549=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15502026/08/25 08:17:07 INFO Received uploads request method=POST path=/1551--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1552 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1553 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1554 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1555 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1556=== CONT TestCacheConfigHandler/full_config,_no_issuer1557=== CONT TestCacheConfigHandler/no_signing_keys1558=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1559=== CONT TestCacheConfigHandler/no_cache_url_configured1560--- PASS: TestCacheConfigHandler (0.00s)1561 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1562 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1563 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1564 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1565=== CONT TestClientErrorHandling/InvalidStorePath1566--- PASS: TestReadProxyNarinfo (2.29s)1567=== CONT TestClientErrorHandling/ServerNotAvailable1568--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)1569 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1570 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1571 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.30s)1572=== CONT TestClientErrorHandling/InvalidAuthToken15732026-08-25 08:17:07.850 UTC [89937] ERROR: relation "goose_db_version" does not exist at character 3615742026-08-25 08:17:07.850 UTC [89937] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15752026-08-25 08:17:07.850 UTC [89936] ERROR: relation "goose_db_version" does not exist at character 3615762026-08-25 08:17:07.850 UTC [89936] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15772026-08-25 08:17:07.875 UTC [89940] ERROR: relation "goose_db_version" does not exist at character 3615782026-08-25 08:17:07.875 UTC [89940] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15792026-08-25 08:17:07.881 UTC [89941] ERROR: relation "goose_db_version" does not exist at character 3615802026-08-25 08:17:07.881 UTC [89941] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15812026/08/25 08:17:07 OK 20241026095416_initial_model.sql (54.19ms)15822026/08/25 08:17:07 OK 20241026095416_initial_model.sql (35.71ms)15832026/08/25 08:17:07 OK 20251210153512_drop_unused_gin_index.sql (500µs)15842026/08/25 08:17:07 OK 20251210153512_drop_unused_gin_index.sql (527.96µs)15852026/08/25 08:17:07 OK 20251218171726_add_pins.sql (1.67ms)15862026/08/25 08:17:07 OK 20251218171726_add_pins.sql (2.25ms)15872026-08-25 08:17:07.936 UTC [89946] ERROR: relation "goose_db_version" does not exist at character 3615882026-08-25 08:17:07.936 UTC [89946] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15892026/08/25 08:17:07 OK 20260628120000_add_object_size_and_stats.sql (7.53ms)15902026/08/25 08:17:07 goose: successfully migrated database to version: 2026062812000015912026/08/25 08:17:07 OK 20241026095416_initial_model.sql (33.26ms)15922026/08/25 08:17:07 OK 20260628120000_add_object_size_and_stats.sql (8.89ms)15932026/08/25 08:17:07 goose: successfully migrated database to version: 2026062812000015942026/08/25 08:17:07 OK 20241026095416_initial_model.sql (34.25ms)15952026/08/25 08:17:07 OK 20251210153512_drop_unused_gin_index.sql (1.16ms)15962026/08/25 08:17:07 OK 1_commit_pending_closure.sql (1.78ms)15972026/08/25 08:17:07 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)15982026/08/25 08:17:07 OK 2_object_stats_trigger.sql (648.13µs)15992026/08/25 08:17:07 goose: up to current file version: 216002026/08/25 08:17:07 OK 1_commit_pending_closure.sql (2.31ms)16012026/08/25 08:17:07 OK 2_object_stats_trigger.sql (649.38µs)16022026/08/25 08:17:07 goose: up to current file version: 216032026/08/25 08:17:07 OK 20251218171726_add_pins.sql (2.44ms)16042026/08/25 08:17:07 OK 20251218171726_add_pins.sql (1.69ms)16052026/08/25 08:17:07 OK 20260628120000_add_object_size_and_stats.sql (13.17ms)16062026/08/25 08:17:07 goose: successfully migrated database to version: 2026062812000016072026/08/25 08:17:07 OK 20260628120000_add_object_size_and_stats.sql (13.44ms)16082026/08/25 08:17:07 goose: successfully migrated database to version: 2026062812000016092026/08/25 08:17:07 OK 1_commit_pending_closure.sql (976.96µs)16102026/08/25 08:17:07 OK 1_commit_pending_closure.sql (985.58µs)16112026/08/25 08:17:07 OK 2_object_stats_trigger.sql (232.92µs)16122026/08/25 08:17:07 goose: up to current file version: 216132026/08/25 08:17:07 OK 2_object_stats_trigger.sql (246.5µs)16142026/08/25 08:17:07 goose: up to current file version: 216152026/08/25 08:17:07 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config16162026/08/25 08:17:07 OK 20241026095416_initial_model.sql (40.34ms)16172026/08/25 08:17:07 OK 20251210153512_drop_unused_gin_index.sql (6.97ms)16182026/08/25 08:17:08 OK 20251218171726_add_pins.sql (10ms)16192026/08/25 08:17:08 OK 20260628120000_add_object_size_and_stats.sql (48.16ms)16202026/08/25 08:17:08 goose: successfully migrated database to version: 2026062812000016212026/08/25 08:17:08 OK 1_commit_pending_closure.sql (13.69ms)16222026/08/25 08:17:08 OK 2_object_stats_trigger.sql (241.13µs)16232026/08/25 08:17:08 goose: up to current file version: 216242026/08/25 08:17:08 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.414306ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1625--- PASS: TestReadProxyHead (2.22s)1626=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token16272026/08/25 08:17:08 INFO OIDC auth successful provider=test1628=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected16292026/08/25 08:17:08 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]1630=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1631=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16322026/08/25 08:17:08 WARN Authentication failed token_preview=eyJhbGciOi...cwr5ksb88w 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]1633=== CONT TestIsValidCachePath/narinfo1634=== CONT TestIsValidCachePath/index.html1635=== CONT TestIsValidCachePath/nix-cache-info1636=== CONT TestIsValidCachePath/traversal_parent1637=== CONT TestIsValidCachePath/empty1638=== CONT TestIsValidCachePath/realisation1639=== CONT TestIsValidCachePath/log1640=== CONT TestIsValidCachePath/short_hash1641=== CONT TestIsValidCachePath/ls1642=== CONT TestIsValidCachePath/wrong_extension1643=== CONT TestIsValidCachePath/nar_uncompressed1644=== CONT TestIsValidCachePath/nar_bz21645=== CONT TestIsValidCachePath/leading_slash1646=== CONT TestIsValidCachePath/nar_xz1647=== CONT TestIsValidCachePath/nar_zst1648=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1649=== CONT TestIsValidCachePath/invalid_char_u1650=== CONT TestIsValidCachePath/invalid_char_e1651=== CONT TestIsValidCachePath/traversal_in_middle1652=== CONT TestIsValidCachePath/random_path1653--- PASS: TestIsValidCachePath (0.00s)1654 --- PASS: TestIsValidCachePath/narinfo (0.00s)1655 --- PASS: TestIsValidCachePath/index.html (0.00s)1656 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1657 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1658 --- PASS: TestIsValidCachePath/empty (0.00s)1659 --- PASS: TestIsValidCachePath/realisation (0.00s)1660 --- PASS: TestIsValidCachePath/log (0.00s)1661 --- PASS: TestIsValidCachePath/short_hash (0.00s)1662 --- PASS: TestIsValidCachePath/ls (0.00s)1663 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1664 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1665 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1666 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1667 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1668 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1669 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1670 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1671 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1672 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1673 --- PASS: TestIsValidCachePath/random_path (0.00s)1674=== CONT TestParseSingleRange/none1675=== CONT TestParseSingleRange/open-ended1676=== CONT TestParseSingleRange/start_far_past_EOF1677=== CONT TestParseSingleRange/start_past_EOF1678=== CONT TestParseSingleRange/single_byte1679=== CONT TestParseSingleRange/suffix_exceeds_size1680=== CONT TestParseSingleRange/suffix1681=== CONT TestParseSingleRange/end_clamped_to_size1682=== CONT TestParseSingleRange/malformed_both_empty1683=== CONT TestParseSingleRange/closed1684=== CONT TestParseSingleRange/malformed_end_before_start1685=== CONT TestParseSingleRange/multi-range_ignored1686=== CONT TestParseSingleRange/malformed_no_dash1687=== CONT TestParseSingleRange/unknown_unit1688--- PASS: TestParseSingleRange (0.00s)1689 --- PASS: TestParseSingleRange/none (0.00s)1690 --- PASS: TestParseSingleRange/open-ended (0.00s)1691 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1692 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1693 --- PASS: TestParseSingleRange/single_byte (0.00s)1694 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1695 --- PASS: TestParseSingleRange/suffix (0.00s)1696 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1697 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1698 --- PASS: TestParseSingleRange/closed (0.00s)1699 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1700 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1701 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1702 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1703--- PASS: TestService_AuthMiddleware_OIDC (1.48s)1704 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1705 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1706 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1707 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1708--- PASS: TestReadProxyConditionalGet (2.17s)17092026/08/25 08:17:08 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=366.085792ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17102026/08/25 08:17:08 INFO Received uploads request method=POST path=/api/pending_closures17112026-08-25 08:17:08.575 UTC [89948] ERROR: relation "goose_db_version" does not exist at character 3617122026-08-25 08:17:08.575 UTC [89948] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17132026/08/25 08:17:08 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=824.525299ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17142026/08/25 08:17:08 OK 20241026095416_initial_model.sql (277.43ms)17152026/08/25 08:17:08 OK 20251210153512_drop_unused_gin_index.sql (8.2ms)17162026/08/25 08:17:08 OK 20251218171726_add_pins.sql (33.92ms)17172026/08/25 08:17:09 OK 20260628120000_add_object_size_and_stats.sql (50.46ms)17182026/08/25 08:17:09 goose: successfully migrated database to version: 2026062812000017192026/08/25 08:17:09 OK 1_commit_pending_closure.sql (11.34ms)17202026/08/25 08:17:09 OK 2_object_stats_trigger.sql (1.03ms)17212026/08/25 08:17:09 goose: up to current file version: 21722--- PASS: TestReadProxyInvalidPath (2.57s)1723=== NAME TestOrphanedObjectsGC1724 orphaned_objects_gc_test.go:290: GC Test Summary:1725 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1726 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1727 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1728 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1729 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1730--- PASS: TestOrphanedObjectsGC (2.95s)17312026/08/25 08:17:09 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.558745261s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17322026-08-25 08:17:09.607 UTC [89949] ERROR: relation "goose_db_version" does not exist at character 3617332026-08-25 08:17:09.607 UTC [89949] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17342026/08/25 08:17:09 OK 20241026095416_initial_model.sql (163.74ms)17352026/08/25 08:17:09 OK 20251210153512_drop_unused_gin_index.sql (11.72ms)17362026/08/25 08:17:09 OK 20251218171726_add_pins.sql (24.81ms)1737=== NAME TestService_verifyS3Integrity1738 uploads_test.go:393: unexpected error: Put "http://localhost:52132/bucket39/nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=rustfsadmin%2F20260825%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20260825T081708Z&X-Amz-Expires=18000&X-Amz-SignedHeaders=host&partNumber=9&uploadId=ZmQxZjM4MzQtNzZmMy00MzEzLWE0NGYtYjg1OGE0NTdiYjBmLmI3NDJlNGQ5LTY1YTQtNGJkYy1hYWJlLWFjYTc5MjdjMDc0N3gxNzg3NjQ1ODI4NTI0NDY2MDAw&X-Amz-Signature=e16c7ffa07b2d510564beac7f76d0c059cfb41ea39343460de484b236abbe3ee": context deadline exceeded1739 1740--- FAIL: TestService_verifyS3Integrity (4.01s)17412026/08/25 08:17:09 OK 20260628120000_add_object_size_and_stats.sql (28.66ms)17422026/08/25 08:17:09 goose: successfully migrated database to version: 2026062812000017432026/08/25 08:17:09 OK 1_commit_pending_closure.sql (10.37ms)17442026/08/25 08:17:09 OK 2_object_stats_trigger.sql (788.58µs)17452026/08/25 08:17:09 goose: up to current file version: 217462026-08-25 08:17:09.945 UTC [89950] ERROR: relation "goose_db_version" does not exist at character 3617472026-08-25 08:17:09.945 UTC [89950] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17482026/08/25 08:17:10 INFO Received uploads request method=POST path=/api/pending_closures17492026/08/25 08:17:10 INFO Received uploads request method=POST path=/api/pending_closures17502026/08/25 08:17:10 INFO Received uploads request method=POST path=/api/pending_closures17512026-08-25 08:17:10.105 UTC [89951] ERROR: relation "goose_db_version" does not exist at character 3617522026-08-25 08:17:10.105 UTC [89951] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1753=== NAME TestService_createPendingClosureHandler1754 uploads_test.go:307: unexpected error: Put "http://localhost:52132/bucket44/nar/0000000000000000000000000000000000000000000000000000.nar.zst?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=rustfsadmin%2F20260825%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20260825T081710Z&X-Amz-Expires=18000&X-Amz-SignedHeaders=host&partNumber=1&uploadId=ZmQxZjM4MzQtNzZmMy00MzEzLWE0NGYtYjg1OGE0NTdiYjBmLjkxNzNmM2VmLTgzMWMtNDMwOC1iYTQxLTcxMjQyNzkwYWI0YngxNzg3NjQ1ODMwMTE0MzMwMDAw&X-Amz-Signature=ed7c2595ad3e13b9df249566aa560b383b0312645baeacc15d6de7ed9d832b56": context deadline exceeded1755 1756--- FAIL: TestService_createPendingClosureHandler (2.86s)17572026/08/25 08:17:10 OK 20241026095416_initial_model.sql (171.19ms)17582026/08/25 08:17:10 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)17592026/08/25 08:17:10 OK 20251218171726_add_pins.sql (17.34ms)17602026/08/25 08:17:10 OK 20260628120000_add_object_size_and_stats.sql (9.2ms)17612026/08/25 08:17:10 goose: successfully migrated database to version: 2026062812000017622026/08/25 08:17:10 OK 1_commit_pending_closure.sql (8.01ms)17632026/08/25 08:17:10 OK 2_object_stats_trigger.sql (785.29µs)17642026/08/25 08:17:10 goose: up to current file version: 217652026/08/25 08:17:10 OK 20241026095416_initial_model.sql (80.96ms)17662026/08/25 08:17:10 OK 20251210153512_drop_unused_gin_index.sql (10.7ms)17672026/08/25 08:17:10 OK 20251218171726_add_pins.sql (31.22ms)17682026/08/25 08:17:10 OK 20260628120000_add_object_size_and_stats.sql (33.12ms)17692026/08/25 08:17:10 goose: successfully migrated database to version: 2026062812000017702026/08/25 08:17:10 OK 1_commit_pending_closure.sql (8.34ms)17712026/08/25 08:17:10 OK 2_object_stats_trigger.sql (1.44ms)17722026/08/25 08:17:10 goose: up to current file version: 217732026/08/25 08:17:10 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17742026/08/25 08:17:10 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"17752026/08/25 08:17:11 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"17762026/08/25 08:17:11 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_closures17772026/08/25 08:17:11 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.880806ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17782026/08/25 08:17:11 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=393.966557ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17792026/08/25 08:17:11 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=817.357748ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17802026/08/25 08:17:12 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.556293774s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1781=== NAME TestOrphanedObjectsGCStressTest1782 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1783 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1784 orphaned_objects_gc_test.go:509: Stress test completed successfully:1785 orphaned_objects_gc_test.go:510: - Active objects preserved: 201786 orphaned_objects_gc_test.go:511: - Objects deleted: 2101787 orphaned_objects_gc_test.go:512: - Total GC'd: 2101788--- PASS: TestOrphanedObjectsGCStressTest (7.97s)1789--- PASS: TestClientErrorHandling (0.00s)1790 --- PASS: TestClientErrorHandling/InvalidStorePath (2.67s)1791 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.86s)1792 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.44s)1793FAIL17942026-08-25 08:17:14.323 UTC [89598] LOG: received smart shutdown request17952026-08-25 08:17:14.324 UTC [89598] LOG: background worker "logical replication launcher" (PID 89608) exited with exit code 117962026-08-25 08:17:14.328 UTC [89603] LOG: shutting down17972026-08-25 08:17:14.328 UTC [89603] LOG: checkpoint starting: shutdown immediate17982026-08-25 08:17:15.351 UTC [89603] LOG: checkpoint complete: wrote 13723 buffers (83.8%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 13 recycled; write=0.745 s, sync=0.255 s, total=1.023 s; sync files=15157, longest=0.001 s, average=0.001 s; distance=212369 kB, estimate=212369 kB; lsn=0/E6EF530, redo lsn=0/E6EF53017992026-08-25 08:17:15.355 UTC [89598] LOG: database system is shut down