niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #154
· 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 TestFileTokenMissing74=== CONT TestResolveStorePath75=== CONT TestEncodeNixBase32WithRealHash76--- PASS: TestEncodeNixBase32WithRealHash (0.00s)77=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess78=== CONT TestDumpPathMatchesNix79=== CONT TestFileTokenReadsAndCaches80=== CONT TestStaticToken81=== CONT TestSetClientTLSErrors822026/08/27 09:57:56 WARN Rate limiter enabled after throttle name=server-test rate=583=== CONT TestSetClientTLSDoesNotMutateDefaultTransport84=== CONT TestSetClientTLS85=== CONT TestShellSplit86--- PASS: TestStaticToken (0.00s)87--- PASS: TestFileTokenMissing (0.00s)88=== CONT TestShellSplitErrors89--- PASS: TestShellSplitErrors (0.00s)90=== CONT TestDoWithRetry_BodyReplayedViaGetBody91--- PASS: TestShellSplit (0.00s)92=== CONT TestPartSizeForNAR93=== RUN TestPartSizeForNAR/zero_stays_at_minimum94=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum95=== RUN TestPartSizeForNAR/small_stays_at_minimum96=== PAUSE TestPartSizeForNAR/small_stays_at_minimum97=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum98=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum99=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts100=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts101=== RUN TestPartSizeForNAR/1_TiB102=== PAUSE TestPartSizeForNAR/1_TiB103=== RUN TestPartSizeForNAR/5_TiB_S3_max_object104=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object105=== RUN TestPartSizeForNAR/capped_at_5_GiB106=== PAUSE TestPartSizeForNAR/capped_at_5_GiB107=== CONT TestUploadMultipart_SupersededByPeer108=== RUN TestUploadMultipart_SupersededByPeer/exists109=== PAUSE TestUploadMultipart_SupersededByPeer/exists110=== RUN TestUploadMultipart_SupersededByPeer/missing111=== PAUSE TestUploadMultipart_SupersededByPeer/missing112=== CONT TestEncodeNixBase32113=== RUN TestEncodeNixBase32/test_string_hash114=== PAUSE TestEncodeNixBase32/test_string_hash115=== RUN TestEncodeNixBase32/empty_input116=== PAUSE TestEncodeNixBase32/empty_input117=== CONT TestParsePathInfoJSON118=== RUN TestParsePathInfoJSON/Nix_format119=== PAUSE TestParsePathInfoJSON/Nix_format120=== RUN TestParsePathInfoJSON/Lix_format121=== PAUSE TestParsePathInfoJSON/Lix_format122=== RUN TestParsePathInfoJSON/empty_input123=== PAUSE TestParsePathInfoJSON/empty_input124=== RUN TestParsePathInfoJSON/whitespace_only125=== PAUSE TestParsePathInfoJSON/whitespace_only126=== RUN TestParsePathInfoJSON/invalid_JSON127=== PAUSE TestParsePathInfoJSON/invalid_JSON128=== CONT TestRateLimiterFeedback129=== RUN TestRateLimiterFeedback/429_enables_limiter130=== PAUSE TestRateLimiterFeedback/429_enables_limiter131=== RUN TestRateLimiterFeedback/503_enables_limiter132=== PAUSE TestRateLimiterFeedback/503_enables_limiter133=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter134=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter135=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter136=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter137=== CONT TestPathInfoCACompatibility138=== RUN TestPathInfoCACompatibility/null_ca_field139=== PAUSE TestPathInfoCACompatibility/null_ca_field140=== RUN TestPathInfoCACompatibility/old_string_format_-_text141=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text142=== CONT TestParsePathInfoJSONMultiplePaths143=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive144=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive145=== RUN TestPathInfoCACompatibility/new_structured_format_-_text146=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text147=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method148=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method149=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths150=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths151=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths152=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths153=== CONT TestScriptTokenEmptyCommand154=== CONT TestScriptTokenBadJSON155=== CONT TestScriptTokenScriptFails156=== CONT TestScriptTokenEmptyToken157--- PASS: TestFileTokenReadsAndCaches (0.00s)158--- PASS: TestResolveStorePath (0.00s)159--- PASS: TestScriptTokenEmptyCommand (0.00s)160--- PASS: TestDoServerRequestAttachesToken (0.01s)1612026/08/27 09:57:56 WARN Rate limiter enabled after throttle name=server-test rate=51622026/08/27 09:57:56 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:54298163=== CONT TestFilterOversizedClosures164=== RUN TestFilterOversizedClosures/no_limit_keeps_everything165=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything166=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped167=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped168=== RUN TestFilterOversizedClosures/all_closures_skipped169=== PAUSE TestFilterOversizedClosures/all_closures_skipped170=== CONT TestDumpPathSingleFile1712026/08/27 09:57:56 WARN Rate limiter backed off name=server-test rate=51722026/08/27 09:57:56 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:54298173=== RUN TestSetClientTLSErrors/missing_cert_file174=== PAUSE TestSetClientTLSErrors/missing_cert_file175=== RUN TestSetClientTLSErrors/missing_key_file176=== PAUSE TestSetClientTLSErrors/missing_key_file177=== RUN TestSetClientTLSErrors/missing_ca_file178=== PAUSE TestSetClientTLSErrors/missing_ca_file179=== RUN TestSetClientTLSErrors/invalid_ca_file180=== PAUSE TestSetClientTLSErrors/invalid_ca_file181=== CONT TestGetStorePathHash182=== RUN TestGetStorePathHash/valid_store_path183--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)184=== CONT TestPathInfoHashCompatibility185=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)186=== PAUSE TestGetStorePathHash/valid_store_path187--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)188=== RUN TestGetStorePathHash/basename_without_hyphen_should_error189=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error190=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error191=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error192=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error193=== RUN TestSetClientTLS/rejects_connection_without_client_cert194=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert195=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA196=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA197=== RUN TestSetClientTLS/preserves_debug_logging_transport198=== PAUSE TestSetClientTLS/preserves_debug_logging_transport199=== CONT TestCaseHackSuffix200=== CONT TestScriptTokenNoExpiryRerunsEveryCall201=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error202=== CONT TestScriptTokenCachesUntilRefresh203=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)204=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon205=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon206=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI207=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI208=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512209=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512210=== CONT TestConvertHashToNix32211=== RUN TestConvertHashToNix32/SRI_format_to_Nix32212=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32213=== RUN TestConvertHashToNix32/already_Nix32_format214=== PAUSE TestConvertHashToNix32/already_Nix32_format215=== RUN TestConvertHashToNix32/invalid_format216=== PAUSE TestConvertHashToNix32/invalid_format217=== CONT TestFileTokenEmpty218--- PASS: TestScriptTokenScriptFails (0.01s)219=== CONT TestDumpPathWriterError220--- PASS: TestFileTokenEmpty (0.00s)221=== CONT TestPartSizeForNAR/zero_stays_at_minimum222=== CONT TestUploadMultipart_SupersededByPeer/exists223=== CONT TestPartSizeForNAR/capped_at_5_GiB224=== CONT TestPartSizeForNAR/5_TiB_S3_max_object225=== CONT TestPartSizeForNAR/1_TiB226=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts227=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum228=== CONT TestPartSizeForNAR/small_stays_at_minimum229--- PASS: TestPartSizeForNAR (0.00s)230 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)231 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)232 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)233 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)234 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)235 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)236 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)237=== CONT TestEncodeNixBase32/test_string_hash238=== CONT TestUploadMultipart_SupersededByPeer/missing239--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)240 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)241 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)242=== CONT TestParsePathInfoJSON/Nix_format243=== CONT TestEncodeNixBase32/empty_input244--- PASS: TestEncodeNixBase32 (0.00s)245 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)246 --- PASS: TestEncodeNixBase32/empty_input (0.00s)247=== CONT TestRateLimiterFeedback/429_enables_limiter248--- PASS: TestScriptTokenBadJSON (0.02s)249=== CONT TestParsePathInfoJSON/invalid_JSON250=== CONT TestParsePathInfoJSON/whitespace_only251=== CONT TestParsePathInfoJSON/empty_input252=== CONT TestParsePathInfoJSON/Lix_format253--- PASS: TestParsePathInfoJSON (0.00s)254 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)255 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)256 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)257 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)258 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)259=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2602026/08/27 09:57:56 WARN Rate limiter enabled after throttle name=server-test rate=52612026/08/27 09:57:56 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:543062622026/08/27 09:57:56 WARN Rate limiter backed off name=server-test rate=5263=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter264=== CONT TestRateLimiterFeedback/503_enables_limiter265--- PASS: TestScriptTokenEmptyToken (0.02s)266=== CONT TestPathInfoCACompatibility/null_ca_field267=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths268=== CONT TestPathInfoCACompatibility/old_string_format_-_text269=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method270=== CONT TestPathInfoCACompatibility/new_structured_format_-_text271=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive2722026/08/27 09:57:56 WARN Rate limiter enabled after throttle name=server-test rate=5273--- PASS: TestPathInfoCACompatibility (0.00s)274 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)275 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)276 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)277 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)278 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)279=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2802026/08/27 09:57:56 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:54311281--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)282 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)283 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)284=== CONT TestFilterOversizedClosures/no_limit_keeps_everything285=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped286=== CONT TestFilterOversizedClosures/all_closures_skipped2872026/08/27 09:57:56 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=50288=== CONT TestSetClientTLSErrors/missing_cert_file2892026/08/27 09:57:56 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=2000290--- PASS: TestFilterOversizedClosures (0.00s)291 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)292 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)293 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)294=== CONT TestSetClientTLSErrors/missing_ca_file295=== CONT TestSetClientTLSErrors/invalid_ca_file2962026/08/27 09:57:56 WARN Rate limiter backed off name=server-test rate=5297--- PASS: TestRateLimiterFeedback (0.00s)298 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)299 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)300 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)301 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)302=== CONT TestSetClientTLSErrors/missing_key_file303=== CONT TestSetClientTLS/rejects_connection_without_client_cert304=== CONT TestSetClientTLS/preserves_debug_logging_transport305=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA306--- PASS: TestSetClientTLSErrors (0.01s)307 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)308 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)309 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)310 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)311=== CONT TestGetStorePathHash/valid_store_path312=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)313=== CONT TestConvertHashToNix32/SRI_format_to_Nix32314=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI315=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon316=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512317=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error318=== CONT TestGetStorePathHash/basename_without_hyphen_should_error319--- PASS: TestPathInfoHashCompatibility (0.00s)320 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)321 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)322 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)323 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)324=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error325--- PASS: TestGetStorePathHash (0.00s)326 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)327 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)328 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)329 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)330=== CONT TestConvertHashToNix32/invalid_format331=== CONT TestConvertHashToNix32/already_Nix32_format332--- PASS: TestConvertHashToNix32 (0.00s)333 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)334 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)335 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)3362026/08/27 09:57:56 http: TLS handshake error from 127.0.0.1:54314: remote error: tls: bad certificate337--- PASS: TestSetClientTLS (0.01s)338 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)339 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)340 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)341--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)342--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)343--- PASS: TestDumpPathWriterError (0.04s)344--- PASS: TestDumpPathSingleFile (0.05s)345--- PASS: TestCaseHackSuffix (0.05s)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-66621-2832122340/postgres2056581647/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-66621-2832122340/postgres2056581647/data -l logfile start376377/nix/var/nix/builds/nix-66621-2832122340/postgres2056581647:5432 - no response3782026-08-27 09:57:58.008 UTC [66657] LOG: starting PostgreSQL 18.4 on aarch64-apple-darwin25.5.0, compiled by clang version 21.1.8, 64-bit3792026-08-27 09:57:58.008 UTC [66657] LOG: listening on Unix socket "/nix/var/nix/builds/nix-66621-2832122340/postgres2056581647/.s.PGSQL.5432"3802026-08-27 09:57:58.010 UTC [66664] LOG: database system was shut down at 2026-08-27 09:57:57 UTC3812026-08-27 09:57:58.011 UTC [66657] LOG: database system is ready to accept connections382/nix/var/nix/builds/nix-66621-2832122340/postgres2056581647: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 09:57:58.414 UTC [66736] ERROR: relation "goose_db_version" does not exist at character 364112026-08-27 09:57:58.414 UTC [66736] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4122026/08/27 09:57:58 OK 20241026095416_initial_model.sql (3.34ms)4132026/08/27 09:57:58 OK 20251210153512_drop_unused_gin_index.sql (502.08µs)4142026/08/27 09:57:58 OK 20251218171726_add_pins.sql (852.17µs)4152026/08/27 09:57:58 OK 20260628120000_add_object_size_and_stats.sql (828.54µs)4162026/08/27 09:57:58 goose: successfully migrated database to version: 202606281200004172026/08/27 09:57:58 OK 1_commit_pending_closure.sql (895.83µs)4182026/08/27 09:57:58 OK 2_object_stats_trigger.sql (223.54µs)4192026/08/27 09:57:58 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 09:57:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5172026/08/27 09:57:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5182026/08/27 09:57:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5192026/08/27 09:57:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5202026/08/27 09:57:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5212026/08/27 09:57:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5222026/08/27 09:57:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5232026/08/27 09:57:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5242026/08/27 09:57:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5252026/08/27 09:57:58 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 TestRedundantMultipartUpload550=== CONT TestIsValidUploadKey551=== RUN TestIsValidUploadKey/narinfo552=== CONT TestSkippedUploadsHandler553=== PAUSE TestIsValidUploadKey/narinfo554=== RUN TestIsValidUploadKey/nar_zst555=== PAUSE TestIsValidUploadKey/nar_zst556=== RUN TestIsValidUploadKey/nar_xz557=== PAUSE TestIsValidUploadKey/nar_xz558=== RUN TestIsValidUploadKey/nar_plain559=== PAUSE TestIsValidUploadKey/nar_plain560=== RUN TestIsValidUploadKey/listing561=== PAUSE TestIsValidUploadKey/listing562=== RUN TestIsValidUploadKey/build_log563=== PAUSE TestIsValidUploadKey/build_log564=== RUN TestIsValidUploadKey/build_log_home-manager_file565=== PAUSE TestIsValidUploadKey/build_log_home-manager_file566=== RUN TestIsValidUploadKey/build_log_plus_in_name567=== PAUSE TestIsValidUploadKey/build_log_plus_in_name568=== CONT TestGCTaskStore_ConflictDifferentParams569--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)570=== CONT TestCompleteMultipartUnregistered571=== RUN TestIsValidUploadKey/build_log_question_mark572=== CONT TestProxyWriteTimeout573=== RUN TestProxyWriteTimeout/narinfo574=== PAUSE TestProxyWriteTimeout/narinfo575=== RUN TestProxyWriteTimeout/1_GiB_nar576=== PAUSE TestProxyWriteTimeout/1_GiB_nar577=== PAUSE TestIsValidUploadKey/build_log_question_mark578=== RUN TestProxyWriteTimeout/10_GiB_nar579=== PAUSE TestProxyWriteTimeout/10_GiB_nar580=== RUN TestProxyWriteTimeout/unknown_size581=== PAUSE TestProxyWriteTimeout/unknown_size582=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle583=== CONT TestService_verifyS3Integrity584=== RUN TestIsValidUploadKey/build_log_equals585=== PAUSE TestIsValidUploadKey/build_log_equals586=== RUN TestIsValidUploadKey/realisation587=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT588=== PAUSE TestIsValidUploadKey/realisation589=== CONT TestParseSize590--- PASS: TestParseSize (0.00s)591=== CONT TestService_createPendingClosureHandler592=== RUN TestIsValidUploadKey/realisation_plus_in_output593=== PAUSE TestIsValidUploadKey/realisation_plus_in_output594=== RUN TestIsValidUploadKey/nix-cache-info595=== PAUSE TestIsValidUploadKey/nix-cache-info596=== RUN TestIsValidUploadKey/index.html597=== PAUSE TestIsValidUploadKey/index.html598=== RUN TestIsValidUploadKey/narinfo_key,_nar_type599=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type600=== RUN TestIsValidUploadKey/nar_key,_narinfo_type601=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type602=== RUN TestIsValidUploadKey/listing_key,_narinfo_type603=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type604=== RUN TestIsValidUploadKey/traversal605=== PAUSE TestIsValidUploadKey/traversal606=== RUN TestIsValidUploadKey/traversal_nar607=== PAUSE TestIsValidUploadKey/traversal_nar608=== RUN TestIsValidUploadKey/absolute609=== PAUSE TestIsValidUploadKey/absolute610=== RUN TestIsValidUploadKey/empty_key611=== PAUSE TestIsValidUploadKey/empty_key612=== RUN TestIsValidUploadKey/unknown_type613=== PAUSE TestIsValidUploadKey/unknown_type6142026/08/27 09:57:58 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000615=== CONT TestService_cleanupPendingClosuresHandler616--- PASS: TestSkippedUploadsHandler (0.01s)617=== CONT TestUploadHandlersRejectOversizedBody618=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure619=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure620=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart621=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart622=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts623=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts624=== CONT TestUploadHandlersRejectInvalidKeys625=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info626=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info627=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal628=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal629=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key630=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key631=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key632=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key633=== CONT TestPresignedUploadRegisteredBeforeCommit6342026-08-27 09:57:58.996 UTC [66758] ERROR: relation "goose_db_version" does not exist at character 366352026-08-27 09:57:58.996 UTC [66758] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6362026-08-27 09:57:59.005 UTC [66761] ERROR: relation "goose_db_version" does not exist at character 366372026-08-27 09:57:59.005 UTC [66761] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6382026-08-27 09:57:59.005 UTC [66759] ERROR: relation "goose_db_version" does not exist at character 366392026-08-27 09:57:59.005 UTC [66759] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6402026-08-27 09:57:59.006 UTC [66760] ERROR: relation "goose_db_version" does not exist at character 366412026-08-27 09:57:59.006 UTC [66760] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6422026-08-27 09:57:59.006 UTC [66763] ERROR: relation "goose_db_version" does not exist at character 366432026-08-27 09:57:59.006 UTC [66763] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6442026-08-27 09:57:59.007 UTC [66764] ERROR: relation "goose_db_version" does not exist at character 366452026-08-27 09:57:59.007 UTC [66764] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6462026-08-27 09:57:59.007 UTC [66762] ERROR: relation "goose_db_version" does not exist at character 366472026-08-27 09:57:59.007 UTC [66762] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6482026-08-27 09:57:59.007 UTC [66765] ERROR: relation "goose_db_version" does not exist at character 366492026-08-27 09:57:59.007 UTC [66765] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6502026-08-27 09:57:59.008 UTC [66766] ERROR: relation "goose_db_version" does not exist at character 366512026-08-27 09:57:59.008 UTC [66766] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6522026-08-27 09:57:59.009 UTC [66767] ERROR: relation "goose_db_version" does not exist at character 366532026-08-27 09:57:59.009 UTC [66767] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6542026/08/27 09:57:59 OK 20241026095416_initial_model.sql (5.24ms)6552026/08/27 09:57:59 OK 20251210153512_drop_unused_gin_index.sql (866.04µs)6562026/08/27 09:57:59 OK 20251218171726_add_pins.sql (2.02ms)6572026/08/27 09:57:59 OK 20241026095416_initial_model.sql (6.48ms)6582026/08/27 09:57:59 OK 20260628120000_add_object_size_and_stats.sql (1.7ms)6592026/08/27 09:57:59 goose: successfully migrated database to version: 202606281200006602026/08/27 09:57:59 OK 20251210153512_drop_unused_gin_index.sql (1.19ms)6612026/08/27 09:57:59 OK 20241026095416_initial_model.sql (7.83ms)6622026/08/27 09:57:59 OK 20241026095416_initial_model.sql (6.69ms)6632026/08/27 09:57:59 OK 20251210153512_drop_unused_gin_index.sql (466.63µs)6642026/08/27 09:57:59 OK 1_commit_pending_closure.sql (1.61ms)6652026/08/27 09:57:59 OK 20241026095416_initial_model.sql (7.42ms)6662026/08/27 09:57:59 OK 2_object_stats_trigger.sql (578µs)6672026/08/27 09:57:59 goose: up to current file version: 26682026/08/27 09:57:59 OK 20241026095416_initial_model.sql (9.46ms)6692026/08/27 09:57:59 OK 20251210153512_drop_unused_gin_index.sql (812.79µs)6702026/08/27 09:57:59 OK 20251218171726_add_pins.sql (2.08ms)6712026/08/27 09:57:59 OK 20251210153512_drop_unused_gin_index.sql (638.33µs)6722026/08/27 09:57:59 OK 20251210153512_drop_unused_gin_index.sql (870.71µs)6732026/08/27 09:57:59 OK 20251218171726_add_pins.sql (1.53ms)6742026/08/27 09:57:59 OK 20241026095416_initial_model.sql (9.36ms)6752026/08/27 09:57:59 OK 20241026095416_initial_model.sql (8.08ms)6762026/08/27 09:57:59 OK 20251210153512_drop_unused_gin_index.sql (534.88µs)6772026/08/27 09:57:59 OK 20260628120000_add_object_size_and_stats.sql (1.4ms)6782026/08/27 09:57:59 goose: successfully migrated database to version: 202606281200006792026/08/27 09:57:59 OK 20241026095416_initial_model.sql (8.22ms)6802026/08/27 09:57:59 OK 20241026095416_initial_model.sql (8.35ms)6812026/08/27 09:57:59 OK 20251218171726_add_pins.sql (1.98ms)6822026/08/27 09:57:59 OK 20251210153512_drop_unused_gin_index.sql (726.71µs)6832026/08/27 09:57:59 OK 20260628120000_add_object_size_and_stats.sql (1.31ms)6842026/08/27 09:57:59 goose: successfully migrated database to version: 202606281200006852026/08/27 09:57:59 OK 20251210153512_drop_unused_gin_index.sql (676.42µs)6862026/08/27 09:57:59 OK 20251218171726_add_pins.sql (1.84ms)6872026/08/27 09:57:59 OK 20251218171726_add_pins.sql (1.3ms)6882026/08/27 09:57:59 OK 1_commit_pending_closure.sql (1.33ms)6892026/08/27 09:57:59 OK 1_commit_pending_closure.sql (1.05ms)6902026/08/27 09:57:59 OK 2_object_stats_trigger.sql (220.58µs)6912026/08/27 09:57:59 goose: up to current file version: 26922026/08/27 09:57:59 OK 2_object_stats_trigger.sql (199.29µs)6932026/08/27 09:57:59 goose: up to current file version: 26942026/08/27 09:57:59 OK 20251210153512_drop_unused_gin_index.sql (3.7ms)6952026/08/27 09:57:59 OK 20251218171726_add_pins.sql (5.98ms)6962026/08/27 09:57:59 OK 20251218171726_add_pins.sql (5.26ms)6972026/08/27 09:57:59 OK 20251218171726_add_pins.sql (5.01ms)6982026/08/27 09:57:59 OK 20260628120000_add_object_size_and_stats.sql (4.72ms)6992026/08/27 09:57:59 goose: successfully migrated database to version: 202606281200007002026/08/27 09:57:59 OK 20260628120000_add_object_size_and_stats.sql (5.03ms)7012026/08/27 09:57:59 goose: successfully migrated database to version: 202606281200007022026/08/27 09:57:59 OK 20260628120000_add_object_size_and_stats.sql (68.92ms)7032026/08/27 09:57:59 goose: successfully migrated database to version: 202606281200007042026/08/27 09:57:59 OK 20251218171726_add_pins.sql (65.48ms)7052026/08/27 09:57:59 OK 1_commit_pending_closure.sql (64.24ms)7062026/08/27 09:57:59 OK 1_commit_pending_closure.sql (64.29ms)7072026/08/27 09:57:59 OK 2_object_stats_trigger.sql (204.58µs)7082026/08/27 09:57:59 goose: up to current file version: 27092026/08/27 09:57:59 OK 2_object_stats_trigger.sql (270.5µs)7102026/08/27 09:57:59 goose: up to current file version: 27112026/08/27 09:57:59 OK 1_commit_pending_closure.sql (1.53ms)7122026/08/27 09:57:59 OK 2_object_stats_trigger.sql (235.25µs)7132026/08/27 09:57:59 goose: up to current file version: 27142026/08/27 09:57:59 OK 20260628120000_add_object_size_and_stats.sql (73.48ms)7152026/08/27 09:57:59 goose: successfully migrated database to version: 202606281200007162026/08/27 09:57:59 OK 20260628120000_add_object_size_and_stats.sql (72.81ms)7172026/08/27 09:57:59 goose: successfully migrated database to version: 202606281200007182026/08/27 09:57:59 OK 20260628120000_add_object_size_and_stats.sql (12.47ms)7192026/08/27 09:57:59 goose: successfully migrated database to version: 202606281200007202026/08/27 09:57:59 OK 20260628120000_add_object_size_and_stats.sql (76.22ms)7212026/08/27 09:57:59 goose: successfully migrated database to version: 202606281200007222026/08/27 09:57:59 OK 1_commit_pending_closure.sql (3.97ms)7232026/08/27 09:57:59 OK 1_commit_pending_closure.sql (4.12ms)7242026/08/27 09:57:59 OK 2_object_stats_trigger.sql (253.08µs)7252026/08/27 09:57:59 goose: up to current file version: 27262026/08/27 09:57:59 OK 2_object_stats_trigger.sql (223.13µs)7272026/08/27 09:57:59 goose: up to current file version: 27282026/08/27 09:57:59 OK 1_commit_pending_closure.sql (1.51ms)7292026/08/27 09:57:59 OK 1_commit_pending_closure.sql (1.54ms)7302026/08/27 09:57:59 OK 2_object_stats_trigger.sql (226.79µs)7312026/08/27 09:57:59 goose: up to current file version: 27322026/08/27 09:57:59 OK 2_object_stats_trigger.sql (233.08µs)7332026/08/27 09:57:59 goose: up to current file version: 27342026/08/27 09:57:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7352026/08/27 09:57:59 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst736--- PASS: TestCompleteMultipartUnregistered (0.44s)737=== CONT TestService_Rustfstest7382026/08/27 09:57:59 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"739--- PASS: TestService_AuthMiddleware (0.52s)740=== CONT TestCompletedNarNotReofferedAcrossClosures7412026/08/27 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures7422026/08/27 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures7432026/08/27 09:57:59 INFO Received cleanup request method=DELETE path=/api/pending_closures7442026/08/27 09:57:59 INFO Aborted multipart uploads count=07452026/08/27 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures7462026/08/27 09:57:59 INFO Received cleanup request method=DELETE path=/api/pending_closures7472026/08/27 09:57:59 INFO Aborted multipart uploads count=17482026/08/27 09:57:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7492026-08-27 09:57:59.500 UTC [66765] ERROR: Closure does not exist: id=17502026-08-27 09:57:59.500 UTC [66765] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE7512026-08-27 09:57:59.500 UTC [66765] STATEMENT: -- name: CommitPendingClosure :exec752 SELECT commit_pending_closure($1::bigint)753 754--- PASS: TestService_cleanupPendingClosuresHandler (0.80s)755=== CONT TestClientIntegration7562026/08/27 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures757--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.94s)758=== CONT TestGCTaskStore_DeduplicateSameParams759--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)760=== CONT TestGCTaskStore_StartNew761--- PASS: TestGCTaskStore_StartNew (0.00s)762=== CONT TestGCMetrics7632026/08/27 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures7642026/08/27 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures7652026/08/27 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures7662026/08/27 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures7672026/08/27 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures7682026/08/27 09:58:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7692026/08/27 09:58:00 INFO Received uploads request method=POST path=/api/pending_closures7702026/08/27 09:58:00 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7712026/08/27 09:58:00 INFO Received uploads request method=POST path=/api/pending_closures772--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.71s)773=== CONT TestGCBugBareHashReferences7742026-08-27 09:58:00.855 UTC [66781] ERROR: relation "goose_db_version" does not exist at character 367752026-08-27 09:58:00.855 UTC [66781] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7762026-08-27 09:58:01.058 UTC [66782] ERROR: relation "goose_db_version" does not exist at character 367772026-08-27 09:58:01.058 UTC [66782] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7782026/08/27 09:58:01 OK 20241026095416_initial_model.sql (175.01ms)7792026/08/27 09:58:01 OK 20251210153512_drop_unused_gin_index.sql (18.49ms)7802026/08/27 09:58:01 OK 20251218171726_add_pins.sql (42.94ms)7812026/08/27 09:58:01 OK 20260628120000_add_object_size_and_stats.sql (40.22ms)7822026/08/27 09:58:01 goose: successfully migrated database to version: 202606281200007832026/08/27 09:58:01 OK 1_commit_pending_closure.sql (10.55ms)7842026/08/27 09:58:01 OK 2_object_stats_trigger.sql (858.42µs)7852026/08/27 09:58:01 goose: up to current file version: 27862026/08/27 09:58:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete787=== NAME TestOrphanedObjectsGC788 orphaned_objects_gc_test.go:290: GC Test Summary:789 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A790 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B791 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)792 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)793 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects794--- PASS: TestOrphanedObjectsGC (2.61s)795=== CONT TestPinProtectsFromGC7962026/08/27 09:58:01 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NjVjYzJjZjktMmE3Yy00MzBlLTljYTMtODQ0ZmQ4YTA4ZGM3LjA4ZjFjOWUzLTBmOTktNGZmMi1hZmM1LWQ0ZGM1YTA2Y2FhOXgxNzg3ODI0Njc5MzI3NjI4MDAw parts=12797--- PASS: TestRedundantMultipartUpload (2.64s)798=== CONT TestClientWithDependencies7992026/08/27 09:58:01 OK 20241026095416_initial_model.sql (252.27ms)8002026/08/27 09:58:01 OK 20251210153512_drop_unused_gin_index.sql (11.93ms)8012026/08/27 09:58:01 OK 20251218171726_add_pins.sql (34.81ms)8022026/08/27 09:58:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete803--- PASS: TestService_Rustfstest (2.29s)804=== CONT TestClientMultipleUploads8052026/08/27 09:58:01 OK 20260628120000_add_object_size_and_stats.sql (40.84ms)8062026/08/27 09:58:01 goose: successfully migrated database to version: 202606281200008072026/08/27 09:58:01 OK 1_commit_pending_closure.sql (9.19ms)8082026/08/27 09:58:01 OK 2_object_stats_trigger.sql (358.92µs)8092026/08/27 09:58:01 goose: up to current file version: 28102026-08-27 09:58:01.458 UTC [66787] ERROR: relation "goose_db_version" does not exist at character 368112026-08-27 09:58:01.458 UTC [66787] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8122026/08/27 09:58:01 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NjVjYzJjZjktMmE3Yy00MzBlLTljYTMtODQ0ZmQ4YTA4ZGM3LjFmMTdiMDdiLTRkNGMtNGVmYy1iOTU0LTMyY2MxZGU4YzExMngxNzg3ODI0Njc5NzI0NzczMDAw parts=108132026/08/27 09:58:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8142026/08/27 09:58:01 INFO Completed upload id=18152026/08/27 09:58:01 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008162026/08/27 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures8172026/08/27 09:58:01 INFO Starting cleanup of old closures method=DELETE path=/api/closures8182026/08/27 09:58:01 INFO Aborted multipart uploads count=08192026/08/27 09:58:01 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=08202026/08/27 09:58:01 INFO Vacuumed table table=pending_closures8212026/08/27 09:58:01 INFO Vacuumed table table=pending_objects8222026/08/27 09:58:01 INFO Vacuumed table table=multipart_uploads8232026/08/27 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures8242026/08/27 09:58:01 INFO Vacuumed table table=closures8252026/08/27 09:58:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8262026/08/27 09:58:01 INFO Vacuumed table table=objects8272026-08-27 09:58:01.698 UTC [66791] ERROR: relation "goose_db_version" does not exist at character 368282026-08-27 09:58:01.698 UTC [66791] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8292026/08/27 09:58:01 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000830--- PASS: TestService_createPendingClosureHandler (3.02s)831=== CONT TestCacheConfigHandler832=== RUN TestCacheConfigHandler/full_config,_no_issuer833=== PAUSE TestCacheConfigHandler/full_config,_no_issuer834=== RUN TestCacheConfigHandler/no_cache_url_configured835=== PAUSE TestCacheConfigHandler/no_cache_url_configured836=== RUN TestCacheConfigHandler/no_signing_keys837=== PAUSE TestCacheConfigHandler/no_signing_keys838=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator839=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator840=== CONT TestClientErrorHandling841=== RUN TestClientErrorHandling/InvalidStorePath842=== PAUSE TestClientErrorHandling/InvalidStorePath843=== RUN TestClientErrorHandling/InvalidAuthToken844=== PAUSE TestClientErrorHandling/InvalidAuthToken845=== RUN TestClientErrorHandling/ServerNotAvailable846=== PAUSE TestClientErrorHandling/ServerNotAvailable847=== CONT TestClientCADerivations8482026/08/27 09:58:01 OK 20241026095416_initial_model.sql (193.01ms)8492026/08/27 09:58:01 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NjVjYzJjZjktMmE3Yy00MzBlLTljYTMtODQ0ZmQ4YTA4ZGM3Ljk2OTRjMTk3LWVlNjUtNDJiYy04NWU0LWMxNGU3YzJkM2ZiZngxNzg3ODI0NjgwMDE4NDU1MDAw parts=108502026/08/27 09:58:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8512026/08/27 09:58:01 OK 20251210153512_drop_unused_gin_index.sql (2.74ms)8522026/08/27 09:58:01 INFO Completed upload id=18532026/08/27 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures8542026/08/27 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures8552026/08/27 09:58:01 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8562026/08/27 09:58:01 WARN Found objects in DB but missing from S3, will re-upload count=1857--- PASS: TestService_verifyS3Integrity (3.05s)858=== CONT TestCacheStatsHandler8592026/08/27 09:58:01 OK 20251218171726_add_pins.sql (32.18ms)8602026/08/27 09:58:01 OK 20260628120000_add_object_size_and_stats.sql (25.07ms)8612026/08/27 09:58:01 goose: successfully migrated database to version: 202606281200008622026/08/27 09:58:01 OK 1_commit_pending_closure.sql (7.02ms)8632026/08/27 09:58:01 OK 2_object_stats_trigger.sql (361.42µs)8642026/08/27 09:58:01 goose: up to current file version: 28652026/08/27 09:58:01 OK 20241026095416_initial_model.sql (157.57ms)8662026/08/27 09:58:01 OK 20251210153512_drop_unused_gin_index.sql (13.57ms)8672026/08/27 09:58:01 OK 20251218171726_add_pins.sql (32.39ms)8682026/08/27 09:58:01 OK 20260628120000_add_object_size_and_stats.sql (37.78ms)8692026/08/27 09:58:01 goose: successfully migrated database to version: 202606281200008702026/08/27 09:58:01 OK 1_commit_pending_closure.sql (2.17ms)8712026/08/27 09:58:01 OK 2_object_stats_trigger.sql (421.92µs)8722026/08/27 09:58:01 goose: up to current file version: 28732026/08/27 09:58:02 INFO Aborted multipart uploads count=08742026/08/27 09:58:02 WARN Force mode enabled - objects will be deleted immediately without grace period8752026/08/27 09:58: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=08762026/08/27 09:58:02 INFO Vacuumed table table=pending_closures8772026/08/27 09:58:02 INFO Vacuumed table table=pending_objects8782026/08/27 09:58:02 INFO Vacuumed table table=multipart_uploads8792026/08/27 09:58:02 INFO Vacuumed table table=closures8802026/08/27 09:58:02 INFO Vacuumed table table=objects881--- PASS: TestGCMetrics (2.45s)882=== CONT TestCompleteMultipartUpload_ErrorButObjectExists883=== NAME TestClientIntegration884 client_integration_test.go:276: Created store path: /nix/var/nix/builds/nix-66621-2832122340/TestClientIntegration413827055/002/store/0jzy56zg2mqvg1fn0k8g8w1vn1pwj2h2-test-file.txt8852026-08-27 09:58:02.133 UTC [66801] ERROR: relation "goose_db_version" does not exist at character 368862026-08-27 09:58:02.133 UTC [66801] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8872026/08/27 09:58:02 OK 20241026095416_initial_model.sql (37.96ms)8882026/08/27 09:58:02 OK 20251210153512_drop_unused_gin_index.sql (5.51ms)8892026/08/27 09:58:02 OK 20251218171726_add_pins.sql (1.63ms)8902026/08/27 09:58:02 OK 20260628120000_add_object_size_and_stats.sql (4.72ms)8912026/08/27 09:58:02 goose: successfully migrated database to version: 202606281200008922026/08/27 09:58:02 OK 1_commit_pending_closure.sql (1.56ms)8932026/08/27 09:58:02 OK 2_object_stats_trigger.sql (615.88µs)8942026/08/27 09:58:02 goose: up to current file version: 28952026/08/27 09:58:02 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8962026/08/27 09:58:02 INFO Received uploads request method=POST path=/api/pending_closures8972026/08/27 09:58:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8982026/08/27 09:58:02 INFO Uploading 0jzy56zg2mqvg1fn0k8g8w1vn1pwj2h2-test-file.txt (152B)8992026/08/27 09:58:02 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"9002026/08/27 09:58:02 WARN Failed to register uploaded object key=0jzy56zg2mqvg1fn0k8g8w1vn1pwj2h2.ls error="server returned 404: 404 page not found\n"9012026/08/27 09:58:02 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9022026/08/27 09:58:02 INFO Signed narinfos id=1 count=19032026/08/27 09:58:02 INFO Uploading 1 narinfos9042026/08/27 09:58:02 WARN Failed to register uploaded object key=0jzy56zg2mqvg1fn0k8g8w1vn1pwj2h2.narinfo error="server returned 404: 404 page not found\n"9052026/08/27 09:58:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9062026/08/27 09:58:02 INFO Completed upload id=19072026/08/27 09:58:02 INFO Upload complete. (271ms)908 client_integration_test.go:292: Retrieved narinfo from S3:909 StorePath: /nix/var/nix/builds/nix-66621-2832122340/TestClientIntegration413827055/002/store/0jzy56zg2mqvg1fn0k8g8w1vn1pwj2h2-test-file.txt910 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst911 Compression: zstd912 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1913 NarSize: 152914 References: 915 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1916 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)917 client_integration_test.go:293: Decompressed .ls content (64 bytes):918 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}919 client_integration_test.go:296: Testing garbage collection...9202026/08/27 09:58:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures9212026/08/27 09:58:02 INFO Garbage collection started9222026/08/27 09:58:02 INFO Aborted multipart uploads count=09232026/08/27 09:58:02 WARN Force mode enabled - objects will be deleted immediately without grace period9242026-08-27 09:58:02.587 UTC [66812] ERROR: relation "goose_db_version" does not exist at character 369252026-08-27 09:58:02.587 UTC [66812] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9262026/08/27 09:58:02 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=09272026/08/27 09:58:02 INFO Vacuumed table table=pending_closures928--- PASS: TestGCBugBareHashReferences (2.17s)929=== CONT TestService_ReadAuthMiddleware9302026/08/27 09:58:02 INFO Vacuumed table table=pending_objects9312026/08/27 09:58:02 INFO Vacuumed table table=multipart_uploads9322026/08/27 09:58:02 INFO Vacuumed table table=closures9332026/08/27 09:58:02 INFO Vacuumed table table=objects9342026/08/27 09:58:02 OK 20241026095416_initial_model.sql (92.61ms)9352026/08/27 09:58:02 OK 20251210153512_drop_unused_gin_index.sql (6.95ms)9362026/08/27 09:58:02 OK 20251218171726_add_pins.sql (24.93ms)9372026/08/27 09:58:02 OK 20260628120000_add_object_size_and_stats.sql (17.4ms)9382026/08/27 09:58:02 goose: successfully migrated database to version: 202606281200009392026/08/27 09:58:02 OK 1_commit_pending_closure.sql (6.71ms)9402026/08/27 09:58:02 OK 2_object_stats_trigger.sql (289.54µs)9412026/08/27 09:58:02 goose: up to current file version: 29422026-08-27 09:58:02.802 UTC [66815] ERROR: relation "goose_db_version" does not exist at character 369432026-08-27 09:58:02.802 UTC [66815] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9442026/08/27 09:58:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9452026-08-27 09:58:02.915 UTC [66816] ERROR: relation "goose_db_version" does not exist at character 369462026-08-27 09:58:02.915 UTC [66816] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9472026/08/27 09:58:03 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NjVjYzJjZjktMmE3Yy00MzBlLTljYTMtODQ0ZmQ4YTA4ZGM3LjllY2JhYjIzLTYzODYtNDY1OC1iOTBlLWYyMmRmOGY3MmMzZHgxNzg3ODI0NjgxNjQyNTY5MDAw parts=129482026/08/27 09:58:03 INFO Received uploads request method=POST path=/api/pending_closures949--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.81s)950=== CONT TestService_AuthMiddleware_OIDC9512026/08/27 09:58:03 INFO OIDC provider initialized name=test9522026/08/27 09:58:03 OK 20241026095416_initial_model.sql (149.05ms)9532026/08/27 09:58:03 OK 20251210153512_drop_unused_gin_index.sql (4.67ms)9542026/08/27 09:58:03 OK 20241026095416_initial_model.sql (52.41ms)9552026/08/27 09:58:03 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)9562026-08-27 09:58:03.045 UTC [66819] ERROR: relation "goose_db_version" does not exist at character 369572026-08-27 09:58:03.045 UTC [66819] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9582026/08/27 09:58:03 OK 20251218171726_add_pins.sql (6.7ms)9592026/08/27 09:58:03 OK 20251218171726_add_pins.sql (8.68ms)9602026-08-27 09:58:03.061 UTC [66820] ERROR: relation "goose_db_version" does not exist at character 369612026-08-27 09:58:03.061 UTC [66820] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9622026/08/27 09:58:03 OK 20260628120000_add_object_size_and_stats.sql (20.36ms)9632026/08/27 09:58:03 goose: successfully migrated database to version: 202606281200009642026/08/27 09:58:03 OK 1_commit_pending_closure.sql (1.9ms)9652026/08/27 09:58:03 OK 2_object_stats_trigger.sql (300.83µs)9662026/08/27 09:58:03 goose: up to current file version: 29672026/08/27 09:58:03 OK 20260628120000_add_object_size_and_stats.sql (34.29ms)9682026/08/27 09:58:03 goose: successfully migrated database to version: 202606281200009692026/08/27 09:58:03 OK 1_commit_pending_closure.sql (1.66ms)9702026/08/27 09:58:03 OK 2_object_stats_trigger.sql (263.63µs)9712026/08/27 09:58:03 goose: up to current file version: 29722026/08/27 09:58:03 OK 20241026095416_initial_model.sql (132.75ms)9732026/08/27 09:58:03 OK 20251210153512_drop_unused_gin_index.sql (4.93ms)9742026/08/27 09:58:03 OK 20241026095416_initial_model.sql (118.69ms)9752026/08/27 09:58:03 OK 20251210153512_drop_unused_gin_index.sql (1.08ms)9762026/08/27 09:58:03 OK 20251218171726_add_pins.sql (17.05ms)9772026-08-27 09:58:03.256 UTC [66824] ERROR: relation "goose_db_version" does not exist at character 369782026-08-27 09:58:03.256 UTC [66824] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9792026/08/27 09:58:03 OK 20260628120000_add_object_size_and_stats.sql (17.28ms)9802026/08/27 09:58:03 goose: successfully migrated database to version: 202606281200009812026/08/27 09:58:03 OK 20251218171726_add_pins.sql (22.38ms)9822026/08/27 09:58:03 OK 1_commit_pending_closure.sql (5.64ms)9832026/08/27 09:58:03 OK 2_object_stats_trigger.sql (230.46µs)9842026/08/27 09:58:03 goose: up to current file version: 29852026/08/27 09:58:03 OK 20260628120000_add_object_size_and_stats.sql (27.82ms)9862026/08/27 09:58:03 goose: successfully migrated database to version: 202606281200009872026/08/27 09:58:03 OK 1_commit_pending_closure.sql (4.64ms)9882026/08/27 09:58:03 OK 2_object_stats_trigger.sql (239.33µs)9892026/08/27 09:58:03 goose: up to current file version: 2990=== NAME TestClientMultipleUploads991 client_integration_test.go:338: Created store path 0: /nix/var/nix/builds/nix-66621-2832122340/TestClientMultipleUploads3708900109/001/store/8qa24bq23glzrgp5fg2wj8l0k2pvf921-test-file-0.txt9922026/08/27 09:58:03 OK 20241026095416_initial_model.sql (51.11ms)9932026/08/27 09:58:03 OK 20251210153512_drop_unused_gin_index.sql (5.7ms)9942026/08/27 09:58:03 OK 20251218171726_add_pins.sql (14.66ms)9952026/08/27 09:58:03 OK 20260628120000_add_object_size_and_stats.sql (31.6ms)9962026/08/27 09:58:03 goose: successfully migrated database to version: 20260628120000997 client_integration_test.go:338: Created store path 1: /nix/var/nix/builds/nix-66621-2832122340/TestClientMultipleUploads3708900109/001/store/2sczh8ma2m5rc36dnjakhhy7db4m1g1a-test-file-1.txt9982026/08/27 09:58:03 OK 1_commit_pending_closure.sql (1.52ms)999=== NAME TestClientWithDependencies1000 client_integration_test.go:593: Built derivation: /nix/var/nix/builds/nix-66621-2832122340/TestClientWithDependencies433348523/001/store/dl6vgrc4y2qnv6ssgr0swf4jjkxgp62q-test-script10012026/08/27 09:58:03 OK 2_object_stats_trigger.sql (268.13µs)10022026/08/27 09:58:03 goose: up to current file version: 21003 client_integration_test.go:595: Found 1 dependencies (including self)1004=== NAME TestClientMultipleUploads1005 client_integration_test.go:338: Created store path 2: /nix/var/nix/builds/nix-66621-2832122340/TestClientMultipleUploads3708900109/001/store/x93h4iyrk7gljvm33hv9fazcn3z1dnph-test-file-2.txt1006=== NAME TestPinProtectsFromGC1007 client_integration_test.go:646: Pinned store path: /nix/var/nix/builds/nix-66621-2832122340/TestPinProtectsFromGC1449895014/001/store/9rl9wc955j2azk4f3c3fr2mzx94ja4ai-pinned-file.txt1008 client_integration_test.go:647: Unpinned store path: /nix/var/nix/builds/nix-66621-2832122340/TestPinProtectsFromGC1449895014/001/store/3rcalvg65dic11di6sri09b2fcl6dvcj-unpinned-file.txt10092026/08/27 09:58:03 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10102026/08/27 09:58:03 INFO Received uploads request method=POST path=/api/pending_closures10112026/08/27 09:58:03 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10122026/08/27 09:58:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10132026/08/27 09:58:03 INFO Uploading dl6vgrc4y2qnv6ssgr0swf4jjkxgp62q-test-script (136B)1014--- PASS: TestCacheStatsHandler (1.82s)1015=== CONT TestReadProxyInvalidPath10162026/08/27 09:58:03 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10172026/08/27 09:58:03 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"10182026/08/27 09:58:03 WARN Failed to register uploaded object key=log/vrhpl7xa7d2ydlla4ybw491nnphvrxvi-test-script.drv error="server returned 404: 404 page not found\n"10192026/08/27 09:58:03 WARN Failed to register uploaded object key=dl6vgrc4y2qnv6ssgr0swf4jjkxgp62q.ls error="server returned 404: 404 page not found\n"10202026/08/27 09:58:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10212026/08/27 09:58:03 INFO Signed narinfos id=1 count=110222026/08/27 09:58:03 INFO Uploading 1 narinfos10232026/08/27 09:58:03 INFO Received uploads request method=POST path=/api/pending_closures10242026/08/27 09:58:03 INFO Received uploads request method=POST path=/api/pending_closures10252026/08/27 09:58:03 INFO Received uploads request method=POST path=/api/pending_closures10262026/08/27 09:58:03 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)10272026/08/27 09:58:03 INFO Uploading x93h4iyrk7gljvm33hv9fazcn3z1dnph-test-file-2.txt (160B)10282026/08/27 09:58:03 INFO Uploading 8qa24bq23glzrgp5fg2wj8l0k2pvf921-test-file-0.txt (160B)10292026/08/27 09:58:03 INFO Uploading 2sczh8ma2m5rc36dnjakhhy7db4m1g1a-test-file-1.txt (160B)10302026/08/27 09:58:03 INFO Received uploads request method=POST path=/api/pending_closures10312026/08/27 09:58:03 WARN Failed to register uploaded object key=dl6vgrc4y2qnv6ssgr0swf4jjkxgp62q.narinfo error="server returned 404: 404 page not found\n"10322026/08/27 09:58:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10332026/08/27 09:58:03 INFO Completed upload id=110342026/08/27 09:58:03 INFO Upload complete. (210ms)10352026/08/27 09:58:03 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"1036=== NAME TestClientWithDependencies1037 client_integration_test.go:597: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-66621-2832122340/TestClientWithDependencies433348523/001/store) requires matching store prefix10382026/08/27 09:58:03 INFO Received uploads request method=POST path=/api/pending_closures10392026/08/27 09:58:03 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"10402026/08/27 09:58:03 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"10412026/08/27 09:58:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10422026/08/27 09:58:03 INFO Uploading 9rl9wc955j2azk4f3c3fr2mzx94ja4ai-pinned-file.txt (128B)10432026/08/27 09:58:03 WARN Failed to register uploaded object key=2sczh8ma2m5rc36dnjakhhy7db4m1g1a.ls error="server returned 404: 404 page not found\n"10442026/08/27 09:58:03 WARN Failed to register uploaded object key=x93h4iyrk7gljvm33hv9fazcn3z1dnph.ls error="server returned 404: 404 page not found\n"10452026/08/27 09:58:03 WARN Failed to register uploaded object key=8qa24bq23glzrgp5fg2wj8l0k2pvf921.ls error="server returned 404: 404 page not found\n"10462026/08/27 09:58:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign10472026/08/27 09:58:03 INFO Signed narinfos id=3 count=110482026/08/27 09:58:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10492026/08/27 09:58:03 INFO Signed narinfos id=1 count=110502026/08/27 09:58:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10512026/08/27 09:58:03 INFO Signed narinfos id=2 count=110522026/08/27 09:58:03 INFO Uploading 3 narinfos10532026/08/27 09:58:03 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"10542026/08/27 09:58:03 WARN Failed to register uploaded object key=8qa24bq23glzrgp5fg2wj8l0k2pvf921.narinfo error="server returned 404: 404 page not found\n"10552026/08/27 09:58:03 WARN Failed to register uploaded object key=x93h4iyrk7gljvm33hv9fazcn3z1dnph.narinfo error="server returned 404: 404 page not found\n"10562026/08/27 09:58:03 WARN Failed to register uploaded object key=2sczh8ma2m5rc36dnjakhhy7db4m1g1a.narinfo error="server returned 404: 404 page not found\n"10572026/08/27 09:58:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1058--- PASS: TestClientWithDependencies (2.48s)1059=== CONT TestGenerateLandingPage1060--- PASS: TestGenerateLandingPage (0.00s)1061=== CONT TestReadProxyRangeRequest10622026/08/27 09:58:03 WARN Failed to register uploaded object key=9rl9wc955j2azk4f3c3fr2mzx94ja4ai.ls error="server returned 404: 404 page not found\n"10632026/08/27 09:58:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10642026/08/27 09:58:03 INFO Signed narinfos id=1 count=110652026/08/27 09:58:03 INFO Uploading 1 narinfos10662026/08/27 09:58:03 INFO Completed upload id=110672026/08/27 09:58:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10682026/08/27 09:58:03 INFO Completed upload id=210692026/08/27 09:58:03 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete10702026/08/27 09:58:03 INFO Completed upload id=310712026/08/27 09:58:03 INFO Upload complete. (339ms)1072=== NAME TestClientMultipleUploads1073 client_integration_test.go:349: Uploaded 3 paths in 368.912666ms10742026/08/27 09:58:03 WARN Failed to register uploaded object key=9rl9wc955j2azk4f3c3fr2mzx94ja4ai.narinfo error="server returned 404: 404 page not found\n"10752026/08/27 09:58:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1076=== NAME TestClientCADerivations1077 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-66621-2832122340/TestClientCADerivations1437031553/001/store/fjm7wf9x95qdhxnf5wq08jx3l6k21hhz-ca-test10782026/08/27 09:58:03 INFO Completed upload id=110792026/08/27 09:58:03 INFO Upload complete. (357ms)1080--- PASS: TestClientMultipleUploads (2.47s)1081=== CONT TestObjectStatsTrigger1082=== NAME TestClientCADerivations1083 client_ca_test.go:139: Found 1 dependencies (including self)10842026/08/27 09:58:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10852026/08/27 09:58:03 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjVjYzJjZjktMmE3Yy00MzBlLTljYTMtODQ0ZmQ4YTA4ZGM3Ljk4NzRkODJlLTU2N2QtNGMzZC1iN2ExLWI1YzE0ZjcxZTQyZngxNzg3ODI0NjgzNjg3NTI5MDAw10862026/08/27 09:58:03 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjVjYzJjZjktMmE3Yy00MzBlLTljYTMtODQ0ZmQ4YTA4ZGM3Ljk4NzRkODJlLTU2N2QtNGMzZC1iN2ExLWI1YzE0ZjcxZTQyZngxNzg3ODI0NjgzNjg3NTI5MDAw parts=11087--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.87s)1088=== CONT TestReadRedirectKeepsNarinfoProxied10892026/08/27 09:58:03 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10902026-08-27 09:58:03.968 UTC [66877] ERROR: relation "goose_db_version" does not exist at character 3610912026-08-27 09:58:03.968 UTC [66877] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10922026/08/27 09:58:03 INFO Received uploads request method=POST path=/api/pending_closures10932026/08/27 09:58:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10942026/08/27 09:58:03 INFO Uploading 3rcalvg65dic11di6sri09b2fcl6dvcj-unpinned-file.txt (128B)10952026/08/27 09:58:03 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10962026/08/27 09:58:04 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"10972026/08/27 09:58:04 INFO Received uploads request method=POST path=/api/pending_closures10982026/08/27 09:58:04 WARN Failed to register uploaded object key=3rcalvg65dic11di6sri09b2fcl6dvcj.ls error="server returned 404: 404 page not found\n"10992026/08/27 09:58:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11002026/08/27 09:58:04 INFO Signed narinfos id=2 count=111012026/08/27 09:58:04 INFO Uploading 1 narinfos11022026/08/27 09:58:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11032026/08/27 09:58:04 INFO Uploading fjm7wf9x95qdhxnf5wq08jx3l6k21hhz-ca-test (144B)11042026/08/27 09:58:04 WARN Failed to register uploaded object key=3rcalvg65dic11di6sri09b2fcl6dvcj.narinfo error="server returned 404: 404 page not found\n"11052026/08/27 09:58:04 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"11062026/08/27 09:58:04 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11072026/08/27 09:58:04 INFO Completed upload id=211082026/08/27 09:58:04 INFO Upload complete. (182ms)11092026/08/27 09:58:04 WARN Failed to register uploaded object key=log/nn9g9fgb19whfdk8k4f3s2m1cawz609b-ca-test.drv error="server returned 404: 404 page not found\n"11102026/08/27 09:58:04 INFO Received create pin request method=POST path=/api/pins/myapp11112026/08/27 09:58:04 WARN Failed to register uploaded object key=fjm7wf9x95qdhxnf5wq08jx3l6k21hhz.ls error="server returned 404: 404 page not found\n"11122026/08/27 09:58:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11132026/08/27 09:58:04 INFO Signed narinfos id=1 count=111142026/08/27 09:58:04 INFO Uploading 1 narinfos11152026/08/27 09:58:04 OK 20241026095416_initial_model.sql (140.56ms)11162026/08/27 09:58:04 OK 20251210153512_drop_unused_gin_index.sql (6.44ms)11172026/08/27 09:58:04 WARN Failed to register uploaded object key=fjm7wf9x95qdhxnf5wq08jx3l6k21hhz.narinfo error="server returned 404: 404 page not found\n"11182026/08/27 09:58:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11192026/08/27 09:58:04 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-66621-2832122340/TestPinProtectsFromGC1449895014/001/store/9rl9wc955j2azk4f3c3fr2mzx94ja4ai-pinned-file.txt narinfo_key=9rl9wc955j2azk4f3c3fr2mzx94ja4ai.narinfo11202026/08/27 09:58:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures11212026/08/27 09:58:04 INFO Garbage collection started11222026/08/27 09:58:04 INFO Aborted multipart uploads count=011232026/08/27 09:58:04 WARN Force mode enabled - objects will be deleted immediately without grace period11242026/08/27 09:58:04 OK 20251218171726_add_pins.sql (8.04ms)11252026-08-27 09:58:04.165 UTC [66885] ERROR: relation "goose_db_version" does not exist at character 3611262026-08-27 09:58:04.165 UTC [66885] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11272026/08/27 09:58:04 INFO Completed upload id=111282026/08/27 09:58:04 INFO Upload complete. (217ms)1129=== NAME TestClientCADerivations1130 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-66621-2832122340/TestClientCADerivations1437031553/001/store/fjm7wf9x95qdhxnf5wq08jx3l6k21hhz-ca-test1131 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1132 Compression: zstd1133 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1134 NarSize: 1441135 References: 1136 Deriver: /nix/var/nix/builds/nix-66621-2832122340/TestClientCADerivations1437031553/001/store/nn9g9fgb19whfdk8k4f3s2m1cawz609b-ca-test.drv1137 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1138 client_ca_test.go:185: Checking for realisation files in S3...1139 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1140 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache11412026/08/27 09:58:04 OK 20260628120000_add_object_size_and_stats.sql (16.72ms)11422026/08/27 09:58:04 goose: successfully migrated database to version: 2026062812000011432026/08/27 09:58:04 OK 1_commit_pending_closure.sql (1.32ms)11442026/08/27 09:58:04 OK 2_object_stats_trigger.sql (233.88µs)11452026/08/27 09:58:04 goose: up to current file version: 21146 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket20?endpoint=http://localhost:54317®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-66621-2832122340/TestClientCADerivations1437031553/001/store'1147 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11148--- PASS: TestClientCADerivations (2.57s)1149=== CONT TestMultipartCleanup11502026/08/27 09:58:04 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=011512026/08/27 09:58:04 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1152--- PASS: TestService_ReadAuthMiddleware (1.65s)1153=== CONT TestReadRedirectNar11542026/08/27 09:58:04 OK 20241026095416_initial_model.sql (98.59ms)11552026/08/27 09:58:04 INFO Vacuumed table table=pending_closures11562026/08/27 09:58:04 OK 20251210153512_drop_unused_gin_index.sql (896.96µs)11572026/08/27 09:58:04 INFO Vacuumed table table=pending_objects11582026/08/27 09:58:04 INFO Vacuumed table table=multipart_uploads11592026/08/27 09:58:04 OK 20251218171726_add_pins.sql (20.61ms)11602026/08/27 09:58:04 INFO Vacuumed table table=closures11612026/08/27 09:58:04 INFO Vacuumed table table=objects11622026/08/27 09:58:04 OK 20260628120000_add_object_size_and_stats.sql (12.11ms)11632026/08/27 09:58:04 goose: successfully migrated database to version: 2026062812000011642026/08/27 09:58:04 OK 1_commit_pending_closure.sql (1.4ms)11652026/08/27 09:58:04 OK 2_object_stats_trigger.sql (268.71µs)11662026/08/27 09:58:04 goose: up to current file version: 21167=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1168=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1169=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1170=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1171=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1172=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1173=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1174=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1175=== CONT TestServerTLSConfig1176=== RUN TestServerTLSConfig/no_client_CA1177=== PAUSE TestServerTLSConfig/no_client_CA1178=== RUN TestServerTLSConfig/missing_CA_file1179=== PAUSE TestServerTLSConfig/missing_CA_file1180=== RUN TestServerTLSConfig/not_a_PEM_file1181=== PAUSE TestServerTLSConfig/not_a_PEM_file1182=== CONT TestReadProxyDisabled11832026-08-27 09:58:04.479 UTC [66896] ERROR: relation "goose_db_version" does not exist at character 3611842026-08-27 09:58:04.479 UTC [66896] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11852026/08/27 09:58:04 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01186=== NAME TestClientIntegration1187 client_integration_test.go:303: Objects in database after GC:1188 client_integration_test.go:303: Successfully deleted all objects with GC --force1189--- PASS: TestClientIntegration (4.99s)1190=== CONT TestService_NativeMTLS11912026/08/27 09:58:04 OK 20241026095416_initial_model.sql (10.62ms)11922026/08/27 09:58:04 OK 20251210153512_drop_unused_gin_index.sql (664.25µs)11932026/08/27 09:58:04 OK 20251218171726_add_pins.sql (1.58ms)11942026/08/27 09:58:04 OK 20260628120000_add_object_size_and_stats.sql (2.94ms)11952026/08/27 09:58:04 goose: successfully migrated database to version: 2026062812000011962026/08/27 09:58:04 OK 1_commit_pending_closure.sql (886.79µs)11972026/08/27 09:58:04 OK 2_object_stats_trigger.sql (230.54µs)11982026/08/27 09:58:04 goose: up to current file version: 21199--- PASS: TestReadProxyInvalidPath (1.06s)1200=== CONT TestReadProxyRootRedirectsToIndexHTML12012026-08-27 09:58:04.699 UTC [66901] ERROR: relation "goose_db_version" does not exist at character 3612022026-08-27 09:58:04.699 UTC [66901] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12032026/08/27 09:58:04 OK 20241026095416_initial_model.sql (13.98ms)12042026/08/27 09:58:04 OK 20251210153512_drop_unused_gin_index.sql (589.42µs)12052026-08-27 09:58:04.746 UTC [66902] ERROR: relation "goose_db_version" does not exist at character 3612062026-08-27 09:58:04.746 UTC [66902] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12072026/08/27 09:58:04 OK 20251218171726_add_pins.sql (1.33ms)12082026-08-27 09:58:04.755 UTC [66903] ERROR: relation "goose_db_version" does not exist at character 3612092026-08-27 09:58:04.755 UTC [66903] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12102026/08/27 09:58:04 OK 20260628120000_add_object_size_and_stats.sql (15.46ms)12112026/08/27 09:58:04 goose: successfully migrated database to version: 2026062812000012122026/08/27 09:58:04 OK 1_commit_pending_closure.sql (1.32ms)12132026/08/27 09:58:04 OK 2_object_stats_trigger.sql (294.92µs)12142026/08/27 09:58:04 goose: up to current file version: 212152026/08/27 09:58:04 WARN Rate limiter enabled after throttle name=s3-test rate=512162026/08/27 09:58:04 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1217=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1218 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101219 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001220--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.19s)1221=== CONT TestMetricsInventory1222--- PASS: TestReadProxyRangeRequest (1.11s)1223=== CONT TestReadProxyConditionalGet12242026/08/27 09:58:04 OK 20241026095416_initial_model.sql (168.73ms)12252026/08/27 09:58:04 OK 20241026095416_initial_model.sql (144.09ms)12262026/08/27 09:58:04 OK 20251210153512_drop_unused_gin_index.sql (7.5ms)12272026/08/27 09:58:04 OK 20251210153512_drop_unused_gin_index.sql (7.56ms)12282026/08/27 09:58:04 OK 20251218171726_add_pins.sql (2.93ms)12292026/08/27 09:58:04 OK 20251218171726_add_pins.sql (2.95ms)12302026/08/27 09:58:04 OK 20260628120000_add_object_size_and_stats.sql (5.39ms)12312026/08/27 09:58:04 goose: successfully migrated database to version: 2026062812000012322026/08/27 09:58:04 OK 20260628120000_add_object_size_and_stats.sql (5.75ms)12332026/08/27 09:58:04 goose: successfully migrated database to version: 2026062812000012342026/08/27 09:58:04 OK 1_commit_pending_closure.sql (2.49ms)12352026/08/27 09:58:04 OK 1_commit_pending_closure.sql (2.22ms)12362026/08/27 09:58:04 OK 2_object_stats_trigger.sql (525.63µs)12372026/08/27 09:58:04 goose: up to current file version: 212382026/08/27 09:58:04 OK 2_object_stats_trigger.sql (547.58µs)12392026/08/27 09:58:04 goose: up to current file version: 21240--- PASS: TestObjectStatsTrigger (1.23s)1241=== CONT TestReadProxyHead1242--- PASS: TestReadRedirectKeepsNarinfoProxied (1.31s)1243=== CONT TestNARDeduplicationMetadataUploadBug12442026-08-27 09:58:05.289 UTC [66911] ERROR: relation "goose_db_version" does not exist at character 3612452026-08-27 09:58:05.289 UTC [66911] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12462026-08-27 09:58:05.289 UTC [66912] ERROR: relation "goose_db_version" does not exist at character 3612472026-08-27 09:58:05.289 UTC [66912] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12482026-08-27 09:58:05.299 UTC [66914] ERROR: relation "goose_db_version" does not exist at character 3612492026-08-27 09:58:05.299 UTC [66914] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12502026/08/27 09:58:05 OK 20241026095416_initial_model.sql (11.89ms)12512026/08/27 09:58:05 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)12522026/08/27 09:58:05 OK 20251218171726_add_pins.sql (2.25ms)12532026/08/27 09:58:05 OK 20241026095416_initial_model.sql (17ms)12542026/08/27 09:58:05 OK 20251210153512_drop_unused_gin_index.sql (778.54µs)12552026/08/27 09:58:05 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)12562026/08/27 09:58:05 goose: successfully migrated database to version: 2026062812000012572026/08/27 09:58:05 OK 20251218171726_add_pins.sql (2.24ms)12582026/08/27 09:58:05 OK 1_commit_pending_closure.sql (2.43ms)12592026/08/27 09:58:05 OK 2_object_stats_trigger.sql (254.33µs)12602026/08/27 09:58:05 goose: up to current file version: 212612026/08/27 09:58:05 OK 20241026095416_initial_model.sql (31.19ms)12622026/08/27 09:58:05 OK 20251210153512_drop_unused_gin_index.sql (12.43ms)12632026/08/27 09:58:05 OK 20260628120000_add_object_size_and_stats.sql (83.32ms)12642026/08/27 09:58:05 goose: successfully migrated database to version: 2026062812000012652026/08/27 09:58:05 OK 20251218171726_add_pins.sql (57.66ms)12662026/08/27 09:58:05 OK 1_commit_pending_closure.sql (8.55ms)12672026/08/27 09:58:05 OK 2_object_stats_trigger.sql (418.5µs)12682026/08/27 09:58:05 goose: up to current file version: 212692026/08/27 09:58:05 OK 20260628120000_add_object_size_and_stats.sql (19.02ms)12702026/08/27 09:58:05 goose: successfully migrated database to version: 2026062812000012712026/08/27 09:58:05 OK 1_commit_pending_closure.sql (2.47ms)12722026/08/27 09:58:05 OK 2_object_stats_trigger.sql (364.67µs)12732026/08/27 09:58:05 goose: up to current file version: 21274--- PASS: TestReadRedirectNar (1.21s)1275=== CONT TestCreatePendingClosureRejectsOversizedNAR12762026/08/27 09:58:05 INFO Received uploads request method=POST path=/api/pending_closures1277--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1278=== CONT TestCacheConfigHandlerMaxNarSize1279--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1280=== CONT TestReadProxyNarinfo12812026/08/27 09:58:05 INFO Received uploads request method=POST path=/api/pending_closures1282--- PASS: TestReadProxyDisabled (1.33s)1283=== CONT TestReadProxy40412842026/08/27 09:58:05 INFO Received cleanup request method=DELETE path=/api/pending_closures12852026/08/27 09:58:05 INFO Aborted multipart uploads count=11286--- PASS: TestMultipartCleanup (1.52s)1287=== CONT TestReadProxyNarStreaming12882026-08-27 09:58:05.807 UTC [66920] ERROR: relation "goose_db_version" does not exist at character 3612892026-08-27 09:58:05.807 UTC [66920] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12902026-08-27 09:58:05.823 UTC [66922] ERROR: relation "goose_db_version" does not exist at character 3612912026-08-27 09:58:05.823 UTC [66922] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12922026/08/27 09:58:05 OK 20241026095416_initial_model.sql (11.18ms)12932026/08/27 09:58:05 OK 20241026095416_initial_model.sql (11.98ms)12942026/08/27 09:58:05 OK 20251210153512_drop_unused_gin_index.sql (462µs)12952026/08/27 09:58:05 OK 20251210153512_drop_unused_gin_index.sql (412.04µs)12962026/08/27 09:58:05 OK 20251218171726_add_pins.sql (919.88µs)12972026/08/27 09:58:05 OK 20251218171726_add_pins.sql (953.54µs)12982026/08/27 09:58:05 OK 20260628120000_add_object_size_and_stats.sql (5.92ms)12992026/08/27 09:58:05 goose: successfully migrated database to version: 2026062812000013002026/08/27 09:58:05 OK 20260628120000_add_object_size_and_stats.sql (6.36ms)13012026/08/27 09:58:05 goose: successfully migrated database to version: 2026062812000013022026/08/27 09:58:05 OK 1_commit_pending_closure.sql (2.08ms)13032026/08/27 09:58:05 OK 1_commit_pending_closure.sql (1.75ms)13042026/08/27 09:58:05 OK 2_object_stats_trigger.sql (225.63µs)13052026/08/27 09:58:05 goose: up to current file version: 213062026/08/27 09:58:05 OK 2_object_stats_trigger.sql (273.96µs)13072026/08/27 09:58:05 goose: up to current file version: 213082026/08/27 09:58:06 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13092026/08/27 09:58:06 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1310--- PASS: TestService_NativeMTLS (1.52s)1311=== CONT TestReadProxyNarinfoAlreadyDecompressed13122026/08/27 09:58:06 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01313=== NAME TestPinProtectsFromGC1314 client_integration_test.go:709: Pin successfully protected closure from garbage collection1315--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.54s)1316=== CONT TestGCTaskStore_PhaseUpdates1317--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1318=== CONT TestService_healthCheckHandler1319--- PASS: TestPinProtectsFromGC (4.89s)1320=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13212026-08-27 09:58:06.207 UTC [66929] ERROR: relation "goose_db_version" does not exist at character 3613222026-08-27 09:58:06.207 UTC [66929] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13232026-08-27 09:58:06.207 UTC [66928] ERROR: relation "goose_db_version" does not exist at character 3613242026-08-27 09:58:06.207 UTC [66928] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13252026/08/27 09:58:06 OK 20241026095416_initial_model.sql (16.25ms)13262026/08/27 09:58:06 OK 20241026095416_initial_model.sql (16.82ms)13272026/08/27 09:58:06 OK 20251210153512_drop_unused_gin_index.sql (901.71µs)13282026/08/27 09:58:06 OK 20251210153512_drop_unused_gin_index.sql (637.92µs)13292026/08/27 09:58:06 OK 20251218171726_add_pins.sql (1.17ms)13302026/08/27 09:58:06 OK 20251218171726_add_pins.sql (1.25ms)13312026/08/27 09:58:06 OK 20260628120000_add_object_size_and_stats.sql (4.81ms)13322026/08/27 09:58:06 goose: successfully migrated database to version: 2026062812000013332026/08/27 09:58:06 OK 20260628120000_add_object_size_and_stats.sql (5.49ms)13342026/08/27 09:58:06 goose: successfully migrated database to version: 2026062812000013352026/08/27 09:58:06 OK 1_commit_pending_closure.sql (1.97ms)13362026/08/27 09:58:06 OK 2_object_stats_trigger.sql (347.33µs)13372026/08/27 09:58:06 goose: up to current file version: 213382026/08/27 09:58:06 OK 1_commit_pending_closure.sql (1.52ms)13392026/08/27 09:58:06 OK 2_object_stats_trigger.sql (390.46µs)13402026/08/27 09:58:06 goose: up to current file version: 21341--- PASS: TestMetricsInventory (1.62s)1342=== CONT TestGracefulShutdownDrainsInflight13432026/08/27 09:58:06 INFO Starting HTTP server address=127.0.0.1:5446213442026/08/27 09:58:06 INFO Shutdown signal received, draining in-flight requests timeout=10s1345--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1346=== CONT TestGCTaskStore_Fail1347--- PASS: TestGCTaskStore_Fail (0.00s)1348=== CONT TestGCTaskStore_GetReturnsLatest1349--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1350=== CONT TestService_AuthMiddleware_MTLSProxyHeader13512026-08-27 09:58:06.627 UTC [66932] ERROR: relation "goose_db_version" does not exist at character 3613522026-08-27 09:58:06.627 UTC [66932] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13532026-08-27 09:58:06.627 UTC [66933] ERROR: relation "goose_db_version" does not exist at character 3613542026-08-27 09:58:06.627 UTC [66933] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1355--- PASS: TestReadProxyConditionalGet (1.71s)1356=== CONT TestParseSingleRange1357=== RUN TestParseSingleRange/none1358=== PAUSE TestParseSingleRange/none1359=== RUN TestParseSingleRange/unknown_unit1360=== PAUSE TestParseSingleRange/unknown_unit1361=== RUN TestParseSingleRange/multi-range_ignored1362=== PAUSE TestParseSingleRange/multi-range_ignored1363=== RUN TestParseSingleRange/malformed_no_dash1364=== PAUSE TestParseSingleRange/malformed_no_dash1365=== RUN TestParseSingleRange/malformed_both_empty1366=== PAUSE TestParseSingleRange/malformed_both_empty1367=== RUN TestParseSingleRange/malformed_end_before_start1368=== PAUSE TestParseSingleRange/malformed_end_before_start1369=== RUN TestParseSingleRange/closed1370=== PAUSE TestParseSingleRange/closed1371=== RUN TestParseSingleRange/open-ended1372=== PAUSE TestParseSingleRange/open-ended1373=== RUN TestParseSingleRange/end_clamped_to_size1374=== PAUSE TestParseSingleRange/end_clamped_to_size1375=== RUN TestParseSingleRange/suffix1376=== PAUSE TestParseSingleRange/suffix1377=== RUN TestParseSingleRange/suffix_exceeds_size1378=== PAUSE TestParseSingleRange/suffix_exceeds_size1379=== RUN TestParseSingleRange/single_byte1380=== PAUSE TestParseSingleRange/single_byte1381=== RUN TestParseSingleRange/start_past_EOF1382=== PAUSE TestParseSingleRange/start_past_EOF1383=== RUN TestParseSingleRange/start_far_past_EOF1384=== PAUSE TestParseSingleRange/start_far_past_EOF1385=== CONT TestIsValidCachePath1386=== RUN TestIsValidCachePath/narinfo1387=== PAUSE TestIsValidCachePath/narinfo1388=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1389=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1390=== RUN TestIsValidCachePath/nar_zst1391=== PAUSE TestIsValidCachePath/nar_zst1392=== RUN TestIsValidCachePath/nar_xz1393=== PAUSE TestIsValidCachePath/nar_xz1394=== RUN TestIsValidCachePath/nar_bz21395=== PAUSE TestIsValidCachePath/nar_bz21396=== RUN TestIsValidCachePath/nar_uncompressed1397=== PAUSE TestIsValidCachePath/nar_uncompressed1398=== RUN TestIsValidCachePath/ls1399=== PAUSE TestIsValidCachePath/ls1400=== RUN TestIsValidCachePath/log1401=== PAUSE TestIsValidCachePath/log1402=== RUN TestIsValidCachePath/realisation1403=== PAUSE TestIsValidCachePath/realisation1404=== RUN TestIsValidCachePath/nix-cache-info1405=== PAUSE TestIsValidCachePath/nix-cache-info1406=== RUN TestIsValidCachePath/index.html1407=== PAUSE TestIsValidCachePath/index.html1408=== RUN TestIsValidCachePath/traversal_parent1409=== PAUSE TestIsValidCachePath/traversal_parent1410=== RUN TestIsValidCachePath/traversal_in_middle1411=== PAUSE TestIsValidCachePath/traversal_in_middle1412=== RUN TestIsValidCachePath/invalid_char_e1413=== PAUSE TestIsValidCachePath/invalid_char_e1414=== RUN TestIsValidCachePath/invalid_char_u1415=== PAUSE TestIsValidCachePath/invalid_char_u1416=== RUN TestIsValidCachePath/random_path1417=== PAUSE TestIsValidCachePath/random_path1418=== RUN TestIsValidCachePath/empty1419=== PAUSE TestIsValidCachePath/empty1420=== RUN TestIsValidCachePath/leading_slash1421=== PAUSE TestIsValidCachePath/leading_slash1422=== RUN TestIsValidCachePath/wrong_extension1423=== PAUSE TestIsValidCachePath/wrong_extension1424=== RUN TestIsValidCachePath/short_hash1425=== PAUSE TestIsValidCachePath/short_hash1426=== CONT TestResurrectedObjectNotDeleted14272026/08/27 09:58:06 OK 20241026095416_initial_model.sql (112.7ms)14282026/08/27 09:58:06 OK 20241026095416_initial_model.sql (114.85ms)14292026/08/27 09:58:06 OK 20251210153512_drop_unused_gin_index.sql (2.49ms)14302026/08/27 09:58:06 OK 20251210153512_drop_unused_gin_index.sql (8.18ms)14312026/08/27 09:58:06 OK 20251218171726_add_pins.sql (28.86ms)14322026/08/27 09:58:06 OK 20251218171726_add_pins.sql (22.67ms)14332026/08/27 09:58:06 OK 20260628120000_add_object_size_and_stats.sql (12.7ms)14342026/08/27 09:58:06 goose: successfully migrated database to version: 2026062812000014352026/08/27 09:58:06 OK 20260628120000_add_object_size_and_stats.sql (16.12ms)14362026/08/27 09:58:06 goose: successfully migrated database to version: 2026062812000014372026/08/27 09:58:06 OK 1_commit_pending_closure.sql (4.95ms)14382026/08/27 09:58:06 OK 2_object_stats_trigger.sql (592.21µs)14392026/08/27 09:58:06 goose: up to current file version: 214402026/08/27 09:58:06 OK 1_commit_pending_closure.sql (10.23ms)14412026/08/27 09:58:06 OK 2_object_stats_trigger.sql (532.83µs)14422026/08/27 09:58:06 goose: up to current file version: 21443--- PASS: TestReadProxyHead (1.98s)1444=== CONT TestOrphanedObjectsGCStressTest14452026-08-27 09:58:07.361 UTC [66940] ERROR: relation "goose_db_version" does not exist at character 3614462026-08-27 09:58:07.361 UTC [66940] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14472026-08-27 09:58:07.361 UTC [66941] ERROR: relation "goose_db_version" does not exist at character 3614482026-08-27 09:58:07.361 UTC [66941] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14492026-08-27 09:58:07.405 UTC [66942] ERROR: relation "goose_db_version" does not exist at character 3614502026-08-27 09:58:07.405 UTC [66942] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1451=== NAME TestNARDeduplicationMetadataUploadBug1452 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-66621-2832122340/TestNARDeduplicationMetadataUploadBug3714852495/001/store/252mnzr3dyy70dr2pg4hk8rg65ypjd41-file1.txt14532026/08/27 09:58:07 OK 20241026095416_initial_model.sql (92.11ms)14542026/08/27 09:58:07 OK 20241026095416_initial_model.sql (100.56ms)14552026/08/27 09:58:07 OK 20251210153512_drop_unused_gin_index.sql (16.6ms)14562026/08/27 09:58:07 OK 20241026095416_initial_model.sql (77.13ms)14572026/08/27 09:58:07 OK 20251210153512_drop_unused_gin_index.sql (9.06ms)14582026/08/27 09:58:07 OK 20251210153512_drop_unused_gin_index.sql (3.85ms)14592026/08/27 09:58:07 OK 20251218171726_add_pins.sql (5.51ms)14602026/08/27 09:58:07 OK 20251218171726_add_pins.sql (5.78ms)14612026/08/27 09:58:07 OK 20251218171726_add_pins.sql (10.59ms)14622026/08/27 09:58:07 OK 20260628120000_add_object_size_and_stats.sql (30.6ms)14632026/08/27 09:58:07 goose: successfully migrated database to version: 2026062812000014642026/08/27 09:58:07 OK 20260628120000_add_object_size_and_stats.sql (21.57ms)14652026/08/27 09:58:07 goose: successfully migrated database to version: 2026062812000014662026/08/27 09:58:07 OK 20260628120000_add_object_size_and_stats.sql (31.54ms)14672026/08/27 09:58:07 goose: successfully migrated database to version: 2026062812000014682026-08-27 09:58:07.552 UTC [66947] ERROR: relation "goose_db_version" does not exist at character 3614692026-08-27 09:58:07.552 UTC [66947] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14702026/08/27 09:58:07 OK 1_commit_pending_closure.sql (1.76ms)14712026/08/27 09:58:07 OK 1_commit_pending_closure.sql (3.19ms)14722026/08/27 09:58:07 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14732026/08/27 09:58:07 OK 1_commit_pending_closure.sql (3.37ms)14742026/08/27 09:58:07 OK 2_object_stats_trigger.sql (689.17µs)14752026/08/27 09:58:07 goose: up to current file version: 214762026/08/27 09:58:07 OK 2_object_stats_trigger.sql (383.46µs)14772026/08/27 09:58:07 goose: up to current file version: 214782026/08/27 09:58:07 OK 2_object_stats_trigger.sql (578.08µs)14792026/08/27 09:58:07 goose: up to current file version: 214802026/08/27 09:58:07 INFO Received uploads request method=POST path=/api/pending_closures14812026/08/27 09:58:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14822026/08/27 09:58:07 INFO Uploading 252mnzr3dyy70dr2pg4hk8rg65ypjd41-file1.txt (160B)14832026/08/27 09:58:07 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14842026/08/27 09:58:07 OK 20241026095416_initial_model.sql (123.54ms)14852026/08/27 09:58:07 WARN Failed to register uploaded object key=252mnzr3dyy70dr2pg4hk8rg65ypjd41.ls error="server returned 404: 404 page not found\n"14862026/08/27 09:58:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14872026/08/27 09:58:07 INFO Signed narinfos id=1 count=114882026/08/27 09:58:07 INFO Uploading 1 narinfos14892026/08/27 09:58:07 OK 20251210153512_drop_unused_gin_index.sql (14.99ms)14902026/08/27 09:58:07 WARN Failed to register uploaded object key=252mnzr3dyy70dr2pg4hk8rg65ypjd41.narinfo error="server returned 404: 404 page not found\n"14912026/08/27 09:58:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1492--- PASS: TestReadProxyNarinfo (2.28s)1493=== CONT TestGCTaskStore_GetEmpty1494--- PASS: TestGCTaskStore_GetEmpty (0.00s)1495=== CONT TestGCTaskStore_CompletedAllowsNewTask1496--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1497=== CONT TestProxyWriteTimeout/narinfo1498=== CONT TestProxyWriteTimeout/unknown_size1499=== CONT TestProxyWriteTimeout/10_GiB_nar1500=== CONT TestProxyWriteTimeout/1_GiB_nar1501--- PASS: TestProxyWriteTimeout (0.00s)1502 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1503 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1504 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1505 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1506=== CONT TestIsValidUploadKey/narinfo1507=== CONT TestIsValidUploadKey/nix-cache-info1508=== CONT TestIsValidUploadKey/realisation_plus_in_output1509=== CONT TestIsValidUploadKey/realisation1510=== CONT TestIsValidUploadKey/build_log_equals1511=== CONT TestIsValidUploadKey/build_log_question_mark1512=== CONT TestIsValidUploadKey/build_log_plus_in_name1513=== CONT TestIsValidUploadKey/build_log_home-manager_file1514=== CONT TestIsValidUploadKey/build_log1515=== CONT TestIsValidUploadKey/listing1516=== CONT TestIsValidUploadKey/nar_plain1517=== CONT TestIsValidUploadKey/nar_xz1518=== CONT TestIsValidUploadKey/nar_zst1519=== CONT TestIsValidUploadKey/traversal1520=== CONT TestIsValidUploadKey/unknown_type1521=== CONT TestIsValidUploadKey/empty_key1522=== CONT TestIsValidUploadKey/absolute1523=== CONT TestIsValidUploadKey/traversal_nar1524=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1525=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1526=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1527=== CONT TestIsValidUploadKey/index.html1528--- PASS: TestIsValidUploadKey (0.01s)1529 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1530 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1531 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1532 --- PASS: TestIsValidUploadKey/realisation (0.00s)1533 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1534 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1535 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1536 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1537 --- PASS: TestIsValidUploadKey/build_log (0.00s)1538 --- PASS: TestIsValidUploadKey/listing (0.00s)1539 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1540 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1541 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1542 --- PASS: TestIsValidUploadKey/traversal (0.00s)1543 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1544 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1545 --- PASS: TestIsValidUploadKey/absolute (0.00s)1546 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1547 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1548 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1549 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1550 --- PASS: TestIsValidUploadKey/index.html (0.00s)1551=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15522026/08/27 09:58:07 INFO Received uploads request method=POST path=/15532026/08/27 09:58:07 OK 20251218171726_add_pins.sql (49.62ms)15542026/08/27 09:58:07 INFO Completed upload id=115552026/08/27 09:58:07 INFO Upload complete. (277ms)1556=== NAME TestNARDeduplicationMetadataUploadBug1557 metadata_upload_test.go:54: Retrieved narinfo from S3:1558 StorePath: /nix/var/nix/builds/nix-66621-2832122340/TestNARDeduplicationMetadataUploadBug3714852495/001/store/252mnzr3dyy70dr2pg4hk8rg65ypjd41-file1.txt1559 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1560 Compression: zstd1561 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1562 NarSize: 1601563 References: 1564 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1565 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1566 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1567 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}15682026-08-27 09:58:07.814 UTC [66951] ERROR: relation "goose_db_version" does not exist at character 3615692026-08-27 09:58:07.814 UTC [66951] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15702026/08/27 09:58:07 OK 20260628120000_add_object_size_and_stats.sql (41.13ms)15712026/08/27 09:58:07 goose: successfully migrated database to version: 2026062812000015722026/08/27 09:58:07 OK 1_commit_pending_closure.sql (6.3ms)15732026/08/27 09:58:07 OK 2_object_stats_trigger.sql (592.58µs)15742026/08/27 09:58:07 goose: up to current file version: 215752026-08-27 09:58:07.855 UTC [66953] ERROR: relation "goose_db_version" does not exist at character 3615762026-08-27 09:58:07.855 UTC [66953] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1577 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-66621-2832122340/TestNARDeduplicationMetadataUploadBug3714852495/001/store/3z9809qdkdl78n1s0mc58cs99fi68c9s-file2.txt1578--- PASS: TestReadProxy404 (2.14s)1579=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15802026/08/27 09:58:07 INFO Received request for more parts method=POST path=/1581=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15822026/08/27 09:58:07 INFO Received complete multipart upload request method=POST path=/1583=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15842026/08/27 09:58:07 INFO Received uploads request method=POST path=/1585=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15862026/08/27 09:58:07 INFO Received request for more parts method=POST path=/1587=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15882026/08/27 09:58:07 INFO Received complete multipart upload request method=POST path=/1589=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15902026/08/27 09:58:07 INFO Received uploads request method=POST path=/1591--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1592 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1593 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1594 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1595 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1596=== CONT TestCacheConfigHandler/full_config,_no_issuer1597=== CONT TestCacheConfigHandler/no_signing_keys1598=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1599=== CONT TestCacheConfigHandler/no_cache_url_configured1600--- PASS: TestCacheConfigHandler (0.00s)1601 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1602 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1603 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1604 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1605=== CONT TestClientErrorHandling/InvalidStorePath16062026/08/27 09:58:07 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16072026/08/27 09:58:07 OK 20241026095416_initial_model.sql (111.39ms)16082026/08/27 09:58:07 OK 20251210153512_drop_unused_gin_index.sql (11.05ms)16092026/08/27 09:58:07 INFO Received uploads request method=POST path=/api/pending_closures16102026/08/27 09:58:07 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16112026/08/27 09:58:07 OK 20251218171726_add_pins.sql (26.32ms)16122026/08/27 09:58:08 OK 20241026095416_initial_model.sql (124.62ms)16132026/08/27 09:58:08 OK 20251210153512_drop_unused_gin_index.sql (11.02ms)16142026/08/27 09:58:08 WARN Failed to register uploaded object key=3z9809qdkdl78n1s0mc58cs99fi68c9s.ls error="server returned 404: 404 page not found\n"16152026/08/27 09:58:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16162026/08/27 09:58:08 INFO Signed narinfos id=2 count=116172026/08/27 09:58:08 INFO Uploading 1 narinfos16182026/08/27 09:58:08 OK 20260628120000_add_object_size_and_stats.sql (53.86ms)16192026/08/27 09:58:08 goose: successfully migrated database to version: 2026062812000016202026/08/27 09:58:08 OK 1_commit_pending_closure.sql (1.1ms)1621--- PASS: TestReadProxyNarStreaming (2.26s)1622=== CONT TestClientErrorHandling/ServerNotAvailable16232026/08/27 09:58:08 OK 2_object_stats_trigger.sql (274.96µs)16242026/08/27 09:58:08 goose: up to current file version: 21625=== CONT TestClientErrorHandling/InvalidAuthToken1626--- PASS: TestUploadHandlersRejectOversizedBody (0.05s)1627 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1628 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1629 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)16302026/08/27 09:58:08 OK 20251218171726_add_pins.sql (52.31ms)16312026/08/27 09:58:08 WARN Failed to register uploaded object key=3z9809qdkdl78n1s0mc58cs99fi68c9s.narinfo error="server returned 404: 404 page not found\n"16322026/08/27 09:58:08 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16332026/08/27 09:58:08 INFO Completed upload id=216342026/08/27 09:58:08 INFO Upload complete. (184ms)1635=== NAME TestNARDeduplicationMetadataUploadBug1636 metadata_upload_test.go:76: Retrieved narinfo from S3:1637 StorePath: /nix/var/nix/builds/nix-66621-2832122340/TestNARDeduplicationMetadataUploadBug3714852495/001/store/3z9809qdkdl78n1s0mc58cs99fi68c9s-file2.txt1638 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1639 Compression: zstd1640 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1641 NarSize: 1601642 References: 1643 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1644 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1645 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1646 {"version":1,"root":{"type":"regular","size":44}}16472026/08/27 09:58:08 OK 20260628120000_add_object_size_and_stats.sql (58.69ms)16482026/08/27 09:58:08 goose: successfully migrated database to version: 202606281200001649--- PASS: TestNARDeduplicationMetadataUploadBug (2.88s)1650=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token16512026/08/27 09:58:08 OK 1_commit_pending_closure.sql (1.39ms)16522026/08/27 09:58:08 OK 2_object_stats_trigger.sql (235.04µs)16532026/08/27 09:58:08 goose: up to current file version: 216542026/08/27 09:58:08 INFO OIDC auth successful provider=test1655=== CONT TestServerTLSConfig/no_client_CA1656=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1657=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected16582026/08/27 09:58:08 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1659=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16602026/08/27 09:58:08 WARN Authentication failed token_preview=eyJhbGciOi...fcmzME9lWw 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]1661=== CONT TestServerTLSConfig/not_a_PEM_file1662--- PASS: TestService_AuthMiddleware_OIDC (1.41s)1663 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1664 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1665 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1666 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1667=== CONT TestServerTLSConfig/missing_CA_file1668=== CONT TestParseSingleRange/none1669--- PASS: TestServerTLSConfig (0.00s)1670 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1671 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1672 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1673=== CONT TestParseSingleRange/open-ended1674=== CONT TestParseSingleRange/start_far_past_EOF1675=== CONT TestParseSingleRange/start_past_EOF1676=== CONT TestParseSingleRange/single_byte1677=== CONT TestParseSingleRange/suffix_exceeds_size1678=== CONT TestParseSingleRange/suffix1679=== CONT TestParseSingleRange/end_clamped_to_size1680=== CONT TestParseSingleRange/malformed_both_empty1681=== CONT TestParseSingleRange/closed1682=== CONT TestParseSingleRange/malformed_end_before_start1683=== CONT TestParseSingleRange/multi-range_ignored1684=== CONT TestParseSingleRange/malformed_no_dash1685=== CONT TestParseSingleRange/unknown_unit1686--- PASS: TestParseSingleRange (0.00s)1687 --- PASS: TestParseSingleRange/none (0.00s)1688 --- PASS: TestParseSingleRange/open-ended (0.00s)1689 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1690 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1691 --- PASS: TestParseSingleRange/single_byte (0.00s)1692 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1693 --- PASS: TestParseSingleRange/suffix (0.00s)1694 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1695 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1696 --- PASS: TestParseSingleRange/closed (0.00s)1697 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1698 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1699 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1700 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1701=== CONT TestIsValidCachePath/narinfo1702=== CONT TestIsValidCachePath/index.html1703=== CONT TestIsValidCachePath/short_hash1704=== CONT TestIsValidCachePath/wrong_extension1705=== CONT TestIsValidCachePath/leading_slash1706=== CONT TestIsValidCachePath/empty1707=== CONT TestIsValidCachePath/random_path1708=== CONT TestIsValidCachePath/invalid_char_u1709=== CONT TestIsValidCachePath/invalid_char_e1710=== CONT TestIsValidCachePath/traversal_in_middle1711=== CONT TestIsValidCachePath/traversal_parent1712=== CONT TestIsValidCachePath/nar_uncompressed1713=== CONT TestIsValidCachePath/nix-cache-info1714=== CONT TestIsValidCachePath/realisation1715=== CONT TestIsValidCachePath/log1716=== CONT TestIsValidCachePath/ls1717=== CONT TestIsValidCachePath/nar_xz1718=== CONT TestIsValidCachePath/nar_bz21719=== CONT TestIsValidCachePath/nar_zst1720=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1721--- PASS: TestIsValidCachePath (0.00s)1722 --- PASS: TestIsValidCachePath/narinfo (0.00s)1723 --- PASS: TestIsValidCachePath/index.html (0.00s)1724 --- PASS: TestIsValidCachePath/short_hash (0.00s)1725 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1726 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1727 --- PASS: TestIsValidCachePath/empty (0.00s)1728 --- PASS: TestIsValidCachePath/random_path (0.00s)1729 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1730 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1731 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1732 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1733 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1734 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1735 --- PASS: TestIsValidCachePath/realisation (0.00s)1736 --- PASS: TestIsValidCachePath/log (0.00s)1737 --- PASS: TestIsValidCachePath/ls (0.00s)1738 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1739 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1740 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1741 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1742--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.24s)17432026/08/27 09:58:08 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17442026/08/27 09:58:08 WARN mTLS auth: bound subjects configured but subject DN unavailable17452026/08/27 09:58:08 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1746--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.14s)17472026/08/27 09:58:08 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-config17482026-08-27 09:58:08.341 UTC [66970] ERROR: relation "goose_db_version" does not exist at character 3617492026-08-27 09:58:08.341 UTC [66970] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17502026-08-27 09:58:08.356 UTC [66972] ERROR: relation "goose_db_version" does not exist at character 3617512026-08-27 09:58:08.356 UTC [66972] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17522026/08/27 09:58:08 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.155104ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1753--- PASS: TestService_healthCheckHandler (2.29s)17542026/08/27 09:58:08 OK 20241026095416_initial_model.sql (77.46ms)17552026/08/27 09:58:08 OK 20241026095416_initial_model.sql (77.59ms)17562026/08/27 09:58:08 OK 20251210153512_drop_unused_gin_index.sql (515.58µs)17572026/08/27 09:58:08 OK 20251210153512_drop_unused_gin_index.sql (567.38µs)17582026/08/27 09:58:08 OK 20251218171726_add_pins.sql (1.12ms)17592026/08/27 09:58:08 OK 20251218171726_add_pins.sql (1.15ms)17602026/08/27 09:58:08 OK 20260628120000_add_object_size_and_stats.sql (17.6ms)17612026/08/27 09:58:08 goose: successfully migrated database to version: 2026062812000017622026/08/27 09:58:08 OK 1_commit_pending_closure.sql (2.07ms)17632026/08/27 09:58:08 OK 2_object_stats_trigger.sql (332.17µs)17642026/08/27 09:58:08 goose: up to current file version: 217652026/08/27 09:58:08 OK 20260628120000_add_object_size_and_stats.sql (25.42ms)17662026/08/27 09:58:08 goose: successfully migrated database to version: 2026062812000017672026/08/27 09:58:08 OK 1_commit_pending_closure.sql (7.76ms)17682026/08/27 09:58:08 OK 2_object_stats_trigger.sql (381.96µs)17692026/08/27 09:58:08 goose: up to current file version: 217702026-08-27 09:58:08.568 UTC [66973] ERROR: relation "goose_db_version" does not exist at character 3617712026-08-27 09:58:08.568 UTC [66973] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1772--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.01s)17732026/08/27 09:58:08 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=361.67807ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17742026/08/27 09:58:08 OK 20241026095416_initial_model.sql (133.47ms)17752026/08/27 09:58:08 OK 20251210153512_drop_unused_gin_index.sql (9.19ms)17762026/08/27 09:58:08 OK 20251218171726_add_pins.sql (28.23ms)17772026/08/27 09:58:08 OK 20260628120000_add_object_size_and_stats.sql (30.56ms)17782026/08/27 09:58:08 goose: successfully migrated database to version: 2026062812000017792026/08/27 09:58:08 OK 1_commit_pending_closure.sql (9.79ms)17802026/08/27 09:58:08 OK 2_object_stats_trigger.sql (1.07ms)17812026/08/27 09:58:08 goose: up to current file version: 21782--- PASS: TestResurrectedObjectNotDeleted (2.19s)17832026/08/27 09:58:09 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=748.422771ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17842026-08-27 09:58:09.298 UTC [66974] ERROR: relation "goose_db_version" does not exist at character 3617852026-08-27 09:58:09.298 UTC [66974] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17862026-08-27 09:58:09.307 UTC [66975] ERROR: relation "goose_db_version" does not exist at character 3617872026-08-27 09:58:09.307 UTC [66975] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17882026/08/27 09:58:09 OK 20241026095416_initial_model.sql (8.71ms)17892026/08/27 09:58:09 OK 20251210153512_drop_unused_gin_index.sql (777.54µs)17902026/08/27 09:58:09 OK 20251218171726_add_pins.sql (1.91ms)17912026/08/27 09:58:09 OK 20260628120000_add_object_size_and_stats.sql (1.7ms)17922026/08/27 09:58:09 goose: successfully migrated database to version: 2026062812000017932026/08/27 09:58:09 OK 1_commit_pending_closure.sql (1.71ms)17942026/08/27 09:58:09 OK 20241026095416_initial_model.sql (7.07ms)17952026/08/27 09:58:09 OK 2_object_stats_trigger.sql (423.42µs)17962026/08/27 09:58:09 goose: up to current file version: 217972026/08/27 09:58:09 OK 20251210153512_drop_unused_gin_index.sql (685.46µs)17982026/08/27 09:58:09 OK 20251218171726_add_pins.sql (1.34ms)17992026/08/27 09:58:09 OK 20260628120000_add_object_size_and_stats.sql (10.36ms)18002026/08/27 09:58:09 goose: successfully migrated database to version: 2026062812000018012026/08/27 09:58:09 OK 1_commit_pending_closure.sql (1.75ms)18022026/08/27 09:58:09 OK 2_object_stats_trigger.sql (368.46µs)18032026/08/27 09:58:09 goose: up to current file version: 218042026/08/27 09:58:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18052026/08/27 09:58:09 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18062026/08/27 09:58:09 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.674583818s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18072026/08/27 09:58:11 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"18082026/08/27 09:58:11 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18092026/08/27 09:58:11 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.059114ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18102026/08/27 09:58:11 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=414.983869ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18112026/08/27 09:58:12 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=858.26599ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18122026/08/27 09:58:13 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.637250273s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1813=== NAME TestOrphanedObjectsGCStressTest1814 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1815 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1816 orphaned_objects_gc_test.go:509: Stress test completed successfully:1817 orphaned_objects_gc_test.go:510: - Active objects preserved: 201818 orphaned_objects_gc_test.go:511: - Objects deleted: 2101819 orphaned_objects_gc_test.go:512: - Total GC'd: 2101820--- PASS: TestOrphanedObjectsGCStressTest (7.30s)1821--- PASS: TestClientErrorHandling (0.00s)1822 --- PASS: TestClientErrorHandling/InvalidStorePath (1.55s)1823 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.58s)1824 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.70s)1825PASS1826{"timestamp":"2026-08-27T09:58:14.751818Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:54368","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(7)"}18272026-08-27 09:58:14.856 UTC [66657] LOG: received smart shutdown request18282026-08-27 09:58:14.857 UTC [66657] LOG: background worker "logical replication launcher" (PID 66667) exited with exit code 118292026-08-27 09:58:14.861 UTC [66662] LOG: shutting down18302026-08-27 09:58:14.861 UTC [66662] LOG: checkpoint starting: shutdown immediate18312026-08-27 09:58:15.933 UTC [66662] LOG: checkpoint complete: wrote 13474 buffers (82.2%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 14 recycled; write=0.773 s, sync=0.270 s, total=1.072 s; sync files=15825, longest=0.001 s, average=0.001 s; distance=221754 kB, estimate=221754 kB; lsn=0/F019938, redo lsn=0/F01993818322026-08-27 09:58:15.937 UTC [66657] 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=== PAUSE TestGlobMatch/foo_foo1855=== RUN TestGlobMatch/foo_bar1856=== CONT TestValidateToken_ValidToken1857=== CONT TestValidateToken_Expired1858=== CONT TestValidateToken_WrongAudience1859=== PAUSE TestGlobMatch/foo_bar1860=== RUN TestGlobMatch/*_1861=== PAUSE TestGlobMatch/*_1862=== RUN TestGlobMatch/*_anything1863=== PAUSE TestGlobMatch/*_anything1864=== RUN TestGlobMatch/foo*_foo1865=== CONT TestAudienceForIssuer1866=== PAUSE TestGlobMatch/foo*_foo1867=== RUN TestGlobMatch/foo*_foobar1868=== PAUSE TestGlobMatch/foo*_foobar1869=== RUN TestGlobMatch/foo*_bar1870=== PAUSE TestGlobMatch/foo*_bar1871=== RUN TestGlobMatch/*bar_bar1872=== PAUSE TestGlobMatch/*bar_bar1873--- PASS: TestAudienceForIssuer (0.00s)1874=== CONT TestValidateToken_NoMatchingProvider1875=== CONT TestValidateToken_BoundSubjectMismatch1876=== CONT TestValidateToken_BoundClaimsMismatch1877=== CONT TestValidateToken_MultipleProviders1878=== 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*bar_foobar1928=== CONT TestGlobMatch/*bar_foo1929=== CONT TestGlobMatch/*bar_foobar1930=== CONT TestGlobMatch/*bar_bar1931=== CONT TestGlobMatch/foo*_bar1932=== CONT TestGlobMatch/foo*_foobar1933=== CONT TestGlobMatch/foo*_foo1934=== CONT TestGlobMatch/*_anything1935=== CONT TestGlobMatch/*_1936=== 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*bar_foobar (0.00s)1954 --- PASS: TestGlobMatch/*bar_foo (0.00s)1955 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1956 --- PASS: TestGlobMatch/*bar_bar (0.00s)1957 --- PASS: TestGlobMatch/foo*_bar (0.00s)1958 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1959 --- PASS: TestGlobMatch/foo*_foo (0.00s)1960 --- PASS: TestGlobMatch/*_anything (0.00s)1961 --- PASS: TestGlobMatch/*_ (0.00s)1962 --- PASS: TestGlobMatch/foo_bar (0.00s)19632026/08/27 09:58:16 INFO OIDC provider initialized name=provider119642026/08/27 09:58:16 INFO OIDC provider initialized name=test19652026/08/27 09:58:16 INFO OIDC provider initialized name=test19662026/08/27 09:58:16 INFO OIDC provider initialized name=provider119672026/08/27 09:58:16 INFO OIDC provider initialized name=test19682026/08/27 09:58:16 INFO OIDC provider initialized name=test19692026/08/27 09:58:16 INFO OIDC provider initialized name=test19702026/08/27 09:58:16 INFO OIDC provider initialized name=provider21971--- PASS: TestValidateToken_WrongAudience (0.01s)1972--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1973--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1974--- PASS: TestValidateToken_ValidToken (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=== CONT TestDrainTimeoutStopsSlowDrain2031=== CONT TestDrainWithoutTimeoutRunsToCompletion2032=== CONT TestWorkerSkipsGCdPaths2033=== CONT TestQueueRetryMovesToBack2034=== CONT TestServerQueueError2035=== CONT TestServerClientIntegration2036=== CONT TestQueueRemoveLargeClosure2037=== CONT TestQueueConcurrentWriters2038=== CONT TestQueueFetchRemoveLifecycle2039--- PASS: TestSendPathsEmpty (0.00s)20402026/08/27 09:58:17 ERROR Failed to queue paths error="permission denied" count=12041--- PASS: TestServerQueueError (0.00s)2042=== CONT TestQueueFetchBatchLimit2043--- PASS: TestServerClientIntegration (0.00s)2044=== CONT TestQueueRemove20452026/08/27 09:58:17 INFO Uploading batch count=220462026/08/27 09:58:17 INFO Uploading batch count=12047--- PASS: TestQueueFetchBatchLimit (0.01s)2048=== CONT TestQueueDeduplication20492026/08/27 09:58:17 INFO Uploading batch count=420502026/08/27 09:58:17 ERROR Upload failed error="upload failed" count=420512026/08/27 09:58:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66621-2832122340/TestDrainIsolatesPoisonPath4125739136/002/bbb20522026/08/27 09:58:17 INFO Upload queue status pending=22053--- PASS: TestQueueRetryMovesToBack (0.01s)2054=== CONT TestQueueEnqueueAndFetch20552026/08/27 09:58:17 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-66621-2832122340/TestWorkerSkipsGCdPaths164561651/002/nonexistent20562026/08/27 09:58:17 INFO Uploading batch count=12057--- PASS: TestQueueRemove (0.01s)2058=== CONT TestDrainTimeoutNotWaitedOutOnSuccess20592026/08/27 09:58:17 INFO Uploading batch count=120602026/08/27 09:58:17 ERROR Upload failed error="upload failed" count=12061--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2062=== CONT TestFailedPathPrunedByLaterClosure20632026/08/27 09:58:17 INFO Uploading batch count=120642026/08/27 09:58:17 ERROR Upload failed error="upload failed" count=120652026/08/27 09:58:17 INFO Uploading batch count=120662026/08/27 09:58:17 ERROR Upload failed error="upload failed" count=12067--- PASS: TestQueueDeduplication (0.00s)20682026/08/27 09:58:17 ERROR Drain finished with paths left in queue remaining=12069=== CONT TestWorkerUploadsAndRemoves2070--- PASS: TestQueueEnqueueAndFetch (0.00s)2071=== CONT TestDrainGivesUpWhenServerDown20722026/08/27 09:58:17 INFO Uploading batch count=220732026/08/27 09:58:17 INFO Uploading batch count=120742026/08/27 09:58:17 ERROR Upload failed error="upload failed" count=120752026/08/27 09:58:17 INFO Uploading batch count=220762026/08/27 09:58:17 INFO Uploading batch count=120772026/08/27 09:58:17 INFO Upload queue status pending=220782026/08/27 09:58:17 INFO Uploading batch count=120792026/08/27 09:58:17 INFO Uploading batch count=22080--- PASS: TestDrainIsolatesPoisonPath (0.02s)2081=== CONT TestWorkerPrunesClosureDeps2082--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2083=== CONT TestRunNotBlockedByPoisonHead2084--- PASS: TestDrainTimeoutNotWaitedOutOnSuccess (0.01s)20852026/08/27 09:58:17 INFO Upload queue status pending=220862026/08/27 09:58:17 INFO Uploading batch count=120872026/08/27 09:58:17 INFO Uploading batch count=220882026/08/27 09:58:17 ERROR Upload failed error="upload failed" count=220892026/08/27 09:58:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66621-2832122340/TestDrainGivesUpWhenServerDown2260896628/002/a20902026/08/27 09:58:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66621-2832122340/TestDrainGivesUpWhenServerDown2260896628/002/b20912026/08/27 09:58:17 INFO Uploading batch count=220922026/08/27 09:58:17 ERROR Upload failed error="upload failed" count=220932026/08/27 09:58:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66621-2832122340/TestDrainGivesUpWhenServerDown2260896628/002/c20942026/08/27 09:58:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66621-2832122340/TestDrainGivesUpWhenServerDown2260896628/002/d20952026/08/27 09:58:17 INFO Upload queue status pending=320962026/08/27 09:58:17 INFO Uploading batch count=120972026/08/27 09:58:17 ERROR Upload failed error="upload failed" count=120982026/08/27 09:58:17 INFO Uploading batch count=220992026/08/27 09:58:17 ERROR Upload failed error="upload failed" count=221002026/08/27 09:58:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66621-2832122340/TestDrainGivesUpWhenServerDown2260896628/002/e21012026/08/27 09:58:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66621-2832122340/TestDrainGivesUpWhenServerDown2260896628/002/f21022026/08/27 09:58:17 ERROR Drain finished with paths left in queue remaining=1021032026/08/27 09:58:17 INFO Uploading batch count=12104--- PASS: TestDrainGivesUpWhenServerDown (0.01s)21052026/08/27 09:58:17 INFO Uploading batch count=12106--- PASS: TestWorkerSkipsGCdPaths (0.03s)2107--- PASS: TestWorkerUploadsAndRemoves (0.02s)2108--- PASS: TestWorkerPrunesClosureDeps (0.02s)21092026/08/27 09:58:17 INFO Uploading batch count=12110--- PASS: TestDrainWithoutTimeoutRunsToCompletion (0.05s)2111--- PASS: TestQueueRemoveLargeClosure (0.06s)2112--- PASS: TestQueueConcurrentWriters (0.13s)21132026/08/27 09:58:17 ERROR Upload failed error="context deadline exceeded" count=221142026/08/27 09:58:17 ERROR Upload failed, will retry later error="context deadline exceeded" path=/nix/var/nix/builds/nix-66621-2832122340/TestDrainTimeoutStopsSlowDrain4055572378/002/a21152026/08/27 09:58:17 ERROR Upload failed, will retry later error="context deadline exceeded" path=/nix/var/nix/builds/nix-66621-2832122340/TestDrainTimeoutStopsSlowDrain4055572378/002/b21162026/08/27 09:58:17 WARN Drain timed out timeout=200ms21172026/08/27 09:58:17 ERROR Drain finished with paths left in queue remaining=42118--- PASS: TestDrainTimeoutStopsSlowDrain (0.21s)21192026/08/27 09:58:18 INFO Uploading batch count=121202026/08/27 09:58:18 INFO Uploading batch count=121212026/08/27 09:58:18 INFO Uploading batch count=121222026/08/27 09:58:18 ERROR Upload failed error="upload failed" count=121232026/08/27 09:58:18 INFO Uploading batch count=121242026/08/27 09:58:18 ERROR Upload failed error="upload failed" count=121252026/08/27 09:58:18 INFO Uploading batch count=121262026/08/27 09:58:18 ERROR Upload failed error="upload failed" count=121272026/08/27 09:58:18 INFO Uploading batch count=121282026/08/27 09:58:18 ERROR Upload failed error="upload failed" count=121292026/08/27 09:58:18 ERROR Drain finished with paths left in queue remaining=12130--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2131PASS