niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #155
· 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 TestEncodeNixBase32WithRealHash74=== CONT TestResolveStorePath75--- PASS: TestEncodeNixBase32WithRealHash (0.00s)76=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess77=== CONT TestFileTokenMissing78=== CONT TestDumpPathMatchesNix79=== CONT TestParsePathInfoJSON802026/08/27 10:00:55 WARN Rate limiter enabled after throttle name=server-test rate=581=== RUN TestParsePathInfoJSON/Nix_format82=== PAUSE TestParsePathInfoJSON/Nix_format83=== CONT TestScriptTokenEmptyToken84=== RUN TestParsePathInfoJSON/Lix_format85=== PAUSE TestParsePathInfoJSON/Lix_format86=== RUN TestParsePathInfoJSON/empty_input87=== PAUSE TestParsePathInfoJSON/empty_input88=== RUN TestParsePathInfoJSON/whitespace_only89=== PAUSE TestParsePathInfoJSON/whitespace_only90=== RUN TestParsePathInfoJSON/invalid_JSON91=== PAUSE TestParsePathInfoJSON/invalid_JSON92=== CONT TestParsePathInfoJSON/Nix_format93=== CONT TestScriptTokenScriptFails94--- PASS: TestFileTokenMissing (0.00s)95=== CONT TestScriptTokenCachesUntilRefresh96=== CONT TestPathInfoHashCompatibility97=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)98=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)99=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon100=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon101=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI102=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI103=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512104=== CONT TestFilterOversizedClosures105=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512106=== RUN TestFilterOversizedClosures/no_limit_keeps_everything107=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything108=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped109=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped110=== CONT TestCaseHackSuffix111=== RUN TestFilterOversizedClosures/all_closures_skipped112=== PAUSE TestFilterOversizedClosures/all_closures_skipped113=== CONT TestGetStorePathHash114=== RUN TestGetStorePathHash/valid_store_path115=== PAUSE TestGetStorePathHash/valid_store_path116=== RUN TestGetStorePathHash/basename_without_hyphen_should_error117=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error118=== CONT TestConvertHashToNix32119=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error120=== RUN TestConvertHashToNix32/SRI_format_to_Nix32121=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error122=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error123=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error124=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32125=== RUN TestConvertHashToNix32/already_Nix32_format126=== CONT TestScriptTokenNoExpiryRerunsEveryCall127=== PAUSE TestConvertHashToNix32/already_Nix32_format128=== RUN TestConvertHashToNix32/invalid_format129=== PAUSE TestConvertHashToNix32/invalid_format130=== CONT TestScriptTokenBadJSON131--- PASS: TestResolveStorePath (0.01s)132=== CONT TestScriptTokenEmptyCommand133--- PASS: TestScriptTokenEmptyCommand (0.00s)134=== CONT TestSetClientTLSDoesNotMutateDefaultTransport135--- PASS: TestDoServerRequestAttachesToken (0.01s)136=== CONT TestFileTokenReadsAndCaches137--- PASS: TestScriptTokenScriptFails (0.01s)138=== CONT TestStaticToken139--- PASS: TestStaticToken (0.00s)140=== CONT TestSetClientTLSErrors141--- PASS: TestFileTokenReadsAndCaches (0.00s)142=== CONT TestUploadMultipart_SupersededByPeer143=== RUN TestUploadMultipart_SupersededByPeer/exists144=== PAUSE TestUploadMultipart_SupersededByPeer/exists145=== RUN TestUploadMultipart_SupersededByPeer/missing146=== PAUSE TestUploadMultipart_SupersededByPeer/missing147=== CONT TestDumpPathWriterError148=== RUN TestSetClientTLSErrors/missing_cert_file149=== PAUSE TestSetClientTLSErrors/missing_cert_file150=== RUN TestSetClientTLSErrors/missing_key_file151=== PAUSE TestSetClientTLSErrors/missing_key_file152=== RUN TestSetClientTLSErrors/missing_ca_file153=== PAUSE TestSetClientTLSErrors/missing_ca_file154=== RUN TestSetClientTLSErrors/invalid_ca_file155=== PAUSE TestSetClientTLSErrors/invalid_ca_file156=== CONT TestEncodeNixBase32157=== RUN TestEncodeNixBase32/test_string_hash158=== PAUSE TestEncodeNixBase32/test_string_hash159=== RUN TestEncodeNixBase32/empty_input160=== PAUSE TestEncodeNixBase32/empty_input161=== CONT TestDumpPathSingleFile162--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)163=== CONT TestShellSplitErrors164--- PASS: TestShellSplitErrors (0.00s)165=== CONT TestSetClientTLS166=== RUN TestSetClientTLS/rejects_connection_without_client_cert167=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert168=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA169=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA170=== RUN TestSetClientTLS/preserves_debug_logging_transport171=== PAUSE TestSetClientTLS/preserves_debug_logging_transport172=== CONT TestFileTokenEmpty173--- PASS: TestFileTokenEmpty (0.00s)174=== CONT TestShellSplit175--- PASS: TestShellSplit (0.00s)176=== CONT TestDoWithRetry_BodyReplayedViaGetBody1772026/08/27 10:00:55 WARN Rate limiter enabled after throttle name=server-test rate=51782026/08/27 10:00:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:545701792026/08/27 10:00:55 WARN Rate limiter backed off name=server-test rate=51802026/08/27 10:00:55 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:54570181--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)182=== CONT TestPartSizeForNAR183=== RUN TestPartSizeForNAR/zero_stays_at_minimum184=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum185=== RUN TestPartSizeForNAR/small_stays_at_minimum186=== PAUSE TestPartSizeForNAR/small_stays_at_minimum187=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum188=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum189=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts190=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts191=== RUN TestPartSizeForNAR/1_TiB192--- PASS: TestScriptTokenEmptyToken (0.02s)193=== CONT TestParsePathInfoJSON/invalid_JSON194=== CONT TestRateLimiterFeedback195=== RUN TestRateLimiterFeedback/429_enables_limiter196=== PAUSE TestRateLimiterFeedback/429_enables_limiter197=== RUN TestRateLimiterFeedback/503_enables_limiter198=== PAUSE TestRateLimiterFeedback/503_enables_limiter199=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter200=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter201=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter202--- PASS: TestScriptTokenBadJSON (0.02s)203=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter204=== PAUSE TestPartSizeForNAR/1_TiB205=== CONT TestParsePathInfoJSONMultiplePaths206=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths207=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths208=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths209=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths210=== RUN TestPartSizeForNAR/5_TiB_S3_max_object211=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object212=== RUN TestPartSizeForNAR/capped_at_5_GiB213=== PAUSE TestPartSizeForNAR/capped_at_5_GiB214=== CONT TestPathInfoCACompatibility215=== RUN TestPathInfoCACompatibility/null_ca_field216=== PAUSE TestPathInfoCACompatibility/null_ca_field217=== RUN TestPathInfoCACompatibility/old_string_format_-_text218=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text219=== CONT TestParsePathInfoJSON/empty_input220=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive221=== CONT TestParsePathInfoJSON/Lix_format222=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive223=== RUN TestPathInfoCACompatibility/new_structured_format_-_text224=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text225=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method226=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method227=== CONT TestParsePathInfoJSON/whitespace_only228=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI229=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)230=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon231=== CONT TestFilterOversizedClosures/no_limit_keeps_everything232=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped233=== CONT TestFilterOversizedClosures/all_closures_skipped2342026/08/27 10:00:55 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=2000235=== CONT TestGetStorePathHash/valid_store_path236=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error237=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error238--- PASS: TestParsePathInfoJSON (0.00s)239 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)240 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)241 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)242 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)243 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)244=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5122452026/08/27 10:00:55 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=50246--- PASS: TestFilterOversizedClosures (0.00s)247 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)248 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)249 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)250=== CONT TestConvertHashToNix32/SRI_format_to_Nix32251=== CONT TestConvertHashToNix32/already_Nix32_format252=== CONT TestUploadMultipart_SupersededByPeer/exists253--- PASS: TestPathInfoHashCompatibility (0.00s)254 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)255 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)256 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)257 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)258=== CONT TestGetStorePathHash/basename_without_hyphen_should_error259=== CONT TestConvertHashToNix32/invalid_format260--- PASS: TestGetStorePathHash (0.00s)261 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)262 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)263 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)264 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)265=== CONT TestUploadMultipart_SupersededByPeer/missing266--- PASS: TestConvertHashToNix32 (0.00s)267 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)268 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)269 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)270=== CONT TestSetClientTLSErrors/missing_cert_file271=== CONT TestSetClientTLSErrors/missing_ca_file272=== CONT TestSetClientTLSErrors/invalid_ca_file273=== CONT TestSetClientTLSErrors/missing_key_file274=== CONT TestEncodeNixBase32/test_string_hash275=== CONT TestEncodeNixBase32/empty_input276=== CONT TestSetClientTLS/rejects_connection_without_client_cert277--- PASS: TestEncodeNixBase32 (0.00s)278 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)279 --- PASS: TestEncodeNixBase32/empty_input (0.00s)280=== CONT TestSetClientTLS/preserves_debug_logging_transport281--- PASS: TestSetClientTLSErrors (0.00s)282 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)283 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)284 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)285 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)286--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)287 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)288 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)289=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA290=== CONT TestRateLimiterFeedback/429_enables_limiter291=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2922026/08/27 10:00:55 WARN Rate limiter enabled after throttle name=server-test rate=52932026/08/27 10:00:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:545792942026/08/27 10:00:55 WARN Rate limiter backed off name=server-test rate=5295=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter296=== CONT TestRateLimiterFeedback/503_enables_limiter2972026/08/27 10:00:55 WARN Rate limiter enabled after throttle name=server-test rate=5298=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2992026/08/27 10:00:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:54584300=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths301--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)302 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)303 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)304=== CONT TestPartSizeForNAR/zero_stays_at_minimum3052026/08/27 10:00:55 WARN Rate limiter backed off name=server-test rate=5306=== CONT TestPartSizeForNAR/1_TiB307=== CONT TestPartSizeForNAR/capped_at_5_GiB308=== CONT TestPartSizeForNAR/5_TiB_S3_max_object309=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum310=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts311=== CONT TestPartSizeForNAR/small_stays_at_minimum312--- PASS: TestPartSizeForNAR (0.00s)313 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)314 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)315 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)316 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)317 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)318 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)319 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)320=== CONT TestPathInfoCACompatibility/null_ca_field321--- PASS: TestRateLimiterFeedback (0.00s)322 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)323 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)324 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)325 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)326=== CONT TestPathInfoCACompatibility/new_structured_format_-_text327=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method328=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive329=== CONT TestPathInfoCACompatibility/old_string_format_-_text330--- PASS: TestPathInfoCACompatibility (0.00s)331 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)332 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)333 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)334 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)335 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)3362026/08/27 10:00:55 http: TLS handshake error from 127.0.0.1:54575: 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.01s)341--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)342--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)343--- PASS: TestDumpPathWriterError (0.04s)344--- PASS: TestDumpPathSingleFile (0.05s)345--- PASS: TestCaseHackSuffix (0.06s)346--- PASS: TestDumpPathMatchesNix (0.08s)347--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)348PASS349Running server tests...350The files belonging to this database system will be owned by user "_nixbld1".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-69671-594980882/postgres1090238857/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-69671-594980882/postgres1090238857/data -l logfile start376377/nix/var/nix/builds/nix-69671-594980882/postgres1090238857:5432 - no response3782026-08-27 10:00:56.786 UTC [69706] LOG: starting PostgreSQL 18.4 on aarch64-apple-darwin25.5.0, compiled by clang version 21.1.8, 64-bit3792026-08-27 10:00:56.786 UTC [69706] LOG: listening on Unix socket "/nix/var/nix/builds/nix-69671-594980882/postgres1090238857/.s.PGSQL.5432"3802026-08-27 10:00:56.788 UTC [69713] LOG: database system was shut down at 2026-08-27 10:00:56 UTC3812026-08-27 10:00:56.789 UTC [69706] LOG: database system is ready to accept connections382/nix/var/nix/builds/nix-69671-594980882/postgres1090238857:5432 - accepting connections383=== RUN TestService_AuthMiddleware384=== PAUSE TestService_AuthMiddleware385=== RUN TestService_AuthMiddleware_MTLSProxyHeader386=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader387=== RUN TestService_AuthMiddleware_MTLSBoundSubjects388=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects389=== RUN TestService_ReadAuthMiddleware390=== PAUSE TestService_ReadAuthMiddleware391=== RUN TestService_AuthMiddleware_OIDC392=== PAUSE TestService_AuthMiddleware_OIDC393=== RUN TestCacheConfigHandler394=== PAUSE TestCacheConfigHandler395=== RUN TestCacheStatsHandler396=== PAUSE TestCacheStatsHandler397=== RUN TestClientCADerivations398=== PAUSE TestClientCADerivations399=== RUN TestClientErrorHandling400=== PAUSE TestClientErrorHandling401=== RUN TestClientIntegration402=== PAUSE TestClientIntegration403=== RUN TestClientMultipleUploads404=== PAUSE TestClientMultipleUploads405=== RUN TestClientWithDependencies406=== PAUSE TestClientWithDependencies407=== RUN TestPinProtectsFromGC408=== PAUSE TestPinProtectsFromGC409=== RUN TestGCAdvisoryLockBlocksConcurrentRun4102026-08-27 10:00:57.194 UTC [69785] ERROR: relation "goose_db_version" does not exist at character 364112026-08-27 10:00:57.194 UTC [69785] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4122026/08/27 10:00:57 OK 20241026095416_initial_model.sql (3.54ms)4132026/08/27 10:00:57 OK 20251210153512_drop_unused_gin_index.sql (401.75µs)4142026/08/27 10:00:57 OK 20251218171726_add_pins.sql (817.96µs)4152026/08/27 10:00:57 OK 20260628120000_add_object_size_and_stats.sql (819.71µs)4162026/08/27 10:00:57 goose: successfully migrated database to version: 202606281200004172026/08/27 10:00:57 OK 1_commit_pending_closure.sql (919.54µs)4182026/08/27 10:00:57 OK 2_object_stats_trigger.sql (212.58µs)4192026/08/27 10:00:57 goose: up to current file version: 2420--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.24s)421=== RUN TestGCBugBareHashReferences422=== PAUSE TestGCBugBareHashReferences423=== RUN TestGCMetrics424=== PAUSE TestGCMetrics425=== RUN TestGCTaskStore_StartNew426=== PAUSE TestGCTaskStore_StartNew427=== RUN TestGCTaskStore_DeduplicateSameParams428=== PAUSE TestGCTaskStore_DeduplicateSameParams429=== RUN TestGCTaskStore_ConflictDifferentParams430=== PAUSE TestGCTaskStore_ConflictDifferentParams431=== RUN TestGCTaskStore_GetEmpty432=== PAUSE TestGCTaskStore_GetEmpty433=== RUN TestGCTaskStore_GetReturnsLatest434=== PAUSE TestGCTaskStore_GetReturnsLatest435=== RUN TestGCTaskStore_CompletedAllowsNewTask436=== PAUSE TestGCTaskStore_CompletedAllowsNewTask437=== RUN TestGCTaskStore_PhaseUpdates438=== PAUSE TestGCTaskStore_PhaseUpdates439=== RUN TestGCTaskStore_Fail440=== PAUSE TestGCTaskStore_Fail441=== RUN TestGracefulShutdownDrainsInflight442=== PAUSE TestGracefulShutdownDrainsInflight443=== RUN TestService_healthCheckHandler444=== PAUSE TestService_healthCheckHandler445=== RUN TestGenerateLandingPage446=== PAUSE TestGenerateLandingPage447=== RUN TestCacheConfigHandlerMaxNarSize448=== PAUSE TestCacheConfigHandlerMaxNarSize449=== RUN TestCreatePendingClosureRejectsOversizedNAR450=== PAUSE TestCreatePendingClosureRejectsOversizedNAR451=== RUN TestNARDeduplicationMetadataUploadBug452=== PAUSE TestNARDeduplicationMetadataUploadBug453=== RUN TestMetricsInventory454=== PAUSE TestMetricsInventory455=== RUN TestService_NativeMTLS456=== PAUSE TestService_NativeMTLS457=== RUN TestServerTLSConfig458=== PAUSE TestServerTLSConfig459=== RUN TestMultipartCleanup460=== PAUSE TestMultipartCleanup461=== RUN TestObjectStatsTrigger462=== PAUSE TestObjectStatsTrigger463=== RUN TestOrphanedObjectsGC464=== PAUSE TestOrphanedObjectsGC465=== RUN TestOrphanedObjectsGCStressTest466=== PAUSE TestOrphanedObjectsGCStressTest467=== RUN TestResurrectedObjectNotDeleted468=== PAUSE TestResurrectedObjectNotDeleted469=== RUN TestParseSingleRange470=== PAUSE TestParseSingleRange471=== RUN TestIsValidCachePath472=== PAUSE TestIsValidCachePath473=== RUN TestReadProxyNarinfo474=== PAUSE TestReadProxyNarinfo475=== RUN TestReadProxyNarinfoAlreadyDecompressed476=== PAUSE TestReadProxyNarinfoAlreadyDecompressed477=== RUN TestReadProxyNarStreaming478=== PAUSE TestReadProxyNarStreaming479=== RUN TestReadProxy404480=== PAUSE TestReadProxy404481=== RUN TestReadProxyInvalidPath482=== PAUSE TestReadProxyInvalidPath483=== RUN TestReadProxyHead484=== PAUSE TestReadProxyHead485=== RUN TestReadProxyConditionalGet486=== PAUSE TestReadProxyConditionalGet487=== RUN TestReadProxyRootRedirectsToIndexHTML488=== PAUSE TestReadProxyRootRedirectsToIndexHTML489=== RUN TestReadProxyDisabled490=== PAUSE TestReadProxyDisabled491=== RUN TestReadRedirectNar492=== PAUSE TestReadRedirectNar493=== RUN TestReadRedirectKeepsNarinfoProxied494=== PAUSE TestReadRedirectKeepsNarinfoProxied495=== RUN TestReadProxyRangeRequest496=== PAUSE TestReadProxyRangeRequest497=== RUN TestRedundantMultipartUpload498=== PAUSE TestRedundantMultipartUpload499=== RUN TestCompleteMultipartUpload_ErrorButObjectExists500=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists501=== RUN TestCompletedNarNotReofferedAcrossClosures502=== PAUSE TestCompletedNarNotReofferedAcrossClosures503=== RUN TestPresignedUploadRegisteredBeforeCommit504=== PAUSE TestPresignedUploadRegisteredBeforeCommit505=== RUN TestService_Rustfstest506=== PAUSE TestService_Rustfstest507=== RUN TestParseSize508=== PAUSE TestParseSize509=== RUN TestSkippedUploadsHandler510=== PAUSE TestSkippedUploadsHandler511=== RUN TestSystemdListenerNotActivated512--- PASS: TestSystemdListenerNotActivated (0.00s)513=== RUN TestWatchdogBeatsWhenHealthy514--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)515=== RUN TestWatchdogSkipsWhenUnhealthy5162026/08/27 10:00:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5172026/08/27 10:00:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5182026/08/27 10:00:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5192026/08/27 10:00:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5202026/08/27 10:00:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5212026/08/27 10:00:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5222026/08/27 10:00:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5232026/08/27 10:00:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5242026/08/27 10:00:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5252026/08/27 10:00:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"526--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)527=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle528=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle529=== RUN TestProxyWriteTimeout530=== PAUSE TestProxyWriteTimeout531=== RUN TestIsValidUploadKey532=== PAUSE TestIsValidUploadKey533=== RUN TestUploadHandlersRejectInvalidKeys534=== PAUSE TestUploadHandlersRejectInvalidKeys535=== RUN TestUploadHandlersRejectOversizedBody536=== PAUSE TestUploadHandlersRejectOversizedBody537=== RUN TestService_cleanupPendingClosuresHandler538=== PAUSE TestService_cleanupPendingClosuresHandler539=== RUN TestService_createPendingClosureHandler540=== PAUSE TestService_createPendingClosureHandler541=== RUN TestService_verifyS3Integrity542=== PAUSE TestService_verifyS3Integrity543=== RUN TestCompleteMultipartUnregistered544=== PAUSE TestCompleteMultipartUnregistered545=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT546=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT547=== CONT TestService_AuthMiddleware548=== CONT TestOrphanedObjectsGC549=== CONT TestGCTaskStore_ConflictDifferentParams550=== CONT TestRedundantMultipartUpload551--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)552=== CONT TestObjectStatsTrigger553=== CONT TestClientIntegration554=== CONT TestReadProxyInvalidPath555=== CONT TestCacheConfigHandler556=== RUN TestCacheConfigHandler/full_config,_no_issuer557=== CONT TestReadProxy404558=== PAUSE TestCacheConfigHandler/full_config,_no_issuer559=== CONT TestReadProxyNarStreaming560=== RUN TestCacheConfigHandler/no_cache_url_configured561=== PAUSE TestCacheConfigHandler/no_cache_url_configured562=== CONT TestReadProxyNarinfoAlreadyDecompressed563=== RUN TestCacheConfigHandler/no_signing_keys564=== PAUSE TestCacheConfigHandler/no_signing_keys565=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator566=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator567=== CONT TestReadProxyNarinfo5682026-08-27 10:00:57.794 UTC [69808] ERROR: relation "goose_db_version" does not exist at character 365692026-08-27 10:00:57.794 UTC [69808] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5702026-08-27 10:00:57.795 UTC [69807] ERROR: relation "goose_db_version" does not exist at character 365712026-08-27 10:00:57.795 UTC [69807] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5722026-08-27 10:00:57.796 UTC [69810] ERROR: relation "goose_db_version" does not exist at character 365732026-08-27 10:00:57.796 UTC [69810] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5742026-08-27 10:00:57.797 UTC [69809] ERROR: relation "goose_db_version" does not exist at character 365752026-08-27 10:00:57.797 UTC [69809] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5762026-08-27 10:00:57.798 UTC [69812] ERROR: relation "goose_db_version" does not exist at character 365772026-08-27 10:00:57.798 UTC [69812] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5782026-08-27 10:00:57.798 UTC [69814] ERROR: relation "goose_db_version" does not exist at character 365792026-08-27 10:00:57.798 UTC [69814] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5802026-08-27 10:00:57.799 UTC [69811] ERROR: relation "goose_db_version" does not exist at character 365812026-08-27 10:00:57.799 UTC [69811] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5822026-08-27 10:00:57.799 UTC [69815] ERROR: relation "goose_db_version" does not exist at character 365832026-08-27 10:00:57.799 UTC [69815] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5842026-08-27 10:00:57.799 UTC [69813] ERROR: relation "goose_db_version" does not exist at character 365852026-08-27 10:00:57.799 UTC [69813] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5862026-08-27 10:00:57.799 UTC [69816] ERROR: relation "goose_db_version" does not exist at character 365872026-08-27 10:00:57.799 UTC [69816] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5882026/08/27 10:00:57 OK 20241026095416_initial_model.sql (7.95ms)5892026/08/27 10:00:57 OK 20241026095416_initial_model.sql (7.82ms)5902026/08/27 10:00:57 OK 20251210153512_drop_unused_gin_index.sql (977.92µs)5912026/08/27 10:00:57 OK 20251210153512_drop_unused_gin_index.sql (797.42µs)5922026/08/27 10:00:57 OK 20241026095416_initial_model.sql (7.5ms)5932026/08/27 10:00:57 OK 20241026095416_initial_model.sql (6.47ms)5942026/08/27 10:00:57 OK 20251210153512_drop_unused_gin_index.sql (601.17µs)5952026/08/27 10:00:57 OK 20241026095416_initial_model.sql (7.26ms)5962026/08/27 10:00:57 OK 20251218171726_add_pins.sql (1.51ms)5972026/08/27 10:00:57 OK 20251210153512_drop_unused_gin_index.sql (623.71µs)5982026/08/27 10:00:57 OK 20251210153512_drop_unused_gin_index.sql (719.38µs)5992026/08/27 10:00:57 OK 20251218171726_add_pins.sql (1.74ms)6002026/08/27 10:00:57 OK 20241026095416_initial_model.sql (8.5ms)6012026/08/27 10:00:57 OK 20241026095416_initial_model.sql (8.02ms)6022026/08/27 10:00:57 OK 20251218171726_add_pins.sql (1.89ms)6032026/08/27 10:00:57 OK 20241026095416_initial_model.sql (8.28ms)6042026/08/27 10:00:57 OK 20260628120000_add_object_size_and_stats.sql (1.28ms)6052026/08/27 10:00:57 goose: successfully migrated database to version: 202606281200006062026/08/27 10:00:57 OK 20251218171726_add_pins.sql (1.77ms)6072026/08/27 10:00:57 OK 20260628120000_add_object_size_and_stats.sql (2.02ms)6082026/08/27 10:00:57 goose: successfully migrated database to version: 202606281200006092026/08/27 10:00:57 OK 20241026095416_initial_model.sql (9ms)6102026/08/27 10:00:57 OK 20251210153512_drop_unused_gin_index.sql (902.21µs)6112026/08/27 10:00:57 OK 20251210153512_drop_unused_gin_index.sql (1ms)6122026/08/27 10:00:57 OK 20251210153512_drop_unused_gin_index.sql (983.04µs)6132026/08/27 10:00:57 OK 20251218171726_add_pins.sql (2.26ms)6142026/08/27 10:00:57 OK 20241026095416_initial_model.sql (10.11ms)6152026/08/27 10:00:57 OK 1_commit_pending_closure.sql (1.28ms)6162026/08/27 10:00:57 OK 20260628120000_add_object_size_and_stats.sql (1.58ms)6172026/08/27 10:00:57 goose: successfully migrated database to version: 202606281200006182026/08/27 10:00:57 OK 20251210153512_drop_unused_gin_index.sql (795.38µs)6192026/08/27 10:00:57 OK 1_commit_pending_closure.sql (1.61ms)6202026/08/27 10:00:57 OK 20251210153512_drop_unused_gin_index.sql (916.38µs)6212026/08/27 10:00:57 OK 2_object_stats_trigger.sql (679.83µs)6222026/08/27 10:00:57 goose: up to current file version: 26232026/08/27 10:00:57 OK 20251218171726_add_pins.sql (1.42ms)6242026/08/27 10:00:57 OK 2_object_stats_trigger.sql (499.63µs)6252026/08/27 10:00:57 goose: up to current file version: 26262026/08/27 10:00:57 OK 20260628120000_add_object_size_and_stats.sql (2.18ms)6272026/08/27 10:00:57 goose: successfully migrated database to version: 202606281200006282026/08/27 10:00:57 OK 20260628120000_add_object_size_and_stats.sql (1.47ms)6292026/08/27 10:00:57 goose: successfully migrated database to version: 202606281200006302026/08/27 10:00:57 OK 1_commit_pending_closure.sql (995.5µs)6312026/08/27 10:00:57 OK 20251218171726_add_pins.sql (1.59ms)6322026/08/27 10:00:57 OK 20251218171726_add_pins.sql (1.67ms)6332026/08/27 10:00:57 OK 2_object_stats_trigger.sql (670.13µs)6342026/08/27 10:00:57 goose: up to current file version: 26352026/08/27 10:00:57 OK 20251218171726_add_pins.sql (1.32ms)6362026/08/27 10:00:57 OK 20251218171726_add_pins.sql (1.46ms)6372026/08/27 10:00:57 OK 20260628120000_add_object_size_and_stats.sql (1.13ms)6382026/08/27 10:00:57 goose: successfully migrated database to version: 202606281200006392026/08/27 10:00:57 OK 20260628120000_add_object_size_and_stats.sql (1.03ms)6402026/08/27 10:00:57 goose: successfully migrated database to version: 202606281200006412026/08/27 10:00:57 OK 1_commit_pending_closure.sql (1.45ms)6422026/08/27 10:00:57 OK 1_commit_pending_closure.sql (1.49ms)6432026/08/27 10:00:57 OK 20260628120000_add_object_size_and_stats.sql (1.43ms)6442026/08/27 10:00:57 goose: successfully migrated database to version: 202606281200006452026/08/27 10:00:57 OK 2_object_stats_trigger.sql (291.13µs)6462026/08/27 10:00:57 goose: up to current file version: 26472026/08/27 10:00:57 OK 2_object_stats_trigger.sql (301.83µs)6482026/08/27 10:00:57 goose: up to current file version: 26492026/08/27 10:00:57 OK 20260628120000_add_object_size_and_stats.sql (1.02ms)6502026/08/27 10:00:57 goose: successfully migrated database to version: 202606281200006512026/08/27 10:00:57 OK 1_commit_pending_closure.sql (998.96µs)6522026/08/27 10:00:57 OK 1_commit_pending_closure.sql (1.17ms)6532026/08/27 10:00:57 OK 2_object_stats_trigger.sql (226.38µs)6542026/08/27 10:00:57 goose: up to current file version: 26552026/08/27 10:00:57 OK 1_commit_pending_closure.sql (875.75µs)6562026/08/27 10:00:57 OK 2_object_stats_trigger.sql (213.13µs)6572026/08/27 10:00:57 goose: up to current file version: 26582026/08/27 10:00:57 OK 2_object_stats_trigger.sql (185.29µs)6592026/08/27 10:00:57 goose: up to current file version: 26602026/08/27 10:00:57 OK 20260628120000_add_object_size_and_stats.sql (5.94ms)6612026/08/27 10:00:57 goose: successfully migrated database to version: 202606281200006622026/08/27 10:00:57 OK 1_commit_pending_closure.sql (5.42ms)6632026/08/27 10:00:57 OK 2_object_stats_trigger.sql (164.29µs)6642026/08/27 10:00:57 goose: up to current file version: 26652026/08/27 10:00:57 OK 1_commit_pending_closure.sql (660.21µs)6662026/08/27 10:00:57 OK 2_object_stats_trigger.sql (169.38µs)6672026/08/27 10:00:57 goose: up to current file version: 26682026/08/27 10:00:57 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"669--- PASS: TestService_AuthMiddleware (0.42s)670=== CONT TestIsValidCachePath671=== RUN TestIsValidCachePath/narinfo672=== PAUSE TestIsValidCachePath/narinfo673=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars674=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars675=== RUN TestIsValidCachePath/nar_zst676=== PAUSE TestIsValidCachePath/nar_zst677=== RUN TestIsValidCachePath/nar_xz678=== PAUSE TestIsValidCachePath/nar_xz679=== RUN TestIsValidCachePath/nar_bz2680=== PAUSE TestIsValidCachePath/nar_bz2681=== RUN TestIsValidCachePath/nar_uncompressed682=== PAUSE TestIsValidCachePath/nar_uncompressed683=== RUN TestIsValidCachePath/ls684=== PAUSE TestIsValidCachePath/ls685=== RUN TestIsValidCachePath/log686=== PAUSE TestIsValidCachePath/log687=== RUN TestIsValidCachePath/realisation688=== PAUSE TestIsValidCachePath/realisation689=== RUN TestIsValidCachePath/nix-cache-info690=== PAUSE TestIsValidCachePath/nix-cache-info691=== RUN TestIsValidCachePath/index.html692=== PAUSE TestIsValidCachePath/index.html693=== RUN TestIsValidCachePath/traversal_parent694=== PAUSE TestIsValidCachePath/traversal_parent695=== RUN TestIsValidCachePath/traversal_in_middle696=== PAUSE TestIsValidCachePath/traversal_in_middle697=== RUN TestIsValidCachePath/invalid_char_e698=== PAUSE TestIsValidCachePath/invalid_char_e699=== RUN TestIsValidCachePath/invalid_char_u700=== PAUSE TestIsValidCachePath/invalid_char_u701=== RUN TestIsValidCachePath/random_path702=== PAUSE TestIsValidCachePath/random_path703=== RUN TestIsValidCachePath/empty704=== PAUSE TestIsValidCachePath/empty705=== RUN TestIsValidCachePath/leading_slash706=== PAUSE TestIsValidCachePath/leading_slash707=== RUN TestIsValidCachePath/wrong_extension708=== PAUSE TestIsValidCachePath/wrong_extension709=== RUN TestIsValidCachePath/short_hash710=== PAUSE TestIsValidCachePath/short_hash711=== CONT TestParseSingleRange712=== RUN TestParseSingleRange/none713=== PAUSE TestParseSingleRange/none714=== RUN TestParseSingleRange/unknown_unit715=== PAUSE TestParseSingleRange/unknown_unit716=== RUN TestParseSingleRange/multi-range_ignored717=== PAUSE TestParseSingleRange/multi-range_ignored718=== RUN TestParseSingleRange/malformed_no_dash719=== PAUSE TestParseSingleRange/malformed_no_dash720=== RUN TestParseSingleRange/malformed_both_empty721=== PAUSE TestParseSingleRange/malformed_both_empty722=== RUN TestParseSingleRange/malformed_end_before_start723=== PAUSE TestParseSingleRange/malformed_end_before_start724=== RUN TestParseSingleRange/closed725=== PAUSE TestParseSingleRange/closed726=== RUN TestParseSingleRange/open-ended727=== PAUSE TestParseSingleRange/open-ended728=== RUN TestParseSingleRange/end_clamped_to_size729=== PAUSE TestParseSingleRange/end_clamped_to_size730=== RUN TestParseSingleRange/suffix731=== PAUSE TestParseSingleRange/suffix732=== RUN TestParseSingleRange/suffix_exceeds_size733=== PAUSE TestParseSingleRange/suffix_exceeds_size734=== RUN TestParseSingleRange/single_byte735=== PAUSE TestParseSingleRange/single_byte736=== RUN TestParseSingleRange/start_past_EOF737=== PAUSE TestParseSingleRange/start_past_EOF738=== RUN TestParseSingleRange/start_far_past_EOF739=== PAUSE TestParseSingleRange/start_far_past_EOF740=== CONT TestResurrectedObjectNotDeleted7412026/08/27 10:00:57 INFO Received uploads request method=POST path=/api/pending_closures7422026/08/27 10:00:58 INFO Received uploads request method=POST path=/api/pending_closures743--- PASS: TestObjectStatsTrigger (0.65s)744=== CONT TestOrphanedObjectsGCStressTest745--- PASS: TestReadProxyInvalidPath (0.75s)746=== CONT TestClientCADerivations747--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.92s)748=== CONT TestClientErrorHandling749=== RUN TestClientErrorHandling/InvalidStorePath750=== PAUSE TestClientErrorHandling/InvalidStorePath751=== RUN TestClientErrorHandling/InvalidAuthToken752=== PAUSE TestClientErrorHandling/InvalidAuthToken753=== RUN TestClientErrorHandling/ServerNotAvailable754=== PAUSE TestClientErrorHandling/ServerNotAvailable755=== CONT TestIsValidUploadKey756=== RUN TestIsValidUploadKey/narinfo757=== PAUSE TestIsValidUploadKey/narinfo758=== RUN TestIsValidUploadKey/nar_zst759=== PAUSE TestIsValidUploadKey/nar_zst760=== RUN TestIsValidUploadKey/nar_xz761=== PAUSE TestIsValidUploadKey/nar_xz762=== RUN TestIsValidUploadKey/nar_plain763=== PAUSE TestIsValidUploadKey/nar_plain764=== RUN TestIsValidUploadKey/listing765=== PAUSE TestIsValidUploadKey/listing766=== RUN TestIsValidUploadKey/build_log767=== PAUSE TestIsValidUploadKey/build_log768=== RUN TestIsValidUploadKey/build_log_home-manager_file769=== PAUSE TestIsValidUploadKey/build_log_home-manager_file770=== RUN TestIsValidUploadKey/build_log_plus_in_name771=== PAUSE TestIsValidUploadKey/build_log_plus_in_name772=== RUN TestIsValidUploadKey/build_log_question_mark773=== PAUSE TestIsValidUploadKey/build_log_question_mark774=== RUN TestIsValidUploadKey/build_log_equals775=== PAUSE TestIsValidUploadKey/build_log_equals776=== RUN TestIsValidUploadKey/realisation777=== PAUSE TestIsValidUploadKey/realisation778=== RUN TestIsValidUploadKey/realisation_plus_in_output779=== PAUSE TestIsValidUploadKey/realisation_plus_in_output780=== RUN TestIsValidUploadKey/nix-cache-info781=== PAUSE TestIsValidUploadKey/nix-cache-info782=== RUN TestIsValidUploadKey/index.html783=== PAUSE TestIsValidUploadKey/index.html784=== RUN TestIsValidUploadKey/narinfo_key,_nar_type785=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type786=== RUN TestIsValidUploadKey/nar_key,_narinfo_type787=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type788=== RUN TestIsValidUploadKey/listing_key,_narinfo_type789=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type790=== RUN TestIsValidUploadKey/traversal791=== PAUSE TestIsValidUploadKey/traversal792=== RUN TestIsValidUploadKey/traversal_nar793=== PAUSE TestIsValidUploadKey/traversal_nar794=== RUN TestIsValidUploadKey/absolute795=== PAUSE TestIsValidUploadKey/absolute796=== RUN TestIsValidUploadKey/empty_key797=== PAUSE TestIsValidUploadKey/empty_key798=== RUN TestIsValidUploadKey/unknown_type799=== PAUSE TestIsValidUploadKey/unknown_type800=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT801--- PASS: TestReadProxy404 (1.02s)802=== CONT TestCompleteMultipartUnregistered803--- PASS: TestReadProxyNarinfo (1.19s)804=== CONT TestService_verifyS3Integrity805--- PASS: TestReadProxyNarStreaming (1.49s)806=== CONT TestService_createPendingClosureHandler807=== NAME TestClientIntegration808 client_integration_test.go:276: Created store path: /nix/var/nix/builds/nix-69671-594980882/TestClientIntegration3444403674/002/store/pk2i390nybssnxi6aqjn8f760w80885k-test-file.txt8092026/08/27 10:00:59 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8102026-08-27 10:00:59.204 UTC [69838] ERROR: relation "goose_db_version" does not exist at character 368112026-08-27 10:00:59.204 UTC [69838] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8122026/08/27 10:00:59 INFO Received uploads request method=POST path=/api/pending_closures8132026/08/27 10:00:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8142026/08/27 10:00:59 INFO Uploading pk2i390nybssnxi6aqjn8f760w80885k-test-file.txt (152B)8152026/08/27 10:00:59 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"8162026/08/27 10:00:59 WARN Failed to register uploaded object key=pk2i390nybssnxi6aqjn8f760w80885k.ls error="server returned 404: 404 page not found\n"8172026/08/27 10:00:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8182026/08/27 10:00:59 INFO Signed narinfos id=1 count=18192026/08/27 10:00:59 INFO Uploading 1 narinfos8202026/08/27 10:00:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8212026/08/27 10:00:59 WARN Failed to register uploaded object key=pk2i390nybssnxi6aqjn8f760w80885k.narinfo error="server returned 404: 404 page not found\n"8222026/08/27 10:00:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8232026/08/27 10:00:59 OK 20241026095416_initial_model.sql (154.98ms)8242026/08/27 10:00:59 INFO Completed upload id=18252026/08/27 10:00:59 INFO Upload complete. (286ms)826 client_integration_test.go:292: Retrieved narinfo from S3:827 StorePath: /nix/var/nix/builds/nix-69671-594980882/TestClientIntegration3444403674/002/store/pk2i390nybssnxi6aqjn8f760w80885k-test-file.txt828 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst829 Compression: zstd830 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1831 NarSize: 152832 References: 833 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk18342026/08/27 10:00:59 OK 20251210153512_drop_unused_gin_index.sql (9.18ms)835 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)836 client_integration_test.go:293: Decompressed .ls content (64 bytes):837 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}838 client_integration_test.go:296: Testing garbage collection...8392026/08/27 10:00:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ODU5YThlNzUtNzljZC00OWYxLWFkM2ItOWQxNzlmZmQ2YTcxLjc5ODNmMjg1LWQ1NDAtNDU3Yy1iNTU5LWJmM2JhMDQ2MGViM3gxNzg3ODI0ODU3OTc3NzYwMDAw parts=12840--- PASS: TestRedundantMultipartUpload (1.97s)841=== CONT TestService_cleanupPendingClosuresHandler8422026/08/27 10:00:59 OK 20251218171726_add_pins.sql (40.13ms)8432026/08/27 10:00:59 INFO Starting cleanup of old closures method=DELETE path=/api/closures8442026/08/27 10:00:59 INFO Garbage collection started8452026/08/27 10:00:59 INFO Aborted multipart uploads count=08462026/08/27 10:00:59 WARN Force mode enabled - objects will be deleted immediately without grace period8472026/08/27 10:00:59 OK 20260628120000_add_object_size_and_stats.sql (32.73ms)8482026/08/27 10:00:59 goose: successfully migrated database to version: 202606281200008492026/08/27 10:00:59 OK 1_commit_pending_closure.sql (1.52ms)8502026/08/27 10:00:59 OK 2_object_stats_trigger.sql (232.58µs)8512026/08/27 10:00:59 goose: up to current file version: 28522026/08/27 10:00:59 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=08532026/08/27 10:00:59 INFO Vacuumed table table=pending_closures8542026-08-27 10:00:59.663 UTC [69846] ERROR: relation "goose_db_version" does not exist at character 368552026-08-27 10:00:59.663 UTC [69846] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8562026/08/27 10:00:59 INFO Vacuumed table table=pending_objects8572026/08/27 10:00:59 INFO Vacuumed table table=multipart_uploads8582026/08/27 10:00:59 INFO Vacuumed table table=closures8592026/08/27 10:00:59 INFO Vacuumed table table=objects8602026-08-27 10:00:59.791 UTC [69847] ERROR: relation "goose_db_version" does not exist at character 368612026-08-27 10:00:59.791 UTC [69847] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC862--- PASS: TestResurrectedObjectNotDeleted (1.90s)863=== CONT TestUploadHandlersRejectOversizedBody864=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure865=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure866=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart867=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart868=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts869=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts870=== CONT TestUploadHandlersRejectInvalidKeys871=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info872=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info873=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal874=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal875=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key876=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key877=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key878=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key879=== CONT TestGCBugBareHashReferences8802026/08/27 10:00:59 OK 20241026095416_initial_model.sql (101.08ms)8812026/08/27 10:00:59 OK 20251210153512_drop_unused_gin_index.sql (764.83µs)8822026/08/27 10:00:59 OK 20251218171726_add_pins.sql (2.36ms)8832026-08-27 10:00:59.825 UTC [69849] ERROR: relation "goose_db_version" does not exist at character 368842026-08-27 10:00:59.825 UTC [69849] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC885=== NAME TestOrphanedObjectsGC886 orphaned_objects_gc_test.go:290: GC Test Summary:887 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A888 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B889 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)890 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)891 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects892--- PASS: TestOrphanedObjectsGC (2.36s)893=== CONT TestGCTaskStore_DeduplicateSameParams894--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)895=== CONT TestGCTaskStore_StartNew896--- PASS: TestGCTaskStore_StartNew (0.00s)897=== CONT TestGCMetrics8982026-08-27 10:00:59.828 UTC [69850] ERROR: relation "goose_db_version" does not exist at character 368992026-08-27 10:00:59.828 UTC [69850] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9002026/08/27 10:00:59 OK 20260628120000_add_object_size_and_stats.sql (9.72ms)9012026/08/27 10:00:59 goose: successfully migrated database to version: 202606281200009022026/08/27 10:00:59 OK 20241026095416_initial_model.sql (15.6ms)9032026/08/27 10:00:59 OK 1_commit_pending_closure.sql (1.5ms)9042026/08/27 10:00:59 OK 2_object_stats_trigger.sql (375.46µs)9052026/08/27 10:00:59 goose: up to current file version: 29062026/08/27 10:00:59 OK 20251210153512_drop_unused_gin_index.sql (909.79µs)9072026/08/27 10:00:59 OK 20251218171726_add_pins.sql (18.31ms)9082026/08/27 10:00:59 OK 20241026095416_initial_model.sql (42.86ms)9092026/08/27 10:00:59 OK 20251210153512_drop_unused_gin_index.sql (5.93ms)9102026/08/27 10:00:59 OK 20260628120000_add_object_size_and_stats.sql (37.67ms)9112026/08/27 10:00:59 goose: successfully migrated database to version: 202606281200009122026/08/27 10:00:59 OK 1_commit_pending_closure.sql (1.78ms)9132026/08/27 10:00:59 OK 2_object_stats_trigger.sql (232.08µs)9142026/08/27 10:00:59 goose: up to current file version: 29152026/08/27 10:00:59 OK 20251218171726_add_pins.sql (22.79ms)9162026/08/27 10:00:59 OK 20260628120000_add_object_size_and_stats.sql (23.84ms)9172026/08/27 10:00:59 goose: successfully migrated database to version: 202606281200009182026/08/27 10:00:59 OK 1_commit_pending_closure.sql (1.19ms)9192026/08/27 10:00:59 OK 2_object_stats_trigger.sql (250.92µs)9202026/08/27 10:00:59 goose: up to current file version: 29212026/08/27 10:00:59 OK 20241026095416_initial_model.sql (100.85ms)9222026/08/27 10:00:59 OK 20251210153512_drop_unused_gin_index.sql (6.11ms)9232026/08/27 10:00:59 OK 20251218171726_add_pins.sql (25.29ms)9242026/08/27 10:01:00 OK 20260628120000_add_object_size_and_stats.sql (36.16ms)9252026/08/27 10:01:00 goose: successfully migrated database to version: 202606281200009262026/08/27 10:01:00 OK 1_commit_pending_closure.sql (11.2ms)9272026/08/27 10:01:00 OK 2_object_stats_trigger.sql (395.17µs)9282026/08/27 10:01:00 goose: up to current file version: 29292026/08/27 10:01:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9302026/08/27 10:01:00 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst931--- PASS: TestCompleteMultipartUnregistered (1.76s)932=== CONT TestParseSize933--- PASS: TestParseSize (0.00s)934=== CONT TestProxyWriteTimeout935=== RUN TestProxyWriteTimeout/narinfo936=== PAUSE TestProxyWriteTimeout/narinfo937=== RUN TestProxyWriteTimeout/1_GiB_nar938=== PAUSE TestProxyWriteTimeout/1_GiB_nar939=== RUN TestProxyWriteTimeout/10_GiB_nar940=== PAUSE TestProxyWriteTimeout/10_GiB_nar941=== RUN TestProxyWriteTimeout/unknown_size942=== PAUSE TestProxyWriteTimeout/unknown_size943=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle9442026/08/27 10:01:00 INFO Received uploads request method=POST path=/api/pending_closures9452026-08-27 10:01:00.444 UTC [69862] ERROR: relation "goose_db_version" does not exist at character 369462026-08-27 10:01:00.444 UTC [69862] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9472026-08-27 10:01:00.474 UTC [69863] ERROR: relation "goose_db_version" does not exist at character 369482026-08-27 10:01:00.474 UTC [69863] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC949--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.11s)950=== CONT TestSkippedUploadsHandler9512026/08/27 10:01:00 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000952--- PASS: TestSkippedUploadsHandler (0.00s)953=== CONT TestGenerateLandingPage954--- PASS: TestGenerateLandingPage (0.00s)955=== CONT TestMultipartCleanup9562026/08/27 10:01:00 OK 20241026095416_initial_model.sql (26.56ms)9572026/08/27 10:01:00 OK 20241026095416_initial_model.sql (32.1ms)9582026/08/27 10:01:00 OK 20251210153512_drop_unused_gin_index.sql (6.72ms)9592026/08/27 10:01:00 OK 20251210153512_drop_unused_gin_index.sql (569.83µs)9602026/08/27 10:01:00 OK 20251218171726_add_pins.sql (1.6ms)9612026/08/27 10:01:00 OK 20251218171726_add_pins.sql (6.49ms)9622026/08/27 10:01:00 OK 20260628120000_add_object_size_and_stats.sql (19.16ms)9632026/08/27 10:01:00 goose: successfully migrated database to version: 202606281200009642026/08/27 10:01:00 OK 20260628120000_add_object_size_and_stats.sql (14.73ms)9652026/08/27 10:01:00 goose: successfully migrated database to version: 202606281200009662026/08/27 10:01:00 OK 1_commit_pending_closure.sql (1.95ms)9672026/08/27 10:01:00 OK 1_commit_pending_closure.sql (1.03ms)9682026/08/27 10:01:00 OK 2_object_stats_trigger.sql (340.21µs)9692026/08/27 10:01:00 goose: up to current file version: 29702026/08/27 10:01:00 OK 2_object_stats_trigger.sql (507.21µs)9712026/08/27 10:01:00 goose: up to current file version: 29722026/08/27 10:01:00 INFO Received uploads request method=POST path=/api/pending_closures973=== NAME TestClientCADerivations974 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-69671-594980882/TestClientCADerivations3102954593/001/store/kv5gdzkgjmr3ld7pa3srhhmfhjdm60c3-ca-test975 client_ca_test.go:139: Found 1 dependencies (including self)9762026/08/27 10:01:00 INFO Received uploads request method=POST path=/api/pending_closures9772026/08/27 10:01:00 INFO Received uploads request method=POST path=/api/pending_closures9782026/08/27 10:01:00 INFO Received uploads request method=POST path=/api/pending_closures9792026/08/27 10:01:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9802026/08/27 10:01:00 INFO Received uploads request method=POST path=/api/pending_closures9812026/08/27 10:01:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9822026/08/27 10:01:00 INFO Uploading kv5gdzkgjmr3ld7pa3srhhmfhjdm60c3-ca-test (144B)9832026/08/27 10:01:00 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"9842026/08/27 10:01:01 WARN Failed to register uploaded object key=log/v658xzk6nwidz4nv1jxzy3p779w8997j-ca-test.drv error="server returned 404: 404 page not found\n"9852026/08/27 10:01:01 WARN Failed to register uploaded object key=kv5gdzkgjmr3ld7pa3srhhmfhjdm60c3.ls error="server returned 404: 404 page not found\n"9862026/08/27 10:01:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9872026/08/27 10:01:01 INFO Signed narinfos id=1 count=19882026/08/27 10:01:01 INFO Uploading 1 narinfos9892026/08/27 10:01:01 WARN Failed to register uploaded object key=kv5gdzkgjmr3ld7pa3srhhmfhjdm60c3.narinfo error="server returned 404: 404 page not found\n"9902026/08/27 10:01:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9912026/08/27 10:01:01 INFO Completed upload id=19922026/08/27 10:01:01 INFO Upload complete. (283ms)993 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-69671-594980882/TestClientCADerivations3102954593/001/store/kv5gdzkgjmr3ld7pa3srhhmfhjdm60c3-ca-test994 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst995 Compression: zstd996 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n997 NarSize: 144998 References: 999 Deriver: /nix/var/nix/builds/nix-69671-594980882/TestClientCADerivations3102954593/001/store/v658xzk6nwidz4nv1jxzy3p779w8997j-ca-test.drv1000 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1001 client_ca_test.go:185: Checking for realisation files in S3...1002 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1003 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache10042026-08-27 10:01:01.099 UTC [69876] ERROR: relation "goose_db_version" does not exist at character 3610052026-08-27 10:01:01.099 UTC [69876] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1006 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket14?endpoint=http://localhost:54587®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-69671-594980882/TestClientCADerivations3102954593/001/store'1007 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11008--- PASS: TestClientCADerivations (3.08s)1009=== CONT TestServerTLSConfig1010=== RUN TestServerTLSConfig/no_client_CA1011=== PAUSE TestServerTLSConfig/no_client_CA1012=== RUN TestServerTLSConfig/missing_CA_file1013=== PAUSE TestServerTLSConfig/missing_CA_file1014=== RUN TestServerTLSConfig/not_a_PEM_file1015=== PAUSE TestServerTLSConfig/not_a_PEM_file1016=== CONT TestService_NativeMTLS10172026/08/27 10:01:01 OK 20241026095416_initial_model.sql (223.35ms)10182026/08/27 10:01:01 OK 20251210153512_drop_unused_gin_index.sql (8.7ms)10192026/08/27 10:01:01 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=010202026/08/27 10:01:01 OK 20251218171726_add_pins.sql (34.58ms)1021=== NAME TestClientIntegration1022 client_integration_test.go:303: Objects in database after GC:1023 client_integration_test.go:303: Successfully deleted all objects with GC --force10242026/08/27 10:01:01 OK 20260628120000_add_object_size_and_stats.sql (55.45ms)10252026/08/27 10:01:01 goose: successfully migrated database to version: 2026062812000010262026/08/27 10:01:01 OK 1_commit_pending_closure.sql (2.83ms)10272026/08/27 10:01:01 OK 2_object_stats_trigger.sql (485.75µs)10282026/08/27 10:01:01 goose: up to current file version: 21029--- PASS: TestClientIntegration (4.10s)1030=== CONT TestMetricsInventory10312026-08-27 10:01:01.575 UTC [69881] ERROR: relation "goose_db_version" does not exist at character 3610322026-08-27 10:01:01.575 UTC [69881] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10332026-08-27 10:01:01.658 UTC [69882] ERROR: relation "goose_db_version" does not exist at character 3610342026-08-27 10:01:01.658 UTC [69882] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10352026/08/27 10:01:01 INFO Received cleanup request method=DELETE path=/api/pending_closures10362026/08/27 10:01:01 INFO Aborted multipart uploads count=010372026/08/27 10:01:01 INFO Received uploads request method=POST path=/api/pending_closures10382026/08/27 10:01:01 INFO Received cleanup request method=DELETE path=/api/pending_closures10392026/08/27 10:01:01 INFO Aborted multipart uploads count=110402026/08/27 10:01:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10412026-08-27 10:01:01.909 UTC [69876] ERROR: Closure does not exist: id=110422026-08-27 10:01:01.909 UTC [69876] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10432026-08-27 10:01:01.909 UTC [69876] STATEMENT: -- name: CommitPendingClosure :exec1044 SELECT commit_pending_closure($1::bigint)1045 10462026/08/27 10:01:01 OK 20241026095416_initial_model.sql (263.98ms)1047--- PASS: TestService_cleanupPendingClosuresHandler (2.47s)1048=== CONT TestNARDeduplicationMetadataUploadBug10492026/08/27 10:01:01 OK 20251210153512_drop_unused_gin_index.sql (11.01ms)10502026/08/27 10:01:01 OK 20251218171726_add_pins.sql (49.62ms)10512026/08/27 10:01:02 OK 20260628120000_add_object_size_and_stats.sql (47ms)10522026/08/27 10:01:02 goose: successfully migrated database to version: 2026062812000010532026/08/27 10:01:02 OK 1_commit_pending_closure.sql (11.07ms)10542026/08/27 10:01:02 OK 2_object_stats_trigger.sql (897.75µs)10552026/08/27 10:01:02 goose: up to current file version: 210562026/08/27 10:01:02 OK 20241026095416_initial_model.sql (291.48ms)10572026/08/27 10:01:02 OK 20251210153512_drop_unused_gin_index.sql (14.84ms)10582026/08/27 10:01:02 OK 20251218171726_add_pins.sql (42.26ms)10592026/08/27 10:01:02 OK 20260628120000_add_object_size_and_stats.sql (55.37ms)10602026/08/27 10:01:02 goose: successfully migrated database to version: 2026062812000010612026/08/27 10:01:02 OK 1_commit_pending_closure.sql (20.67ms)10622026/08/27 10:01:02 OK 2_object_stats_trigger.sql (948.88µs)10632026/08/27 10:01:02 goose: up to current file version: 210642026/08/27 10:01:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10652026/08/27 10:01:02 INFO Aborted multipart uploads count=010662026/08/27 10:01:02 WARN Force mode enabled - objects will be deleted immediately without grace period10672026/08/27 10:01: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=010682026/08/27 10:01:02 INFO Vacuumed table table=pending_closures10692026/08/27 10:01:02 INFO Vacuumed table table=pending_objects10702026/08/27 10:01:02 INFO Vacuumed table table=multipart_uploads10712026/08/27 10:01:02 INFO Vacuumed table table=closures10722026/08/27 10:01:02 INFO Vacuumed table table=objects1073--- PASS: TestGCMetrics (2.63s)1074=== CONT TestCreatePendingClosureRejectsOversizedNAR10752026/08/27 10:01:02 INFO Received uploads request method=POST path=/api/pending_closures1076--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1077=== CONT TestCacheConfigHandlerMaxNarSize1078--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1079=== CONT TestClientWithDependencies10802026/08/27 10:01:02 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ODU5YThlNzUtNzljZC00OWYxLWFkM2ItOWQxNzlmZmQ2YTcxLmY0MTkxN2UxLTY1NmUtNDBlMi1iN2YyLWU1ZDk2ZmQwODMwM3gxNzg3ODI0ODYwNzIyOTg5MDAw parts=1010812026/08/27 10:01:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10822026/08/27 10:01:02 INFO Completed upload id=110832026/08/27 10:01:02 INFO Received uploads request method=POST path=/api/pending_closures10842026/08/27 10:01:02 INFO Received uploads request method=POST path=/api/pending_closures10852026/08/27 10:01:02 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10862026/08/27 10:01:02 WARN Found objects in DB but missing from S3, will re-upload count=11087--- PASS: TestService_verifyS3Integrity (3.85s)1088--- PASS: TestGCBugBareHashReferences (2.69s)1089=== CONT TestClientMultipleUploads1090=== CONT TestPinProtectsFromGC10912026/08/27 10:01:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10922026/08/27 10:01:02 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ODU5YThlNzUtNzljZC00OWYxLWFkM2ItOWQxNzlmZmQ2YTcxLjdkMDEyZGIyLTE5MTYtNDhlMC1hM2E0LTVkNzQxYzYxMGZiYngxNzg3ODI0ODYwODg2NzEwMDAw parts=1010932026/08/27 10:01:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10942026/08/27 10:01:02 INFO Completed upload id=110952026/08/27 10:01:02 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010962026/08/27 10:01:02 INFO Received uploads request method=POST path=/api/pending_closures10972026/08/27 10:01:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures10982026/08/27 10:01:02 INFO Aborted multipart uploads count=010992026/08/27 10:01:02 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=011002026-08-27 10:01:02.705 UTC [69894] ERROR: relation "goose_db_version" does not exist at character 3611012026-08-27 10:01:02.705 UTC [69894] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11022026/08/27 10:01:02 INFO Vacuumed table table=pending_closures11032026/08/27 10:01:02 INFO Vacuumed table table=pending_objects11042026/08/27 10:01:02 INFO Vacuumed table table=multipart_uploads11052026/08/27 10:01:02 INFO Vacuumed table table=closures11062026/08/27 10:01:02 INFO Vacuumed table table=objects11072026/08/27 10:01:02 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001108--- PASS: TestService_createPendingClosureHandler (3.87s)1109=== CONT TestService_ReadAuthMiddleware11102026-08-27 10:01:02.832 UTC [69896] ERROR: relation "goose_db_version" does not exist at character 3611112026-08-27 10:01:02.832 UTC [69896] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11122026/08/27 10:01:02 OK 20241026095416_initial_model.sql (164.93ms)11132026/08/27 10:01:02 OK 20251210153512_drop_unused_gin_index.sql (7.68ms)11142026/08/27 10:01:02 OK 20251218171726_add_pins.sql (22.34ms)11152026/08/27 10:01:03 OK 20260628120000_add_object_size_and_stats.sql (42.46ms)11162026/08/27 10:01:03 goose: successfully migrated database to version: 2026062812000011172026/08/27 10:01:03 OK 1_commit_pending_closure.sql (9.14ms)11182026/08/27 10:01:03 OK 2_object_stats_trigger.sql (876.46µs)11192026/08/27 10:01:03 goose: up to current file version: 211202026/08/27 10:01:03 OK 20241026095416_initial_model.sql (152.65ms)11212026/08/27 10:01:03 OK 20251210153512_drop_unused_gin_index.sql (19.51ms)11222026/08/27 10:01:03 OK 20251218171726_add_pins.sql (40.7ms)11232026/08/27 10:01:03 OK 20260628120000_add_object_size_and_stats.sql (45.46ms)11242026/08/27 10:01:03 goose: successfully migrated database to version: 2026062812000011252026/08/27 10:01:03 INFO Received uploads request method=POST path=/api/pending_closures11262026/08/27 10:01:03 OK 1_commit_pending_closure.sql (63.81ms)11272026/08/27 10:01:03 OK 2_object_stats_trigger.sql (1.38ms)11282026/08/27 10:01:03 goose: up to current file version: 211292026/08/27 10:01:03 INFO Received uploads request method=POST path=/api/pending_closures11302026/08/27 10:01:03 INFO Received cleanup request method=DELETE path=/api/pending_closures11312026/08/27 10:01:03 INFO Aborted multipart uploads count=11132--- PASS: TestMultipartCleanup (3.13s)1133=== CONT TestService_AuthMiddleware_OIDC11342026/08/27 10:01:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11352026/08/27 10:01:03 INFO OIDC provider initialized name=test11362026-08-27 10:01:03.867 UTC [69901] ERROR: relation "goose_db_version" does not exist at character 3611372026-08-27 10:01:03.867 UTC [69901] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11382026-08-27 10:01:03.995 UTC [69902] ERROR: relation "goose_db_version" does not exist at character 3611392026-08-27 10:01:03.995 UTC [69902] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11402026/08/27 10:01:04 OK 20241026095416_initial_model.sql (222.27ms)11412026/08/27 10:01:04 OK 20251210153512_drop_unused_gin_index.sql (13.92ms)11422026/08/27 10:01:04 OK 20251218171726_add_pins.sql (23.9ms)11432026/08/27 10:01:04 OK 20260628120000_add_object_size_and_stats.sql (51.97ms)11442026/08/27 10:01:04 goose: successfully migrated database to version: 2026062812000011452026/08/27 10:01:04 OK 1_commit_pending_closure.sql (14.25ms)11462026/08/27 10:01:04 OK 2_object_stats_trigger.sql (1.74ms)11472026/08/27 10:01:04 goose: up to current file version: 211482026/08/27 10:01:04 OK 20241026095416_initial_model.sql (183.97ms)11492026/08/27 10:01:04 OK 20251210153512_drop_unused_gin_index.sql (17.21ms)11502026/08/27 10:01:04 OK 20251218171726_add_pins.sql (42.9ms)11512026/08/27 10:01:04 OK 20260628120000_add_object_size_and_stats.sql (55.54ms)11522026/08/27 10:01:04 goose: successfully migrated database to version: 2026062812000011532026/08/27 10:01:04 OK 1_commit_pending_closure.sql (16.35ms)11542026/08/27 10:01:04 OK 2_object_stats_trigger.sql (1.06ms)11552026/08/27 10:01:04 goose: up to current file version: 211562026-08-27 10:01:04.437 UTC [69903] ERROR: relation "goose_db_version" does not exist at character 3611572026-08-27 10:01:04.437 UTC [69903] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11582026/08/27 10:01:04 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11592026/08/27 10:01:04 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1160--- PASS: TestService_NativeMTLS (3.15s)1161=== CONT TestCacheStatsHandler1162--- PASS: TestMetricsInventory (3.13s)1163=== CONT TestGCTaskStore_PhaseUpdates1164--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1165=== CONT TestService_healthCheckHandler11662026/08/27 10:01:04 OK 20241026095416_initial_model.sql (188.42ms)11672026/08/27 10:01:04 OK 20251210153512_drop_unused_gin_index.sql (13.57ms)11682026-08-27 10:01:04.734 UTC [69906] ERROR: relation "goose_db_version" does not exist at character 3611692026-08-27 10:01:04.734 UTC [69906] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11702026-08-27 10:01:04.735 UTC [69908] ERROR: relation "goose_db_version" does not exist at character 3611712026-08-27 10:01:04.735 UTC [69908] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11722026-08-27 10:01:04.744 UTC [69907] ERROR: relation "goose_db_version" does not exist at character 3611732026-08-27 10:01:04.744 UTC [69907] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11742026/08/27 10:01:04 OK 20251218171726_add_pins.sql (36.42ms)11752026/08/27 10:01:04 OK 20260628120000_add_object_size_and_stats.sql (20.96ms)11762026/08/27 10:01:04 goose: successfully migrated database to version: 2026062812000011772026/08/27 10:01:04 OK 1_commit_pending_closure.sql (3.17ms)11782026/08/27 10:01:04 OK 2_object_stats_trigger.sql (683.54µs)11792026/08/27 10:01:04 goose: up to current file version: 211802026/08/27 10:01:05 OK 20241026095416_initial_model.sql (244.91ms)11812026-08-27 10:01:05.026 UTC [69911] ERROR: relation "goose_db_version" does not exist at character 3611822026-08-27 10:01:05.026 UTC [69911] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11832026/08/27 10:01:05 OK 20241026095416_initial_model.sql (224ms)11842026/08/27 10:01:05 OK 20241026095416_initial_model.sql (224.08ms)11852026/08/27 10:01:05 OK 20251210153512_drop_unused_gin_index.sql (9.54ms)11862026/08/27 10:01:05 OK 20251210153512_drop_unused_gin_index.sql (5.36ms)11872026/08/27 10:01:05 OK 20251210153512_drop_unused_gin_index.sql (10.56ms)11882026/08/27 10:01:05 OK 20251218171726_add_pins.sql (34.22ms)11892026/08/27 10:01:05 OK 20251218171726_add_pins.sql (32.26ms)11902026/08/27 10:01:05 OK 20251218171726_add_pins.sql (27.49ms)11912026/08/27 10:01:05 OK 20260628120000_add_object_size_and_stats.sql (31.88ms)11922026/08/27 10:01:05 goose: successfully migrated database to version: 2026062812000011932026/08/27 10:01:05 OK 20260628120000_add_object_size_and_stats.sql (31.96ms)11942026/08/27 10:01:05 goose: successfully migrated database to version: 2026062812000011952026/08/27 10:01:05 OK 20260628120000_add_object_size_and_stats.sql (32.6ms)11962026/08/27 10:01:05 goose: successfully migrated database to version: 2026062812000011972026/08/27 10:01:05 OK 1_commit_pending_closure.sql (1.61ms)11982026/08/27 10:01:05 OK 2_object_stats_trigger.sql (268.79µs)11992026/08/27 10:01:05 goose: up to current file version: 212002026/08/27 10:01:05 OK 1_commit_pending_closure.sql (8.59ms)12012026/08/27 10:01:05 OK 1_commit_pending_closure.sql (8.64ms)12022026/08/27 10:01:05 OK 2_object_stats_trigger.sql (286.71µs)12032026/08/27 10:01:05 goose: up to current file version: 212042026/08/27 10:01:05 OK 2_object_stats_trigger.sql (264.04µs)12052026/08/27 10:01:05 goose: up to current file version: 21206=== NAME TestNARDeduplicationMetadataUploadBug1207 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-69671-594980882/TestNARDeduplicationMetadataUploadBug1051715439/001/store/fvr7j8snni44gr39k9rwmqs0dgryi7rb-file1.txt12082026/08/27 10:01:05 OK 20241026095416_initial_model.sql (206.7ms)12092026/08/27 10:01:05 OK 20251210153512_drop_unused_gin_index.sql (12.28ms)12102026/08/27 10:01:05 OK 20251218171726_add_pins.sql (43.79ms)12112026/08/27 10:01:05 OK 20260628120000_add_object_size_and_stats.sql (36.05ms)12122026/08/27 10:01:05 goose: successfully migrated database to version: 2026062812000012132026/08/27 10:01:05 OK 1_commit_pending_closure.sql (6.67ms)12142026/08/27 10:01:05 OK 2_object_stats_trigger.sql (260.79µs)12152026/08/27 10:01:05 goose: up to current file version: 212162026/08/27 10:01:05 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12172026/08/27 10:01:05 INFO Received uploads request method=POST path=/api/pending_closures12182026/08/27 10:01:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12192026/08/27 10:01:05 INFO Uploading fvr7j8snni44gr39k9rwmqs0dgryi7rb-file1.txt (160B)12202026/08/27 10:01:05 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12212026/08/27 10:01:05 WARN Failed to register uploaded object key=fvr7j8snni44gr39k9rwmqs0dgryi7rb.ls error="server returned 404: 404 page not found\n"12222026/08/27 10:01:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12232026/08/27 10:01:05 INFO Signed narinfos id=1 count=112242026/08/27 10:01:05 INFO Uploading 1 narinfos12252026/08/27 10:01:05 WARN Failed to register uploaded object key=fvr7j8snni44gr39k9rwmqs0dgryi7rb.narinfo error="server returned 404: 404 page not found\n"12262026/08/27 10:01:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12272026/08/27 10:01:05 INFO Completed upload id=112282026/08/27 10:01:05 INFO Upload complete. (335ms)1229 metadata_upload_test.go:54: Retrieved narinfo from S3:1230 StorePath: /nix/var/nix/builds/nix-69671-594980882/TestNARDeduplicationMetadataUploadBug1051715439/001/store/fvr7j8snni44gr39k9rwmqs0dgryi7rb-file1.txt1231 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1232 Compression: zstd1233 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1234 NarSize: 1601235 References: 1236 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1237 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1238 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1239 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1240=== NAME TestPinProtectsFromGC1241 client_integration_test.go:646: Pinned store path: /nix/var/nix/builds/nix-69671-594980882/TestPinProtectsFromGC930585239/001/store/b571pqha26fg6c3215n4q2bkq4b5zhsl-pinned-file.txt1242 client_integration_test.go:647: Unpinned store path: /nix/var/nix/builds/nix-69671-594980882/TestPinProtectsFromGC930585239/001/store/x1q5wc13d23a39qkkffj4iqrr92zna0k-unpinned-file.txt1243=== NAME TestClientMultipleUploads1244 client_integration_test.go:338: Created store path 0: /nix/var/nix/builds/nix-69671-594980882/TestClientMultipleUploads3051094693/001/store/5bb10fapcwgvrw09ajx4m0bh9xzda47v-test-file-0.txt1245=== NAME TestNARDeduplicationMetadataUploadBug1246 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-69671-594980882/TestNARDeduplicationMetadataUploadBug1051715439/001/store/mbipq37qrydxglx0nj98ilnh60hz82pd-file2.txt12472026/08/27 10:01:05 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12482026/08/27 10:01:05 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1249--- PASS: TestService_ReadAuthMiddleware (3.00s)1250=== CONT TestGracefulShutdownDrainsInflight12512026/08/27 10:01:05 INFO Starting HTTP server address=127.0.0.1:5470812522026/08/27 10:01:05 INFO Shutdown signal received, draining in-flight requests timeout=10s12532026/08/27 10:01:05 INFO Received uploads request method=POST path=/api/pending_closures12542026/08/27 10:01:05 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12552026-08-27 10:01:05.847 UTC [69941] ERROR: relation "goose_db_version" does not exist at character 3612562026-08-27 10:01:05.847 UTC [69941] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1257=== NAME TestClientMultipleUploads1258 client_integration_test.go:338: Created store path 1: /nix/var/nix/builds/nix-69671-594980882/TestClientMultipleUploads3051094693/001/store/xqjrzjyqjpa5gyh18rc75ivnsmg5llyj-test-file-1.txt12592026/08/27 10:01:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12602026/08/27 10:01:05 INFO Uploading b571pqha26fg6c3215n4q2bkq4b5zhsl-pinned-file.txt (128B)1261--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1262=== CONT TestGCTaskStore_Fail1263--- PASS: TestGCTaskStore_Fail (0.00s)1264=== CONT TestGCTaskStore_GetReturnsLatest1265--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1266=== CONT TestGCTaskStore_CompletedAllowsNewTask1267--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1268=== CONT TestPresignedUploadRegisteredBeforeCommit12692026/08/27 10:01:05 INFO Received uploads request method=POST path=/api/pending_closures12702026/08/27 10:01:05 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12712026/08/27 10:01:05 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12722026/08/27 10:01:05 WARN Rate limiter enabled after throttle name=s3-test rate=512732026/08/27 10:01:05 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1274=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1275 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101276 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001277--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.67s)1278=== CONT TestService_Rustfstest12792026/08/27 10:01:05 WARN Failed to register uploaded object key=mbipq37qrydxglx0nj98ilnh60hz82pd.ls error="server returned 404: 404 page not found\n"12802026/08/27 10:01:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12812026/08/27 10:01:05 INFO Signed narinfos id=2 count=112822026/08/27 10:01:05 INFO Uploading 1 narinfos12832026/08/27 10:01:05 WARN Failed to register uploaded object key=b571pqha26fg6c3215n4q2bkq4b5zhsl.ls error="server returned 404: 404 page not found\n"12842026/08/27 10:01:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12852026/08/27 10:01:05 INFO Signed narinfos id=1 count=112862026/08/27 10:01:05 INFO Uploading 1 narinfos1287=== NAME TestClientMultipleUploads1288 client_integration_test.go:338: Created store path 2: /nix/var/nix/builds/nix-69671-594980882/TestClientMultipleUploads3051094693/001/store/a617ph77grrwl4h7a7girpz3zhn33zh6-test-file-2.txt12892026/08/27 10:01:05 WARN Failed to register uploaded object key=mbipq37qrydxglx0nj98ilnh60hz82pd.narinfo error="server returned 404: 404 page not found\n"12902026/08/27 10:01:05 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12912026/08/27 10:01:05 INFO Completed upload id=212922026/08/27 10:01:05 INFO Upload complete. (176ms)1293=== NAME TestNARDeduplicationMetadataUploadBug1294 metadata_upload_test.go:76: Retrieved narinfo from S3:1295 StorePath: /nix/var/nix/builds/nix-69671-594980882/TestNARDeduplicationMetadataUploadBug1051715439/001/store/mbipq37qrydxglx0nj98ilnh60hz82pd-file2.txt1296 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1297 Compression: zstd1298 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1299 NarSize: 1601300 References: 1301 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1302 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1303 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1304 {"version":1,"root":{"type":"regular","size":44}}13052026/08/27 10:01:05 WARN Failed to register uploaded object key=b571pqha26fg6c3215n4q2bkq4b5zhsl.narinfo error="server returned 404: 404 page not found\n"13062026/08/27 10:01:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13072026/08/27 10:01:06 INFO Completed upload id=113082026/08/27 10:01:06 INFO Upload complete. (308ms)13092026/08/27 10:01:06 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1310--- PASS: TestNARDeduplicationMetadataUploadBug (4.15s)1311=== CONT TestReadProxyDisabled13122026/08/27 10:01:06 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13132026/08/27 10:01:06 INFO Received uploads request method=POST path=/api/pending_closures1314=== NAME TestClientWithDependencies1315 client_integration_test.go:593: Built derivation: /nix/var/nix/builds/nix-69671-594980882/TestClientWithDependencies228238731/001/store/7bc5mybh7cm2l83s8vjwdbs7lzhgfsmd-test-script13162026/08/27 10:01:06 INFO Received uploads request method=POST path=/api/pending_closures13172026/08/27 10:01:06 OK 20241026095416_initial_model.sql (205.02ms)13182026/08/27 10:01:06 INFO Received uploads request method=POST path=/api/pending_closures13192026/08/27 10:01:06 INFO Received uploads request method=POST path=/api/pending_closures13202026/08/27 10:01:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13212026/08/27 10:01:06 INFO Uploading x1q5wc13d23a39qkkffj4iqrr92zna0k-unpinned-file.txt (128B)13222026/08/27 10:01:06 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13232026/08/27 10:01:06 INFO Uploading 5bb10fapcwgvrw09ajx4m0bh9xzda47v-test-file-0.txt (160B)13242026/08/27 10:01:06 INFO Uploading xqjrzjyqjpa5gyh18rc75ivnsmg5llyj-test-file-1.txt (160B)13252026/08/27 10:01:06 INFO Uploading a617ph77grrwl4h7a7girpz3zhn33zh6-test-file-2.txt (160B)13262026/08/27 10:01:06 OK 20251210153512_drop_unused_gin_index.sql (7.34ms)13272026/08/27 10:01:06 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13282026/08/27 10:01:06 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13292026/08/27 10:01:06 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"1330 client_integration_test.go:595: Found 1 dependencies (including self)13312026/08/27 10:01:06 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13322026/08/27 10:01:06 OK 20251218171726_add_pins.sql (62.35ms)13332026/08/27 10:01:06 WARN Failed to register uploaded object key=5bb10fapcwgvrw09ajx4m0bh9xzda47v.ls error="server returned 404: 404 page not found\n"13342026/08/27 10:01:06 WARN Failed to register uploaded object key=x1q5wc13d23a39qkkffj4iqrr92zna0k.ls error="server returned 404: 404 page not found\n"13352026/08/27 10:01:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13362026/08/27 10:01:06 INFO Signed narinfos id=2 count=113372026/08/27 10:01:06 INFO Uploading 1 narinfos13382026/08/27 10:01:06 WARN Failed to register uploaded object key=xqjrzjyqjpa5gyh18rc75ivnsmg5llyj.ls error="server returned 404: 404 page not found\n"13392026/08/27 10:01:06 WARN Failed to register uploaded object key=a617ph77grrwl4h7a7girpz3zhn33zh6.ls error="server returned 404: 404 page not found\n"13402026/08/27 10:01:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13412026/08/27 10:01:06 INFO Signed narinfos id=1 count=113422026/08/27 10:01:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13432026/08/27 10:01:06 INFO Signed narinfos id=2 count=113442026/08/27 10:01:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign13452026/08/27 10:01:06 INFO Signed narinfos id=3 count=113462026/08/27 10:01:06 INFO Uploading 3 narinfos13472026/08/27 10:01:06 OK 20260628120000_add_object_size_and_stats.sql (54.52ms)13482026/08/27 10:01:06 goose: successfully migrated database to version: 2026062812000013492026/08/27 10:01:06 OK 1_commit_pending_closure.sql (1.52ms)13502026/08/27 10:01:06 OK 2_object_stats_trigger.sql (245µs)13512026/08/27 10:01:06 goose: up to current file version: 213522026/08/27 10:01:06 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13532026/08/27 10:01:06 INFO Received uploads request method=POST path=/api/pending_closures13542026/08/27 10:01:06 WARN Failed to register uploaded object key=xqjrzjyqjpa5gyh18rc75ivnsmg5llyj.narinfo error="server returned 404: 404 page not found\n"13552026/08/27 10:01:06 WARN Failed to register uploaded object key=x1q5wc13d23a39qkkffj4iqrr92zna0k.narinfo error="server returned 404: 404 page not found\n"13562026/08/27 10:01:06 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13572026/08/27 10:01:06 INFO Completed upload id=213582026/08/27 10:01:06 INFO Upload complete. (248ms)13592026/08/27 10:01:06 WARN Failed to register uploaded object key=5bb10fapcwgvrw09ajx4m0bh9xzda47v.narinfo error="server returned 404: 404 page not found\n"13602026/08/27 10:01:06 WARN Failed to register uploaded object key=a617ph77grrwl4h7a7girpz3zhn33zh6.narinfo error="server returned 404: 404 page not found\n"13612026/08/27 10:01:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13622026/08/27 10:01:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13632026/08/27 10:01:06 INFO Uploading 7bc5mybh7cm2l83s8vjwdbs7lzhgfsmd-test-script (136B)13642026/08/27 10:01:06 INFO Received create pin request method=POST path=/api/pins/myapp13652026/08/27 10:01:06 INFO Completed upload id=113662026/08/27 10:01:06 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13672026/08/27 10:01:06 INFO Completed upload id=213682026/08/27 10:01:06 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete13692026/08/27 10:01:06 INFO Completed upload id=313702026/08/27 10:01:06 INFO Upload complete. (354ms)1371=== NAME TestClientMultipleUploads1372 client_integration_test.go:349: Uploaded 3 paths in 385.721875ms13732026/08/27 10:01:06 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13742026/08/27 10:01:06 WARN Failed to register uploaded object key=log/01vfcb1k38vs5f9yvxj8g43lkl7fmv2i-test-script.drv error="server returned 404: 404 page not found\n"13752026/08/27 10:01:06 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-69671-594980882/TestPinProtectsFromGC930585239/001/store/b571pqha26fg6c3215n4q2bkq4b5zhsl-pinned-file.txt narinfo_key=b571pqha26fg6c3215n4q2bkq4b5zhsl.narinfo13762026/08/27 10:01:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures13772026/08/27 10:01:06 INFO Garbage collection started13782026/08/27 10:01:06 INFO Aborted multipart uploads count=013792026/08/27 10:01:06 WARN Force mode enabled - objects will be deleted immediately without grace period13802026/08/27 10:01:06 WARN Failed to register uploaded object key=7bc5mybh7cm2l83s8vjwdbs7lzhgfsmd.ls error="server returned 404: 404 page not found\n"13812026/08/27 10:01:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13822026/08/27 10:01:06 INFO Signed narinfos id=1 count=113832026/08/27 10:01:06 INFO Uploading 1 narinfos13842026-08-27 10:01:06.459 UTC [69976] ERROR: relation "goose_db_version" does not exist at character 3613852026-08-27 10:01:06.459 UTC [69976] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1386=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1387=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1388=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1389=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1390=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1391=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1392=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1393=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1394=== CONT TestReadProxyRangeRequest1395--- PASS: TestClientMultipleUploads (3.96s)1396=== CONT TestReadRedirectKeepsNarinfoProxied13972026/08/27 10:01:06 WARN Failed to register uploaded object key=7bc5mybh7cm2l83s8vjwdbs7lzhgfsmd.narinfo error="server returned 404: 404 page not found\n"13982026/08/27 10:01:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13992026/08/27 10:01:06 INFO Completed upload id=114002026/08/27 10:01:06 INFO Upload complete. (317ms)1401=== NAME TestClientWithDependencies1402 client_integration_test.go:597: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-69671-594980882/TestClientWithDependencies228238731/001/store) requires matching store prefix14032026/08/27 10:01:06 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=01404--- PASS: TestClientWithDependencies (4.09s)1405=== CONT TestReadRedirectNar14062026/08/27 10:01:06 INFO Vacuumed table table=pending_closures14072026-08-27 10:01:06.564 UTC [69983] ERROR: relation "goose_db_version" does not exist at character 3614082026-08-27 10:01:06.564 UTC [69983] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14092026/08/27 10:01:06 INFO Vacuumed table table=pending_objects14102026/08/27 10:01:06 INFO Vacuumed table table=multipart_uploads14112026/08/27 10:01:06 OK 20241026095416_initial_model.sql (85.7ms)14122026/08/27 10:01:06 INFO Vacuumed table table=closures14132026/08/27 10:01:06 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)14142026/08/27 10:01:06 INFO Vacuumed table table=objects14152026/08/27 10:01:06 OK 20251218171726_add_pins.sql (15.05ms)14162026/08/27 10:01:06 OK 20260628120000_add_object_size_and_stats.sql (16.37ms)14172026/08/27 10:01:06 goose: successfully migrated database to version: 2026062812000014182026/08/27 10:01:06 OK 1_commit_pending_closure.sql (5.68ms)14192026/08/27 10:01:06 OK 2_object_stats_trigger.sql (213.58µs)14202026/08/27 10:01:06 goose: up to current file version: 214212026/08/27 10:01:06 OK 20241026095416_initial_model.sql (124.95ms)14222026/08/27 10:01:06 OK 20251210153512_drop_unused_gin_index.sql (8.5ms)14232026/08/27 10:01:06 OK 20251218171726_add_pins.sql (24.48ms)14242026/08/27 10:01:06 OK 20260628120000_add_object_size_and_stats.sql (17.65ms)14252026/08/27 10:01:06 goose: successfully migrated database to version: 2026062812000014262026/08/27 10:01:06 OK 1_commit_pending_closure.sql (2.06ms)14272026/08/27 10:01:06 OK 2_object_stats_trigger.sql (357.17µs)14282026/08/27 10:01:06 goose: up to current file version: 21429--- PASS: TestCacheStatsHandler (2.34s)1430=== CONT TestGCTaskStore_GetEmpty1431--- PASS: TestGCTaskStore_GetEmpty (0.00s)1432=== CONT TestCompletedNarNotReofferedAcrossClosures1433--- PASS: TestService_healthCheckHandler (2.20s)1434=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14352026-08-27 10:01:07.772 UTC [69990] ERROR: relation "goose_db_version" does not exist at character 3614362026-08-27 10:01:07.772 UTC [69990] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14372026-08-27 10:01:07.842 UTC [69991] ERROR: relation "goose_db_version" does not exist at character 3614382026-08-27 10:01:07.842 UTC [69991] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14392026-08-27 10:01:07.897 UTC [69992] ERROR: relation "goose_db_version" does not exist at character 3614402026-08-27 10:01:07.897 UTC [69992] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14412026/08/27 10:01:08 OK 20241026095416_initial_model.sql (233.18ms)14422026/08/27 10:01:08 OK 20251210153512_drop_unused_gin_index.sql (10.8ms)14432026/08/27 10:01:08 OK 20251218171726_add_pins.sql (14.68ms)14442026/08/27 10:01:08 OK 20260628120000_add_object_size_and_stats.sql (48.49ms)14452026/08/27 10:01:08 goose: successfully migrated database to version: 2026062812000014462026/08/27 10:01:08 OK 1_commit_pending_closure.sql (17.39ms)14472026/08/27 10:01:08 OK 2_object_stats_trigger.sql (1.02ms)14482026/08/27 10:01:08 goose: up to current file version: 214492026/08/27 10:01:08 OK 20241026095416_initial_model.sql (257.77ms)14502026/08/27 10:01:08 OK 20251210153512_drop_unused_gin_index.sql (9.96ms)14512026/08/27 10:01:08 OK 20251218171726_add_pins.sql (57.49ms)14522026/08/27 10:01:08 OK 20241026095416_initial_model.sql (264.79ms)14532026/08/27 10:01:08 OK 20251210153512_drop_unused_gin_index.sql (12.6ms)14542026/08/27 10:01:08 OK 20260628120000_add_object_size_and_stats.sql (33.75ms)14552026/08/27 10:01:08 goose: successfully migrated database to version: 2026062812000014562026/08/27 10:01:08 OK 1_commit_pending_closure.sql (22.09ms)14572026/08/27 10:01:08 OK 2_object_stats_trigger.sql (1.82ms)14582026/08/27 10:01:08 goose: up to current file version: 214592026/08/27 10:01:08 OK 20251218171726_add_pins.sql (57.96ms)14602026/08/27 10:01:08 OK 20260628120000_add_object_size_and_stats.sql (52.88ms)14612026/08/27 10:01:08 goose: successfully migrated database to version: 2026062812000014622026/08/27 10:01:08 OK 1_commit_pending_closure.sql (17.88ms)14632026/08/27 10:01:08 OK 2_object_stats_trigger.sql (1.15ms)14642026/08/27 10:01:08 goose: up to current file version: 214652026/08/27 10:01:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01466--- PASS: TestService_Rustfstest (2.52s)1467=== CONT TestService_AuthMiddleware_MTLSProxyHeader1468=== NAME TestPinProtectsFromGC1469 client_integration_test.go:709: Pin successfully protected closure from garbage collection14702026-08-27 10:01:08.534 UTC [69994] ERROR: relation "goose_db_version" does not exist at character 3614712026-08-27 10:01:08.534 UTC [69994] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1472--- PASS: TestPinProtectsFromGC (6.06s)1473=== CONT TestCompleteMultipartUpload_ErrorButObjectExists14742026-08-27 10:01:08.576 UTC [69996] ERROR: relation "goose_db_version" does not exist at character 3614752026-08-27 10:01:08.576 UTC [69996] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14762026/08/27 10:01:08 INFO Received uploads request method=POST path=/api/pending_closures14772026/08/27 10:01:08 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst14782026/08/27 10:01:08 INFO Received uploads request method=POST path=/api/pending_closures1479--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.88s)1480=== CONT TestReadProxyConditionalGet14812026-08-27 10:01:08.812 UTC [69999] ERROR: relation "goose_db_version" does not exist at character 3614822026-08-27 10:01:08.812 UTC [69999] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14832026/08/27 10:01:08 OK 20241026095416_initial_model.sql (206.7ms)14842026/08/27 10:01:08 OK 20251210153512_drop_unused_gin_index.sql (10.73ms)14852026/08/27 10:01:08 OK 20251218171726_add_pins.sql (32.75ms)1486--- PASS: TestReadProxyDisabled (2.81s)1487=== CONT TestReadProxyRootRedirectsToIndexHTML14882026/08/27 10:01:08 OK 20241026095416_initial_model.sql (202.67ms)14892026/08/27 10:01:08 OK 20260628120000_add_object_size_and_stats.sql (40.43ms)14902026/08/27 10:01:08 goose: successfully migrated database to version: 2026062812000014912026/08/27 10:01:08 OK 20251210153512_drop_unused_gin_index.sql (3.29ms)14922026/08/27 10:01:08 OK 1_commit_pending_closure.sql (3.64ms)14932026/08/27 10:01:08 OK 2_object_stats_trigger.sql (386µs)14942026/08/27 10:01:08 goose: up to current file version: 214952026/08/27 10:01:08 OK 20251218171726_add_pins.sql (48.22ms)14962026/08/27 10:01:08 OK 20260628120000_add_object_size_and_stats.sql (41.6ms)14972026/08/27 10:01:08 goose: successfully migrated database to version: 2026062812000014982026/08/27 10:01:09 OK 1_commit_pending_closure.sql (12.07ms)14992026/08/27 10:01:09 OK 2_object_stats_trigger.sql (1.06ms)15002026/08/27 10:01:09 goose: up to current file version: 215012026-08-27 10:01:09.026 UTC [70004] ERROR: relation "goose_db_version" does not exist at character 3615022026-08-27 10:01:09.026 UTC [70004] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15032026/08/27 10:01:09 OK 20241026095416_initial_model.sql (228.96ms)15042026/08/27 10:01:09 OK 20251210153512_drop_unused_gin_index.sql (11.36ms)15052026/08/27 10:01:09 OK 20251218171726_add_pins.sql (52.04ms)1506--- PASS: TestReadProxyRangeRequest (2.72s)1507=== CONT TestReadProxyHead15082026/08/27 10:01:09 OK 20260628120000_add_object_size_and_stats.sql (24.06ms)15092026/08/27 10:01:09 goose: successfully migrated database to version: 2026062812000015102026/08/27 10:01:09 OK 1_commit_pending_closure.sql (6.16ms)15112026/08/27 10:01:09 OK 2_object_stats_trigger.sql (505.75µs)15122026/08/27 10:01:09 goose: up to current file version: 215132026-08-27 10:01:09.243 UTC [70006] ERROR: relation "goose_db_version" does not exist at character 3615142026-08-27 10:01:09.243 UTC [70006] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15152026/08/27 10:01:09 OK 20241026095416_initial_model.sql (141.56ms)15162026/08/27 10:01:09 OK 20251210153512_drop_unused_gin_index.sql (11.55ms)15172026/08/27 10:01:09 OK 20251218171726_add_pins.sql (9ms)15182026/08/27 10:01:09 OK 20260628120000_add_object_size_and_stats.sql (44.03ms)15192026/08/27 10:01:09 goose: successfully migrated database to version: 202606281200001520--- PASS: TestReadRedirectKeepsNarinfoProxied (2.88s)1521=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1522=== CONT TestCacheConfigHandler/full_config,_no_issuer1523=== CONT TestCacheConfigHandler/no_signing_keys1524=== CONT TestCacheConfigHandler/no_cache_url_configured1525--- PASS: TestCacheConfigHandler (0.00s)1526 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1527 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1528 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1529 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1530=== CONT TestIsValidCachePath/narinfo1531=== CONT TestIsValidCachePath/index.html1532=== CONT TestIsValidCachePath/short_hash1533=== CONT TestIsValidCachePath/wrong_extension1534=== CONT TestIsValidCachePath/leading_slash1535=== CONT TestIsValidCachePath/empty1536=== CONT TestIsValidCachePath/random_path1537=== CONT TestIsValidCachePath/invalid_char_u1538=== CONT TestIsValidCachePath/invalid_char_e1539=== CONT TestIsValidCachePath/traversal_in_middle1540=== CONT TestIsValidCachePath/traversal_parent1541=== CONT TestIsValidCachePath/nar_uncompressed1542=== CONT TestIsValidCachePath/nix-cache-info1543=== CONT TestIsValidCachePath/realisation1544=== CONT TestIsValidCachePath/log1545=== CONT TestIsValidCachePath/ls1546=== CONT TestIsValidCachePath/nar_xz1547=== CONT TestIsValidCachePath/nar_bz21548=== CONT TestIsValidCachePath/nar_zst1549=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1550--- PASS: TestIsValidCachePath (0.00s)1551 --- PASS: TestIsValidCachePath/narinfo (0.00s)1552 --- PASS: TestIsValidCachePath/index.html (0.00s)1553 --- PASS: TestIsValidCachePath/short_hash (0.00s)1554 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1555 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1556 --- PASS: TestIsValidCachePath/empty (0.00s)1557 --- PASS: TestIsValidCachePath/random_path (0.00s)1558 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1559 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1560 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1561 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1562 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1563 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1564 --- PASS: TestIsValidCachePath/realisation (0.00s)1565 --- PASS: TestIsValidCachePath/log (0.00s)1566 --- PASS: TestIsValidCachePath/ls (0.00s)1567 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1568 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)15692026/08/27 10:01:09 OK 1_commit_pending_closure.sql (16.05ms)1570 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1571 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1572=== CONT TestParseSingleRange/none1573=== CONT TestParseSingleRange/open-ended1574=== CONT TestParseSingleRange/start_far_past_EOF1575=== CONT TestParseSingleRange/start_past_EOF1576=== CONT TestParseSingleRange/single_byte1577=== CONT TestParseSingleRange/suffix_exceeds_size1578=== CONT TestParseSingleRange/suffix1579=== CONT TestParseSingleRange/end_clamped_to_size1580=== CONT TestParseSingleRange/closed1581=== CONT TestParseSingleRange/malformed_end_before_start1582=== CONT TestParseSingleRange/malformed_both_empty1583=== CONT TestParseSingleRange/multi-range_ignored1584=== CONT TestParseSingleRange/malformed_no_dash1585=== CONT TestParseSingleRange/unknown_unit1586--- PASS: TestParseSingleRange (0.00s)1587 --- PASS: TestParseSingleRange/none (0.00s)1588 --- PASS: TestParseSingleRange/open-ended (0.00s)1589 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1590 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1591 --- PASS: TestParseSingleRange/single_byte (0.00s)1592 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1593 --- PASS: TestParseSingleRange/suffix (0.00s)1594 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1595 --- PASS: TestParseSingleRange/closed (0.00s)1596 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1597 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1598 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1599 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1600 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1601=== CONT TestClientErrorHandling/InvalidStorePath16022026/08/27 10:01:09 OK 2_object_stats_trigger.sql (5.69ms)16032026/08/27 10:01:09 goose: up to current file version: 216042026/08/27 10:01:09 OK 20241026095416_initial_model.sql (191.94ms)16052026/08/27 10:01:09 OK 20251210153512_drop_unused_gin_index.sql (14.25ms)1606--- PASS: TestReadRedirectNar (2.96s)1607=== CONT TestClientErrorHandling/ServerNotAvailable16082026/08/27 10:01:09 OK 20251218171726_add_pins.sql (38.4ms)16092026/08/27 10:01:09 OK 20260628120000_add_object_size_and_stats.sql (42.84ms)16102026/08/27 10:01:09 goose: successfully migrated database to version: 2026062812000016112026/08/27 10:01:09 OK 1_commit_pending_closure.sql (8.86ms)16122026/08/27 10:01:09 OK 2_object_stats_trigger.sql (766.29µs)16132026/08/27 10:01:09 goose: up to current file version: 216142026/08/27 10:01:09 INFO Received uploads request method=POST path=/api/pending_closures16152026/08/27 10:01:09 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16162026/08/27 10:01:09 WARN mTLS auth: bound subjects configured but subject DN unavailable16172026/08/27 10:01:09 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1618--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.86s)1619=== CONT TestClientErrorHandling/InvalidAuthToken16202026/08/27 10:01:09 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-config16212026/08/27 10:01:09 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.005076ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config16222026/08/27 10:01:10 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=368.54378ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1623=== NAME TestOrphanedObjectsGCStressTest1624 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1625 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion16262026-08-27 10:01:10.288 UTC [70018] ERROR: relation "goose_db_version" does not exist at character 3616272026-08-27 10:01:10.288 UTC [70018] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16282026-08-27 10:01:10.295 UTC [70019] ERROR: relation "goose_db_version" does not exist at character 3616292026-08-27 10:01:10.295 UTC [70019] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16302026-08-27 10:01:10.337 UTC [70020] ERROR: relation "goose_db_version" does not exist at character 3616312026-08-27 10:01:10.337 UTC [70020] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16322026/08/27 10:01:10 OK 20241026095416_initial_model.sql (23.69ms)16332026/08/27 10:01:10 OK 20241026095416_initial_model.sql (24.32ms)16342026/08/27 10:01:10 OK 20251210153512_drop_unused_gin_index.sql (934.17µs)16352026/08/27 10:01:10 OK 20251210153512_drop_unused_gin_index.sql (1.07ms)16362026/08/27 10:01:10 OK 20251218171726_add_pins.sql (1.94ms)16372026/08/27 10:01:10 OK 20251218171726_add_pins.sql (2.44ms)16382026/08/27 10:01:10 OK 20260628120000_add_object_size_and_stats.sql (2.2ms)16392026/08/27 10:01:10 goose: successfully migrated database to version: 2026062812000016402026/08/27 10:01:10 OK 20260628120000_add_object_size_and_stats.sql (2.27ms)16412026/08/27 10:01:10 goose: successfully migrated database to version: 2026062812000016422026/08/27 10:01:10 OK 20241026095416_initial_model.sql (14.16ms)16432026/08/27 10:01:10 OK 1_commit_pending_closure.sql (1.7ms)16442026/08/27 10:01:10 OK 1_commit_pending_closure.sql (2.4ms)16452026/08/27 10:01:10 OK 2_object_stats_trigger.sql (323.75µs)16462026/08/27 10:01:10 goose: up to current file version: 216472026/08/27 10:01:10 OK 2_object_stats_trigger.sql (344.42µs)16482026/08/27 10:01:10 goose: up to current file version: 216492026/08/27 10:01:10 OK 20251210153512_drop_unused_gin_index.sql (15.6ms)16502026/08/27 10:01:10 OK 20251218171726_add_pins.sql (68.42ms)16512026/08/27 10:01:10 OK 20260628120000_add_object_size_and_stats.sql (44.87ms)16522026/08/27 10:01:10 goose: successfully migrated database to version: 2026062812000016532026/08/27 10:01:10 OK 1_commit_pending_closure.sql (8.95ms)16542026/08/27 10:01:10 OK 2_object_stats_trigger.sql (1.47ms)16552026/08/27 10:01:10 goose: up to current file version: 216562026-08-27 10:01:10.539 UTC [70021] ERROR: relation "goose_db_version" does not exist at character 3616572026-08-27 10:01:10.539 UTC [70021] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16582026/08/27 10:01:10 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=800.23797ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config16592026/08/27 10:01:10 INFO Received uploads request method=POST path=/api/pending_closures1660--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.33s)1661=== CONT TestIsValidUploadKey/narinfo1662=== CONT TestIsValidUploadKey/realisation_plus_in_output1663=== CONT TestIsValidUploadKey/unknown_type1664=== CONT TestIsValidUploadKey/empty_key1665=== CONT TestIsValidUploadKey/absolute1666=== CONT TestIsValidUploadKey/traversal_nar1667=== CONT TestIsValidUploadKey/traversal1668=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1669=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1670=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1671=== CONT TestIsValidUploadKey/index.html1672=== CONT TestIsValidUploadKey/nix-cache-info1673=== CONT TestIsValidUploadKey/build_log_home-manager_file1674=== CONT TestIsValidUploadKey/realisation1675=== CONT TestIsValidUploadKey/build_log_equals1676=== CONT TestIsValidUploadKey/build_log_question_mark1677=== CONT TestIsValidUploadKey/build_log_plus_in_name1678=== CONT TestIsValidUploadKey/nar_plain1679=== CONT TestIsValidUploadKey/build_log1680=== CONT TestIsValidUploadKey/listing1681=== CONT TestIsValidUploadKey/nar_xz1682=== CONT TestIsValidUploadKey/nar_zst1683--- PASS: TestIsValidUploadKey (0.00s)1684 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1685 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1686 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1687 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1688 --- PASS: TestIsValidUploadKey/absolute (0.00s)1689 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1690 --- PASS: TestIsValidUploadKey/traversal (0.00s)1691 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1692 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1693 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1694 --- PASS: TestIsValidUploadKey/index.html (0.00s)1695 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1696 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1697 --- PASS: TestIsValidUploadKey/realisation (0.00s)1698 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1699 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1700 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1701 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1702 --- PASS: TestIsValidUploadKey/build_log (0.00s)1703 --- PASS: TestIsValidUploadKey/listing (0.00s)1704 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1705 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1706=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17072026/08/27 10:01:10 INFO Received uploads request method=POST path=/17082026/08/27 10:01:10 OK 20241026095416_initial_model.sql (202.49ms)17092026/08/27 10:01:10 OK 20251210153512_drop_unused_gin_index.sql (15.56ms)17102026-08-27 10:01:10.895 UTC [70022] ERROR: relation "goose_db_version" does not exist at character 3617112026-08-27 10:01:10.895 UTC [70022] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17122026/08/27 10:01:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17132026/08/27 10:01:10 OK 20251218171726_add_pins.sql (15.15ms)17142026/08/27 10:01:10 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODU5YThlNzUtNzljZC00OWYxLWFkM2ItOWQxNzlmZmQ2YTcxLjBlMjRmZjJkLTBkMWMtNDA0MC1hYjdjLTQ1YjNhNDRkOGZmOXgxNzg3ODI0ODcwNjA1OTM1MDAw17152026/08/27 10:01:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODU5YThlNzUtNzljZC00OWYxLWFkM2ItOWQxNzlmZmQ2YTcxLjBlMjRmZjJkLTBkMWMtNDA0MC1hYjdjLTQ1YjNhNDRkOGZmOXgxNzg3ODI0ODcwNjA1OTM1MDAw parts=11716--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.34s)1717=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17182026/08/27 10:01:10 INFO Received request for more parts method=POST path=/1719=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17202026/08/27 10:01:10 INFO Received complete multipart upload request method=POST path=/17212026/08/27 10:01:10 OK 20260628120000_add_object_size_and_stats.sql (33.48ms)17222026/08/27 10:01:10 goose: successfully migrated database to version: 202606281200001723=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17242026/08/27 10:01:10 INFO Received uploads request method=POST path=/1725=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17262026/08/27 10:01:10 INFO Received complete multipart upload request method=POST path=/1727=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17282026/08/27 10:01:10 INFO Received request for more parts method=POST path=/1729=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17302026/08/27 10:01:10 INFO Received uploads request method=POST path=/1731--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1732 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1733 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1734 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1735 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1736=== CONT TestProxyWriteTimeout/narinfo1737=== CONT TestProxyWriteTimeout/10_GiB_nar1738=== CONT TestProxyWriteTimeout/unknown_size1739=== CONT TestProxyWriteTimeout/1_GiB_nar1740--- PASS: TestProxyWriteTimeout (0.00s)1741 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1742 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1743 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1744 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1745=== CONT TestServerTLSConfig/no_client_CA1746=== CONT TestServerTLSConfig/not_a_PEM_file17472026/08/27 10:01:10 OK 1_commit_pending_closure.sql (7.18ms)17482026/08/27 10:01:10 OK 2_object_stats_trigger.sql (379.79µs)17492026/08/27 10:01:10 goose: up to current file version: 21750=== CONT TestServerTLSConfig/missing_CA_file1751--- PASS: TestServerTLSConfig (0.00s)1752 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1753 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.04s)1754 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1755=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token17562026/08/27 10:01:10 INFO OIDC auth successful provider=test1757=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17582026/08/27 10:01:10 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]1759=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17602026/08/27 10:01:10 WARN Authentication failed token_preview=eyJhbGciOi...anNIgYGojA 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]1761=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1762--- PASS: TestService_AuthMiddleware_OIDC (2.83s)1763 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1764 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1765 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1766 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1767--- PASS: TestReadProxyConditionalGet (2.21s)1768--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)1769 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1770 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1771 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.30s)17722026/08/27 10:01:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17732026/08/27 10:01:11 OK 20241026095416_initial_model.sql (105.15ms)17742026/08/27 10:01:11 OK 20251210153512_drop_unused_gin_index.sql (27.82ms)17752026/08/27 10:01:11 OK 20251218171726_add_pins.sql (34.49ms)17762026/08/27 10:01:11 OK 20260628120000_add_object_size_and_stats.sql (10.57ms)17772026/08/27 10:01:11 goose: successfully migrated database to version: 202606281200001778--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.28s)17792026/08/27 10:01:11 OK 1_commit_pending_closure.sql (1.27ms)17802026/08/27 10:01:11 OK 2_object_stats_trigger.sql (249.08µs)17812026/08/27 10:01:11 goose: up to current file version: 217822026/08/27 10:01:11 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ODU5YThlNzUtNzljZC00OWYxLWFkM2ItOWQxNzlmZmQ2YTcxLjcxMTM3MzBmLWQxZWMtNDcyZS1iYmQyLTU3ZDk3NTA2ODA2NXgxNzg3ODI0ODY5NjUwOTg0MDAw parts=1217832026/08/27 10:01:11 INFO Received uploads request method=POST path=/api/pending_closures1784--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.37s)17852026-08-27 10:01:11.229 UTC [70023] ERROR: relation "goose_db_version" does not exist at character 3617862026-08-27 10:01:11.229 UTC [70023] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17872026-08-27 10:01:11.271 UTC [70024] ERROR: relation "goose_db_version" does not exist at character 3617882026-08-27 10:01:11.271 UTC [70024] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1789--- PASS: TestReadProxyHead (2.12s)17902026/08/27 10:01:11 OK 20241026095416_initial_model.sql (71.73ms)17912026/08/27 10:01:11 OK 20251210153512_drop_unused_gin_index.sql (10.62ms)17922026/08/27 10:01:11 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.688144372s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17932026/08/27 10:01:11 OK 20251218171726_add_pins.sql (33.54ms)17942026/08/27 10:01:11 OK 20241026095416_initial_model.sql (64.91ms)17952026/08/27 10:01:11 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)17962026/08/27 10:01:11 OK 20260628120000_add_object_size_and_stats.sql (4.09ms)17972026/08/27 10:01:11 goose: successfully migrated database to version: 2026062812000017982026/08/27 10:01:11 OK 20251218171726_add_pins.sql (3.1ms)17992026/08/27 10:01:11 OK 1_commit_pending_closure.sql (3.12ms)18002026/08/27 10:01:11 OK 2_object_stats_trigger.sql (664.63µs)18012026/08/27 10:01:11 goose: up to current file version: 218022026/08/27 10:01:11 OK 20260628120000_add_object_size_and_stats.sql (3.19ms)18032026/08/27 10:01:11 goose: successfully migrated database to version: 2026062812000018042026/08/27 10:01:11 OK 1_commit_pending_closure.sql (2.56ms)18052026/08/27 10:01:11 OK 2_object_stats_trigger.sql (616.17µs)18062026/08/27 10:01:11 goose: up to current file version: 218072026/08/27 10:01:11 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18082026/08/27 10:01:11 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1809=== NAME TestOrphanedObjectsGCStressTest1810 orphaned_objects_gc_test.go:509: Stress test completed successfully:1811 orphaned_objects_gc_test.go:510: - Active objects preserved: 201812 orphaned_objects_gc_test.go:511: - Objects deleted: 2101813 orphaned_objects_gc_test.go:512: - Total GC'd: 2101814--- PASS: TestOrphanedObjectsGCStressTest (13.73s)18152026/08/27 10:01:13 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"18162026/08/27 10:01:13 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_closures18172026/08/27 10:01:13 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=191.456276ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18182026/08/27 10:01:13 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.079697ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18192026/08/27 10:01:13 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=803.27475ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18202026/08/27 10:01:14 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.74402973s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1821--- PASS: TestClientErrorHandling (0.00s)1822 --- PASS: TestClientErrorHandling/InvalidStorePath (2.22s)1823 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.10s)1824 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.83s)1825PASS1826{"timestamp":"2026-08-27T10:01:16.339551Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:54679","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1836,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}18272026-08-27 10:01:16.447 UTC [69706] LOG: received smart shutdown request18282026-08-27 10:01:16.448 UTC [69706] LOG: background worker "logical replication launcher" (PID 69716) exited with exit code 118292026-08-27 10:01:16.453 UTC [69711] LOG: shutting down18302026-08-27 10:01:16.453 UTC [69711] LOG: checkpoint starting: shutdown immediate18312026-08-27 10:01:17.509 UTC [69711] LOG: checkpoint complete: wrote 13341 buffers (81.4%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 14 recycled; write=0.784 s, sync=0.271 s, total=1.057 s; sync files=15825, longest=0.001 s, average=0.001 s; distance=221754 kB, estimate=221754 kB; lsn=0/F019958, redo lsn=0/F01995818322026-08-27 10:01:17.513 UTC [69706] LOG: database system is shut down1833Running OIDC tests...1834=== RUN TestGlobMatch1835=== PAUSE TestGlobMatch1836=== RUN TestAudienceForIssuer1837=== PAUSE TestAudienceForIssuer1838=== RUN TestValidateToken_ValidToken1839=== PAUSE TestValidateToken_ValidToken1840=== RUN TestValidateToken_WrongAudience1841=== PAUSE TestValidateToken_WrongAudience1842=== RUN TestValidateToken_Expired1843=== PAUSE TestValidateToken_Expired1844=== RUN TestValidateToken_BoundClaimsMismatch1845=== PAUSE TestValidateToken_BoundClaimsMismatch1846=== RUN TestValidateToken_BoundSubjectMismatch1847=== PAUSE TestValidateToken_BoundSubjectMismatch1848=== RUN TestValidateToken_MultipleProviders1849=== PAUSE TestValidateToken_MultipleProviders1850=== RUN TestValidateToken_NoMatchingProvider1851=== PAUSE TestValidateToken_NoMatchingProvider1852=== CONT TestGlobMatch1853=== RUN TestGlobMatch/foo_foo1854=== CONT TestValidateToken_MultipleProviders1855=== CONT TestValidateToken_Expired1856=== CONT TestValidateToken_BoundClaimsMismatch1857=== CONT TestValidateToken_WrongAudience1858=== PAUSE TestGlobMatch/foo_foo1859=== RUN TestGlobMatch/foo_bar1860=== PAUSE TestGlobMatch/foo_bar1861=== RUN TestGlobMatch/*_1862=== PAUSE TestGlobMatch/*_1863=== RUN TestGlobMatch/*_anything1864=== PAUSE TestGlobMatch/*_anything1865=== RUN TestGlobMatch/foo*_foo1866=== PAUSE TestGlobMatch/foo*_foo1867=== CONT TestValidateToken_ValidToken1868=== CONT TestAudienceForIssuer1869--- PASS: TestAudienceForIssuer (0.00s)1870=== CONT TestValidateToken_NoMatchingProvider1871=== CONT TestValidateToken_BoundSubjectMismatch1872=== RUN TestGlobMatch/foo*_foobar1873=== PAUSE TestGlobMatch/foo*_foobar1874=== RUN TestGlobMatch/foo*_bar1875=== PAUSE TestGlobMatch/foo*_bar1876=== RUN TestGlobMatch/*bar_bar1877=== PAUSE TestGlobMatch/*bar_bar1878=== RUN TestGlobMatch/*bar_foobar1879=== PAUSE TestGlobMatch/*bar_foobar1880=== RUN TestGlobMatch/*bar_foo1881=== PAUSE TestGlobMatch/*bar_foo1882=== RUN TestGlobMatch/foo*bar_foobar1883=== PAUSE TestGlobMatch/foo*bar_foobar1884=== RUN TestGlobMatch/foo*bar_foo123bar1885=== PAUSE TestGlobMatch/foo*bar_foo123bar1886=== RUN TestGlobMatch/foo*bar_foobarbaz1887=== PAUSE TestGlobMatch/foo*bar_foobarbaz1888=== RUN TestGlobMatch/*/*_foo/bar1889=== PAUSE TestGlobMatch/*/*_foo/bar1890=== RUN TestGlobMatch/*/*_foo1891=== PAUSE TestGlobMatch/*/*_foo1892=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1893=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1894=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01895=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01896=== RUN TestGlobMatch/refs/*/main_refs/heads/main1897=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1898=== RUN TestGlobMatch/fo?_foo1899=== PAUSE TestGlobMatch/fo?_foo1900=== RUN TestGlobMatch/fo?_fo1901=== PAUSE TestGlobMatch/fo?_fo1902=== RUN TestGlobMatch/fo?_fooo1903=== PAUSE TestGlobMatch/fo?_fooo1904=== RUN TestGlobMatch/?oo_foo1905=== PAUSE TestGlobMatch/?oo_foo1906=== RUN TestGlobMatch/?oo_boo1907=== PAUSE TestGlobMatch/?oo_boo1908=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1909=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1910=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1911=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1912=== CONT TestGlobMatch/foo_foo1913=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1914=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1915=== CONT TestGlobMatch/?oo_boo1916=== CONT TestGlobMatch/?oo_foo1917=== CONT TestGlobMatch/fo?_fooo1918=== CONT TestGlobMatch/fo?_fo1919=== CONT TestGlobMatch/fo?_foo1920=== CONT TestGlobMatch/refs/*/main_refs/heads/main1921=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01922=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1923=== CONT TestGlobMatch/*/*_foo1924=== CONT TestGlobMatch/*/*_foo/bar1925=== CONT TestGlobMatch/foo*bar_foobarbaz1926=== CONT TestGlobMatch/foo*bar_foo123bar1927=== CONT TestGlobMatch/foo*_foobar1928=== CONT TestGlobMatch/foo*_foo1929=== CONT TestGlobMatch/*_anything1930=== CONT TestGlobMatch/*_1931=== CONT TestGlobMatch/foo_bar1932=== CONT TestGlobMatch/*bar_foo1933=== CONT TestGlobMatch/foo*bar_foobar1934=== CONT TestGlobMatch/*bar_foobar1935=== CONT TestGlobMatch/*bar_bar1936=== CONT TestGlobMatch/foo*_bar1937--- PASS: TestGlobMatch (0.00s)1938 --- PASS: TestGlobMatch/foo_foo (0.00s)1939 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1940 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1941 --- PASS: TestGlobMatch/?oo_boo (0.00s)1942 --- PASS: TestGlobMatch/?oo_foo (0.00s)1943 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1944 --- PASS: TestGlobMatch/fo?_fo (0.00s)1945 --- PASS: TestGlobMatch/fo?_foo (0.00s)1946 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1947 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1948 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1949 --- PASS: TestGlobMatch/*/*_foo (0.00s)1950 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1951 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1952 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1953 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1954 --- PASS: TestGlobMatch/foo*_foo (0.00s)1955 --- PASS: TestGlobMatch/*_anything (0.00s)1956 --- PASS: TestGlobMatch/*_ (0.00s)1957 --- PASS: TestGlobMatch/foo_bar (0.00s)1958 --- PASS: TestGlobMatch/*bar_foo (0.00s)1959 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1960 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1961 --- PASS: TestGlobMatch/*bar_bar (0.00s)1962 --- PASS: TestGlobMatch/foo*_bar (0.00s)19632026/08/27 10:01:18 INFO OIDC provider initialized name=test19642026/08/27 10:01:18 INFO OIDC provider initialized name=test19652026/08/27 10:01:18 INFO OIDC provider initialized name=test19662026/08/27 10:01:18 INFO OIDC provider initialized name=test19672026/08/27 10:01:18 INFO OIDC provider initialized name=test19682026/08/27 10:01:18 INFO OIDC provider initialized name=provider119692026/08/27 10:01:18 INFO OIDC provider initialized name=provider119702026/08/27 10:01:18 INFO OIDC provider initialized name=provider21971--- PASS: TestValidateToken_ValidToken (0.01s)1972--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1973--- PASS: TestValidateToken_WrongAudience (0.01s)1974--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1975--- PASS: TestValidateToken_Expired (0.01s)1976--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1977--- PASS: TestValidateToken_MultipleProviders (0.01s)1978PASS1979Running hook tests...1980=== RUN TestSendPathsEmpty1981=== PAUSE TestSendPathsEmpty1982=== RUN TestQueueEnqueueAndFetch1983=== PAUSE TestQueueEnqueueAndFetch1984=== RUN TestQueueDeduplication1985=== PAUSE TestQueueDeduplication1986=== RUN TestQueueRemove1987=== PAUSE TestQueueRemove1988=== RUN TestQueueFetchBatchLimit1989=== PAUSE TestQueueFetchBatchLimit1990=== RUN TestQueueRetryMovesToBack1991=== PAUSE TestQueueRetryMovesToBack1992=== RUN TestQueueFetchRemoveLifecycle1993=== PAUSE TestQueueFetchRemoveLifecycle1994=== RUN TestQueueConcurrentWriters1995=== PAUSE TestQueueConcurrentWriters1996=== RUN TestQueueRemoveLargeClosure1997=== PAUSE TestQueueRemoveLargeClosure1998=== RUN TestServerClientIntegration1999=== PAUSE TestServerClientIntegration2000=== RUN TestServerQueueError2001=== PAUSE TestServerQueueError2002=== RUN TestGetListenerSocketActivation2003 server_test.go:210: === RUN TestGetListenerSocketActivation2004 --- PASS: TestGetListenerSocketActivation (0.00s)2005 PASS2006 2007--- PASS: TestGetListenerSocketActivation (0.01s)2008=== RUN TestDrainIsolatesPoisonPath2009=== PAUSE TestDrainIsolatesPoisonPath2010=== RUN TestRunNotBlockedByPoisonHead2011=== PAUSE TestRunNotBlockedByPoisonHead2012=== RUN TestDrainGivesUpWhenServerDown2013=== PAUSE TestDrainGivesUpWhenServerDown2014=== RUN TestFailedPathPrunedByLaterClosure2015=== PAUSE TestFailedPathPrunedByLaterClosure2016=== RUN TestWorkerUploadsAndRemoves2017=== PAUSE TestWorkerUploadsAndRemoves2018=== RUN TestWorkerSkipsGCdPaths2019=== PAUSE TestWorkerSkipsGCdPaths2020=== RUN TestWorkerPrunesClosureDeps2021=== PAUSE TestWorkerPrunesClosureDeps2022=== RUN TestDrainTimeoutStopsSlowDrain2023=== PAUSE TestDrainTimeoutStopsSlowDrain2024=== RUN TestDrainWithoutTimeoutRunsToCompletion2025=== PAUSE TestDrainWithoutTimeoutRunsToCompletion2026=== RUN TestDrainTimeoutNotWaitedOutOnSuccess2027=== PAUSE TestDrainTimeoutNotWaitedOutOnSuccess2028=== CONT TestSendPathsEmpty2029=== CONT TestDrainIsolatesPoisonPath2030--- PASS: TestSendPathsEmpty (0.00s)2031=== CONT TestQueueFetchRemoveLifecycle2032=== CONT TestQueueDeduplication2033=== CONT TestQueueEnqueueAndFetch2034=== CONT TestQueueRetryMovesToBack2035=== CONT TestQueueFetchBatchLimit2036=== CONT TestServerClientIntegration2037=== CONT TestServerQueueError2038=== CONT TestWorkerSkipsGCdPaths2039=== CONT TestDrainTimeoutNotWaitedOutOnSuccess20402026/08/27 10:01:18 ERROR Failed to queue paths error="permission denied" count=12041--- PASS: TestServerClientIntegration (0.00s)2042=== CONT TestDrainWithoutTimeoutRunsToCompletion2043--- PASS: TestServerQueueError (0.00s)2044=== CONT TestDrainTimeoutStopsSlowDrain2045--- PASS: TestQueueDeduplication (0.01s)2046=== CONT TestWorkerPrunesClosureDeps2047--- PASS: TestQueueFetchBatchLimit (0.01s)2048=== CONT TestFailedPathPrunedByLaterClosure20492026/08/27 10:01:18 INFO Uploading batch count=220502026/08/27 10:01:18 INFO Uploading batch count=120512026/08/27 10:01:18 INFO Uploading batch count=22052--- PASS: TestQueueEnqueueAndFetch (0.01s)2053=== CONT TestWorkerUploadsAndRemoves20542026/08/27 10:01:18 INFO Uploading batch count=220552026/08/27 10:01:18 INFO Uploading batch count=420562026/08/27 10:01:18 ERROR Upload failed error="upload failed" count=420572026/08/27 10:01:18 INFO Upload queue status pending=220582026/08/27 10:01:18 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-69671-594980882/TestWorkerSkipsGCdPaths2872536156/002/nonexistent20592026/08/27 10:01:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-69671-594980882/TestDrainIsolatesPoisonPath3117866983/002/bbb2060--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2061--- PASS: TestQueueRetryMovesToBack (0.01s)2062=== CONT TestDrainGivesUpWhenServerDown2063=== CONT TestRunNotBlockedByPoisonHead20642026/08/27 10:01:18 INFO Uploading batch count=120652026/08/27 10:01:18 INFO Uploading batch count=120662026/08/27 10:01:18 ERROR Upload failed error="upload failed" count=12067--- PASS: TestDrainTimeoutNotWaitedOutOnSuccess (0.01s)2068=== CONT TestQueueRemoveLargeClosure20692026/08/27 10:01:18 INFO Uploading batch count=120702026/08/27 10:01:18 ERROR Upload failed error="upload failed" count=120712026/08/27 10:01:18 INFO Uploading batch count=120722026/08/27 10:01:18 ERROR Upload failed error="upload failed" count=120732026/08/27 10:01:18 ERROR Drain finished with paths left in queue remaining=120742026/08/27 10:01:18 INFO Upload queue status pending=220752026/08/27 10:01:18 INFO Uploading batch count=220762026/08/27 10:01:18 INFO Uploading batch count=120772026/08/27 10:01:18 ERROR Upload failed error="upload failed" count=120782026/08/27 10:01:18 INFO Uploading batch count=120792026/08/27 10:01:18 INFO Upload queue status pending=220802026/08/27 10:01:18 INFO Uploading batch count=120812026/08/27 10:01:18 INFO Uploading batch count=12082--- PASS: TestDrainIsolatesPoisonPath (0.01s)2083=== CONT TestQueueConcurrentWriters20842026/08/27 10:01:18 INFO Upload queue status pending=320852026/08/27 10:01:18 INFO Uploading batch count=120862026/08/27 10:01:18 ERROR Upload failed error="upload failed" count=120872026/08/27 10:01:18 INFO Uploading batch count=220882026/08/27 10:01:18 ERROR Upload failed error="upload failed" count=220892026/08/27 10:01:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-69671-594980882/TestDrainGivesUpWhenServerDown3909913839/002/a2090--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2091=== CONT TestQueueRemove20922026/08/27 10:01:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-69671-594980882/TestDrainGivesUpWhenServerDown3909913839/002/b20932026/08/27 10:01:18 INFO Uploading batch count=220942026/08/27 10:01:18 ERROR Upload failed error="upload failed" count=220952026/08/27 10:01:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-69671-594980882/TestDrainGivesUpWhenServerDown3909913839/002/c20962026/08/27 10:01:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-69671-594980882/TestDrainGivesUpWhenServerDown3909913839/002/d20972026/08/27 10:01:18 INFO Uploading batch count=220982026/08/27 10:01:18 ERROR Upload failed error="upload failed" count=220992026/08/27 10:01:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-69671-594980882/TestDrainGivesUpWhenServerDown3909913839/002/e21002026/08/27 10:01:18 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-69671-594980882/TestDrainGivesUpWhenServerDown3909913839/002/f21012026/08/27 10:01:18 ERROR Drain finished with paths left in queue remaining=102102--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2103--- PASS: TestQueueRemove (0.00s)21042026/08/27 10:01:18 INFO Uploading batch count=121052026/08/27 10:01:18 INFO Uploading batch count=12106--- PASS: TestWorkerSkipsGCdPaths (0.03s)2107--- PASS: TestWorkerPrunesClosureDeps (0.02s)2108--- PASS: TestWorkerUploadsAndRemoves (0.02s)21092026/08/27 10:01:18 INFO Uploading batch count=12110--- PASS: TestDrainWithoutTimeoutRunsToCompletion (0.05s)2111--- PASS: TestQueueRemoveLargeClosure (0.05s)2112--- PASS: TestQueueConcurrentWriters (0.15s)21132026/08/27 10:01:18 ERROR Upload failed error="context deadline exceeded" count=221142026/08/27 10:01:18 ERROR Upload failed, will retry later error="context deadline exceeded" path=/nix/var/nix/builds/nix-69671-594980882/TestDrainTimeoutStopsSlowDrain3898125473/002/a21152026/08/27 10:01:18 ERROR Upload failed, will retry later error="context deadline exceeded" path=/nix/var/nix/builds/nix-69671-594980882/TestDrainTimeoutStopsSlowDrain3898125473/002/b21162026/08/27 10:01:18 WARN Drain timed out timeout=200ms21172026/08/27 10:01:18 ERROR Drain finished with paths left in queue remaining=42118--- PASS: TestDrainTimeoutStopsSlowDrain (0.21s)21192026/08/27 10:01:19 INFO Uploading batch count=121202026/08/27 10:01:19 INFO Uploading batch count=121212026/08/27 10:01:19 INFO Uploading batch count=121222026/08/27 10:01:19 ERROR Upload failed error="upload failed" count=121232026/08/27 10:01:19 INFO Uploading batch count=121242026/08/27 10:01:19 ERROR Upload failed error="upload failed" count=121252026/08/27 10:01:19 INFO Uploading batch count=121262026/08/27 10:01:19 ERROR Upload failed error="upload failed" count=121272026/08/27 10:01:19 INFO Uploading batch count=121282026/08/27 10:01:19 ERROR Upload failed error="upload failed" count=121292026/08/27 10:01:19 ERROR Drain finished with paths left in queue remaining=12130--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2131PASS