niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #165
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestCaseHackSuffix6=== PAUSE TestCaseHackSuffix7=== RUN TestFilterOversizedClosures8=== PAUSE TestFilterOversizedClosures9=== RUN TestPartSizeForNAR10=== PAUSE TestPartSizeForNAR11=== RUN TestUploadMultipart_SupersededByPeer12=== PAUSE TestUploadMultipart_SupersededByPeer13=== RUN TestDumpPathMatchesNix14=== PAUSE TestDumpPathMatchesNix15=== RUN TestDumpPathSingleFile16=== PAUSE TestDumpPathSingleFile17=== RUN TestDumpPathWriterError18=== PAUSE TestDumpPathWriterError19=== RUN TestEncodeNixBase3220=== PAUSE TestEncodeNixBase3221=== RUN TestEncodeNixBase32WithRealHash22=== PAUSE TestEncodeNixBase32WithRealHash23=== RUN TestConvertHashToNix3224=== PAUSE TestConvertHashToNix3225=== RUN TestGetStorePathHash26=== PAUSE TestGetStorePathHash27=== RUN TestPathInfoHashCompatibility28=== PAUSE TestPathInfoHashCompatibility29=== RUN TestParsePathInfoJSON30=== PAUSE TestParsePathInfoJSON31=== RUN TestParsePathInfoJSONMultiplePaths32=== PAUSE TestParsePathInfoJSONMultiplePaths33=== RUN TestPathInfoCACompatibility34=== PAUSE TestPathInfoCACompatibility35=== RUN TestRateLimiterFeedback36=== PAUSE TestRateLimiterFeedback37=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess38=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess39=== RUN TestResolveStorePath40=== PAUSE TestResolveStorePath41=== RUN TestDoWithRetry_BodyReplayedViaGetBody42=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody43=== RUN TestShellSplit44=== PAUSE TestShellSplit45=== RUN TestShellSplitErrors46=== PAUSE TestShellSplitErrors47=== RUN TestSetClientTLS48=== PAUSE TestSetClientTLS49=== RUN TestSetClientTLSDoesNotMutateDefaultTransport50=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport51=== RUN TestSetClientTLSErrors52=== PAUSE TestSetClientTLSErrors53=== RUN TestStaticToken54=== PAUSE TestStaticToken55=== RUN TestFileTokenReadsAndCaches56=== PAUSE TestFileTokenReadsAndCaches57=== RUN TestFileTokenMissing58=== PAUSE TestFileTokenMissing59=== RUN TestFileTokenEmpty60=== PAUSE TestFileTokenEmpty61=== RUN TestScriptTokenNoExpiryRerunsEveryCall62=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall63=== RUN TestScriptTokenCachesUntilRefresh64=== PAUSE TestScriptTokenCachesUntilRefresh65=== RUN TestScriptTokenEmptyToken66=== PAUSE TestScriptTokenEmptyToken67=== RUN TestScriptTokenBadJSON68=== PAUSE TestScriptTokenBadJSON69=== RUN TestScriptTokenScriptFails70=== PAUSE TestScriptTokenScriptFails71=== RUN TestScriptTokenEmptyCommand72=== PAUSE TestScriptTokenEmptyCommand73=== CONT TestDoServerRequestAttachesToken74=== CONT TestPathInfoHashCompatibility75=== CONT TestScriptTokenCachesUntilRefresh76=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)77=== CONT TestDumpPathSingleFile78=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)79=== CONT TestScriptTokenEmptyCommand80--- PASS: TestScriptTokenEmptyCommand (0.00s)81=== CONT TestFileTokenReadsAndCaches82=== CONT TestScriptTokenScriptFails83=== CONT TestScriptTokenBadJSON84=== CONT TestScriptTokenEmptyToken85=== CONT TestSetClientTLS86=== CONT TestShellSplitErrors87=== CONT TestSetClientTLSErrors88=== CONT TestShellSplit89=== CONT TestDoWithRetry_BodyReplayedViaGetBody90=== CONT TestPartSizeForNAR91=== RUN TestPartSizeForNAR/zero_stays_at_minimum92=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum93=== RUN TestPartSizeForNAR/small_stays_at_minimum94=== PAUSE TestPartSizeForNAR/small_stays_at_minimum95=== CONT TestResolveStorePath96=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum97=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum98=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts99=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts100=== RUN TestPartSizeForNAR/1_TiB101=== PAUSE TestPartSizeForNAR/1_TiB102=== RUN TestPartSizeForNAR/5_TiB_S3_max_object103=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object104=== RUN TestPartSizeForNAR/capped_at_5_GiB105=== PAUSE TestPartSizeForNAR/capped_at_5_GiB106=== CONT TestDumpPathMatchesNix107=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess108=== CONT TestRateLimiterFeedback109=== CONT TestPathInfoCACompatibility110=== CONT TestParsePathInfoJSONMultiplePaths111=== CONT TestParsePathInfoJSON112=== CONT TestSetClientTLSDoesNotMutateDefaultTransport113=== CONT TestFileTokenMissing114=== CONT TestScriptTokenNoExpiryRerunsEveryCall115=== CONT TestFileTokenEmpty116=== CONT TestGetStorePathHash117=== CONT TestStaticToken118=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon119--- PASS: TestFileTokenReadsAndCaches (0.00s)120=== CONT TestEncodeNixBase32121--- PASS: TestShellSplitErrors (0.00s)122--- PASS: TestShellSplit (0.00s)123=== RUN TestEncodeNixBase32/test_string_hash124=== RUN TestRateLimiterFeedback/429_enables_limiter125=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths126=== RUN TestPathInfoCACompatibility/null_ca_field127--- PASS: TestScriptTokenScriptFails (0.00s)128--- PASS: TestScriptTokenBadJSON (0.00s)129--- PASS: TestScriptTokenEmptyToken (0.00s)130=== CONT TestFilterOversizedClosures131=== RUN TestFilterOversizedClosures/no_limit_keeps_everything132=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything133=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped134=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped135=== RUN TestFilterOversizedClosures/all_closures_skipped136=== PAUSE TestFilterOversizedClosures/all_closures_skipped137=== CONT TestCaseHackSuffix138=== RUN TestParsePathInfoJSON/Nix_format139=== CONT TestUploadMultipart_SupersededByPeer140=== RUN TestUploadMultipart_SupersededByPeer/exists141=== RUN TestGetStorePathHash/valid_store_path142=== PAUSE TestGetStorePathHash/valid_store_path143=== RUN TestGetStorePathHash/basename_without_hyphen_should_error144--- PASS: TestFileTokenMissing (0.00s)145=== PAUSE TestUploadMultipart_SupersededByPeer/exists146=== PAUSE TestRateLimiterFeedback/429_enables_limiter147=== RUN TestUploadMultipart_SupersededByPeer/missing148=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error149=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error150=== CONT TestEncodeNixBase32WithRealHash1512026/08/29 16:25:26 WARN Rate limiter enabled after throttle name=server-test rate=5152--- PASS: TestEncodeNixBase32WithRealHash (0.00s)153--- PASS: TestStaticToken (0.00s)154=== CONT TestPartSizeForNAR/zero_stays_at_minimum155=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon156=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts157=== PAUSE TestParsePathInfoJSON/Nix_format158=== PAUSE TestEncodeNixBase32/test_string_hash159=== RUN TestRateLimiterFeedback/503_enables_limiter160=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths161=== PAUSE TestUploadMultipart_SupersededByPeer/missing162=== RUN TestEncodeNixBase32/empty_input1632026/08/29 16:25:26 WARN Rate limiter enabled after throttle name=server-test rate=5164=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1652026/08/29 16:25:26 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:38271166=== PAUSE TestPathInfoCACompatibility/null_ca_field167=== CONT TestDumpPathWriterError168=== CONT TestConvertHashToNix32169=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI170=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI171=== RUN TestSetClientTLSErrors/missing_cert_file172=== RUN TestParsePathInfoJSON/Lix_format173=== RUN TestPathInfoCACompatibility/old_string_format_-_text174=== CONT TestPartSizeForNAR/capped_at_5_GiB175=== CONT TestPartSizeForNAR/5_TiB_S3_max_object176=== CONT TestFilterOversizedClosures/no_limit_keeps_everything177=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped178=== CONT TestFilterOversizedClosures/all_closures_skipped179=== PAUSE TestRateLimiterFeedback/503_enables_limiter1802026/08/29 16:25:26 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=2000181=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error1822026/08/29 16:25:26 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50183=== RUN TestConvertHashToNix32/SRI_format_to_Nix32184=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter185=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32186=== CONT TestPartSizeForNAR/1_TiB187=== CONT TestPartSizeForNAR/small_stays_at_minimum188=== PAUSE TestEncodeNixBase32/empty_input189=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths190=== PAUSE TestSetClientTLSErrors/missing_cert_file1912026/08/29 16:25:26 WARN Rate limiter backed off name=server-test rate=5192=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum1932026/08/29 16:25:26 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:38271194=== PAUSE TestParsePathInfoJSON/Lix_format195=== RUN TestSetClientTLSErrors/missing_key_file196=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512197=== CONT TestUploadMultipart_SupersededByPeer/exists198--- PASS: TestResolveStorePath (0.01s)199=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error200=== CONT TestUploadMultipart_SupersededByPeer/missing201=== RUN TestConvertHashToNix32/already_Nix32_format202=== CONT TestEncodeNixBase32/empty_input203=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter204=== CONT TestEncodeNixBase32/test_string_hash205=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths206=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths207=== RUN TestParsePathInfoJSON/empty_input208=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text209=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512210=== PAUSE TestSetClientTLSErrors/missing_key_file211--- PASS: TestFileTokenEmpty (0.01s)212=== RUN TestSetClientTLS/rejects_connection_without_client_cert213=== PAUSE TestConvertHashToNix32/already_Nix32_format214=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter215=== PAUSE TestParsePathInfoJSON/empty_input216--- PASS: TestDoServerRequestAttachesToken (0.01s)217--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)218--- PASS: TestEncodeNixBase32 (0.01s)219 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)220 --- PASS: TestEncodeNixBase32/empty_input (0.00s)221--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)222 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)223 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)224--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)225--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)226=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512227=== RUN TestSetClientTLSErrors/missing_ca_file228=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI229=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive230=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive231=== RUN TestPathInfoCACompatibility/new_structured_format_-_text232=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text233=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method234=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method235=== PAUSE TestSetClientTLSErrors/missing_ca_file236=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert237=== RUN TestSetClientTLSErrors/invalid_ca_file238=== RUN TestConvertHashToNix32/invalid_format239=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon240=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)241=== RUN TestParsePathInfoJSON/whitespace_only242=== CONT TestPathInfoCACompatibility/null_ca_field243=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method244=== PAUSE TestParsePathInfoJSON/whitespace_only245=== RUN TestParsePathInfoJSON/invalid_JSON246=== PAUSE TestParsePathInfoJSON/invalid_JSON247=== CONT TestPathInfoCACompatibility/new_structured_format_-_text248=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive249=== CONT TestPathInfoCACompatibility/old_string_format_-_text250=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error251=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter252--- PASS: TestFilterOversizedClosures (0.01s)253 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)254 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)255 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)256=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA257=== PAUSE TestSetClientTLSErrors/invalid_ca_file258=== PAUSE TestConvertHashToNix32/invalid_format259=== CONT TestParsePathInfoJSON/whitespace_only260=== CONT TestParsePathInfoJSON/invalid_JSON261=== CONT TestSetClientTLSErrors/missing_ca_file262=== CONT TestSetClientTLSErrors/invalid_ca_file263=== CONT TestRateLimiterFeedback/503_enables_limiter264=== CONT TestSetClientTLSErrors/missing_cert_file265=== CONT TestParsePathInfoJSON/Nix_format266=== CONT TestConvertHashToNix32/invalid_format267=== CONT TestConvertHashToNix32/already_Nix32_format268=== CONT TestConvertHashToNix32/SRI_format_to_Nix32269=== CONT TestParsePathInfoJSON/empty_input270=== CONT TestParsePathInfoJSON/Lix_format271--- PASS: TestPartSizeForNAR (0.01s)272 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)273 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)274 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)275 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)276 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)277 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)278 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)279--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)280=== CONT TestGetStorePathHash/basename_without_hyphen_should_error281=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA282=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter283=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error284=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error285=== CONT TestGetStorePathHash/valid_store_path286=== CONT TestSetClientTLSErrors/missing_key_file287=== CONT TestRateLimiterFeedback/429_enables_limiter288=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter289--- PASS: TestPathInfoHashCompatibility (0.01s)290 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)291 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)292 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)293 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)294=== RUN TestSetClientTLS/preserves_debug_logging_transport2952026/08/29 16:25:26 WARN Rate limiter enabled after throttle name=server-test rate=5296--- PASS: TestPathInfoCACompatibility (0.02s)297 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)298 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)299 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)300 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)301 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)3022026/08/29 16:25:26 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:46517303=== PAUSE TestSetClientTLS/preserves_debug_logging_transport304--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)305 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.02s)306 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.02s)307=== CONT TestSetClientTLS/rejects_connection_without_client_cert308--- PASS: TestConvertHashToNix32 (0.02s)309 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)310 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)311 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)3122026/08/29 16:25:26 WARN Rate limiter backed off name=server-test rate=5313--- PASS: TestParsePathInfoJSON (0.02s)314 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)315 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)316 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)317 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)318 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)3192026/08/29 16:25:26 WARN Rate limiter enabled after throttle name=server-test rate=5320=== CONT TestSetClientTLS/preserves_debug_logging_transport3212026/08/29 16:25:26 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:39907322=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA323--- PASS: TestGetStorePathHash (0.02s)324 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)325 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)326 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)327 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)3282026/08/29 16:25:26 WARN Rate limiter backed off name=server-test rate=5329--- PASS: TestRateLimiterFeedback (0.02s)330 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)331 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)332 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)333 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)334--- PASS: TestSetClientTLSErrors (0.03s)335 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)336 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)337 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)338 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3392026/08/29 16:25:26 http: TLS handshake error from 127.0.0.1:55528: remote error: tls: bad certificate340--- PASS: TestSetClientTLS (0.03s)341 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)342 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)343 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)344--- PASS: TestDumpPathSingleFile (0.06s)345--- PASS: TestCaseHackSuffix (0.05s)346--- PASS: TestDumpPathWriterError (0.06s)347--- PASS: TestDumpPathMatchesNix (0.10s)348--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)349PASS350Running server tests...351The files belonging to this database system will be owned by user "nixbld".352This user must also own the server process.353354The database cluster will be initialized with locale "C".355The default database encoding has accordingly been set to "SQL_ASCII".356The default text search configuration will be set to "english".357358Data page checksums are enabled.359360creating directory /build/postgres2734418275/data ... ok361creating subdirectories ... ok362selecting dynamic shared memory implementation ... posix363selecting default "max_connections" ... 100364selecting default "shared_buffers" ... 128MB365selecting default time zone ... UTC366creating configuration files ... ok367running bootstrap script ... ok368performing post-bootstrap initialization ... ok369syncing data to disk ... ok370371initdb: warning: enabling "trust" authentication for local connections372initdb: 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.373374Success. You can now start the database server using:375376 pg_ctl -D /build/postgres2734418275/data -l logfile start377378/build/postgres2734418275:5432 - no response3792026-08-29 16:25:27.974 UTC [110] LOG: starting PostgreSQL 18.4 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit3802026-08-29 16:25:27.974 UTC [110] LOG: listening on Unix socket "/build/postgres2734418275/.s.PGSQL.5432"3812026-08-29 16:25:27.978 UTC [117] LOG: database system was shut down at 2026-08-29 16:25:27 UTC3822026-08-29 16:25:27.981 UTC [110] LOG: database system is ready to accept connections383/build/postgres2734418275:5432 - accepting connections384=== RUN TestService_AuthMiddleware385=== PAUSE TestService_AuthMiddleware386=== RUN TestService_AuthMiddleware_MTLSProxyHeader387=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader388=== RUN TestService_AuthMiddleware_MTLSBoundSubjects389=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects390=== RUN TestService_ReadAuthMiddleware391=== PAUSE TestService_ReadAuthMiddleware392=== RUN TestService_AuthMiddleware_OIDC393=== PAUSE TestService_AuthMiddleware_OIDC394=== RUN TestService_RequireScope_OIDC395=== PAUSE TestService_RequireScope_OIDC396=== RUN TestService_ReadScope_PublicByDefault397=== PAUSE TestService_ReadScope_PublicByDefault398=== RUN TestCacheConfigHandler399=== PAUSE TestCacheConfigHandler400=== RUN TestCacheStatsHandler401=== PAUSE TestCacheStatsHandler402=== RUN TestClientCADerivations403=== PAUSE TestClientCADerivations404=== RUN TestClientErrorHandling405=== PAUSE TestClientErrorHandling406=== RUN TestClientIntegration407=== PAUSE TestClientIntegration408=== RUN TestClientMultipleUploads409=== PAUSE TestClientMultipleUploads410=== RUN TestClientWithDependencies411=== PAUSE TestClientWithDependencies412=== RUN TestPinProtectsFromGC413=== PAUSE TestPinProtectsFromGC414=== RUN TestResolveDBConnectionString415=== PAUSE TestResolveDBConnectionString416=== RUN TestGCAdvisoryLockBlocksConcurrentRun4172026-08-29 16:25:32.529 UTC [449] ERROR: relation "goose_db_version" does not exist at character 364182026-08-29 16:25:32.529 UTC [449] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4192026/08/29 16:25:32 OK 20241026095416_initial_model.sql (14.03ms)4202026/08/29 16:25:32 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)4212026/08/29 16:25:32 OK 20251218171726_add_pins.sql (3.52ms)4222026/08/29 16:25:32 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)4232026/08/29 16:25:32 goose: successfully migrated database to version: 202606281200004242026/08/29 16:25:32 OK 1_commit_pending_closure.sql (3.11ms)4252026/08/29 16:25:32 OK 2_object_stats_trigger.sql (1.05ms)4262026/08/29 16:25:32 goose: up to current file version: 2427--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.17s)428=== RUN TestGCBugBareHashReferences429=== PAUSE TestGCBugBareHashReferences430=== RUN TestGCMetrics431=== PAUSE TestGCMetrics432=== RUN TestGCTaskStore_StartNew433=== PAUSE TestGCTaskStore_StartNew434=== RUN TestGCTaskStore_DeduplicateSameParams435=== PAUSE TestGCTaskStore_DeduplicateSameParams436=== RUN TestGCTaskStore_ConflictDifferentParams437=== PAUSE TestGCTaskStore_ConflictDifferentParams438=== RUN TestGCTaskStore_GetEmpty439=== PAUSE TestGCTaskStore_GetEmpty440=== RUN TestGCTaskStore_GetReturnsLatest441=== PAUSE TestGCTaskStore_GetReturnsLatest442=== RUN TestGCTaskStore_CompletedAllowsNewTask443=== PAUSE TestGCTaskStore_CompletedAllowsNewTask444=== RUN TestGCTaskStore_PhaseUpdates445=== PAUSE TestGCTaskStore_PhaseUpdates446=== RUN TestGCTaskStore_Fail447=== PAUSE TestGCTaskStore_Fail448=== RUN TestGracefulShutdownDrainsInflight449=== PAUSE TestGracefulShutdownDrainsInflight450=== RUN TestService_healthCheckHandler451=== PAUSE TestService_healthCheckHandler452=== RUN TestService_readinessHandler453=== PAUSE TestService_readinessHandler454=== RUN TestGenerateLandingPage455=== PAUSE TestGenerateLandingPage456=== RUN TestCacheConfigHandlerMaxNarSize457=== PAUSE TestCacheConfigHandlerMaxNarSize458=== RUN TestCreatePendingClosureRejectsOversizedNAR459=== PAUSE TestCreatePendingClosureRejectsOversizedNAR460=== RUN TestNARDeduplicationMetadataUploadBug461=== PAUSE TestNARDeduplicationMetadataUploadBug462=== RUN TestMetricsInventory463=== PAUSE TestMetricsInventory464=== RUN TestService_NativeMTLS465=== PAUSE TestService_NativeMTLS466=== RUN TestServerTLSConfig467=== PAUSE TestServerTLSConfig468=== RUN TestMultipartCleanup469=== PAUSE TestMultipartCleanup470=== RUN TestObjectStatsTrigger471=== PAUSE TestObjectStatsTrigger472=== RUN TestOrphanedObjectsGC473=== PAUSE TestOrphanedObjectsGC474=== RUN TestOrphanedObjectsGCStressTest475=== PAUSE TestOrphanedObjectsGCStressTest476=== RUN TestResurrectedObjectNotDeleted477=== PAUSE TestResurrectedObjectNotDeleted478=== RUN TestParseSingleRange479=== PAUSE TestParseSingleRange480=== RUN TestIsValidCachePath481=== PAUSE TestIsValidCachePath482=== RUN TestReadProxyNarinfo483=== PAUSE TestReadProxyNarinfo484=== RUN TestReadProxyNarinfoAlreadyDecompressed485=== PAUSE TestReadProxyNarinfoAlreadyDecompressed486=== RUN TestReadProxyNarStreaming487=== PAUSE TestReadProxyNarStreaming488=== RUN TestReadProxy404489=== PAUSE TestReadProxy404490=== RUN TestReadProxyInvalidPath491=== PAUSE TestReadProxyInvalidPath492=== RUN TestReadProxyHead493=== PAUSE TestReadProxyHead494=== RUN TestReadProxyConditionalGet495=== PAUSE TestReadProxyConditionalGet496=== RUN TestReadProxyRootRedirectsToIndexHTML497=== PAUSE TestReadProxyRootRedirectsToIndexHTML498=== RUN TestReadProxyDisabled499=== PAUSE TestReadProxyDisabled500=== RUN TestReadRedirectNar501=== PAUSE TestReadRedirectNar502=== RUN TestReadRedirectKeepsNarinfoProxied503=== PAUSE TestReadRedirectKeepsNarinfoProxied504=== RUN TestReadProxyRangeRequest505=== PAUSE TestReadProxyRangeRequest506=== RUN TestReadRedirectUsesPublicS3URL507=== PAUSE TestReadRedirectUsesPublicS3URL508=== RUN TestRedundantMultipartUpload509=== PAUSE TestRedundantMultipartUpload510=== RUN TestCompleteMultipartUpload_ErrorButObjectExists511=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists512=== RUN TestCompletedNarNotReofferedAcrossClosures513=== PAUSE TestCompletedNarNotReofferedAcrossClosures514=== RUN TestPresignedUploadRegisteredBeforeCommit515=== PAUSE TestPresignedUploadRegisteredBeforeCommit516=== RUN TestService_Rustfstest517=== PAUSE TestService_Rustfstest518=== RUN TestParseSize519=== PAUSE TestParseSize520=== RUN TestSkippedUploadsHandler521=== PAUSE TestSkippedUploadsHandler522=== RUN TestSystemdListenerNotActivated523--- PASS: TestSystemdListenerNotActivated (0.00s)524=== RUN TestWatchdogBeatsWhenHealthy525--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)526=== RUN TestWatchdogSkipsWhenUnhealthy5272026/08/29 16:25:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5282026/08/29 16:25:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5292026/08/29 16:25:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5302026/08/29 16:25:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5312026/08/29 16:25:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5322026/08/29 16:25:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5332026/08/29 16:25:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5342026/08/29 16:25:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5352026/08/29 16:25:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5362026/08/29 16:25:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"537--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)538=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle539=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle540=== RUN TestProxyWriteTimeout541=== PAUSE TestProxyWriteTimeout542=== RUN TestIsValidUploadKey543=== PAUSE TestIsValidUploadKey544=== RUN TestUploadHandlersRejectInvalidKeys545=== PAUSE TestUploadHandlersRejectInvalidKeys546=== RUN TestUploadHandlersRejectOversizedBody547=== PAUSE TestUploadHandlersRejectOversizedBody548=== RUN TestService_cleanupPendingClosuresHandler549=== PAUSE TestService_cleanupPendingClosuresHandler550=== RUN TestService_createPendingClosureHandler551=== PAUSE TestService_createPendingClosureHandler552=== RUN TestService_verifyS3Integrity553=== PAUSE TestService_verifyS3Integrity554=== RUN TestCompleteMultipartUnregistered555=== PAUSE TestCompleteMultipartUnregistered556=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT557=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT558=== CONT TestParseSize559=== CONT TestService_healthCheckHandler560=== CONT TestReadRedirectKeepsNarinfoProxied561--- PASS: TestParseSize (0.00s)562=== CONT TestService_AuthMiddleware563=== CONT TestPinProtectsFromGC564=== CONT TestCompleteMultipartUnregistered565=== CONT TestGCTaskStore_ConflictDifferentParams566=== CONT TestUploadHandlersRejectOversizedBody567=== CONT TestCacheConfigHandlerMaxNarSize568=== CONT TestService_Rustfstest569=== CONT TestGCTaskStore_StartNew570=== CONT TestCacheConfigHandler571=== CONT TestGenerateLandingPage572=== CONT TestService_readinessHandler573=== CONT TestPresignedUploadRegisteredBeforeCommit574=== CONT TestCompletedNarNotReofferedAcrossClosures575=== CONT TestCompleteMultipartUpload_ErrorButObjectExists576=== RUN TestCacheConfigHandler/full_config,_no_issuer577=== CONT TestRedundantMultipartUpload578=== CONT TestReadRedirectUsesPublicS3URL579=== CONT TestReadProxyRangeRequest580=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT581=== CONT TestClientWithDependencies582=== CONT TestClientMultipleUploads583=== CONT TestClientIntegration584=== CONT TestGCTaskStore_GetEmpty585--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)586--- PASS: TestGCTaskStore_StartNew (0.00s)587=== CONT TestClientErrorHandling588--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)589=== RUN TestClientErrorHandling/InvalidStorePath590=== PAUSE TestClientErrorHandling/InvalidStorePath591=== RUN TestClientErrorHandling/InvalidAuthToken592=== CONT TestClientCADerivations593=== PAUSE TestClientErrorHandling/InvalidAuthToken594=== RUN TestClientErrorHandling/ServerNotAvailable595=== PAUSE TestClientErrorHandling/ServerNotAvailable596--- PASS: TestGenerateLandingPage (0.01s)597=== CONT TestCacheStatsHandler598=== CONT TestService_AuthMiddleware_OIDC599=== PAUSE TestCacheConfigHandler/full_config,_no_issuer600=== CONT TestService_ReadScope_PublicByDefault601=== RUN TestCacheConfigHandler/no_cache_url_configured602=== PAUSE TestCacheConfigHandler/no_cache_url_configured603=== RUN TestCacheConfigHandler/no_signing_keys6042026/08/29 16:25:33 INFO OIDC provider initialized name=test605=== PAUSE TestCacheConfigHandler/no_signing_keys606--- PASS: TestGCTaskStore_GetEmpty (0.00s)607=== CONT TestService_RequireScope_OIDC608=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator609=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator610=== CONT TestGracefulShutdownDrainsInflight6112026/08/29 16:25:33 INFO Starting HTTP server address=127.0.0.1:467016122026/08/29 16:25:33 INFO Shutdown signal received, draining in-flight requests timeout=10s6132026/08/29 16:25:33 INFO OIDC provider initialized name=test6142026-08-29 16:25:33.923 UTC [517] ERROR: relation "goose_db_version" does not exist at character 366152026-08-29 16:25:33.923 UTC [517] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6162026-08-29 16:25:33.924 UTC [519] ERROR: relation "goose_db_version" does not exist at character 366172026-08-29 16:25:33.924 UTC [519] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6182026-08-29 16:25:33.972 UTC [525] ERROR: relation "goose_db_version" does not exist at character 366192026-08-29 16:25:33.972 UTC [525] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6202026-08-29 16:25:33.978 UTC [526] ERROR: relation "goose_db_version" does not exist at character 366212026-08-29 16:25:33.978 UTC [526] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC622--- PASS: TestGracefulShutdownDrainsInflight (0.07s)623=== CONT TestGCBugBareHashReferences624=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts625=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts626=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure627=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure628=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart629=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart630=== CONT TestGCTaskStore_Fail631--- PASS: TestGCTaskStore_Fail (0.00s)632=== CONT TestGCMetrics6332026-08-29 16:25:34.012 UTC [529] ERROR: relation "goose_db_version" does not exist at character 366342026-08-29 16:25:34.012 UTC [529] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6352026/08/29 16:25:34 OK 20241026095416_initial_model.sql (66ms)6362026-08-29 16:25:34.020 UTC [535] ERROR: relation "goose_db_version" does not exist at character 366372026-08-29 16:25:34.020 UTC [535] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6382026/08/29 16:25:34 OK 20241026095416_initial_model.sql (69.78ms)6392026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (3.32ms)6402026-08-29 16:25:34.033 UTC [536] ERROR: relation "goose_db_version" does not exist at character 366412026-08-29 16:25:34.033 UTC [536] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6422026-08-29 16:25:34.035 UTC [537] ERROR: relation "goose_db_version" does not exist at character 366432026-08-29 16:25:34.035 UTC [537] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6442026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (15.35ms)6452026/08/29 16:25:34 OK 20251218171726_add_pins.sql (16.03ms)6462026/08/29 16:25:34 OK 20241026095416_initial_model.sql (33.04ms)6472026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (4.02ms)6482026-08-29 16:25:34.048 UTC [538] ERROR: relation "goose_db_version" does not exist at character 366492026-08-29 16:25:34.048 UTC [538] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6502026/08/29 16:25:34 OK 20241026095416_initial_model.sql (27.52ms)6512026/08/29 16:25:34 OK 20251218171726_add_pins.sql (12.35ms)6522026/08/29 16:25:34 OK 20241026095416_initial_model.sql (36.46ms)6532026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (11.61ms)6542026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200006552026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (3.32ms)6562026/08/29 16:25:34 OK 20251218171726_add_pins.sql (8.16ms)6572026/08/29 16:25:34 OK 1_commit_pending_closure.sql (4.55ms)6582026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (6.55ms)6592026/08/29 16:25:34 OK 20251218171726_add_pins.sql (6.14ms)6602026/08/29 16:25:34 OK 2_object_stats_trigger.sql (2.94ms)6612026/08/29 16:25:34 goose: up to current file version: 26622026/08/29 16:25:34 OK 20241026095416_initial_model.sql (21.66ms)6632026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (9.36ms)6642026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200006652026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (16.24ms)6662026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200006672026/08/29 16:25:34 OK 1_commit_pending_closure.sql (13.46ms)6682026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (15.35ms)6692026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200006702026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (14.44ms)6712026/08/29 16:25:34 OK 20251218171726_add_pins.sql (20.22ms)6722026/08/29 16:25:34 OK 1_commit_pending_closure.sql (5.17ms)6732026/08/29 16:25:34 OK 2_object_stats_trigger.sql (5.75ms)6742026/08/29 16:25:34 goose: up to current file version: 26752026/08/29 16:25:34 OK 1_commit_pending_closure.sql (7.71ms)6762026/08/29 16:25:34 OK 20241026095416_initial_model.sql (32.75ms)6772026/08/29 16:25:34 OK 2_object_stats_trigger.sql (4.22ms)6782026/08/29 16:25:34 goose: up to current file version: 26792026/08/29 16:25:34 OK 2_object_stats_trigger.sql (4.43ms)6802026/08/29 16:25:34 goose: up to current file version: 26812026/08/29 16:25:34 OK 20251218171726_add_pins.sql (9.63ms)6822026/08/29 16:25:34 OK 20241026095416_initial_model.sql (32.83ms)6832026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (10.74ms)6842026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200006852026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (4.36ms)6862026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (6.69ms)6872026/08/29 16:25:34 OK 20241026095416_initial_model.sql (32.75ms)6882026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (8.9ms)6892026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200006902026-08-29 16:25:34.094 UTC [539] ERROR: relation "goose_db_version" does not exist at character 366912026-08-29 16:25:34.094 UTC [539] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6922026-08-29 16:25:34.096 UTC [540] ERROR: relation "goose_db_version" does not exist at character 366932026-08-29 16:25:34.096 UTC [540] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6942026/08/29 16:25:34 OK 1_commit_pending_closure.sql (7.55ms)6952026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (5.06ms)6962026/08/29 16:25:34 OK 20251218171726_add_pins.sql (10.19ms)6972026/08/29 16:25:34 OK 20251218171726_add_pins.sql (10.25ms)6982026/08/29 16:25:34 OK 1_commit_pending_closure.sql (7.14ms)6992026/08/29 16:25:34 OK 2_object_stats_trigger.sql (4.37ms)7002026/08/29 16:25:34 goose: up to current file version: 27012026-08-29 16:25:34.102 UTC [542] ERROR: relation "goose_db_version" does not exist at character 367022026-08-29 16:25:34.102 UTC [542] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7032026-08-29 16:25:34.102 UTC [541] ERROR: relation "goose_db_version" does not exist at character 367042026-08-29 16:25:34.102 UTC [541] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7052026/08/29 16:25:34 OK 20251218171726_add_pins.sql (5.63ms)7062026-08-29 16:25:34.112 UTC [543] ERROR: relation "goose_db_version" does not exist at character 367072026-08-29 16:25:34.112 UTC [543] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7082026-08-29 16:25:34.113 UTC [546] ERROR: relation "goose_db_version" does not exist at character 367092026-08-29 16:25:34.113 UTC [546] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7102026-08-29 16:25:34.114 UTC [544] ERROR: relation "goose_db_version" does not exist at character 367112026-08-29 16:25:34.114 UTC [544] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7122026-08-29 16:25:34.115 UTC [545] ERROR: relation "goose_db_version" does not exist at character 367132026-08-29 16:25:34.115 UTC [545] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7142026/08/29 16:25:34 OK 2_object_stats_trigger.sql (13.99ms)7152026/08/29 16:25:34 goose: up to current file version: 27162026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (20.2ms)7172026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200007182026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (20.32ms)7192026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200007202026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (17.3ms)7212026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200007222026/08/29 16:25:34 OK 1_commit_pending_closure.sql (4.2ms)7232026/08/29 16:25:34 OK 1_commit_pending_closure.sql (5.94ms)7242026/08/29 16:25:34 OK 1_commit_pending_closure.sql (6.37ms)7252026/08/29 16:25:34 OK 2_object_stats_trigger.sql (2.9ms)7262026/08/29 16:25:34 goose: up to current file version: 27272026/08/29 16:25:34 OK 2_object_stats_trigger.sql (2.08ms)7282026/08/29 16:25:34 goose: up to current file version: 27292026-08-29 16:25:34.130 UTC [547] ERROR: relation "goose_db_version" does not exist at character 367302026-08-29 16:25:34.130 UTC [547] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7312026/08/29 16:25:34 OK 2_object_stats_trigger.sql (4.22ms)7322026/08/29 16:25:34 goose: up to current file version: 27332026-08-29 16:25:34.133 UTC [548] ERROR: relation "goose_db_version" does not exist at character 367342026-08-29 16:25:34.133 UTC [548] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7352026/08/29 16:25:34 OK 20241026095416_initial_model.sql (11.89ms)7362026-08-29 16:25:34.133 UTC [549] ERROR: relation "goose_db_version" does not exist at character 367372026-08-29 16:25:34.133 UTC [549] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7382026-08-29 16:25:34.135 UTC [550] ERROR: relation "goose_db_version" does not exist at character 367392026-08-29 16:25:34.135 UTC [550] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7402026-08-29 16:25:34.135 UTC [551] ERROR: relation "goose_db_version" does not exist at character 367412026-08-29 16:25:34.135 UTC [551] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7422026/08/29 16:25:34 OK 20241026095416_initial_model.sql (18.16ms)7432026-08-29 16:25:34.136 UTC [552] ERROR: relation "goose_db_version" does not exist at character 367442026-08-29 16:25:34.136 UTC [552] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7452026/08/29 16:25:34 OK 20241026095416_initial_model.sql (16.67ms)7462026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (4.32ms)7472026/08/29 16:25:34 OK 20241026095416_initial_model.sql (17.37ms)7482026/08/29 16:25:34 OK 20241026095416_initial_model.sql (17.06ms)7492026/08/29 16:25:34 OK 20241026095416_initial_model.sql (17.28ms)7502026/08/29 16:25:34 OK 20241026095416_initial_model.sql (15.36ms)7512026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (4.03ms)7522026-08-29 16:25:34.140 UTC [553] ERROR: relation "goose_db_version" does not exist at character 367532026-08-29 16:25:34.140 UTC [553] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7542026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (5.01ms)7552026/08/29 16:25:34 OK 20241026095416_initial_model.sql (15.65ms)7562026/08/29 16:25:34 OK 20251218171726_add_pins.sql (6.06ms)7572026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (4.61ms)7582026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (4.38ms)7592026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (3.88ms)7602026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (4.56ms)7612026/08/29 16:25:34 OK 20251218171726_add_pins.sql (6.26ms)7622026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (5.02ms)7632026/08/29 16:25:34 OK 20251218171726_add_pins.sql (6.05ms)7642026/08/29 16:25:34 OK 20251218171726_add_pins.sql (7.69ms)7652026/08/29 16:25:34 OK 20251218171726_add_pins.sql (5.87ms)7662026/08/29 16:25:34 OK 20251218171726_add_pins.sql (7.26ms)7672026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (7.58ms)7682026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200007692026/08/29 16:25:34 OK 20251218171726_add_pins.sql (8.75ms)7702026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (6.96ms)7712026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200007722026/08/29 16:25:34 OK 20251218171726_add_pins.sql (5.42ms)7732026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (4.44ms)7742026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200007752026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (5.58ms)7762026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200007772026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (5.61ms)7782026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200007792026/08/29 16:25:34 OK 1_commit_pending_closure.sql (4.28ms)7802026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (5.71ms)7812026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200007822026/08/29 16:25:34 OK 1_commit_pending_closure.sql (4.11ms)7832026/08/29 16:25:34 OK 20241026095416_initial_model.sql (14.61ms)7842026/08/29 16:25:34 OK 20241026095416_initial_model.sql (17.19ms)7852026/08/29 16:25:34 OK 1_commit_pending_closure.sql (2.82ms)7862026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (5.78ms)7872026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200007882026/08/29 16:25:34 OK 20241026095416_initial_model.sql (11.48ms)7892026/08/29 16:25:34 OK 20241026095416_initial_model.sql (14.28ms)7902026/08/29 16:25:34 OK 2_object_stats_trigger.sql (2.7ms)7912026/08/29 16:25:34 goose: up to current file version: 27922026/08/29 16:25:34 OK 2_object_stats_trigger.sql (2.25ms)7932026/08/29 16:25:34 goose: up to current file version: 27942026/08/29 16:25:34 OK 1_commit_pending_closure.sql (3.55ms)7952026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (5.25ms)7962026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200007972026/08/29 16:25:34 OK 2_object_stats_trigger.sql (1.67ms)7982026/08/29 16:25:34 OK 1_commit_pending_closure.sql (4.45ms)7992026/08/29 16:25:34 goose: up to current file version: 28002026/08/29 16:25:34 OK 1_commit_pending_closure.sql (4.17ms)8012026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (2.72ms)8022026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (2.87ms)8032026/08/29 16:25:34 OK 20241026095416_initial_model.sql (10.6ms)8042026/08/29 16:25:34 OK 20241026095416_initial_model.sql (14.44ms)8052026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (2.91ms)8062026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (2.97ms)8072026/08/29 16:25:34 OK 1_commit_pending_closure.sql (2.99ms)8082026/08/29 16:25:34 OK 2_object_stats_trigger.sql (3.18ms)8092026/08/29 16:25:34 goose: up to current file version: 28102026/08/29 16:25:34 OK 1_commit_pending_closure.sql (3.97ms)8112026/08/29 16:25:34 OK 2_object_stats_trigger.sql (2.36ms)8122026/08/29 16:25:34 goose: up to current file version: 28132026/08/29 16:25:34 OK 2_object_stats_trigger.sql (3.18ms)8142026/08/29 16:25:34 goose: up to current file version: 28152026/08/29 16:25:34 OK 20241026095416_initial_model.sql (16.59ms)8162026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)8172026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)8182026/08/29 16:25:34 OK 2_object_stats_trigger.sql (2.54ms)8192026/08/29 16:25:34 goose: up to current file version: 28202026/08/29 16:25:34 OK 2_object_stats_trigger.sql (2.73ms)8212026/08/29 16:25:34 goose: up to current file version: 28222026/08/29 16:25:34 OK 20251218171726_add_pins.sql (4.93ms)8232026/08/29 16:25:34 OK 20251218171726_add_pins.sql (4.89ms)824--- PASS: TestService_healthCheckHandler (0.33s)825=== CONT TestGCTaskStore_PhaseUpdates826--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)827=== CONT TestGCTaskStore_GetReturnsLatest828--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)829=== CONT TestGCTaskStore_CompletedAllowsNewTask830--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)831=== CONT TestProxyWriteTimeout832=== RUN TestProxyWriteTimeout/narinfo833=== PAUSE TestProxyWriteTimeout/narinfo834=== RUN TestProxyWriteTimeout/1_GiB_nar835=== PAUSE TestProxyWriteTimeout/1_GiB_nar836=== RUN TestProxyWriteTimeout/10_GiB_nar837=== PAUSE TestProxyWriteTimeout/10_GiB_nar838=== RUN TestProxyWriteTimeout/unknown_size839=== PAUSE TestProxyWriteTimeout/unknown_size840=== CONT TestReadProxyHead8412026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (3.43ms)8422026/08/29 16:25:34 OK 20251218171726_add_pins.sql (3.68ms)8432026/08/29 16:25:34 OK 20251218171726_add_pins.sql (6.08ms)8442026/08/29 16:25:34 OK 20251218171726_add_pins.sql (3.82ms)8452026/08/29 16:25:34 OK 20251218171726_add_pins.sql (6.07ms)8462026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (4.46ms)8472026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200008482026/08/29 16:25:34 OK 20251218171726_add_pins.sql (3.99ms)8492026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (5.79ms)8502026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200008512026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (4.02ms)8522026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200008532026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)8542026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200008552026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)8562026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200008572026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (3.88ms)8582026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200008592026/08/29 16:25:34 OK 1_commit_pending_closure.sql (1.9ms)8602026/08/29 16:25:34 OK 1_commit_pending_closure.sql (2.31ms)8612026/08/29 16:25:34 OK 1_commit_pending_closure.sql (2.39ms)8622026/08/29 16:25:34 OK 2_object_stats_trigger.sql (1.93ms)8632026/08/29 16:25:34 goose: up to current file version: 28642026/08/29 16:25:34 OK 1_commit_pending_closure.sql (1.99ms)8652026/08/29 16:25:34 OK 1_commit_pending_closure.sql (2.15ms)8662026/08/29 16:25:34 OK 1_commit_pending_closure.sql (2.28ms)8672026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (2.77ms)8682026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200008692026/08/29 16:25:34 OK 2_object_stats_trigger.sql (1.02ms)8702026/08/29 16:25:34 goose: up to current file version: 28712026/08/29 16:25:34 OK 2_object_stats_trigger.sql (998.19µs)8722026/08/29 16:25:34 goose: up to current file version: 28732026/08/29 16:25:34 OK 2_object_stats_trigger.sql (1.14ms)8742026/08/29 16:25:34 goose: up to current file version: 28752026/08/29 16:25:34 OK 2_object_stats_trigger.sql (1.31ms)8762026/08/29 16:25:34 goose: up to current file version: 28772026/08/29 16:25:34 OK 2_object_stats_trigger.sql (1.28ms)8782026/08/29 16:25:34 goose: up to current file version: 28792026/08/29 16:25:34 OK 1_commit_pending_closure.sql (1.68ms)8802026/08/29 16:25:34 OK 2_object_stats_trigger.sql (2.23ms)8812026/08/29 16:25:34 goose: up to current file version: 28822026/08/29 16:25:34 INFO Received uploads request method=POST path=/api/pending_closures8832026/08/29 16:25:34 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"884--- PASS: TestService_AuthMiddleware (0.37s)885=== CONT TestUploadHandlersRejectInvalidKeys886=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info887=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info888=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal889=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal890=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key891=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key892=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key893=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key894=== CONT TestReadRedirectNar895--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.37s)896=== CONT TestIsValidUploadKey897=== RUN TestIsValidUploadKey/narinfo898=== PAUSE TestIsValidUploadKey/narinfo899=== RUN TestIsValidUploadKey/nar_zst900=== PAUSE TestIsValidUploadKey/nar_zst901=== RUN TestIsValidUploadKey/nar_xz902=== PAUSE TestIsValidUploadKey/nar_xz903=== RUN TestIsValidUploadKey/nar_plain904=== PAUSE TestIsValidUploadKey/nar_plain905=== RUN TestIsValidUploadKey/listing906=== PAUSE TestIsValidUploadKey/listing907=== RUN TestIsValidUploadKey/build_log908=== PAUSE TestIsValidUploadKey/build_log909=== RUN TestIsValidUploadKey/build_log_home-manager_file910=== PAUSE TestIsValidUploadKey/build_log_home-manager_file911=== RUN TestIsValidUploadKey/build_log_plus_in_name912=== PAUSE TestIsValidUploadKey/build_log_plus_in_name913=== RUN TestIsValidUploadKey/build_log_question_mark914=== PAUSE TestIsValidUploadKey/build_log_question_mark915=== RUN TestIsValidUploadKey/build_log_equals916=== PAUSE TestIsValidUploadKey/build_log_equals917=== RUN TestIsValidUploadKey/realisation918=== PAUSE TestIsValidUploadKey/realisation919=== RUN TestIsValidUploadKey/realisation_plus_in_output920=== PAUSE TestIsValidUploadKey/realisation_plus_in_output921=== RUN TestIsValidUploadKey/nix-cache-info922=== PAUSE TestIsValidUploadKey/nix-cache-info923=== RUN TestIsValidUploadKey/index.html924=== PAUSE TestIsValidUploadKey/index.html925=== RUN TestIsValidUploadKey/narinfo_key,_nar_type926=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type927=== RUN TestIsValidUploadKey/nar_key,_narinfo_type928=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type929=== RUN TestIsValidUploadKey/listing_key,_narinfo_type930=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type931=== RUN TestIsValidUploadKey/traversal932=== PAUSE TestIsValidUploadKey/traversal933=== RUN TestIsValidUploadKey/traversal_nar934=== PAUSE TestIsValidUploadKey/traversal_nar935=== RUN TestIsValidUploadKey/absolute936=== PAUSE TestIsValidUploadKey/absolute937=== RUN TestIsValidUploadKey/empty_key938=== PAUSE TestIsValidUploadKey/empty_key939=== RUN TestIsValidUploadKey/unknown_type940=== PAUSE TestIsValidUploadKey/unknown_type941=== CONT TestReadProxyDisabled9422026-08-29 16:25:34.232 UTC [560] ERROR: relation "goose_db_version" does not exist at character 369432026-08-29 16:25:34.232 UTC [560] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9442026/08/29 16:25:34 OK 20241026095416_initial_model.sql (11.18ms)9452026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (2.83ms)9462026/08/29 16:25:34 OK 20251218171726_add_pins.sql (5.17ms)9472026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)9482026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200009492026/08/29 16:25:34 OK 1_commit_pending_closure.sql (9.74ms)9502026/08/29 16:25:34 OK 2_object_stats_trigger.sql (2.73ms)9512026/08/29 16:25:34 goose: up to current file version: 29522026-08-29 16:25:34.286 UTC [562] ERROR: relation "goose_db_version" does not exist at character 369532026-08-29 16:25:34.286 UTC [562] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9542026-08-29 16:25:34.301 UTC [563] ERROR: relation "goose_db_version" does not exist at character 369552026-08-29 16:25:34.301 UTC [563] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9562026/08/29 16:25:34 OK 20241026095416_initial_model.sql (10.18ms)9572026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)9582026/08/29 16:25:34 OK 20251218171726_add_pins.sql (2.8ms)9592026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (5.54ms)9602026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200009612026/08/29 16:25:34 OK 1_commit_pending_closure.sql (3.05ms)9622026/08/29 16:25:34 OK 20241026095416_initial_model.sql (9.6ms)9632026/08/29 16:25:34 OK 2_object_stats_trigger.sql (1.27ms)9642026/08/29 16:25:34 goose: up to current file version: 29652026/08/29 16:25:34 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)9662026/08/29 16:25:34 OK 20251218171726_add_pins.sql (3ms)9672026/08/29 16:25:34 OK 20260628120000_add_object_size_and_stats.sql (2.65ms)9682026/08/29 16:25:34 goose: successfully migrated database to version: 202606281200009692026/08/29 16:25:34 OK 1_commit_pending_closure.sql (1.68ms)9702026/08/29 16:25:34 OK 2_object_stats_trigger.sql (771.41µs)9712026/08/29 16:25:34 goose: up to current file version: 2972--- PASS: TestReadRedirectKeepsNarinfoProxied (1.19s)973=== CONT TestReadProxyRootRedirectsToIndexHTML9742026/08/29 16:25:35 INFO Received uploads request method=POST path=/api/pending_closures975--- PASS: TestService_Rustfstest (1.22s)976=== CONT TestMultipartCleanup9772026/08/29 16:25:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9782026/08/29 16:25:35 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst979--- PASS: TestCompleteMultipartUnregistered (1.23s)980=== CONT TestReadProxyConditionalGet9812026/08/29 16:25:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9822026-08-29 16:25:35.085 UTC [588] ERROR: relation "goose_db_version" does not exist at character 369832026-08-29 16:25:35.085 UTC [588] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9842026/08/29 16:25:35 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTY1YzFkMmEtMGU4MS00Y2RmLTkzMmMtYWQ3NTljMjg3MTRjLmYyMmVlOTgzLWRhNzAtNDFlNi1iMjUzLWQwNDE0ZDE4NWE2NXgxNzg4MDIwNzM1MDQwMjIwMzk59852026/08/29 16:25:35 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTY1YzFkMmEtMGU4MS00Y2RmLTkzMmMtYWQ3NTljMjg3MTRjLmYyMmVlOTgzLWRhNzAtNDFlNi1iMjUzLWQwNDE0ZDE4NWE2NXgxNzg4MDIwNzM1MDQwMjIwMzk5 parts=1986--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.26s)987=== CONT TestParseSingleRange988=== RUN TestParseSingleRange/none989=== PAUSE TestParseSingleRange/none990=== RUN TestParseSingleRange/unknown_unit991=== PAUSE TestParseSingleRange/unknown_unit992=== RUN TestParseSingleRange/multi-range_ignored993=== PAUSE TestParseSingleRange/multi-range_ignored994=== RUN TestParseSingleRange/malformed_no_dash995=== PAUSE TestParseSingleRange/malformed_no_dash996=== RUN TestParseSingleRange/malformed_both_empty997=== PAUSE TestParseSingleRange/malformed_both_empty998=== RUN TestParseSingleRange/malformed_end_before_start999=== PAUSE TestParseSingleRange/malformed_end_before_start1000=== RUN TestParseSingleRange/closed1001=== PAUSE TestParseSingleRange/closed1002=== RUN TestParseSingleRange/open-ended1003=== PAUSE TestParseSingleRange/open-ended1004=== RUN TestParseSingleRange/end_clamped_to_size1005=== PAUSE TestParseSingleRange/end_clamped_to_size1006=== RUN TestParseSingleRange/suffix1007=== PAUSE TestParseSingleRange/suffix1008=== RUN TestParseSingleRange/suffix_exceeds_size1009=== PAUSE TestParseSingleRange/suffix_exceeds_size1010=== RUN TestParseSingleRange/single_byte1011=== PAUSE TestParseSingleRange/single_byte1012=== RUN TestParseSingleRange/start_past_EOF1013=== PAUSE TestParseSingleRange/start_past_EOF1014=== RUN TestParseSingleRange/start_far_past_EOF1015=== PAUSE TestParseSingleRange/start_far_past_EOF1016=== CONT TestResurrectedObjectNotDeleted10172026/08/29 16:25:35 OK 20241026095416_initial_model.sql (15.02ms)10182026/08/29 16:25:35 INFO Received uploads request method=POST path=/api/pending_closures10192026/08/29 16:25:35 OK 20251210153512_drop_unused_gin_index.sql (2.98ms)10202026/08/29 16:25:35 OK 20251218171726_add_pins.sql (5.4ms)1021=== NAME TestPinProtectsFromGC1022 client_integration_test.go:648: Pinned store path: /build/TestPinProtectsFromGC1939306943/001/store/laf8giq46wmfg38gjk4kvzrx5k52ill6-pinned-file.txt1023 client_integration_test.go:649: Unpinned store path: /build/TestPinProtectsFromGC1939306943/001/store/gn5m908m54z3rzdl645h1b2g4qab0rhq-unpinned-file.txt10242026/08/29 16:25:35 OK 20260628120000_add_object_size_and_stats.sql (4.91ms)10252026/08/29 16:25:35 goose: successfully migrated database to version: 2026062812000010262026-08-29 16:25:35.131 UTC [626] ERROR: relation "goose_db_version" does not exist at character 3610272026-08-29 16:25:35.131 UTC [626] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10282026/08/29 16:25:35 OK 1_commit_pending_closure.sql (11.15ms)10292026/08/29 16:25:35 OK 2_object_stats_trigger.sql (4.03ms)10302026/08/29 16:25:35 goose: up to current file version: 210312026/08/29 16:25:35 WARN readiness check failed error="closed pool"1032--- PASS: TestService_readinessHandler (1.30s)1033=== CONT TestReadProxyNarStreaming10342026-08-29 16:25:35.152 UTC [628] ERROR: relation "goose_db_version" does not exist at character 3610352026-08-29 16:25:35.152 UTC [628] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1036--- PASS: TestService_ReadScope_PublicByDefault (1.30s)1037=== CONT TestOrphanedObjectsGCStressTest10382026/08/29 16:25:35 OK 20241026095416_initial_model.sql (22.62ms)10392026/08/29 16:25:35 OK 20251210153512_drop_unused_gin_index.sql (3.27ms)10402026-08-29 16:25:35.175 UTC [634] ERROR: relation "goose_db_version" does not exist at character 3610412026-08-29 16:25:35.175 UTC [634] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10422026/08/29 16:25:35 OK 20251218171726_add_pins.sql (6.46ms)10432026/08/29 16:25:35 OK 20241026095416_initial_model.sql (14.29ms)10442026/08/29 16:25:35 OK 20251210153512_drop_unused_gin_index.sql (3.18ms)10452026/08/29 16:25:35 OK 20260628120000_add_object_size_and_stats.sql (8.19ms)10462026/08/29 16:25:35 goose: successfully migrated database to version: 2026062812000010472026/08/29 16:25:35 OK 20251218171726_add_pins.sql (4.82ms)10482026/08/29 16:25:35 INFO Received uploads request method=POST path=/api/pending_closures1049=== NAME TestClientIntegration1050 client_integration_test.go:277: Created store path: /build/TestClientIntegration4005948511/002/store/jnzvapmd3zv3rmmml4cpn13qc6jplny9-test-file.txt10512026/08/29 16:25:35 OK 1_commit_pending_closure.sql (4.14ms)10522026/08/29 16:25:35 OK 20260628120000_add_object_size_and_stats.sql (5.25ms)10532026/08/29 16:25:35 goose: successfully migrated database to version: 2026062812000010542026/08/29 16:25:35 OK 2_object_stats_trigger.sql (3.8ms)10552026/08/29 16:25:35 goose: up to current file version: 21056=== NAME TestClientCADerivations1057 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations467905541/001/store/32pny32y0k2a6jn6wc4x69rkzg32yj85-ca-test10582026/08/29 16:25:35 OK 20241026095416_initial_model.sql (17.65ms)10592026/08/29 16:25:35 OK 1_commit_pending_closure.sql (9.79ms)10602026/08/29 16:25:35 OK 2_object_stats_trigger.sql (2.25ms)10612026/08/29 16:25:35 goose: up to current file version: 210622026/08/29 16:25:35 OK 20251210153512_drop_unused_gin_index.sql (2.79ms)1063--- PASS: TestReadRedirectUsesPublicS3URL (1.35s)1064=== CONT TestReadProxyInvalidPath10652026/08/29 16:25:35 OK 20251218171726_add_pins.sql (4.69ms)10662026/08/29 16:25:35 OK 20260628120000_add_object_size_and_stats.sql (4.98ms)10672026/08/29 16:25:35 goose: successfully migrated database to version: 2026062812000010682026/08/29 16:25:35 OK 1_commit_pending_closure.sql (3.41ms)10692026/08/29 16:25:35 OK 2_object_stats_trigger.sql (4.77ms)10702026/08/29 16:25:35 goose: up to current file version: 21071=== NAME TestClientCADerivations1072 client_ca_test.go:139: Found 1 dependencies (including self)10732026/08/29 16:25:35 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10742026-08-29 16:25:35.240 UTC [741] ERROR: relation "goose_db_version" does not exist at character 3610752026-08-29 16:25:35.240 UTC [741] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10762026/08/29 16:25:35 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10772026/08/29 16:25:35 OK 20241026095416_initial_model.sql (15.82ms)10782026/08/29 16:25:35 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)10792026/08/29 16:25:35 INFO Received uploads request method=POST path=/api/pending_closures10802026/08/29 16:25:35 OK 20251218171726_add_pins.sql (3.37ms)10812026-08-29 16:25:35.275 UTC [796] ERROR: relation "goose_db_version" does not exist at character 3610822026-08-29 16:25:35.275 UTC [796] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10832026/08/29 16:25:35 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)10842026/08/29 16:25:35 goose: successfully migrated database to version: 2026062812000010852026/08/29 16:25:35 OK 1_commit_pending_closure.sql (2.06ms)10862026-08-29 16:25:35.279 UTC [798] ERROR: relation "goose_db_version" does not exist at character 3610872026-08-29 16:25:35.279 UTC [798] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10882026/08/29 16:25:35 OK 2_object_stats_trigger.sql (1.29ms)10892026/08/29 16:25:35 goose: up to current file version: 210902026/08/29 16:25:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10912026/08/29 16:25:35 INFO Uploading laf8giq46wmfg38gjk4kvzrx5k52ill6-pinned-file.txt (128B)10922026/08/29 16:25:35 OK 20241026095416_initial_model.sql (9.37ms)10932026/08/29 16:25:35 OK 20251210153512_drop_unused_gin_index.sql (1.29ms)10942026/08/29 16:25:35 OK 20251218171726_add_pins.sql (2.95ms)10952026/08/29 16:25:35 OK 20260628120000_add_object_size_and_stats.sql (3.83ms)10962026/08/29 16:25:35 goose: successfully migrated database to version: 2026062812000010972026/08/29 16:25:35 OK 20241026095416_initial_model.sql (20.02ms)10982026/08/29 16:25:35 OK 1_commit_pending_closure.sql (2.32ms)10992026/08/29 16:25:35 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)11002026/08/29 16:25:35 OK 2_object_stats_trigger.sql (1.36ms)11012026/08/29 16:25:35 goose: up to current file version: 211022026/08/29 16:25:35 INFO Received uploads request method=POST path=/api/pending_closures11032026/08/29 16:25:35 OK 20251218171726_add_pins.sql (7.34ms)11042026/08/29 16:25:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11052026/08/29 16:25:35 INFO Uploading jnzvapmd3zv3rmmml4cpn13qc6jplny9-test-file.txt (152B)11062026/08/29 16:25:35 OK 20260628120000_add_object_size_and_stats.sql (4.66ms)11072026/08/29 16:25:35 goose: successfully migrated database to version: 2026062812000011082026/08/29 16:25:35 OK 1_commit_pending_closure.sql (2.47ms)11092026/08/29 16:25:35 OK 2_object_stats_trigger.sql (1.16ms)11102026/08/29 16:25:35 goose: up to current file version: 211112026/08/29 16:25:35 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11122026/08/29 16:25:35 INFO Received uploads request method=POST path=/api/pending_closures11132026/08/29 16:25:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11142026/08/29 16:25:35 INFO Uploading 32pny32y0k2a6jn6wc4x69rkzg32yj85-ca-test (144B)1115=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1116=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token11172026/08/29 16:25:35 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1118=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1119=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1120=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1121=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1122=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1123=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1124=== CONT TestOrphanedObjectsGC11252026/08/29 16:25:35 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"11262026/08/29 16:25:35 WARN Failed to register uploaded object key=log/wngvfqp9538wfn6l6d6zprvcp52k9vlx-ca-test.drv error="server returned 404: 404 page not found\n"11272026/08/29 16:25:35 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11282026/08/29 16:25:35 INFO Received uploads request method=POST path=/api/pending_closures11292026/08/29 16:25:35 WARN Failed to register uploaded object key=32pny32y0k2a6jn6wc4x69rkzg32yj85.ls error="server returned 404: 404 page not found\n"11302026/08/29 16:25:35 WARN Failed to register uploaded object key=laf8giq46wmfg38gjk4kvzrx5k52ill6.ls error="server returned 404: 404 page not found\n"11312026/08/29 16:25:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11322026/08/29 16:25:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1133--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.99s)1134=== CONT TestReadProxy40411352026/08/29 16:25:35 INFO Signed narinfos id=1 count=111362026/08/29 16:25:35 INFO Signed narinfos id=1 count=111372026/08/29 16:25:35 INFO Uploading 1 narinfos11382026/08/29 16:25:35 INFO Uploading 1 narinfos11392026/08/29 16:25:35 WARN Failed to register uploaded object key=laf8giq46wmfg38gjk4kvzrx5k52ill6.narinfo error="server returned 404: 404 page not found\n"11402026/08/29 16:25:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11412026/08/29 16:25:35 WARN Failed to register uploaded object key=32pny32y0k2a6jn6wc4x69rkzg32yj85.narinfo error="server returned 404: 404 page not found\n"11422026/08/29 16:25:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11432026/08/29 16:25:35 INFO Completed upload id=111442026/08/29 16:25:35 INFO Upload complete. (589ms)1145=== NAME TestClientCADerivations1146 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations467905541/001/store/32pny32y0k2a6jn6wc4x69rkzg32yj85-ca-test1147 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1148 Compression: zstd1149 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1150 NarSize: 1441151 References: 1152 Deriver: /build/TestClientCADerivations467905541/001/store/wngvfqp9538wfn6l6d6zprvcp52k9vlx-ca-test.drv1153 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1154 client_ca_test.go:185: Checking for realisation files in S3...11552026/08/29 16:25:35 INFO Completed upload id=111562026/08/29 16:25:35 INFO Upload complete. (670ms)1157 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1158 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache11592026/08/29 16:25:35 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1160--- PASS: TestReadProxyRangeRequest (2.01s)1161=== CONT TestObjectStatsTrigger11622026/08/29 16:25:35 WARN Failed to register uploaded object key=jnzvapmd3zv3rmmml4cpn13qc6jplny9.ls error="server returned 404: 404 page not found\n"11632026/08/29 16:25:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11642026/08/29 16:25:35 INFO Signed narinfos id=1 count=111652026/08/29 16:25:35 INFO Uploading 1 narinfos11662026/08/29 16:25:35 WARN Failed to register uploaded object key=jnzvapmd3zv3rmmml4cpn13qc6jplny9.narinfo error="server returned 404: 404 page not found\n"11672026/08/29 16:25:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11682026/08/29 16:25:35 INFO Received uploads request method=POST path=/api/pending_closures11692026/08/29 16:25:35 INFO Completed upload id=111702026/08/29 16:25:35 INFO Upload complete. (657ms)1171=== NAME TestClientIntegration1172 client_integration_test.go:293: Retrieved narinfo from S3:1173 StorePath: /build/TestClientIntegration4005948511/002/store/jnzvapmd3zv3rmmml4cpn13qc6jplny9-test-file.txt1174 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1175 Compression: zstd1176 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11177 NarSize: 1521178 References: 1179 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11180 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1181 client_integration_test.go:294: Decompressed .ls content (64 bytes):1182 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1183 client_integration_test.go:297: Testing garbage collection...1184--- PASS: TestCacheStatsHandler (2.04s)1185=== CONT TestReadProxyNarinfoAlreadyDecompressed11862026/08/29 16:25:35 INFO Received uploads request method=POST path=/api/pending_closures11872026-08-29 16:25:35.920 UTC [898] ERROR: relation "goose_db_version" does not exist at character 3611882026-08-29 16:25:35.920 UTC [898] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11892026-08-29 16:25:35.929 UTC [904] ERROR: relation "goose_db_version" does not exist at character 3611902026-08-29 16:25:35.929 UTC [904] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11912026/08/29 16:25:35 INFO Starting cleanup of old closures method=DELETE path=/api/closures11922026/08/29 16:25:35 INFO Garbage collection started11932026/08/29 16:25:35 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1194=== RUN TestService_RequireScope_OIDC/builder_may_write1195=== PAUSE TestService_RequireScope_OIDC/builder_may_write1196=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1197=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1198=== RUN TestService_RequireScope_OIDC/ops_may_admin1199=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1200=== RUN TestService_RequireScope_OIDC/ops_may_not_write1201=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1202=== RUN TestService_RequireScope_OIDC/reader_may_not_write1203=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1204=== RUN TestService_RequireScope_OIDC/static_token_may_admin1205=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1206=== RUN TestService_RequireScope_OIDC/static_token_may_write12072026/08/29 16:25:35 INFO Aborted multipart uploads count=01208=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1209=== RUN TestService_RequireScope_OIDC/reader_may_read1210=== PAUSE TestService_RequireScope_OIDC/reader_may_read1211=== RUN TestService_RequireScope_OIDC/writer_implies_read1212=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1213=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1214=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1215=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle12162026/08/29 16:25:35 WARN Force mode enabled - objects will be deleted immediately without grace period12172026/08/29 16:25:35 OK 20241026095416_initial_model.sql (21.6ms)12182026/08/29 16:25:35 OK 20251210153512_drop_unused_gin_index.sql (2.56ms)12192026/08/29 16:25:35 OK 20251218171726_add_pins.sql (4.86ms)12202026-08-29 16:25:35.961 UTC [998] ERROR: relation "goose_db_version" does not exist at character 3612212026-08-29 16:25:35.961 UTC [998] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12222026/08/29 16:25:35 OK 20260628120000_add_object_size_and_stats.sql (5.38ms)12232026/08/29 16:25:35 goose: successfully migrated database to version: 2026062812000012242026/08/29 16:25:35 OK 1_commit_pending_closure.sql (4.04ms)12252026/08/29 16:25:35 OK 20241026095416_initial_model.sql (18.39ms)12262026/08/29 16:25:35 INFO Received uploads request method=POST path=/api/pending_closures12272026/08/29 16:25:35 OK 2_object_stats_trigger.sql (2.42ms)12282026/08/29 16:25:35 goose: up to current file version: 212292026/08/29 16:25:35 OK 20251210153512_drop_unused_gin_index.sql (3.9ms)12302026/08/29 16:25:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12312026/08/29 16:25:35 INFO Uploading gn5m908m54z3rzdl645h1b2g4qab0rhq-unpinned-file.txt (128B)12322026/08/29 16:25:35 OK 20251218171726_add_pins.sql (4.79ms)12332026/08/29 16:25:35 OK 20241026095416_initial_model.sql (10.64ms)12342026-08-29 16:25:35.980 UTC [1016] ERROR: relation "goose_db_version" does not exist at character 3612352026-08-29 16:25:35.980 UTC [1016] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12362026/08/29 16:25:35 OK 20251210153512_drop_unused_gin_index.sql (3.16ms)12372026/08/29 16:25:35 OK 20260628120000_add_object_size_and_stats.sql (5.51ms)12382026/08/29 16:25:35 goose: successfully migrated database to version: 2026062812000012392026/08/29 16:25:35 OK 1_commit_pending_closure.sql (3.35ms)12402026/08/29 16:25:35 OK 20251218171726_add_pins.sql (5.48ms)12412026/08/29 16:25:35 OK 2_object_stats_trigger.sql (2ms)12422026/08/29 16:25:35 goose: up to current file version: 212432026/08/29 16:25:35 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)12442026/08/29 16:25:35 goose: successfully migrated database to version: 2026062812000012452026/08/29 16:25:35 OK 1_commit_pending_closure.sql (2.8ms)12462026/08/29 16:25:35 OK 2_object_stats_trigger.sql (863.99µs)12472026/08/29 16:25:35 goose: up to current file version: 212482026/08/29 16:25:36 OK 20241026095416_initial_model.sql (10.93ms)12492026/08/29 16:25:36 OK 20251210153512_drop_unused_gin_index.sql (1.29ms)12502026-08-29 16:25:36.004 UTC [1017] ERROR: relation "goose_db_version" does not exist at character 3612512026-08-29 16:25:36.004 UTC [1017] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12522026/08/29 16:25:36 OK 20251218171726_add_pins.sql (3.59ms)12532026/08/29 16:25:36 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)12542026/08/29 16:25:36 goose: successfully migrated database to version: 2026062812000012552026/08/29 16:25:36 OK 1_commit_pending_closure.sql (1.84ms)12562026/08/29 16:25:36 OK 2_object_stats_trigger.sql (883.95µs)12572026/08/29 16:25:36 goose: up to current file version: 212582026/08/29 16:25:36 OK 20241026095416_initial_model.sql (9.67ms)12592026/08/29 16:25:36 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)12602026/08/29 16:25:36 OK 20251218171726_add_pins.sql (3.47ms)1261=== NAME TestClientCADerivations1262 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1263 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1264 error: binary cache 's3://bucket9?endpoint=http://localhost:46139®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations467905541/001/store'1265 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 112662026/08/29 16:25:36 OK 20260628120000_add_object_size_and_stats.sql (2.8ms)12672026/08/29 16:25:36 goose: successfully migrated database to version: 2026062812000012682026/08/29 16:25:36 OK 1_commit_pending_closure.sql (1.75ms)12692026/08/29 16:25:36 OK 2_object_stats_trigger.sql (771.55µs)12702026/08/29 16:25:36 goose: up to current file version: 21271--- PASS: TestClientCADerivations (2.19s)1272=== CONT TestResolveDBConnectionString1273=== RUN TestResolveDBConnectionString/flag_wins1274=== PAUSE TestResolveDBConnectionString/flag_wins1275=== RUN TestResolveDBConnectionString/file_when_flag_empty1276=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1277=== RUN TestResolveDBConnectionString/missing_file_is_an_error1278=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1279=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1280=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1281=== RUN TestResolveDBConnectionString/nothing_configured1282=== PAUSE TestResolveDBConnectionString/nothing_configured1283=== CONT TestMetricsInventory12842026-08-29 16:25:36.107 UTC [1057] ERROR: relation "goose_db_version" does not exist at character 3612852026-08-29 16:25:36.107 UTC [1057] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12862026/08/29 16:25:36 OK 20241026095416_initial_model.sql (9.74ms)12872026/08/29 16:25:36 OK 20251210153512_drop_unused_gin_index.sql (1.31ms)12882026/08/29 16:25:36 OK 20251218171726_add_pins.sql (2.83ms)12892026/08/29 16:25:36 OK 20260628120000_add_object_size_and_stats.sql (2.71ms)12902026/08/29 16:25:36 goose: successfully migrated database to version: 2026062812000012912026/08/29 16:25:36 OK 1_commit_pending_closure.sql (1.96ms)12922026/08/29 16:25:36 OK 2_object_stats_trigger.sql (833.79µs)12932026/08/29 16:25:36 goose: up to current file version: 212942026/08/29 16:25:36 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12952026/08/29 16:25:36 WARN Failed to register uploaded object key=gn5m908m54z3rzdl645h1b2g4qab0rhq.ls error="server returned 404: 404 page not found\n"12962026/08/29 16:25:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12972026/08/29 16:25:36 INFO Signed narinfos id=2 count=112982026/08/29 16:25:36 INFO Uploading 1 narinfos12992026/08/29 16:25:36 WARN Failed to register uploaded object key=gn5m908m54z3rzdl645h1b2g4qab0rhq.narinfo error="server returned 404: 404 page not found\n"13002026/08/29 16:25:36 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13012026/08/29 16:25:36 INFO Completed upload id=213022026/08/29 16:25:36 INFO Upload complete. (560ms)13032026/08/29 16:25:36 INFO Received create pin request method=POST path=/api/pins/myapp13042026/08/29 16:25:36 INFO Aborted multipart uploads count=013052026/08/29 16:25:36 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1939306943/001/store/laf8giq46wmfg38gjk4kvzrx5k52ill6-pinned-file.txt narinfo_key=laf8giq46wmfg38gjk4kvzrx5k52ill6.narinfo13062026/08/29 16:25:36 WARN Force mode enabled - objects will be deleted immediately without grace period13072026/08/29 16:25:36 INFO Starting cleanup of old closures method=DELETE path=/api/closures13082026/08/29 16:25:36 INFO Garbage collection started13092026/08/29 16:25:36 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=013102026/08/29 16:25:36 INFO Vacuumed table table=pending_closures13112026/08/29 16:25:36 INFO Vacuumed table table=pending_objects13122026/08/29 16:25:36 INFO Vacuumed table table=multipart_uploads13132026/08/29 16:25:36 INFO Vacuumed table table=closures13142026/08/29 16:25:36 INFO Vacuumed table table=objects13152026/08/29 16:25:36 INFO Aborted multipart uploads count=013162026/08/29 16:25:36 WARN Force mode enabled - objects will be deleted immediately without grace period1317--- PASS: TestGCMetrics (2.52s)1318=== CONT TestGCTaskStore_DeduplicateSameParams1319--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1320=== CONT TestServerTLSConfig1321=== RUN TestServerTLSConfig/no_client_CA1322=== PAUSE TestServerTLSConfig/no_client_CA1323=== RUN TestServerTLSConfig/missing_CA_file1324=== PAUSE TestServerTLSConfig/missing_CA_file1325=== RUN TestServerTLSConfig/not_a_PEM_file1326=== PAUSE TestServerTLSConfig/not_a_PEM_file1327=== CONT TestReadProxyNarinfo1328--- PASS: TestReadProxyHead (2.37s)1329=== CONT TestService_NativeMTLS1330--- PASS: TestReadRedirectNar (2.34s)1331=== CONT TestService_createPendingClosureHandler1332=== NAME TestClientMultipleUploads1333 client_integration_test.go:339: Created store path 0: /build/TestClientMultipleUploads1045688290/001/store/jwd38d2yk8vss6r3y9i0c0rx55l5q9v9-test-file-0.txt1334 client_integration_test.go:339: Created store path 1: /build/TestClientMultipleUploads1045688290/001/store/w6c21i1fqyag43397i5aqs9kj43nbirg-test-file-1.txt1335=== NAME TestClientWithDependencies1336 client_integration_test.go:594: Built derivation: /build/TestClientWithDependencies1660923894/001/store/wv3g77xvs3xrhg15483aqqgi862lyv21-test-script13372026-08-29 16:25:36.627 UTC [1159] ERROR: relation "goose_db_version" does not exist at character 3613382026-08-29 16:25:36.627 UTC [1159] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1339=== NAME TestClientMultipleUploads1340 client_integration_test.go:339: Created store path 2: /build/TestClientMultipleUploads1045688290/001/store/2p483qixpr2xcknsskzzw417zz8jpb7d-test-file-2.txt13412026-08-29 16:25:36.647 UTC [1177] ERROR: relation "goose_db_version" does not exist at character 3613422026-08-29 16:25:36.647 UTC [1177] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13432026/08/29 16:25:36 OK 20241026095416_initial_model.sql (11.56ms)13442026/08/29 16:25:36 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)13452026-08-29 16:25:36.650 UTC [1178] ERROR: relation "goose_db_version" does not exist at character 3613462026-08-29 16:25:36.650 UTC [1178] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13472026/08/29 16:25:36 OK 20251218171726_add_pins.sql (4.4ms)13482026/08/29 16:25:36 OK 20260628120000_add_object_size_and_stats.sql (3.32ms)13492026/08/29 16:25:36 goose: successfully migrated database to version: 202606281200001350=== NAME TestClientWithDependencies1351 client_integration_test.go:596: Found 1 dependencies (including self)13522026/08/29 16:25:36 OK 1_commit_pending_closure.sql (2.94ms)13532026/08/29 16:25:36 OK 2_object_stats_trigger.sql (2.25ms)13542026/08/29 16:25:36 goose: up to current file version: 213552026/08/29 16:25:36 OK 20241026095416_initial_model.sql (9.79ms)13562026/08/29 16:25:36 OK 20241026095416_initial_model.sql (11.51ms)13572026/08/29 16:25:36 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)13582026/08/29 16:25:36 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)13592026/08/29 16:25:36 OK 20251218171726_add_pins.sql (4.28ms)13602026/08/29 16:25:36 OK 20251218171726_add_pins.sql (3.76ms)13612026/08/29 16:25:36 OK 20260628120000_add_object_size_and_stats.sql (3.67ms)13622026/08/29 16:25:36 goose: successfully migrated database to version: 2026062812000013632026/08/29 16:25:36 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)13642026/08/29 16:25:36 goose: successfully migrated database to version: 2026062812000013652026/08/29 16:25:36 OK 1_commit_pending_closure.sql (1.82ms)13662026/08/29 16:25:36 OK 1_commit_pending_closure.sql (1.84ms)13672026/08/29 16:25:36 OK 2_object_stats_trigger.sql (904.25µs)13682026/08/29 16:25:36 goose: up to current file version: 213692026/08/29 16:25:36 OK 2_object_stats_trigger.sql (927.35µs)13702026/08/29 16:25:36 goose: up to current file version: 21371--- PASS: TestGCBugBareHashReferences (2.73s)1372=== CONT TestSkippedUploadsHandler13732026/08/29 16:25:36 INFO Client skipped oversized paths paths=3 nar_bytes=500000000013742026/08/29 16:25:36 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13752026/08/29 16:25:36 INFO Received uploads request method=POST path=/api/pending_closures1376--- PASS: TestSkippedUploadsHandler (0.01s)1377=== CONT TestService_verifyS3Integrity13782026/08/29 16:25:36 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13792026/08/29 16:25:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13802026/08/29 16:25:36 INFO Uploading wv3g77xvs3xrhg15483aqqgi862lyv21-test-script (136B)13812026/08/29 16:25:36 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13822026/08/29 16:25:36 WARN Failed to register uploaded object key=log/x2mbks41wiqx0ikrmfxbjwv8rr80sr0r-test-script.drv error="server returned 404: 404 page not found\n"13832026/08/29 16:25:36 WARN Failed to register uploaded object key=wv3g77xvs3xrhg15483aqqgi862lyv21.ls error="server returned 404: 404 page not found\n"13842026/08/29 16:25:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13852026/08/29 16:25:36 INFO Signed narinfos id=1 count=113862026/08/29 16:25:36 INFO Uploading 1 narinfos13872026/08/29 16:25:36 WARN Failed to register uploaded object key=wv3g77xvs3xrhg15483aqqgi862lyv21.narinfo error="server returned 404: 404 page not found\n"13882026/08/29 16:25:36 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13892026/08/29 16:25:36 INFO Completed upload id=113902026/08/29 16:25:36 INFO Upload complete. (64ms)1391=== NAME TestClientWithDependencies1392 client_integration_test.go:598: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1660923894/001/store) requires matching store prefix13932026/08/29 16:25:36 INFO Received uploads request method=POST path=/api/pending_closures1394--- PASS: TestClientWithDependencies (2.85s)1395=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13962026/08/29 16:25:36 INFO Received uploads request method=POST path=/api/pending_closures13972026/08/29 16:25:36 INFO Received uploads request method=POST path=/api/pending_closures13982026/08/29 16:25:36 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13992026/08/29 16:25:36 INFO Uploading w6c21i1fqyag43397i5aqs9kj43nbirg-test-file-1.txt (160B)14002026/08/29 16:25:36 INFO Uploading jwd38d2yk8vss6r3y9i0c0rx55l5q9v9-test-file-0.txt (160B)14012026/08/29 16:25:36 INFO Uploading 2p483qixpr2xcknsskzzw417zz8jpb7d-test-file-2.txt (160B)14022026-08-29 16:25:36.788 UTC [1292] ERROR: relation "goose_db_version" does not exist at character 3614032026-08-29 16:25:36.788 UTC [1292] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14042026/08/29 16:25:36 OK 20241026095416_initial_model.sql (21.32ms)14052026/08/29 16:25:36 OK 20251210153512_drop_unused_gin_index.sql (3.66ms)14062026/08/29 16:25:36 OK 20251218171726_add_pins.sql (3.92ms)14072026/08/29 16:25:36 OK 20260628120000_add_object_size_and_stats.sql (3.26ms)14082026/08/29 16:25:36 goose: successfully migrated database to version: 2026062812000014092026/08/29 16:25:36 OK 1_commit_pending_closure.sql (1.87ms)14102026/08/29 16:25:36 OK 2_object_stats_trigger.sql (848.23µs)14112026/08/29 16:25:36 goose: up to current file version: 214122026-08-29 16:25:36.835 UTC [1293] ERROR: relation "goose_db_version" does not exist at character 3614132026-08-29 16:25:36.835 UTC [1293] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14142026/08/29 16:25:36 OK 20241026095416_initial_model.sql (9.66ms)14152026/08/29 16:25:36 OK 20251210153512_drop_unused_gin_index.sql (1.27ms)14162026/08/29 16:25:36 OK 20251218171726_add_pins.sql (3.45ms)14172026/08/29 16:25:36 OK 20260628120000_add_object_size_and_stats.sql (3.47ms)14182026/08/29 16:25:36 goose: successfully migrated database to version: 2026062812000014192026/08/29 16:25:36 OK 1_commit_pending_closure.sql (2.36ms)14202026/08/29 16:25:36 OK 2_object_stats_trigger.sql (925.55µs)14212026/08/29 16:25:36 goose: up to current file version: 214222026/08/29 16:25:37 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14232026/08/29 16:25:37 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14242026/08/29 16:25:37 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14252026/08/29 16:25:37 WARN Failed to register uploaded object key=jwd38d2yk8vss6r3y9i0c0rx55l5q9v9.ls error="server returned 404: 404 page not found\n"14262026/08/29 16:25:37 WARN Failed to register uploaded object key=w6c21i1fqyag43397i5aqs9kj43nbirg.ls error="server returned 404: 404 page not found\n"14272026/08/29 16:25:37 WARN Failed to register uploaded object key=2p483qixpr2xcknsskzzw417zz8jpb7d.ls error="server returned 404: 404 page not found\n"14282026/08/29 16:25:37 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14292026/08/29 16:25:37 INFO Signed narinfos id=2 count=114302026/08/29 16:25:37 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign14312026/08/29 16:25:37 INFO Signed narinfos id=3 count=114322026/08/29 16:25:37 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14332026/08/29 16:25:37 INFO Signed narinfos id=1 count=114342026/08/29 16:25:37 INFO Uploading 3 narinfos14352026/08/29 16:25:37 WARN Failed to register uploaded object key=2p483qixpr2xcknsskzzw417zz8jpb7d.narinfo error="server returned 404: 404 page not found\n"14362026/08/29 16:25:37 WARN Failed to register uploaded object key=w6c21i1fqyag43397i5aqs9kj43nbirg.narinfo error="server returned 404: 404 page not found\n"14372026/08/29 16:25:37 WARN Failed to register uploaded object key=jwd38d2yk8vss6r3y9i0c0rx55l5q9v9.narinfo error="server returned 404: 404 page not found\n"14382026/08/29 16:25:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14392026/08/29 16:25:37 INFO Completed upload id=114402026/08/29 16:25:37 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14412026/08/29 16:25:37 INFO Completed upload id=214422026/08/29 16:25:37 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete14432026/08/29 16:25:37 INFO Completed upload id=314442026/08/29 16:25:37 INFO Upload complete. (564ms)1445=== NAME TestClientMultipleUploads1446 client_integration_test.go:350: Uploaded 3 paths in 601.248462ms1447--- PASS: TestClientMultipleUploads (3.35s)1448=== CONT TestNARDeduplicationMetadataUploadBug14492026-08-29 16:25:37.332 UTC [1316] ERROR: relation "goose_db_version" does not exist at character 3614502026-08-29 16:25:37.332 UTC [1316] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14512026/08/29 16:25:37 OK 20241026095416_initial_model.sql (9.01ms)14522026/08/29 16:25:37 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)14532026/08/29 16:25:37 OK 20251218171726_add_pins.sql (3.12ms)14542026/08/29 16:25:37 OK 20260628120000_add_object_size_and_stats.sql (3.65ms)14552026/08/29 16:25:37 goose: successfully migrated database to version: 2026062812000014562026/08/29 16:25:37 OK 1_commit_pending_closure.sql (1.89ms)14572026/08/29 16:25:37 OK 2_object_stats_trigger.sql (787.07µs)14582026/08/29 16:25:37 goose: up to current file version: 21459--- PASS: TestReadProxyDisabled (3.50s)1460=== CONT TestService_ReadAuthMiddleware14612026-08-29 16:25:37.796 UTC [1319] ERROR: relation "goose_db_version" does not exist at character 3614622026-08-29 16:25:37.796 UTC [1319] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14632026/08/29 16:25:37 OK 20241026095416_initial_model.sql (10.06ms)14642026/08/29 16:25:37 OK 20251210153512_drop_unused_gin_index.sql (1.39ms)14652026/08/29 16:25:37 OK 20251218171726_add_pins.sql (4.13ms)14662026/08/29 16:25:37 OK 20260628120000_add_object_size_and_stats.sql (2.95ms)14672026/08/29 16:25:37 goose: successfully migrated database to version: 2026062812000014682026/08/29 16:25:37 OK 1_commit_pending_closure.sql (1.76ms)14692026/08/29 16:25:37 OK 2_object_stats_trigger.sql (892.33µs)14702026/08/29 16:25:37 goose: up to current file version: 214712026/08/29 16:25:37 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=1000 objects_failed=01472--- PASS: TestReadProxyRootRedirectsToIndexHTML (3.27s)1473=== CONT TestCreatePendingClosureRejectsOversizedNAR14742026/08/29 16:25:38 INFO Received uploads request method=POST path=/api/pending_closures1475--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1476=== CONT TestService_AuthMiddleware_MTLSProxyHeader14772026/08/29 16:25:38 INFO Received uploads request method=POST path=/api/pending_closures1478--- PASS: TestReadProxyConditionalGet (3.26s)1479=== CONT TestService_cleanupPendingClosuresHandler14802026-08-29 16:25:38.373 UTC [1324] ERROR: relation "goose_db_version" does not exist at character 3614812026-08-29 16:25:38.373 UTC [1324] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1482--- PASS: TestReadProxyInvalidPath (3.17s)1483=== CONT TestIsValidCachePath1484=== RUN TestIsValidCachePath/narinfo1485=== PAUSE TestIsValidCachePath/narinfo1486=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1487=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1488=== RUN TestIsValidCachePath/nar_zst1489=== PAUSE TestIsValidCachePath/nar_zst1490=== RUN TestIsValidCachePath/nar_xz1491=== PAUSE TestIsValidCachePath/nar_xz1492=== RUN TestIsValidCachePath/nar_bz21493=== PAUSE TestIsValidCachePath/nar_bz21494=== RUN TestIsValidCachePath/nar_uncompressed1495=== PAUSE TestIsValidCachePath/nar_uncompressed1496=== RUN TestIsValidCachePath/ls1497=== PAUSE TestIsValidCachePath/ls1498=== RUN TestIsValidCachePath/log1499=== PAUSE TestIsValidCachePath/log1500=== RUN TestIsValidCachePath/realisation1501=== PAUSE TestIsValidCachePath/realisation1502=== RUN TestIsValidCachePath/nix-cache-info1503=== PAUSE TestIsValidCachePath/nix-cache-info1504=== RUN TestIsValidCachePath/index.html1505=== PAUSE TestIsValidCachePath/index.html1506=== RUN TestIsValidCachePath/traversal_parent1507=== PAUSE TestIsValidCachePath/traversal_parent1508=== RUN TestIsValidCachePath/traversal_in_middle1509=== PAUSE TestIsValidCachePath/traversal_in_middle1510=== RUN TestIsValidCachePath/invalid_char_e1511=== PAUSE TestIsValidCachePath/invalid_char_e1512=== RUN TestIsValidCachePath/invalid_char_u1513=== PAUSE TestIsValidCachePath/invalid_char_u1514=== RUN TestIsValidCachePath/random_path1515=== PAUSE TestIsValidCachePath/random_path1516=== RUN TestIsValidCachePath/empty1517=== PAUSE TestIsValidCachePath/empty1518=== RUN TestIsValidCachePath/leading_slash1519=== PAUSE TestIsValidCachePath/leading_slash1520=== RUN TestIsValidCachePath/wrong_extension1521=== PAUSE TestIsValidCachePath/wrong_extension1522=== RUN TestIsValidCachePath/short_hash1523=== PAUSE TestIsValidCachePath/short_hash1524=== CONT TestClientErrorHandling/InvalidStorePath15252026/08/29 16:25:38 OK 20241026095416_initial_model.sql (12.6ms)1526--- PASS: TestReadProxyNarStreaming (3.25s)1527=== CONT TestClientErrorHandling/ServerNotAvailable15282026/08/29 16:25:38 OK 20251210153512_drop_unused_gin_index.sql (3.68ms)15292026/08/29 16:25:38 OK 20251218171726_add_pins.sql (6.17ms)1530--- PASS: TestResurrectedObjectNotDeleted (3.32s)1531=== CONT TestClientErrorHandling/InvalidAuthToken15322026/08/29 16:25:38 OK 20260628120000_add_object_size_and_stats.sql (14.79ms)15332026/08/29 16:25:38 goose: successfully migrated database to version: 2026062812000015342026/08/29 16:25:38 INFO Received cleanup request method=DELETE path=/api/pending_closures15352026-08-29 16:25:38.423 UTC [1328] ERROR: relation "goose_db_version" does not exist at character 3615362026-08-29 16:25:38.423 UTC [1328] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15372026/08/29 16:25:38 OK 1_commit_pending_closure.sql (6.23ms)15382026/08/29 16:25:38 INFO Aborted multipart uploads count=115392026/08/29 16:25:38 OK 2_object_stats_trigger.sql (2.87ms)15402026/08/29 16:25:38 goose: up to current file version: 21541--- PASS: TestMultipartCleanup (3.38s)1542=== CONT TestCacheConfigHandler/full_config,_no_issuer1543=== CONT TestCacheConfigHandler/no_signing_keys1544=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1545=== CONT TestCacheConfigHandler/no_cache_url_configured1546=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15472026/08/29 16:25:38 INFO Received request for more parts method=POST path=/1548--- PASS: TestCacheConfigHandler (0.08s)1549 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1550 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1551 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1552 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)15532026/08/29 16:25:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1554--- PASS: TestReadProxy404 (2.60s)1555=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15562026/08/29 16:25:38 INFO Received complete multipart upload request method=POST path=/15572026/08/29 16:25:38 OK 20241026095416_initial_model.sql (17.6ms)15582026/08/29 16:25:38 OK 20251210153512_drop_unused_gin_index.sql (3.58ms)15592026/08/29 16:25:38 OK 20251218171726_add_pins.sql (5.97ms)15602026/08/29 16:25:38 OK 20260628120000_add_object_size_and_stats.sql (4.98ms)15612026/08/29 16:25:38 goose: successfully migrated database to version: 2026062812000015622026-08-29 16:25:38.464 UTC [1349] ERROR: relation "goose_db_version" does not exist at character 3615632026-08-29 16:25:38.464 UTC [1349] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15642026/08/29 16:25:38 OK 1_commit_pending_closure.sql (6.7ms)15652026/08/29 16:25:38 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OTY1YzFkMmEtMGU4MS00Y2RmLTkzMmMtYWQ3NTljMjg3MTRjLmU2NDkyMWE1LTU4YmEtNDVjNS1hZTcwLTdlYzYwMWNlN2RkYXgxNzg4MDIwNzM1OTAxMTQxNzkw parts=1215662026/08/29 16:25:38 OK 2_object_stats_trigger.sql (3.35ms)15672026/08/29 16:25:38 goose: up to current file version: 21568--- PASS: TestRedundantMultipartUpload (4.56s)1569=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15702026/08/29 16:25:38 INFO Received uploads request method=POST path=/15712026/08/29 16:25:38 OK 20241026095416_initial_model.sql (13.86ms)15722026/08/29 16:25:38 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)15732026/08/29 16:25:38 OK 20251218171726_add_pins.sql (3.3ms)15742026/08/29 16:25:38 OK 20260628120000_add_object_size_and_stats.sql (2.71ms)15752026/08/29 16:25:38 goose: successfully migrated database to version: 202606281200001576--- PASS: TestObjectStatsTrigger (2.62s)1577=== CONT TestProxyWriteTimeout/narinfo1578=== CONT TestProxyWriteTimeout/10_GiB_nar1579=== CONT TestProxyWriteTimeout/unknown_size1580=== CONT TestProxyWriteTimeout/1_GiB_nar1581=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1582--- PASS: TestProxyWriteTimeout (0.00s)1583 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1584 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1585 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1586 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)15872026/08/29 16:25:38 INFO Received uploads request method=POST path=/1588=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15892026/08/29 16:25:38 INFO Received complete multipart upload request method=POST path=/1590=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15912026/08/29 16:25:38 INFO Received request for more parts method=POST path=/1592=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1593--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.60s)15942026/08/29 16:25:38 INFO Received uploads request method=POST path=/1595=== CONT TestIsValidUploadKey/narinfo1596=== CONT TestIsValidUploadKey/empty_key1597=== CONT TestIsValidUploadKey/absolute1598=== CONT TestIsValidUploadKey/unknown_type1599=== CONT TestIsValidUploadKey/traversal1600=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1601=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1602=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1603=== CONT TestIsValidUploadKey/index.html1604--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1605 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1606 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1607 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1608 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1609=== CONT TestIsValidUploadKey/traversal_nar1610=== CONT TestIsValidUploadKey/nix-cache-info16112026/08/29 16:25:38 OK 1_commit_pending_closure.sql (1.66ms)1612=== CONT TestIsValidUploadKey/realisation1613=== CONT TestIsValidUploadKey/build_log_equals1614=== CONT TestIsValidUploadKey/realisation_plus_in_output1615=== CONT TestIsValidUploadKey/build_log_plus_in_name1616=== CONT TestIsValidUploadKey/build_log_home-manager_file1617=== CONT TestIsValidUploadKey/build_log1618=== CONT TestIsValidUploadKey/build_log_question_mark1619=== CONT TestIsValidUploadKey/listing1620=== CONT TestIsValidUploadKey/nar_xz1621=== CONT TestIsValidUploadKey/nar_zst1622=== CONT TestIsValidUploadKey/nar_plain1623--- PASS: TestIsValidUploadKey (0.00s)1624 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1625 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1626 --- PASS: TestIsValidUploadKey/absolute (0.00s)1627 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1628 --- PASS: TestIsValidUploadKey/traversal (0.00s)1629 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1630 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1631 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1632 --- PASS: TestIsValidUploadKey/index.html (0.00s)1633 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1634 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1635 --- PASS: TestIsValidUploadKey/realisation (0.00s)1636 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1637 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1638 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1639 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1640 --- PASS: TestIsValidUploadKey/build_log (0.00s)1641 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1642 --- PASS: TestIsValidUploadKey/listing (0.00s)1643 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1644 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1645 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1646=== CONT TestParseSingleRange/open-ended1647=== CONT TestParseSingleRange/none1648=== CONT TestParseSingleRange/start_far_past_EOF1649=== CONT TestParseSingleRange/single_byte1650=== CONT TestParseSingleRange/start_past_EOF1651=== CONT TestParseSingleRange/suffix1652=== CONT TestParseSingleRange/suffix_exceeds_size1653=== CONT TestParseSingleRange/malformed_both_empty1654=== CONT TestParseSingleRange/end_clamped_to_size16552026/08/29 16:25:38 OK 2_object_stats_trigger.sql (931.83µs)1656=== CONT TestParseSingleRange/closed16572026/08/29 16:25:38 goose: up to current file version: 21658=== CONT TestParseSingleRange/multi-range_ignored1659=== CONT TestParseSingleRange/malformed_no_dash1660=== CONT TestParseSingleRange/malformed_end_before_start1661=== CONT TestParseSingleRange/unknown_unit1662=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1663--- PASS: TestParseSingleRange (0.00s)1664 --- PASS: TestParseSingleRange/open-ended (0.00s)1665 --- PASS: TestParseSingleRange/none (0.00s)1666 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1667 --- PASS: TestParseSingleRange/single_byte (0.00s)1668 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1669 --- PASS: TestParseSingleRange/suffix (0.00s)1670 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1671 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1672 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1673 --- PASS: TestParseSingleRange/closed (0.00s)1674 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1675 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1676 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1677 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1678=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1679=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected16802026/08/29 16:25:38 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]1681=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16822026-08-29 16:25:38.499 UTC [1368] ERROR: relation "goose_db_version" does not exist at character 3616832026-08-29 16:25:38.499 UTC [1368] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16842026/08/29 16:25:38 INFO Received uploads request method=POST path=/api/pending_closures16852026/08/29 16:25:38 INFO OIDC auth successful provider=test scopes=[write]16862026/08/29 16:25:38 WARN Authentication failed token_preview=eyJhbGciOi...IluXFtG1rQ token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1687=== CONT TestService_RequireScope_OIDC/builder_may_write1688=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1689=== CONT TestService_RequireScope_OIDC/writer_implies_read1690--- PASS: TestService_AuthMiddleware_OIDC (1.99s)1691 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1692 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1693 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)1694 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)16952026/08/29 16:25:38 INFO OIDC auth successful provider=test scopes=[write]16962026/08/29 16:25:38 INFO OIDC auth successful provider=test scopes=[write]1697=== CONT TestService_RequireScope_OIDC/static_token_may_write1698=== CONT TestService_RequireScope_OIDC/reader_may_read16992026/08/29 16:25:38 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=1000 objects_failed=01700=== CONT TestService_RequireScope_OIDC/static_token_may_admin1701=== CONT TestService_RequireScope_OIDC/reader_may_not_write17022026/08/29 16:25:38 INFO OIDC auth successful provider=test scopes=[read]1703=== CONT TestService_RequireScope_OIDC/ops_may_not_write17042026/08/29 16:25:38 INFO OIDC auth successful provider=test scopes=[read]1705=== CONT TestService_RequireScope_OIDC/ops_may_admin17062026/08/29 16:25:38 INFO OIDC auth successful provider=test scopes=[admin]1707=== CONT TestService_RequireScope_OIDC/builder_may_not_admin17082026/08/29 16:25:38 INFO OIDC auth successful provider=test scopes=[admin]1709=== CONT TestResolveDBConnectionString/flag_wins1710=== CONT TestResolveDBConnectionString/missing_file_is_an_error1711=== CONT TestResolveDBConnectionString/file_when_flag_empty1712=== CONT TestResolveDBConnectionString/PGHOST_allows_empty17132026/08/29 16:25:38 INFO OIDC auth successful provider=test scopes=[write]1714=== CONT TestResolveDBConnectionString/nothing_configured1715=== CONT TestServerTLSConfig/missing_CA_file1716=== CONT TestServerTLSConfig/no_client_CA1717=== CONT TestServerTLSConfig/not_a_PEM_file1718=== CONT TestIsValidCachePath/narinfo1719=== CONT TestIsValidCachePath/leading_slash1720=== CONT TestIsValidCachePath/empty1721=== CONT TestIsValidCachePath/random_path1722=== CONT TestIsValidCachePath/invalid_char_u1723=== CONT TestIsValidCachePath/invalid_char_e1724=== CONT TestIsValidCachePath/wrong_extension1725=== CONT TestIsValidCachePath/traversal_in_middle1726--- PASS: TestResolveDBConnectionString (0.00s)1727 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1728 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1729 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1730 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1731 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1732=== CONT TestIsValidCachePath/traversal_parent1733=== CONT TestIsValidCachePath/index.html1734=== CONT TestIsValidCachePath/nix-cache-info1735=== CONT TestIsValidCachePath/realisation1736=== CONT TestIsValidCachePath/log1737=== CONT TestIsValidCachePath/ls1738=== CONT TestIsValidCachePath/nar_uncompressed1739=== CONT TestIsValidCachePath/nar_bz21740=== CONT TestIsValidCachePath/nar_xz1741=== CONT TestIsValidCachePath/nar_zst1742--- PASS: TestService_RequireScope_OIDC (2.03s)1743 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1744 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1745 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1746 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1747 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1748 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1749 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1750 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1751 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1752 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1753=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1754=== CONT TestIsValidCachePath/short_hash1755--- PASS: TestServerTLSConfig (0.00s)1756 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1757 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1758 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1759--- PASS: TestIsValidCachePath (0.00s)1760 --- PASS: TestIsValidCachePath/narinfo (0.00s)1761 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1762 --- PASS: TestIsValidCachePath/empty (0.00s)1763 --- PASS: TestIsValidCachePath/random_path (0.00s)1764 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1765 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1766 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1767 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1768 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1769 --- PASS: TestIsValidCachePath/index.html (0.00s)1770 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1771 --- PASS: TestIsValidCachePath/realisation (0.00s)1772 --- PASS: TestIsValidCachePath/log (0.00s)1773 --- PASS: TestIsValidCachePath/ls (0.00s)1774 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1775 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1776 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1777 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1778 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1779 --- PASS: TestIsValidCachePath/short_hash (0.00s)17802026/08/29 16:25:38 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-config17812026/08/29 16:25:38 OK 20241026095416_initial_model.sql (9.28ms)17822026/08/29 16:25:38 OK 20251210153512_drop_unused_gin_index.sql (1.34ms)17832026/08/29 16:25:38 OK 20251218171726_add_pins.sql (3.71ms)17842026/08/29 16:25:38 OK 20260628120000_add_object_size_and_stats.sql (6.75ms)17852026/08/29 16:25:38 goose: successfully migrated database to version: 2026062812000017862026/08/29 16:25:38 OK 1_commit_pending_closure.sql (1.93ms)17872026/08/29 16:25:38 OK 2_object_stats_trigger.sql (1.04ms)17882026/08/29 16:25:38 goose: up to current file version: 21789--- PASS: TestMetricsInventory (2.51s)1790--- PASS: TestReadProxyNarinfo (2.02s)17912026/08/29 16:25:38 INFO Received uploads request method=POST path=/api/pending_closures17922026/08/29 16:25:38 INFO Received uploads request method=POST path=/api/pending_closures17932026/08/29 16:25:38 INFO Received uploads request method=POST path=/api/pending_closures17942026/08/29 16:25:38 WARN mTLS auth: subject not in bound subjects subject="CN=reader"17952026/08/29 16:25:38 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1796--- PASS: TestService_NativeMTLS (2.02s)17972026/08/29 16:25:38 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.416683ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17982026/08/29 16:25:38 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=368.49506ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1799=== NAME TestOrphanedObjectsGC1800 orphaned_objects_gc_test.go:290: GC Test Summary:1801 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1802 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1803 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1804 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1805 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1806--- PASS: TestOrphanedObjectsGC (3.05s)18072026/08/29 16:25:38 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=018082026/08/29 16:25:38 INFO Vacuumed table table=pending_closures18092026/08/29 16:25:38 INFO Vacuumed table table=pending_objects18102026/08/29 16:25:38 INFO Vacuumed table table=multipart_uploads18112026/08/29 16:25:38 INFO Vacuumed table table=closures18122026/08/29 16:25:38 INFO Vacuumed table table=objects18132026/08/29 16:25:39 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=824.7672ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18142026/08/29 16:25:39 INFO Received uploads request method=POST path=/api/pending_closures18152026/08/29 16:25:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18162026/08/29 16:25:39 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18172026/08/29 16:25:39 WARN mTLS auth: bound subjects configured but subject DN unavailable18182026/08/29 16:25:39 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1819--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.50s)18202026/08/29 16:25:39 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OTY1YzFkMmEtMGU4MS00Y2RmLTkzMmMtYWQ3NTljMjg3MTRjLmEwMThlYzdjLWI1MjQtNGMyZC1hNWQ1LTFmY2U4YTg5NTNkZHgxNzg4MDIwNzM1MTE2NTM3NTE0 parts=1218212026/08/29 16:25:39 INFO Received uploads request method=POST path=/api/pending_closures1822--- PASS: TestCompletedNarNotReofferedAcrossClosures (5.44s)1823--- PASS: TestService_ReadAuthMiddleware (1.57s)18242026/08/29 16:25:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18252026/08/29 16:25:39 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2091 objects-failed-to-delete=01826--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.01s)18272026/08/29 16:25:39 INFO Vacuumed table table=pending_closures18282026/08/29 16:25:39 INFO Vacuumed table table=pending_objects18292026/08/29 16:25:39 INFO Vacuumed table table=multipart_uploads18302026/08/29 16:25:39 INFO Vacuumed table table=closures18312026/08/29 16:25:39 INFO Vacuumed table table=objects18322026/08/29 16:25:39 INFO Received cleanup request method=DELETE path=/api/pending_closures18332026/08/29 16:25:39 INFO Aborted multipart uploads count=01834=== NAME TestNARDeduplicationMetadataUploadBug1835 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1957267049/001/store/msa310mak84bf1mjgn2y0144hh7g5bbp-file1.txt18362026/08/29 16:25:39 INFO Received uploads request method=POST path=/api/pending_closures18372026/08/29 16:25:39 INFO Received cleanup request method=DELETE path=/api/pending_closures18382026/08/29 16:25:39 INFO Aborted multipart uploads count=118392026/08/29 16:25:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18402026-08-29 16:25:39.334 UTC [1328] ERROR: Closure does not exist: id=118412026-08-29 16:25:39.334 UTC [1328] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE18422026-08-29 16:25:39.334 UTC [1328] STATEMENT: -- name: CommitPendingClosure :exec1843 SELECT commit_pending_closure($1::bigint)1844 1845--- PASS: TestService_cleanupPendingClosuresHandler (1.00s)18462026/08/29 16:25:39 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18472026/08/29 16:25:39 INFO Received uploads request method=POST path=/api/pending_closures18482026/08/29 16:25:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18492026/08/29 16:25:39 INFO Uploading msa310mak84bf1mjgn2y0144hh7g5bbp-file1.txt (160B)18502026/08/29 16:25:39 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18512026/08/29 16:25:39 WARN Failed to register uploaded object key=msa310mak84bf1mjgn2y0144hh7g5bbp.ls error="server returned 404: 404 page not found\n"18522026/08/29 16:25:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18532026/08/29 16:25:39 INFO Signed narinfos id=1 count=118542026/08/29 16:25:39 INFO Uploading 1 narinfos18552026/08/29 16:25:39 WARN Failed to register uploaded object key=msa310mak84bf1mjgn2y0144hh7g5bbp.narinfo error="server returned 404: 404 page not found\n"18562026/08/29 16:25:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18572026/08/29 16:25:39 INFO Completed upload id=118582026/08/29 16:25:39 INFO Upload complete. (94ms)1859=== NAME TestNARDeduplicationMetadataUploadBug1860 metadata_upload_test.go:54: Retrieved narinfo from S3:1861 StorePath: /build/TestNARDeduplicationMetadataUploadBug1957267049/001/store/msa310mak84bf1mjgn2y0144hh7g5bbp-file1.txt1862 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1863 Compression: zstd1864 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1865 NarSize: 1601866 References: 1867 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf18682026/08/29 16:25:39 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1869 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1870 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1871 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}18722026/08/29 16:25:39 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1873 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1957267049/001/store/68mp4bcbxg6yzci7sj9bb85gnm02fi91-file2.txt1874=== NAME TestOrphanedObjectsGCStressTest1875 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains18762026/08/29 16:25:39 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1877 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion18782026/08/29 16:25:39 INFO Received uploads request method=POST path=/api/pending_closures18792026/08/29 16:25:39 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18802026/08/29 16:25:39 WARN Failed to register uploaded object key=68mp4bcbxg6yzci7sj9bb85gnm02fi91.ls error="server returned 404: 404 page not found\n"18812026/08/29 16:25:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18822026/08/29 16:25:39 INFO Signed narinfos id=2 count=118832026/08/29 16:25:39 INFO Uploading 1 narinfos18842026/08/29 16:25:39 WARN Failed to register uploaded object key=68mp4bcbxg6yzci7sj9bb85gnm02fi91.narinfo error="server returned 404: 404 page not found\n"18852026/08/29 16:25:39 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18862026/08/29 16:25:39 INFO Completed upload id=218872026/08/29 16:25:39 INFO Upload complete. (85ms)1888=== NAME TestNARDeduplicationMetadataUploadBug1889 metadata_upload_test.go:76: Retrieved narinfo from S3:1890 StorePath: /build/TestNARDeduplicationMetadataUploadBug1957267049/001/store/68mp4bcbxg6yzci7sj9bb85gnm02fi91-file2.txt1891 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1892 Compression: zstd1893 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1894 NarSize: 1601895 References: 1896 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1897 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1898 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1899 {"version":1,"root":{"type":"regular","size":44}}1900--- PASS: TestNARDeduplicationMetadataUploadBug (2.35s)19012026/08/29 16:25:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19022026/08/29 16:25:39 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OTY1YzFkMmEtMGU4MS00Y2RmLTkzMmMtYWQ3NTljMjg3MTRjLmRlMTM5NTBlLTZjZWUtNGRlYy04MmFkLWU0ZjQxYmUyY2Y5ZXgxNzg4MDIwNzM4NTUxMjg4NDQx parts=1019032026/08/29 16:25:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19042026/08/29 16:25:39 INFO Completed upload id=119052026/08/29 16:25:39 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000019062026/08/29 16:25:39 INFO Received uploads request method=POST path=/api/pending_closures19072026/08/29 16:25:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures19082026/08/29 16:25:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19092026/08/29 16:25:39 INFO Aborted multipart uploads count=019102026/08/29 16:25:39 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OTY1YzFkMmEtMGU4MS00Y2RmLTkzMmMtYWQ3NTljMjg3MTRjLmQwZjU1OTUwLWMxZDgtNGMyOC1hOTQxLWFkNzVjNWY4ZDM3ZXgxNzg4MDIwNzM5MjYxMTkwNzM2 parts=1019112026/08/29 16:25:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19122026/08/29 16:25:39 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=019132026/08/29 16:25:39 INFO Vacuumed table table=pending_closures19142026/08/29 16:25:39 INFO Completed upload id=119152026/08/29 16:25:39 INFO Vacuumed table table=pending_objects19162026/08/29 16:25:39 INFO Vacuumed table table=multipart_uploads19172026/08/29 16:25:39 INFO Received uploads request method=POST path=/api/pending_closures19182026/08/29 16:25:39 INFO Vacuumed table table=closures19192026/08/29 16:25:39 INFO Received uploads request method=POST path=/api/pending_closures19202026/08/29 16:25:39 INFO Vacuumed table table=objects19212026/08/29 16:25:39 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo19222026/08/29 16:25:39 WARN Found objects in DB but missing from S3, will re-upload count=11923--- PASS: TestService_verifyS3Integrity (3.03s)1924--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)1925 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.10s)1926 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.10s)1927 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.29s)19282026/08/29 16:25:39 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001929--- PASS: TestService_createPendingClosureHandler (3.23s)19302026/08/29 16:25:39 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2091 objects_failed=01931=== NAME TestClientIntegration1932 client_integration_test.go:304: Objects in database after GC:1933=== NAME TestOrphanedObjectsGCStressTest1934 orphaned_objects_gc_test.go:509: Stress test completed successfully:1935 orphaned_objects_gc_test.go:510: - Active objects preserved: 201936 orphaned_objects_gc_test.go:511: - Objects deleted: 2101937 orphaned_objects_gc_test.go:512: - Total GC'd: 2101938--- PASS: TestOrphanedObjectsGCStressTest (4.78s)1939=== NAME TestClientIntegration1940 client_integration_test.go:304: Successfully deleted all objects with GC --force1941--- PASS: TestClientIntegration (6.09s)19422026/08/29 16:25:40 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.485359872s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19432026/08/29 16:25:40 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01944=== NAME TestPinProtectsFromGC1945 client_integration_test.go:711: Pin successfully protected closure from garbage collection1946--- PASS: TestPinProtectsFromGC (6.68s)19472026/08/29 16:25:41 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"19482026/08/29 16:25:41 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_closures19492026/08/29 16:25:41 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.433259ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19502026/08/29 16:25:41 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=414.709139ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19512026/08/29 16:25:42 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=819.426124ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19522026/08/29 16:25:42 WARN Rate limiter enabled after throttle name=s3-test rate=519532026/08/29 16:25:42 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1954=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1955 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101956 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001957--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.62s)19582026/08/29 16:25:43 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.447831589s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1959--- PASS: TestClientErrorHandling (0.00s)1960 --- PASS: TestClientErrorHandling/InvalidStorePath (0.98s)1961 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.07s)1962 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.15s)1963PASS1964{"timestamp":"2026-08-29T16:25:44.546494312Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:37960","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(286)"}19652026-08-29 16:25:44.827 UTC [110] LOG: received smart shutdown request19662026-08-29 16:25:44.831 UTC [110] LOG: background worker "logical replication launcher" (PID 120) exited with exit code 119672026-08-29 16:25:44.842 UTC [115] LOG: shutting down19682026-08-29 16:25:44.842 UTC [115] LOG: checkpoint starting: shutdown immediate19692026-08-29 16:25:45.660 UTC [115] LOG: checkpoint complete: wrote 12061 buffers (73.6%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 14 recycled; write=0.223 s, sync=0.589 s, total=0.819 s; sync files=17141, longest=0.013 s, average=0.001 s; distance=236074 kB, estimate=236074 kB; lsn=0/FDEE538, redo lsn=0/FDEE53819702026-08-29 16:25:45.743 UTC [110] LOG: database system is shut down1971Running OIDC tests...1972=== RUN TestGlobMatch1973=== PAUSE TestGlobMatch1974=== RUN TestAudienceForIssuer1975=== PAUSE TestAudienceForIssuer1976=== RUN TestValidateToken_ValidToken1977=== PAUSE TestValidateToken_ValidToken1978=== RUN TestValidateToken_WrongAudience1979=== PAUSE TestValidateToken_WrongAudience1980=== RUN TestValidateToken_Expired1981=== PAUSE TestValidateToken_Expired1982=== RUN TestValidateToken_BoundClaimsMismatch1983=== PAUSE TestValidateToken_BoundClaimsMismatch1984=== RUN TestValidateToken_BoundSubjectMismatch1985=== PAUSE TestValidateToken_BoundSubjectMismatch1986=== RUN TestValidateToken_MultipleProviders1987=== PAUSE TestValidateToken_MultipleProviders1988=== RUN TestValidateToken_NoMatchingProvider1989=== PAUSE TestValidateToken_NoMatchingProvider1990=== RUN TestValidateToken_KubernetesServiceAccount1991=== PAUSE TestValidateToken_KubernetesServiceAccount1992=== RUN TestNewValidator_KubernetesRequiresCA1993=== PAUSE TestNewValidator_KubernetesRequiresCA1994=== RUN TestScopes_LegacyProviderDefaultsToWrite1995=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1996=== RUN TestScopes_Rules1997=== PAUSE TestScopes_Rules1998=== RUN TestScopes_ConfigValidation1999=== PAUSE TestScopes_ConfigValidation2000=== CONT TestGlobMatch2001=== CONT TestValidateToken_Expired2002=== CONT TestValidateToken_MultipleProviders2003=== CONT TestScopes_LegacyProviderDefaultsToWrite2004=== RUN TestGlobMatch/foo_foo2005=== PAUSE TestGlobMatch/foo_foo2006=== RUN TestGlobMatch/foo_bar2007=== PAUSE TestGlobMatch/foo_bar2008=== RUN TestGlobMatch/*_2009=== PAUSE TestGlobMatch/*_2010=== RUN TestGlobMatch/*_anything2011=== PAUSE TestGlobMatch/*_anything2012=== RUN TestGlobMatch/foo*_foo2013=== PAUSE TestGlobMatch/foo*_foo2014=== RUN TestGlobMatch/foo*_foobar2015=== PAUSE TestGlobMatch/foo*_foobar2016=== RUN TestGlobMatch/foo*_bar2017=== PAUSE TestGlobMatch/foo*_bar2018=== RUN TestGlobMatch/*bar_bar2019=== PAUSE TestGlobMatch/*bar_bar2020=== CONT TestValidateToken_WrongAudience2021=== CONT TestValidateToken_ValidToken2022=== CONT TestAudienceForIssuer2023--- PASS: TestAudienceForIssuer (0.00s)2024=== CONT TestValidateToken_BoundSubjectMismatch2025=== CONT TestValidateToken_KubernetesServiceAccount2026=== CONT TestNewValidator_KubernetesRequiresCA2027=== CONT TestScopes_ConfigValidation2028=== CONT TestScopes_Rules2029=== CONT TestValidateToken_NoMatchingProvider2030=== CONT TestValidateToken_BoundClaimsMismatch2031=== RUN TestGlobMatch/*bar_foobar2032=== PAUSE TestGlobMatch/*bar_foobar2033=== RUN TestGlobMatch/*bar_foo2034=== PAUSE TestGlobMatch/*bar_foo2035=== RUN TestGlobMatch/foo*bar_foobar2036=== PAUSE TestGlobMatch/foo*bar_foobar2037=== RUN TestGlobMatch/foo*bar_foo123bar2038=== PAUSE TestGlobMatch/foo*bar_foo123bar2039=== RUN TestGlobMatch/foo*bar_foobarbaz2040=== PAUSE TestGlobMatch/foo*bar_foobarbaz2041=== RUN TestGlobMatch/*/*_foo/bar2042=== PAUSE TestGlobMatch/*/*_foo/bar2043=== RUN TestGlobMatch/*/*_foo2044=== PAUSE TestGlobMatch/*/*_foo2045=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2046=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2047=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02048=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02049=== RUN TestGlobMatch/refs/*/main_refs/heads/main2050=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2051=== RUN TestGlobMatch/fo?_foo2052=== PAUSE TestGlobMatch/fo?_foo2053=== RUN TestGlobMatch/fo?_fo2054=== PAUSE TestGlobMatch/fo?_fo2055=== RUN TestGlobMatch/fo?_fooo2056=== PAUSE TestGlobMatch/fo?_fooo2057=== RUN TestGlobMatch/?oo_foo2058=== PAUSE TestGlobMatch/?oo_foo2059=== RUN TestGlobMatch/?oo_boo2060=== PAUSE TestGlobMatch/?oo_boo2061=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2062=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2063=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2064=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2065=== CONT TestGlobMatch/foo_foo2066=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2067=== CONT TestGlobMatch/?oo_boo2068=== CONT TestGlobMatch/foo*_foo2069=== CONT TestGlobMatch/fo?_fo2070=== CONT TestGlobMatch/fo?_fooo2071=== CONT TestGlobMatch/fo?_foo2072=== CONT TestGlobMatch/*_anything2073=== CONT TestGlobMatch/foo_bar2074--- PASS: TestScopes_ConfigValidation (0.00s)2075=== CONT TestGlobMatch/foo*_bar2076=== CONT TestGlobMatch/*/*_foo2077=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02078=== CONT TestGlobMatch/*/*_foo/bar2079=== CONT TestGlobMatch/foo*bar_foo123bar2080=== CONT TestGlobMatch/foo*bar_foobar2081=== CONT TestGlobMatch/*bar_foo2082=== CONT TestGlobMatch/refs/*/main_refs/heads/main2083=== CONT TestGlobMatch/foo*bar_foobarbaz2084=== CONT TestGlobMatch/*bar_foobar2085=== CONT TestGlobMatch/?oo_foo2086=== CONT TestGlobMatch/foo*_foobar2087=== CONT TestGlobMatch/*bar_bar2088=== CONT TestGlobMatch/*_2089=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2090=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2091--- PASS: TestGlobMatch (0.01s)2092 --- PASS: TestGlobMatch/foo_foo (0.00s)2093 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2094 --- PASS: TestGlobMatch/?oo_boo (0.00s)2095 --- PASS: TestGlobMatch/foo*_foo (0.00s)2096 --- PASS: TestGlobMatch/fo?_fo (0.00s)2097 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2098 --- PASS: TestGlobMatch/fo?_foo (0.00s)2099 --- PASS: TestGlobMatch/*_anything (0.00s)2100 --- PASS: TestGlobMatch/foo_bar (0.00s)2101 --- PASS: TestGlobMatch/foo*_bar (0.00s)2102 --- PASS: TestGlobMatch/*/*_foo (0.00s)2103 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2104 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2105 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2106 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2107 --- PASS: TestGlobMatch/*bar_foo (0.00s)2108 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2109 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2110 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2111 --- PASS: TestGlobMatch/?oo_foo (0.00s)2112 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2113 --- PASS: TestGlobMatch/*bar_bar (0.00s)2114 --- PASS: TestGlobMatch/*_ (0.00s)2115 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2116 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)21172026/08/29 16:25:46 INFO OIDC provider initialized name=test21182026/08/29 16:25:46 INFO OIDC provider initialized name=test21192026/08/29 16:25:46 INFO OIDC provider initialized name=test21202026/08/29 16:25:46 INFO OIDC provider initialized name=test21212026/08/29 16:25:46 INFO OIDC provider initialized name=test21222026/08/29 16:25:46 INFO OIDC provider initialized name=test21232026/08/29 16:25:46 INFO OIDC provider initialized name=test21242026/08/29 16:25:46 INFO OIDC provider initialized name=provider121252026/08/29 16:25:46 INFO OIDC provider initialized name=provider121262026/08/29 16:25:46 INFO OIDC provider initialized name=provider22127--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2128--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2129--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2130--- PASS: TestValidateToken_Expired (0.01s)2131--- PASS: TestValidateToken_ValidToken (0.01s)2132--- PASS: TestValidateToken_NoMatchingProvider (0.01s)21332026/08/29 16:25:46 INFO OIDC provider initialized name=kubernetes2134--- PASS: TestValidateToken_WrongAudience (0.02s)2135--- PASS: TestValidateToken_MultipleProviders (0.02s)2136--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)21372026/08/29 16:25:46 http: TLS handshake error from 127.0.0.1:46206: remote error: tls: bad certificate2138--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2139--- PASS: TestScopes_Rules (0.02s)2140PASS2141Running hook tests...2142=== RUN TestSendPathsEmpty2143=== PAUSE TestSendPathsEmpty2144=== RUN TestQueueEnqueueAndFetch2145=== PAUSE TestQueueEnqueueAndFetch2146=== RUN TestQueueDeduplication2147=== PAUSE TestQueueDeduplication2148=== RUN TestQueueRemove2149=== PAUSE TestQueueRemove2150=== RUN TestQueueFetchBatchLimit2151=== PAUSE TestQueueFetchBatchLimit2152=== RUN TestQueueRetryMovesToBack2153=== PAUSE TestQueueRetryMovesToBack2154=== RUN TestQueueFetchRemoveLifecycle2155=== PAUSE TestQueueFetchRemoveLifecycle2156=== RUN TestQueueConcurrentWriters2157=== PAUSE TestQueueConcurrentWriters2158=== RUN TestQueueRemoveLargeClosure2159=== PAUSE TestQueueRemoveLargeClosure2160=== RUN TestServerClientIntegration2161=== PAUSE TestServerClientIntegration2162=== RUN TestServerQueueError2163=== PAUSE TestServerQueueError2164=== RUN TestGetListenerSocketActivation2165 server_test.go:210: === RUN TestGetListenerSocketActivation2166 --- PASS: TestGetListenerSocketActivation (0.00s)2167 PASS2168 2169--- PASS: TestGetListenerSocketActivation (0.01s)2170=== RUN TestDrainIsolatesPoisonPath2171=== PAUSE TestDrainIsolatesPoisonPath2172=== RUN TestRunNotBlockedByPoisonHead2173=== PAUSE TestRunNotBlockedByPoisonHead2174=== RUN TestDrainGivesUpWhenServerDown2175=== PAUSE TestDrainGivesUpWhenServerDown2176=== RUN TestFailedPathPrunedByLaterClosure2177=== PAUSE TestFailedPathPrunedByLaterClosure2178=== RUN TestWorkerUploadsAndRemoves2179=== PAUSE TestWorkerUploadsAndRemoves2180=== RUN TestWorkerSkipsGCdPaths2181=== PAUSE TestWorkerSkipsGCdPaths2182=== RUN TestWorkerPrunesClosureDeps2183=== PAUSE TestWorkerPrunesClosureDeps2184=== RUN TestDrainTimeout2185=== PAUSE TestDrainTimeout2186=== CONT TestSendPathsEmpty2187=== CONT TestDrainIsolatesPoisonPath2188=== CONT TestQueueDeduplication2189=== CONT TestQueueFetchRemoveLifecycle2190--- PASS: TestSendPathsEmpty (0.00s)2191=== CONT TestServerQueueError2192=== CONT TestQueueRetryMovesToBack2193=== CONT TestQueueFetchBatchLimit2194=== CONT TestServerClientIntegration2195=== CONT TestQueueEnqueueAndFetch2196=== CONT TestQueueRemoveLargeClosure2197=== CONT TestWorkerUploadsAndRemoves2198=== CONT TestQueueConcurrentWriters2199=== CONT TestDrainTimeout2200=== CONT TestWorkerPrunesClosureDeps2201=== CONT TestWorkerSkipsGCdPaths22022026/08/29 16:25:46 ERROR Failed to queue paths error="permission denied" count=12203=== CONT TestFailedPathPrunedByLaterClosure2204=== CONT TestDrainGivesUpWhenServerDown2205=== CONT TestRunNotBlockedByPoisonHead2206=== CONT TestQueueRemove2207--- PASS: TestServerClientIntegration (0.00s)2208--- PASS: TestServerQueueError (0.00s)22092026/08/29 16:25:46 INFO Uploading batch count=222102026/08/29 16:25:46 INFO Uploading batch count=422112026/08/29 16:25:46 ERROR Upload failed error="upload failed" count=422122026/08/29 16:25:46 INFO Uploading batch count=122132026/08/29 16:25:46 ERROR Upload failed error="upload failed" count=12214--- PASS: TestQueueEnqueueAndFetch (0.02s)22152026/08/29 16:25:46 INFO Upload queue status pending=322162026/08/29 16:25:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2044854195/002/bbb22172026/08/29 16:25:46 INFO Upload queue status pending=222182026/08/29 16:25:46 INFO Uploading batch count=122192026/08/29 16:25:46 ERROR Upload failed error="upload failed" count=122202026/08/29 16:25:46 INFO Upload queue status pending=22221--- PASS: TestQueueRemove (0.02s)22222026/08/29 16:25:46 INFO Uploading batch count=122232026/08/29 16:25:46 INFO Uploading batch count=12224--- PASS: TestQueueFetchBatchLimit (0.02s)22252026/08/29 16:25:46 INFO Uploading batch count=222262026/08/29 16:25:46 INFO Uploading batch count=122272026/08/29 16:25:46 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3049900900/002/nonexistent22282026/08/29 16:25:46 ERROR Upload failed error="upload failed" count=222292026/08/29 16:25:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4190858816/002/a22302026/08/29 16:25:46 ERROR Upload failed error="upload failed" count=12231--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2232--- PASS: TestQueueRetryMovesToBack (0.02s)22332026/08/29 16:25:46 INFO Uploading batch count=122342026/08/29 16:25:46 INFO Uploading batch count=122352026/08/29 16:25:46 INFO Upload queue status pending=222362026/08/29 16:25:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4190858816/002/b22372026/08/29 16:25:46 INFO Uploading batch count=122382026/08/29 16:25:46 ERROR Upload failed error="upload failed" count=12239--- PASS: TestQueueDeduplication (0.02s)22402026/08/29 16:25:46 INFO Uploading batch count=222412026/08/29 16:25:46 INFO Uploading batch count=222422026/08/29 16:25:46 ERROR Upload failed error="upload failed" count=222432026/08/29 16:25:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4190858816/002/c22442026/08/29 16:25:46 INFO Uploading batch count=122452026/08/29 16:25:46 ERROR Upload failed error="upload failed" count=122462026/08/29 16:25:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4190858816/002/d22472026/08/29 16:25:46 ERROR Drain finished with paths left in queue remaining=122482026/08/29 16:25:46 INFO Uploading batch count=222492026/08/29 16:25:46 ERROR Upload failed error="upload failed" count=222502026/08/29 16:25:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4190858816/002/e22512026/08/29 16:25:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4190858816/002/f2252--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)22532026/08/29 16:25:46 ERROR Drain finished with paths left in queue remaining=102254--- PASS: TestDrainIsolatesPoisonPath (0.02s)2255--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2256--- PASS: TestWorkerSkipsGCdPaths (0.03s)2257--- PASS: TestWorkerPrunesClosureDeps (0.04s)2258--- PASS: TestWorkerUploadsAndRemoves (0.04s)22592026/08/29 16:25:47 ERROR Upload failed error="context deadline exceeded" count=222602026/08/29 16:25:47 ERROR Drain finished with paths left in queue remaining=42261--- PASS: TestDrainTimeout (0.22s)2262--- PASS: TestQueueConcurrentWriters (0.27s)2263--- PASS: TestQueueRemoveLargeClosure (0.32s)22642026/08/29 16:25:47 INFO Uploading batch count=122652026/08/29 16:25:47 INFO Uploading batch count=122662026/08/29 16:25:47 INFO Uploading batch count=122672026/08/29 16:25:47 ERROR Upload failed error="upload failed" count=122682026/08/29 16:25:47 INFO Uploading batch count=122692026/08/29 16:25:47 ERROR Upload failed error="upload failed" count=122702026/08/29 16:25:47 INFO Uploading batch count=122712026/08/29 16:25:47 ERROR Upload failed error="upload failed" count=122722026/08/29 16:25:47 INFO Uploading batch count=122732026/08/29 16:25:47 ERROR Upload failed error="upload failed" count=122742026/08/29 16:25:47 ERROR Drain finished with paths left in queue remaining=12275--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2276PASS