niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #171
· 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 TestConvertHashToNix3275=== CONT TestShellSplit76=== RUN TestConvertHashToNix32/SRI_format_to_Nix3277=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix3278=== RUN TestConvertHashToNix32/already_Nix32_format79=== PAUSE TestConvertHashToNix32/already_Nix32_format80=== RUN TestConvertHashToNix32/invalid_format81=== PAUSE TestConvertHashToNix32/invalid_format82=== CONT TestPathInfoCACompatibility83--- PASS: TestShellSplit (0.00s)84=== CONT TestFilterOversizedClosures85=== RUN TestPathInfoCACompatibility/null_ca_field86=== RUN TestFilterOversizedClosures/no_limit_keeps_everything87=== CONT TestParsePathInfoJSONMultiplePaths88=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths89=== PAUSE TestPathInfoCACompatibility/null_ca_field90=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths91=== CONT TestPathInfoHashCompatibility92=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths93=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)94=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)95=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon96=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths97=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything98=== CONT TestConvertHashToNix32/invalid_format99=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped100=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped101=== RUN TestFilterOversizedClosures/all_closures_skipped102=== PAUSE TestFilterOversizedClosures/all_closures_skipped103=== CONT TestRateLimiterFeedback104=== RUN TestRateLimiterFeedback/429_enables_limiter105=== CONT TestResolveStorePath106=== CONT TestDumpPathSingleFile107=== CONT TestDoWithRetry_BodyReplayedViaGetBody108=== CONT TestEncodeNixBase32109=== RUN TestEncodeNixBase32/test_string_hash110=== PAUSE TestEncodeNixBase32/test_string_hash111=== RUN TestEncodeNixBase32/empty_input112=== PAUSE TestEncodeNixBase32/empty_input113=== CONT TestEncodeNixBase32WithRealHash114--- PASS: TestEncodeNixBase32WithRealHash (0.00s)115=== CONT TestSetClientTLSErrors116=== CONT TestCaseHackSuffix117--- PASS: TestResolveStorePath (0.00s)118=== CONT TestFileTokenMissing119=== CONT TestDumpPathWriterError120=== CONT TestFileTokenEmpty121=== CONT TestScriptTokenEmptyCommand122--- PASS: TestScriptTokenEmptyCommand (0.00s)123=== CONT TestFileTokenReadsAndCaches124=== CONT TestScriptTokenScriptFails125=== CONT TestScriptTokenBadJSON126=== CONT TestScriptTokenEmptyToken127=== CONT TestScriptTokenCachesUntilRefresh128=== CONT TestScriptTokenNoExpiryRerunsEveryCall129=== CONT TestPartSizeForNAR130=== CONT TestUploadMultipart_SupersededByPeer131=== CONT TestConvertHashToNix32/SRI_format_to_Nix32132=== CONT TestParsePathInfoJSON133=== RUN TestPathInfoCACompatibility/old_string_format_-_text134=== CONT TestGetStorePathHash135=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon136=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess137=== CONT TestConvertHashToNix32/already_Nix32_format138=== PAUSE TestRateLimiterFeedback/429_enables_limiter139--- PASS: TestFileTokenMissing (0.00s)140=== CONT TestStaticToken141=== CONT TestSetClientTLS142=== RUN TestUploadMultipart_SupersededByPeer/exists143=== PAUSE TestUploadMultipart_SupersededByPeer/exists144=== RUN TestUploadMultipart_SupersededByPeer/missing145--- PASS: TestFileTokenReadsAndCaches (0.00s)146=== PAUSE TestUploadMultipart_SupersededByPeer/missing147=== RUN TestRateLimiterFeedback/503_enables_limiter148=== PAUSE TestRateLimiterFeedback/503_enables_limiter149=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter150=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter151=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter152=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter153=== CONT TestDumpPathMatchesNix154--- PASS: TestScriptTokenScriptFails (0.00s)155--- PASS: TestFileTokenEmpty (0.00s)1562026/08/29 17:01:49 WARN Rate limiter enabled after throttle name=server-test rate=5157=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1582026/08/29 17:01:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:39653159=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths160=== RUN TestGetStorePathHash/valid_store_path161=== RUN TestPartSizeForNAR/zero_stays_at_minimum162=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI163=== CONT TestSetClientTLSDoesNotMutateDefaultTransport164=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text165=== CONT TestShellSplitErrors166=== CONT TestFilterOversizedClosures/no_limit_keeps_everything1672026/08/29 17:01:49 WARN Rate limiter enabled after throttle name=server-test rate=5168--- PASS: TestConvertHashToNix32 (0.00s)169 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)170 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)171 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)172=== RUN TestParsePathInfoJSON/Nix_format173=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped174=== CONT TestFilterOversizedClosures/all_closures_skipped175--- PASS: TestStaticToken (0.01s)1762026/08/29 17:01:49 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=20001772026/08/29 17:01:49 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50178=== PAUSE TestGetStorePathHash/valid_store_path179=== CONT TestEncodeNixBase32/test_string_hash1802026/08/29 17:01:49 WARN Rate limiter backed off name=server-test rate=5181=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter1822026/08/29 17:01:49 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:39653183=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive184=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum185=== CONT TestEncodeNixBase32/empty_input186=== CONT TestUploadMultipart_SupersededByPeer/missing187=== RUN TestSetClientTLSErrors/missing_cert_file188=== PAUSE TestParsePathInfoJSON/Nix_format189=== PAUSE TestSetClientTLSErrors/missing_cert_file190=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter191=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI192=== CONT TestRateLimiterFeedback/429_enables_limiter193--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)194 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.01s)195 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.01s)196=== RUN TestGetStorePathHash/basename_without_hyphen_should_error197=== CONT TestRateLimiterFeedback/503_enables_limiter198=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive199=== CONT TestUploadMultipart_SupersededByPeer/exists200=== RUN TestPartSizeForNAR/small_stays_at_minimum201=== RUN TestParsePathInfoJSON/Lix_format202=== RUN TestSetClientTLSErrors/missing_key_file203--- PASS: TestScriptTokenEmptyToken (0.01s)204=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error205=== PAUSE TestParsePathInfoJSON/Lix_format206=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512207=== RUN TestPathInfoCACompatibility/new_structured_format_-_text208--- PASS: TestScriptTokenBadJSON (0.01s)209--- PASS: TestShellSplitErrors (0.00s)210--- PASS: TestDoServerRequestAttachesToken (0.02s)211--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)212=== RUN TestSetClientTLS/rejects_connection_without_client_cert213=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert214=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error215=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA216=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error217=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA218=== RUN TestSetClientTLS/preserves_debug_logging_transport219=== PAUSE TestSetClientTLS/preserves_debug_logging_transport220=== CONT TestSetClientTLS/rejects_connection_without_client_cert221=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error222=== CONT TestSetClientTLS/preserves_debug_logging_transport223--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)224--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)225=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA226=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error227=== CONT TestGetStorePathHash/valid_store_path228=== CONT TestGetStorePathHash/basename_without_hyphen_should_error229--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)230=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error231=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error232--- PASS: TestGetStorePathHash (0.01s)233 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)234 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)235 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)236 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)237=== PAUSE TestPartSizeForNAR/small_stays_at_minimum238=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum239=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum240=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts241=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts242=== RUN TestPartSizeForNAR/1_TiB243=== PAUSE TestPartSizeForNAR/1_TiB244=== RUN TestPartSizeForNAR/5_TiB_S3_max_object245=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object246--- PASS: TestEncodeNixBase32 (0.01s)247 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)248 --- PASS: TestEncodeNixBase32/empty_input (0.00s)249=== RUN TestPartSizeForNAR/capped_at_5_GiB250=== PAUSE TestPartSizeForNAR/capped_at_5_GiB251=== CONT TestPartSizeForNAR/zero_stays_at_minimum252=== CONT TestPartSizeForNAR/5_TiB_S3_max_object253=== CONT TestPartSizeForNAR/1_TiB254=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum255=== CONT TestPartSizeForNAR/capped_at_5_GiB256=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts257=== CONT TestPartSizeForNAR/small_stays_at_minimum258=== PAUSE TestSetClientTLSErrors/missing_key_file259=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512260=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)261=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512262=== RUN TestParsePathInfoJSON/empty_input263=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2642026/08/29 17:01:49 WARN Rate limiter enabled after throttle name=server-test rate=52652026/08/29 17:01:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:332752662026/08/29 17:01:49 WARN Rate limiter enabled after throttle name=server-test rate=5267--- PASS: TestPartSizeForNAR (0.02s)268 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)269 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)270 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)271 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)272 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)273 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)274 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)2752026/08/29 17:01:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:39811276=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text277=== PAUSE TestParsePathInfoJSON/empty_input278=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method2792026/08/29 17:01:49 WARN Rate limiter backed off name=server-test rate=5280=== RUN TestParsePathInfoJSON/whitespace_only281=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method2822026/08/29 17:01:49 WARN Rate limiter backed off name=server-test rate=5283=== PAUSE TestParsePathInfoJSON/whitespace_only284=== RUN TestSetClientTLSErrors/missing_ca_file285=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method286=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon287--- PASS: TestFilterOversizedClosures (0.01s)288 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)289 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)290 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)291=== CONT TestPathInfoCACompatibility/null_ca_field292--- PASS: TestRateLimiterFeedback (0.00s)293 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)294 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)295 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)296 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)297=== CONT TestPathInfoCACompatibility/new_structured_format_-_text298=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive299=== CONT TestPathInfoCACompatibility/old_string_format_-_text300=== RUN TestParsePathInfoJSON/invalid_JSON301=== PAUSE TestParsePathInfoJSON/invalid_JSON302=== CONT TestParsePathInfoJSON/Nix_format303=== CONT TestParsePathInfoJSON/whitespace_only304=== CONT TestParsePathInfoJSON/empty_input305--- PASS: TestPathInfoHashCompatibility (0.03s)306 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)307 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)308 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)309 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)310=== CONT TestParsePathInfoJSON/Lix_format311=== PAUSE TestSetClientTLSErrors/missing_ca_file312=== CONT TestParsePathInfoJSON/invalid_JSON313--- PASS: TestPathInfoCACompatibility (0.03s)314 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)315 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)316 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)317 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)318 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)319=== RUN TestSetClientTLSErrors/invalid_ca_file320=== PAUSE TestSetClientTLSErrors/invalid_ca_file321=== CONT TestSetClientTLSErrors/missing_cert_file322=== CONT TestSetClientTLSErrors/invalid_ca_file323--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)324 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)325 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)326=== CONT TestSetClientTLSErrors/missing_ca_file327--- PASS: TestParsePathInfoJSON (0.02s)328 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)329 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)330 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)331 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)332 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)333=== CONT TestSetClientTLSErrors/missing_key_file334--- 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)339--- PASS: TestDumpPathSingleFile (0.03s)340--- PASS: TestCaseHackSuffix (0.03s)3412026/08/29 17:01:49 http: TLS handshake error from 127.0.0.1:39980: remote error: tls: bad certificate342--- PASS: TestSetClientTLS (0.01s)343 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)344 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)345 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)346--- PASS: TestDumpPathWriterError (0.04s)347--- PASS: TestDumpPathMatchesNix (0.08s)348--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)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/postgres3213862755/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/postgres3213862755/data -l logfile start377378/build/postgres3213862755:5432 - no response3792026-08-29 17:01:51.072 UTC [110] LOG: starting PostgreSQL 18.4 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit3802026-08-29 17:01:51.072 UTC [110] LOG: listening on Unix socket "/build/postgres3213862755/.s.PGSQL.5432"3812026-08-29 17:01:51.076 UTC [117] LOG: database system was shut down at 2026-08-29 17:01:50 UTC3822026-08-29 17:01:51.080 UTC [110] LOG: database system is ready to accept connections383/build/postgres3213862755: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 17:01:52.462 UTC [454] ERROR: relation "goose_db_version" does not exist at character 364182026-08-29 17:01:52.462 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4192026/08/29 17:01:52 OK 20241026095416_initial_model.sql (10.71ms)4202026/08/29 17:01:52 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)4212026/08/29 17:01:52 OK 20251218171726_add_pins.sql (3.17ms)4222026/08/29 17:01:52 OK 20260628120000_add_object_size_and_stats.sql (3.05ms)4232026/08/29 17:01:52 goose: successfully migrated database to version: 202606281200004242026/08/29 17:01:52 OK 1_commit_pending_closure.sql (2.32ms)4252026/08/29 17:01:52 OK 2_object_stats_trigger.sql (997.73µs)4262026/08/29 17:01:52 goose: up to current file version: 2427--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.89s)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 17:01:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5282026/08/29 17:01:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5292026/08/29 17:01:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5302026/08/29 17:01:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5312026/08/29 17:01:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5322026/08/29 17:01:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5332026/08/29 17:01:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5342026/08/29 17:01:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5352026/08/29 17:01:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5362026/08/29 17:01:53 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 TestCreatePendingClosure_SmallNARUsesSimplePUT559=== CONT TestService_NativeMTLS560=== CONT TestUploadHandlersRejectInvalidKeys561=== CONT TestGCTaskStore_Fail562--- PASS: TestGCTaskStore_Fail (0.00s)563=== CONT TestReadRedirectUsesPublicS3URL564=== CONT TestMultipartCleanup565=== CONT TestGCMetrics566=== CONT TestServerTLSConfig567=== RUN TestServerTLSConfig/no_client_CA568=== CONT TestCompleteMultipartUnregistered569=== CONT TestService_verifyS3Integrity570=== CONT TestService_createPendingClosureHandler571=== CONT TestService_cleanupPendingClosuresHandler572=== CONT TestUploadHandlersRejectOversizedBody573=== CONT TestMetricsInventory574=== CONT TestNARDeduplicationMetadataUploadBug575=== CONT TestCreatePendingClosureRejectsOversizedNAR576=== CONT TestCacheConfigHandlerMaxNarSize577=== CONT TestGenerateLandingPage578=== CONT TestService_readinessHandler579=== CONT TestService_healthCheckHandler5802026/08/29 17:01:53 INFO Received uploads request method=POST path=/api/pending_closures581=== CONT TestGracefulShutdownDrainsInflight582=== CONT TestReadProxyDisabled583=== CONT TestCompleteMultipartUpload_ErrorButObjectExists5842026/08/29 17:01:53 INFO Starting HTTP server address=127.0.0.1:39505585=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info586=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info587=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal588=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal589=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key590=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key591=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key5922026/08/29 17:01:53 INFO Shutdown signal received, draining in-flight requests timeout=10s593=== CONT TestClientCADerivations594=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key595=== CONT TestRedundantMultipartUpload596=== CONT TestService_AuthMiddleware597=== CONT TestPresignedUploadRegisteredBeforeCommit598=== PAUSE TestServerTLSConfig/no_client_CA599--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)600=== CONT TestCompletedNarNotReofferedAcrossClosures601--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)602--- PASS: TestGenerateLandingPage (0.01s)603=== CONT TestGCTaskStore_GetEmpty604--- PASS: TestGCTaskStore_GetEmpty (0.00s)605=== CONT TestGCTaskStore_PhaseUpdates606--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)607=== CONT TestGCTaskStore_CompletedAllowsNewTask608--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)609=== CONT TestGCTaskStore_GetReturnsLatest610--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)611=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle612=== RUN TestServerTLSConfig/missing_CA_file613=== PAUSE TestServerTLSConfig/missing_CA_file614=== RUN TestServerTLSConfig/not_a_PEM_file615=== PAUSE TestServerTLSConfig/not_a_PEM_file616=== CONT TestIsValidUploadKey617=== RUN TestIsValidUploadKey/narinfo618=== PAUSE TestIsValidUploadKey/narinfo619=== RUN TestIsValidUploadKey/nar_zst620=== PAUSE TestIsValidUploadKey/nar_zst621=== RUN TestIsValidUploadKey/nar_xz622=== PAUSE TestIsValidUploadKey/nar_xz623=== RUN TestIsValidUploadKey/nar_plain624=== PAUSE TestIsValidUploadKey/nar_plain625=== RUN TestIsValidUploadKey/listing626=== PAUSE TestIsValidUploadKey/listing627=== RUN TestIsValidUploadKey/build_log628=== PAUSE TestIsValidUploadKey/build_log629=== RUN TestIsValidUploadKey/build_log_home-manager_file630=== PAUSE TestIsValidUploadKey/build_log_home-manager_file631=== RUN TestIsValidUploadKey/build_log_plus_in_name632=== PAUSE TestIsValidUploadKey/build_log_plus_in_name633=== RUN TestIsValidUploadKey/build_log_question_mark634=== PAUSE TestIsValidUploadKey/build_log_question_mark635=== RUN TestIsValidUploadKey/build_log_equals636=== PAUSE TestIsValidUploadKey/build_log_equals637=== RUN TestIsValidUploadKey/realisation638=== PAUSE TestIsValidUploadKey/realisation639=== RUN TestIsValidUploadKey/realisation_plus_in_output640=== PAUSE TestIsValidUploadKey/realisation_plus_in_output641=== RUN TestIsValidUploadKey/nix-cache-info642=== PAUSE TestIsValidUploadKey/nix-cache-info643=== RUN TestIsValidUploadKey/index.html644=== PAUSE TestIsValidUploadKey/index.html645=== RUN TestIsValidUploadKey/narinfo_key,_nar_type646=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type647=== RUN TestIsValidUploadKey/nar_key,_narinfo_type648=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type649=== RUN TestIsValidUploadKey/listing_key,_narinfo_type650=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type651=== RUN TestIsValidUploadKey/traversal652=== PAUSE TestIsValidUploadKey/traversal653=== RUN TestIsValidUploadKey/traversal_nar654=== PAUSE TestIsValidUploadKey/traversal_nar655=== RUN TestIsValidUploadKey/absolute656=== PAUSE TestIsValidUploadKey/absolute657=== RUN TestIsValidUploadKey/empty_key658=== PAUSE TestIsValidUploadKey/empty_key659=== RUN TestIsValidUploadKey/unknown_type660=== PAUSE TestIsValidUploadKey/unknown_type661=== CONT TestProxyWriteTimeout662=== RUN TestProxyWriteTimeout/narinfo663=== PAUSE TestProxyWriteTimeout/narinfo664=== RUN TestProxyWriteTimeout/1_GiB_nar665=== PAUSE TestProxyWriteTimeout/1_GiB_nar666=== RUN TestProxyWriteTimeout/10_GiB_nar667=== PAUSE TestProxyWriteTimeout/10_GiB_nar668=== RUN TestProxyWriteTimeout/unknown_size669=== PAUSE TestProxyWriteTimeout/unknown_size670=== CONT TestParseSize671--- PASS: TestParseSize (0.00s)672=== CONT TestSkippedUploadsHandler6732026/08/29 17:01:53 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000674--- PASS: TestSkippedUploadsHandler (0.00s)675=== CONT TestService_ReadAuthMiddleware676--- PASS: TestGracefulShutdownDrainsInflight (0.07s)677=== CONT TestService_AuthMiddleware_OIDC6782026/08/29 17:01:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34767/oidc6792026-08-29 17:01:53.589 UTC [525] ERROR: relation "goose_db_version" does not exist at character 366802026-08-29 17:01:53.589 UTC [525] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6812026-08-29 17:01:53.591 UTC [527] ERROR: relation "goose_db_version" does not exist at character 366822026-08-29 17:01:53.591 UTC [527] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6832026-08-29 17:01:53.604 UTC [528] ERROR: relation "goose_db_version" does not exist at character 366842026-08-29 17:01:53.604 UTC [528] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6852026-08-29 17:01:53.607 UTC [530] ERROR: relation "goose_db_version" does not exist at character 366862026-08-29 17:01:53.607 UTC [530] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6872026-08-29 17:01:53.616 UTC [531] ERROR: relation "goose_db_version" does not exist at character 366882026-08-29 17:01:53.616 UTC [531] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC689=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure690=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure691=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart692=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart693=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts694=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts695=== CONT TestCacheConfigHandler696=== RUN TestCacheConfigHandler/full_config,_no_issuer697=== PAUSE TestCacheConfigHandler/full_config,_no_issuer698=== RUN TestCacheConfigHandler/no_cache_url_configured699=== PAUSE TestCacheConfigHandler/no_cache_url_configured700=== RUN TestCacheConfigHandler/no_signing_keys701=== PAUSE TestCacheConfigHandler/no_signing_keys702=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator703=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator704=== CONT TestCacheStatsHandler7052026-08-29 17:01:53.671 UTC [536] ERROR: relation "goose_db_version" does not exist at character 367062026-08-29 17:01:53.671 UTC [536] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7072026/08/29 17:01:53 OK 20241026095416_initial_model.sql (68.85ms)7082026/08/29 17:01:53 OK 20241026095416_initial_model.sql (71.62ms)7092026/08/29 17:01:53 OK 20241026095416_initial_model.sql (78.44ms)7102026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (9.32ms)7112026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (3.44ms)7122026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (10.98ms)7132026/08/29 17:01:53 OK 20251218171726_add_pins.sql (6.07ms)7142026/08/29 17:01:53 OK 20251218171726_add_pins.sql (6.47ms)7152026/08/29 17:01:53 OK 20251218171726_add_pins.sql (11.02ms)7162026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (8.24ms)7172026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200007182026/08/29 17:01:53 OK 20241026095416_initial_model.sql (44.2ms)7192026/08/29 17:01:53 OK 20241026095416_initial_model.sql (31.08ms)7202026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (8.1ms)7212026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200007222026/08/29 17:01:53 OK 20241026095416_initial_model.sql (20.68ms)7232026/08/29 17:01:53 OK 1_commit_pending_closure.sql (4.8ms)7242026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (5.26ms)7252026-08-29 17:01:53.716 UTC [538] ERROR: relation "goose_db_version" does not exist at character 367262026-08-29 17:01:53.716 UTC [538] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7272026-08-29 17:01:53.719 UTC [539] ERROR: relation "goose_db_version" does not exist at character 367282026-08-29 17:01:53.719 UTC [539] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7292026-08-29 17:01:53.722 UTC [540] ERROR: relation "goose_db_version" does not exist at character 367302026-08-29 17:01:53.722 UTC [540] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7312026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (15.16ms)7322026/08/29 17:01:53 OK 2_object_stats_trigger.sql (13.93ms)7332026/08/29 17:01:53 goose: up to current file version: 27342026/08/29 17:01:53 OK 20251218171726_add_pins.sql (13.71ms)7352026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (19.27ms)7362026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200007372026/08/29 17:01:53 OK 1_commit_pending_closure.sql (15.59ms)7382026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (15.25ms)7392026/08/29 17:01:53 OK 2_object_stats_trigger.sql (3.37ms)7402026/08/29 17:01:53 goose: up to current file version: 27412026/08/29 17:01:53 OK 1_commit_pending_closure.sql (5.28ms)7422026/08/29 17:01:53 OK 20251218171726_add_pins.sql (8.56ms)7432026/08/29 17:01:53 OK 20251218171726_add_pins.sql (11.08ms)7442026-08-29 17:01:53.737 UTC [541] ERROR: relation "goose_db_version" does not exist at character 367452026-08-29 17:01:53.737 UTC [541] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7462026/08/29 17:01:53 OK 2_object_stats_trigger.sql (5.62ms)7472026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (11.22ms)7482026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200007492026/08/29 17:01:53 goose: up to current file version: 27502026-08-29 17:01:53.744 UTC [542] ERROR: relation "goose_db_version" does not exist at character 367512026-08-29 17:01:53.744 UTC [542] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7522026-08-29 17:01:53.747 UTC [543] ERROR: relation "goose_db_version" does not exist at character 367532026-08-29 17:01:53.747 UTC [543] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7542026/08/29 17:01:53 OK 1_commit_pending_closure.sql (8.51ms)7552026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (11.46ms)7562026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200007572026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (11.34ms)7582026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200007592026-08-29 17:01:53.751 UTC [544] ERROR: relation "goose_db_version" does not exist at character 367602026-08-29 17:01:53.751 UTC [544] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7612026/08/29 17:01:53 OK 1_commit_pending_closure.sql (4.02ms)7622026/08/29 17:01:53 OK 1_commit_pending_closure.sql (6.39ms)7632026/08/29 17:01:53 OK 2_object_stats_trigger.sql (6.63ms)7642026/08/29 17:01:53 goose: up to current file version: 27652026/08/29 17:01:53 OK 2_object_stats_trigger.sql (3.75ms)7662026/08/29 17:01:53 goose: up to current file version: 27672026/08/29 17:01:53 OK 20241026095416_initial_model.sql (22.31ms)7682026/08/29 17:01:53 OK 20241026095416_initial_model.sql (21.34ms)7692026/08/29 17:01:53 OK 2_object_stats_trigger.sql (2.64ms)7702026/08/29 17:01:53 goose: up to current file version: 27712026/08/29 17:01:53 OK 20241026095416_initial_model.sql (20.98ms)7722026-08-29 17:01:53.760 UTC [545] ERROR: relation "goose_db_version" does not exist at character 367732026-08-29 17:01:53.760 UTC [545] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7742026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (5.12ms)7752026-08-29 17:01:53.770 UTC [546] ERROR: relation "goose_db_version" does not exist at character 367762026-08-29 17:01:53.770 UTC [546] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7772026-08-29 17:01:53.771 UTC [547] ERROR: relation "goose_db_version" does not exist at character 367782026-08-29 17:01:53.771 UTC [547] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7792026-08-29 17:01:53.772 UTC [548] ERROR: relation "goose_db_version" does not exist at character 367802026-08-29 17:01:53.772 UTC [548] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7812026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (16.51ms)7822026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (14.72ms)7832026/08/29 17:01:53 OK 20241026095416_initial_model.sql (18.9ms)7842026/08/29 17:01:53 OK 20241026095416_initial_model.sql (18.98ms)7852026/08/29 17:01:53 OK 20241026095416_initial_model.sql (16.01ms)7862026/08/29 17:01:53 OK 20251218171726_add_pins.sql (14.62ms)7872026/08/29 17:01:53 OK 20241026095416_initial_model.sql (24.23ms)7882026/08/29 17:01:53 OK 20251218171726_add_pins.sql (6.09ms)7892026/08/29 17:01:53 OK 20251218171726_add_pins.sql (6.14ms)7902026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (3.15ms)7912026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (3.4ms)7922026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (3.48ms)7932026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (3.67ms)7942026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (8.04ms)7952026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200007962026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (6.1ms)7972026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200007982026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (6.24ms)7992026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200008002026/08/29 17:01:53 OK 20251218171726_add_pins.sql (5.9ms)8012026/08/29 17:01:53 OK 20251218171726_add_pins.sql (5.36ms)8022026/08/29 17:01:53 OK 20251218171726_add_pins.sql (7.37ms)8032026/08/29 17:01:53 OK 20251218171726_add_pins.sql (7.42ms)8042026/08/29 17:01:53 OK 1_commit_pending_closure.sql (4.09ms)8052026-08-29 17:01:53.790 UTC [550] ERROR: relation "goose_db_version" does not exist at character 368062026-08-29 17:01:53.790 UTC [550] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8072026-08-29 17:01:53.790 UTC [549] ERROR: relation "goose_db_version" does not exist at character 368082026-08-29 17:01:53.790 UTC [549] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8092026/08/29 17:01:53 OK 1_commit_pending_closure.sql (4.89ms)8102026-08-29 17:01:53.792 UTC [551] ERROR: relation "goose_db_version" does not exist at character 368112026-08-29 17:01:53.792 UTC [551] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8122026/08/29 17:01:53 OK 1_commit_pending_closure.sql (6.35ms)8132026/08/29 17:01:53 OK 20241026095416_initial_model.sql (13.31ms)8142026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (6.38ms)8152026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200008162026/08/29 17:01:53 OK 2_object_stats_trigger.sql (3.43ms)8172026/08/29 17:01:53 goose: up to current file version: 28182026/08/29 17:01:53 OK 20241026095416_initial_model.sql (11.42ms)8192026/08/29 17:01:53 OK 20241026095416_initial_model.sql (11ms)8202026-08-29 17:01:53.794 UTC [553] ERROR: relation "goose_db_version" does not exist at character 368212026-08-29 17:01:53.794 UTC [553] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8222026-08-29 17:01:53.794 UTC [554] ERROR: relation "goose_db_version" does not exist at character 368232026-08-29 17:01:53.794 UTC [554] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8242026-08-29 17:01:53.794 UTC [552] ERROR: relation "goose_db_version" does not exist at character 368252026-08-29 17:01:53.794 UTC [552] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8262026/08/29 17:01:53 OK 2_object_stats_trigger.sql (2.75ms)8272026/08/29 17:01:53 goose: up to current file version: 28282026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (6.44ms)8292026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200008302026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (7.61ms)8312026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200008322026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (6.56ms)8332026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200008342026/08/29 17:01:53 OK 20241026095416_initial_model.sql (16.22ms)8352026/08/29 17:01:53 OK 2_object_stats_trigger.sql (2.48ms)8362026/08/29 17:01:53 goose: up to current file version: 28372026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)8382026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)8392026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (2.34ms)8402026/08/29 17:01:53 OK 1_commit_pending_closure.sql (2.82ms)8412026/08/29 17:01:53 OK 1_commit_pending_closure.sql (2.42ms)8422026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)8432026/08/29 17:01:53 OK 1_commit_pending_closure.sql (2.27ms)8442026/08/29 17:01:53 OK 1_commit_pending_closure.sql (2.54ms)8452026/08/29 17:01:53 OK 2_object_stats_trigger.sql (2.45ms)8462026/08/29 17:01:53 goose: up to current file version: 28472026/08/29 17:01:53 OK 2_object_stats_trigger.sql (2.41ms)8482026-08-29 17:01:53.799 UTC [555] ERROR: relation "goose_db_version" does not exist at character 368492026-08-29 17:01:53.799 UTC [555] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8502026/08/29 17:01:53 OK 2_object_stats_trigger.sql (2.53ms)8512026/08/29 17:01:53 goose: up to current file version: 28522026/08/29 17:01:53 goose: up to current file version: 28532026/08/29 17:01:53 OK 2_object_stats_trigger.sql (2.15ms)8542026/08/29 17:01:53 goose: up to current file version: 28552026/08/29 17:01:53 OK 20251218171726_add_pins.sql (4.79ms)8562026/08/29 17:01:53 OK 20251218171726_add_pins.sql (4.71ms)8572026/08/29 17:01:53 OK 20251218171726_add_pins.sql (6.19ms)8582026/08/29 17:01:53 OK 20251218171726_add_pins.sql (5.99ms)8592026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (4.24ms)8602026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200008612026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (4.98ms)8622026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200008632026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (5.06ms)8642026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200008652026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (6.19ms)8662026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200008672026/08/29 17:01:53 OK 1_commit_pending_closure.sql (3.69ms)8682026/08/29 17:01:53 OK 20241026095416_initial_model.sql (9.62ms)8692026/08/29 17:01:53 OK 1_commit_pending_closure.sql (2.57ms)8702026/08/29 17:01:53 OK 1_commit_pending_closure.sql (2.68ms)8712026/08/29 17:01:53 OK 20241026095416_initial_model.sql (13.97ms)8722026/08/29 17:01:53 OK 1_commit_pending_closure.sql (3.72ms)8732026/08/29 17:01:53 OK 2_object_stats_trigger.sql (2.22ms)8742026/08/29 17:01:53 goose: up to current file version: 28752026/08/29 17:01:53 OK 2_object_stats_trigger.sql (2.9ms)8762026/08/29 17:01:53 goose: up to current file version: 28772026/08/29 17:01:53 OK 20241026095416_initial_model.sql (11.79ms)8782026/08/29 17:01:53 OK 2_object_stats_trigger.sql (2.2ms)8792026/08/29 17:01:53 goose: up to current file version: 28802026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (3.21ms)8812026/08/29 17:01:53 OK 20241026095416_initial_model.sql (15.06ms)8822026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (2.46ms)8832026/08/29 17:01:53 OK 2_object_stats_trigger.sql (2.64ms)8842026/08/29 17:01:53 goose: up to current file version: 28852026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (2.71ms)8862026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (3.41ms)8872026/08/29 17:01:53 OK 20241026095416_initial_model.sql (13.93ms)8882026/08/29 17:01:53 OK 20251218171726_add_pins.sql (4.34ms)8892026/08/29 17:01:53 OK 20251218171726_add_pins.sql (5.63ms)8902026/08/29 17:01:53 OK 20241026095416_initial_model.sql (15.08ms)8912026/08/29 17:01:53 OK 20251218171726_add_pins.sql (4.11ms)8922026/08/29 17:01:53 OK 20241026095416_initial_model.sql (10.23ms)8932026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)8942026/08/29 17:01:53 OK 20251218171726_add_pins.sql (3.51ms)8952026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)8962026/08/29 17:01:53 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)8972026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (4.54ms)8982026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200008992026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (3.35ms)9002026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200009012026/08/29 17:01:53 OK 20251218171726_add_pins.sql (3.41ms)9022026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (4.88ms)9032026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200009042026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (3.77ms)9052026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200009062026/08/29 17:01:53 OK 20251218171726_add_pins.sql (3.72ms)9072026/08/29 17:01:53 OK 20251218171726_add_pins.sql (3.53ms)9082026/08/29 17:01:53 OK 1_commit_pending_closure.sql (3.34ms)9092026/08/29 17:01:53 OK 1_commit_pending_closure.sql (3.48ms)9102026/08/29 17:01:53 OK 1_commit_pending_closure.sql (3.21ms)9112026/08/29 17:01:53 OK 1_commit_pending_closure.sql (3.57ms)9122026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (3.79ms)9132026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200009142026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)9152026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200009162026/08/29 17:01:53 OK 2_object_stats_trigger.sql (955.77µs)9172026/08/29 17:01:53 goose: up to current file version: 29182026/08/29 17:01:53 OK 2_object_stats_trigger.sql (1ms)9192026/08/29 17:01:53 goose: up to current file version: 29202026/08/29 17:01:53 OK 2_object_stats_trigger.sql (1.07ms)9212026/08/29 17:01:53 goose: up to current file version: 29222026/08/29 17:01:53 OK 2_object_stats_trigger.sql (1.42ms)9232026/08/29 17:01:53 goose: up to current file version: 29242026/08/29 17:01:53 OK 1_commit_pending_closure.sql (1.78ms)9252026/08/29 17:01:53 OK 1_commit_pending_closure.sql (1.75ms)9262026/08/29 17:01:53 OK 20260628120000_add_object_size_and_stats.sql (3.59ms)9272026/08/29 17:01:53 goose: successfully migrated database to version: 202606281200009282026/08/29 17:01:53 OK 2_object_stats_trigger.sql (890.25µs)9292026/08/29 17:01:53 goose: up to current file version: 29302026/08/29 17:01:53 OK 2_object_stats_trigger.sql (1.41ms)9312026/08/29 17:01:53 goose: up to current file version: 29322026/08/29 17:01:53 OK 1_commit_pending_closure.sql (2.01ms)9332026/08/29 17:01:53 OK 2_object_stats_trigger.sql (806.61µs)9342026/08/29 17:01:53 goose: up to current file version: 29352026/08/29 17:01:54 INFO Received uploads request method=POST path=/api/pending_closures936--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.90s)937=== CONT TestService_ReadScope_PublicByDefault9382026/08/29 17:01:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9392026/08/29 17:01:54 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst940--- PASS: TestCompleteMultipartUnregistered (0.91s)941=== CONT TestReadProxyNarinfoAlreadyDecompressed9422026/08/29 17:01:54 INFO Received uploads request method=POST path=/api/pending_closures9432026/08/29 17:01:54 INFO Aborted multipart uploads count=09442026/08/29 17:01:54 WARN Force mode enabled - objects will be deleted immediately without grace period9452026/08/29 17:01:54 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=09462026/08/29 17:01:54 INFO Vacuumed table table=pending_closures9472026/08/29 17:01:54 INFO Vacuumed table table=pending_objects9482026/08/29 17:01:54 INFO Vacuumed table table=multipart_uploads9492026/08/29 17:01:54 INFO Vacuumed table table=closures9502026/08/29 17:01:54 INFO Vacuumed table table=objects9512026-08-29 17:01:54.472 UTC [561] ERROR: relation "goose_db_version" does not exist at character 369522026-08-29 17:01:54.472 UTC [561] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC953--- PASS: TestGCMetrics (0.98s)954=== CONT TestReadProxyRootRedirectsToIndexHTML9552026/08/29 17:01:54 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9562026/08/29 17:01:54 WARN mTLS auth: subject not in bound subjects subject="CN=reader"957--- PASS: TestService_NativeMTLS (0.98s)958=== CONT TestReadProxyConditionalGet9592026-08-29 17:01:54.488 UTC [564] ERROR: relation "goose_db_version" does not exist at character 369602026-08-29 17:01:54.488 UTC [564] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9612026/08/29 17:01:54 OK 20241026095416_initial_model.sql (10.42ms)9622026/08/29 17:01:54 OK 20251210153512_drop_unused_gin_index.sql (3.01ms)9632026/08/29 17:01:54 OK 20251218171726_add_pins.sql (5.44ms)9642026/08/29 17:01:54 OK 20260628120000_add_object_size_and_stats.sql (11.51ms)9652026/08/29 17:01:54 goose: successfully migrated database to version: 202606281200009662026/08/29 17:01:54 OK 20241026095416_initial_model.sql (14.54ms)9672026/08/29 17:01:54 OK 1_commit_pending_closure.sql (3.46ms)9682026/08/29 17:01:54 OK 20251210153512_drop_unused_gin_index.sql (3.02ms)9692026/08/29 17:01:54 OK 2_object_stats_trigger.sql (2.39ms)9702026/08/29 17:01:54 goose: up to current file version: 29712026/08/29 17:01:54 OK 20251218171726_add_pins.sql (4.53ms)9722026/08/29 17:01:54 OK 20260628120000_add_object_size_and_stats.sql (4.71ms)9732026/08/29 17:01:54 goose: successfully migrated database to version: 20260628120000974--- PASS: TestReadRedirectUsesPublicS3URL (1.03s)975=== CONT TestReadProxyHead9762026/08/29 17:01:54 OK 1_commit_pending_closure.sql (3.24ms)9772026/08/29 17:01:54 OK 2_object_stats_trigger.sql (2.81ms)9782026/08/29 17:01:54 goose: up to current file version: 29792026/08/29 17:01:54 INFO Received uploads request method=POST path=/api/pending_closures9802026/08/29 17:01:54 INFO Received uploads request method=POST path=/api/pending_closures9812026/08/29 17:01:54 INFO Received uploads request method=POST path=/api/pending_closures9822026-08-29 17:01:54.550 UTC [570] ERROR: relation "goose_db_version" does not exist at character 369832026-08-29 17:01:54.550 UTC [570] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9842026/08/29 17:01:54 INFO Received uploads request method=POST path=/api/pending_closures9852026/08/29 17:01:54 INFO Received cleanup request method=DELETE path=/api/pending_closures9862026-08-29 17:01:54.558 UTC [572] ERROR: relation "goose_db_version" does not exist at character 369872026-08-29 17:01:54.558 UTC [572] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9882026/08/29 17:01:54 INFO Aborted multipart uploads count=1989=== NAME TestNARDeduplicationMetadataUploadBug990 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug4052144691/001/store/yj4nhdy7lk3fjv3gw14389gdp2rk42d0-file1.txt9912026/08/29 17:01:54 INFO Received uploads request method=POST path=/api/pending_closures992--- PASS: TestMultipartCleanup (1.07s)9932026/08/29 17:01:54 OK 20241026095416_initial_model.sql (11.77ms)994=== CONT TestReadProxyInvalidPath995--- PASS: TestReadProxyDisabled (1.07s)996=== CONT TestReadProxy4049972026/08/29 17:01:54 OK 20251210153512_drop_unused_gin_index.sql (3.95ms)9982026/08/29 17:01:54 OK 20241026095416_initial_model.sql (12.8ms)9992026/08/29 17:01:54 OK 20251218171726_add_pins.sql (4.28ms)10002026/08/29 17:01:54 OK 20251210153512_drop_unused_gin_index.sql (2.9ms)10012026/08/29 17:01:54 OK 20260628120000_add_object_size_and_stats.sql (5.2ms)10022026/08/29 17:01:54 goose: successfully migrated database to version: 2026062812000010032026/08/29 17:01:54 OK 20251218171726_add_pins.sql (3.63ms)10042026/08/29 17:01:54 OK 1_commit_pending_closure.sql (2.08ms)10052026/08/29 17:01:54 OK 2_object_stats_trigger.sql (1.62ms)10062026/08/29 17:01:54 goose: up to current file version: 210072026/08/29 17:01:54 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)10082026/08/29 17:01:54 goose: successfully migrated database to version: 2026062812000010092026/08/29 17:01:54 OK 1_commit_pending_closure.sql (2.67ms)10102026-08-29 17:01:54.592 UTC [593] ERROR: relation "goose_db_version" does not exist at character 3610112026-08-29 17:01:54.592 UTC [593] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10122026/08/29 17:01:54 OK 2_object_stats_trigger.sql (2.82ms)10132026/08/29 17:01:54 goose: up to current file version: 210142026/08/29 17:01:54 OK 20241026095416_initial_model.sql (10.96ms)10152026/08/29 17:01:54 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)10162026/08/29 17:01:54 OK 20251218171726_add_pins.sql (3.58ms)10172026/08/29 17:01:54 OK 20260628120000_add_object_size_and_stats.sql (14.09ms)10182026/08/29 17:01:54 goose: successfully migrated database to version: 2026062812000010192026/08/29 17:01:54 OK 1_commit_pending_closure.sql (15.58ms)10202026/08/29 17:01:54 OK 2_object_stats_trigger.sql (2.37ms)10212026/08/29 17:01:54 goose: up to current file version: 210222026/08/29 17:01:54 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10232026-08-29 17:01:54.661 UTC [630] ERROR: relation "goose_db_version" does not exist at character 3610242026-08-29 17:01:54.661 UTC [630] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10252026-08-29 17:01:54.661 UTC [631] ERROR: relation "goose_db_version" does not exist at character 3610262026-08-29 17:01:54.661 UTC [631] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10272026/08/29 17:01:54 OK 20241026095416_initial_model.sql (11.79ms)10282026/08/29 17:01:54 OK 20241026095416_initial_model.sql (12.19ms)10292026/08/29 17:01:54 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)10302026/08/29 17:01:54 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)10312026/08/29 17:01:54 OK 20251218171726_add_pins.sql (4.1ms)10322026/08/29 17:01:54 OK 20251218171726_add_pins.sql (4.23ms)10332026/08/29 17:01:54 INFO Received uploads request method=POST path=/api/pending_closures10342026/08/29 17:01:54 OK 20260628120000_add_object_size_and_stats.sql (4.11ms)10352026/08/29 17:01:54 goose: successfully migrated database to version: 2026062812000010362026/08/29 17:01:54 OK 20260628120000_add_object_size_and_stats.sql (3.6ms)10372026/08/29 17:01:54 goose: successfully migrated database to version: 2026062812000010382026/08/29 17:01:54 OK 1_commit_pending_closure.sql (2.09ms)10392026/08/29 17:01:54 OK 1_commit_pending_closure.sql (2.47ms)10402026/08/29 17:01:54 OK 2_object_stats_trigger.sql (854.17µs)10412026/08/29 17:01:54 goose: up to current file version: 210422026/08/29 17:01:54 OK 2_object_stats_trigger.sql (957.19µs)10432026/08/29 17:01:54 goose: up to current file version: 210442026/08/29 17:01:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10452026/08/29 17:01:54 INFO Uploading yj4nhdy7lk3fjv3gw14389gdp2rk42d0-file1.txt (160B)10462026/08/29 17:01:54 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10472026/08/29 17:01:54 WARN Failed to register uploaded object key=yj4nhdy7lk3fjv3gw14389gdp2rk42d0.ls error="server returned 404: 404 page not found\n"10482026/08/29 17:01:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10492026/08/29 17:01:54 INFO Signed narinfos id=1 count=110502026/08/29 17:01:54 INFO Uploading 1 narinfos10512026/08/29 17:01:54 WARN Failed to register uploaded object key=yj4nhdy7lk3fjv3gw14389gdp2rk42d0.narinfo error="server returned 404: 404 page not found\n"10522026/08/29 17:01:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10532026/08/29 17:01:54 INFO Completed upload id=110542026/08/29 17:01:54 INFO Upload complete. (116ms)1055=== NAME TestNARDeduplicationMetadataUploadBug1056 metadata_upload_test.go:54: Retrieved narinfo from S3:1057 StorePath: /build/TestNARDeduplicationMetadataUploadBug4052144691/001/store/yj4nhdy7lk3fjv3gw14389gdp2rk42d0-file1.txt1058 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1059 Compression: zstd1060 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1061 NarSize: 1601062 References: 1063 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1064 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1065 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1066 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1067 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug4052144691/001/store/0isxgcgd7r2zv3zma0lzvbp3llg4wxg6-file2.txt10682026/08/29 17:01:54 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10692026/08/29 17:01:54 INFO Received uploads request method=POST path=/api/pending_closures10702026/08/29 17:01:54 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)10712026/08/29 17:01:54 WARN Failed to register uploaded object key=0isxgcgd7r2zv3zma0lzvbp3llg4wxg6.ls error="server returned 404: 404 page not found\n"10722026/08/29 17:01:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10732026/08/29 17:01:54 INFO Signed narinfos id=2 count=110742026/08/29 17:01:54 INFO Uploading 1 narinfos10752026/08/29 17:01:54 WARN Failed to register uploaded object key=0isxgcgd7r2zv3zma0lzvbp3llg4wxg6.narinfo error="server returned 404: 404 page not found\n"10762026/08/29 17:01:54 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10772026/08/29 17:01:54 INFO Completed upload id=210782026/08/29 17:01:54 INFO Upload complete. (96ms)1079 metadata_upload_test.go:76: Retrieved narinfo from S3:1080 StorePath: /build/TestNARDeduplicationMetadataUploadBug4052144691/001/store/0isxgcgd7r2zv3zma0lzvbp3llg4wxg6-file2.txt1081 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1082 Compression: zstd1083 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1084 NarSize: 1601085 References: 1086 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1087 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1088 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1089 {"version":1,"root":{"type":"regular","size":44}}1090--- PASS: TestNARDeduplicationMetadataUploadBug (1.40s)1091=== CONT TestReadProxyNarStreaming10922026-08-29 17:01:54.965 UTC [722] ERROR: relation "goose_db_version" does not exist at character 3610932026-08-29 17:01:54.965 UTC [722] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10942026/08/29 17:01:54 OK 20241026095416_initial_model.sql (10.35ms)10952026/08/29 17:01:54 OK 20251210153512_drop_unused_gin_index.sql (1.47ms)10962026/08/29 17:01:54 OK 20251218171726_add_pins.sql (2.56ms)10972026/08/29 17:01:54 OK 20260628120000_add_object_size_and_stats.sql (2.74ms)10982026/08/29 17:01:54 goose: successfully migrated database to version: 2026062812000010992026/08/29 17:01:54 OK 1_commit_pending_closure.sql (1.82ms)11002026/08/29 17:01:54 OK 2_object_stats_trigger.sql (845.73µs)11012026/08/29 17:01:54 goose: up to current file version: 211022026/08/29 17:01:55 INFO Received uploads request method=POST path=/api/pending_closures11032026/08/29 17:01:55 INFO Received cleanup request method=DELETE path=/api/pending_closures11042026/08/29 17:01:55 INFO Aborted multipart uploads count=011052026/08/29 17:01:55 INFO Received uploads request method=POST path=/api/pending_closures11062026/08/29 17:01:55 INFO Received cleanup request method=DELETE path=/api/pending_closures11072026/08/29 17:01:55 INFO Aborted multipart uploads count=111082026/08/29 17:01:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11092026-08-29 17:01:55.262 UTC [541] ERROR: Closure does not exist: id=111102026-08-29 17:01:55.262 UTC [541] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE11112026-08-29 17:01:55.262 UTC [541] STATEMENT: -- name: CommitPendingClosure :exec1112 SELECT commit_pending_closure($1::bigint)1113 1114--- PASS: TestService_cleanupPendingClosuresHandler (1.76s)1115=== CONT TestResurrectedObjectNotDeleted1116--- PASS: TestMetricsInventory (1.76s)1117=== CONT TestReadProxyNarinfo11182026/08/29 17:01:55 INFO Received uploads request method=POST path=/api/pending_closures11192026-08-29 17:01:55.349 UTC [731] ERROR: relation "goose_db_version" does not exist at character 3611202026-08-29 17:01:55.349 UTC [731] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11212026-08-29 17:01:55.349 UTC [732] ERROR: relation "goose_db_version" does not exist at character 3611222026-08-29 17:01:55.349 UTC [732] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11232026/08/29 17:01:55 OK 20241026095416_initial_model.sql (10.29ms)11242026/08/29 17:01:55 OK 20241026095416_initial_model.sql (10.36ms)11252026/08/29 17:01:55 OK 20251210153512_drop_unused_gin_index.sql (1.54ms)11262026/08/29 17:01:55 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)11272026/08/29 17:01:55 OK 20251218171726_add_pins.sql (4.3ms)11282026/08/29 17:01:55 OK 20251218171726_add_pins.sql (4.57ms)11292026/08/29 17:01:55 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)11302026/08/29 17:01:55 goose: successfully migrated database to version: 2026062812000011312026/08/29 17:01:55 OK 20260628120000_add_object_size_and_stats.sql (3.38ms)11322026/08/29 17:01:55 goose: successfully migrated database to version: 2026062812000011332026/08/29 17:01:55 OK 1_commit_pending_closure.sql (2.04ms)11342026/08/29 17:01:55 OK 1_commit_pending_closure.sql (2.13ms)11352026/08/29 17:01:55 OK 2_object_stats_trigger.sql (907.47µs)11362026/08/29 17:01:55 goose: up to current file version: 211372026/08/29 17:01:55 OK 2_object_stats_trigger.sql (1.28ms)11382026/08/29 17:01:55 goose: up to current file version: 211392026/08/29 17:01:55 INFO Received uploads request method=POST path=/api/pending_closures11402026/08/29 17:01:55 INFO Received uploads request method=POST path=/api/pending_closures11412026/08/29 17:01:55 WARN readiness check failed error="closed pool"1142--- PASS: TestService_readinessHandler (2.43s)1143=== CONT TestIsValidCachePath1144=== RUN TestIsValidCachePath/narinfo1145=== PAUSE TestIsValidCachePath/narinfo1146=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1147=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1148=== RUN TestIsValidCachePath/nar_zst1149=== PAUSE TestIsValidCachePath/nar_zst1150=== RUN TestIsValidCachePath/nar_xz1151=== PAUSE TestIsValidCachePath/nar_xz1152=== RUN TestIsValidCachePath/nar_bz21153=== PAUSE TestIsValidCachePath/nar_bz21154=== RUN TestIsValidCachePath/nar_uncompressed1155=== PAUSE TestIsValidCachePath/nar_uncompressed1156=== RUN TestIsValidCachePath/ls1157=== PAUSE TestIsValidCachePath/ls1158=== RUN TestIsValidCachePath/log1159=== PAUSE TestIsValidCachePath/log1160=== RUN TestIsValidCachePath/realisation1161=== PAUSE TestIsValidCachePath/realisation1162=== RUN TestIsValidCachePath/nix-cache-info1163=== PAUSE TestIsValidCachePath/nix-cache-info1164=== RUN TestIsValidCachePath/index.html1165=== PAUSE TestIsValidCachePath/index.html1166=== RUN TestIsValidCachePath/traversal_parent1167=== PAUSE TestIsValidCachePath/traversal_parent1168=== RUN TestIsValidCachePath/traversal_in_middle1169=== PAUSE TestIsValidCachePath/traversal_in_middle1170=== RUN TestIsValidCachePath/invalid_char_e1171=== PAUSE TestIsValidCachePath/invalid_char_e1172=== RUN TestIsValidCachePath/invalid_char_u1173=== PAUSE TestIsValidCachePath/invalid_char_u1174=== RUN TestIsValidCachePath/random_path1175=== PAUSE TestIsValidCachePath/random_path1176=== RUN TestIsValidCachePath/empty1177=== PAUSE TestIsValidCachePath/empty1178=== RUN TestIsValidCachePath/leading_slash1179=== PAUSE TestIsValidCachePath/leading_slash1180=== RUN TestIsValidCachePath/wrong_extension1181=== PAUSE TestIsValidCachePath/wrong_extension1182=== RUN TestIsValidCachePath/short_hash1183=== PAUSE TestIsValidCachePath/short_hash1184=== CONT TestParseSingleRange1185=== RUN TestParseSingleRange/none1186=== PAUSE TestParseSingleRange/none1187=== RUN TestParseSingleRange/unknown_unit1188=== PAUSE TestParseSingleRange/unknown_unit1189=== RUN TestParseSingleRange/multi-range_ignored1190=== PAUSE TestParseSingleRange/multi-range_ignored1191=== RUN TestParseSingleRange/malformed_no_dash1192=== PAUSE TestParseSingleRange/malformed_no_dash1193=== RUN TestParseSingleRange/malformed_both_empty1194=== PAUSE TestParseSingleRange/malformed_both_empty1195=== RUN TestParseSingleRange/malformed_end_before_start1196=== PAUSE TestParseSingleRange/malformed_end_before_start1197=== RUN TestParseSingleRange/closed1198=== PAUSE TestParseSingleRange/closed1199=== RUN TestParseSingleRange/open-ended1200=== PAUSE TestParseSingleRange/open-ended1201=== RUN TestParseSingleRange/end_clamped_to_size1202=== PAUSE TestParseSingleRange/end_clamped_to_size1203=== RUN TestParseSingleRange/suffix1204=== PAUSE TestParseSingleRange/suffix1205=== RUN TestParseSingleRange/suffix_exceeds_size1206=== PAUSE TestParseSingleRange/suffix_exceeds_size1207=== RUN TestParseSingleRange/single_byte1208=== PAUSE TestParseSingleRange/single_byte1209=== RUN TestParseSingleRange/start_past_EOF1210=== PAUSE TestParseSingleRange/start_past_EOF1211=== RUN TestParseSingleRange/start_far_past_EOF1212=== PAUSE TestParseSingleRange/start_far_past_EOF1213=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12142026/08/29 17:01:55 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12152026/08/29 17:01:55 INFO Received uploads request method=POST path=/api/pending_closures1216--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.38s)1217=== CONT TestService_AuthMiddleware_MTLSProxyHeader12182026/08/29 17:01:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12192026/08/29 17:01:55 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTQ2YzZhYTgtZmEzNy00ZDhkLTg5NjEtZjMyOTI3M2U2ZTQ3LjhkMGQyYWMzLTE4MWQtNDFkMy1iMTU1LWUyYTk0YzAzZjZlYXgxNzg4MDIyOTE1OTE1ODUwMDg112202026/08/29 17:01:55 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTQ2YzZhYTgtZmEzNy00ZDhkLTg5NjEtZjMyOTI3M2U2ZTQ3LjhkMGQyYWMzLTE4MWQtNDFkMy1iMTU1LWUyYTk0YzAzZjZlYXgxNzg4MDIyOTE1OTE1ODUwMDg1 parts=11221--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.46s)1222=== CONT TestOrphanedObjectsGC12232026/08/29 17:01:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12242026/08/29 17:01:55 INFO Received uploads request method=POST path=/api/pending_closures1225--- PASS: TestService_ReadAuthMiddleware (2.42s)1226=== CONT TestOrphanedObjectsGCStressTest1227--- PASS: TestService_healthCheckHandler (2.51s)1228=== CONT TestService_Rustfstest12292026-08-29 17:01:56.020 UTC [760] ERROR: relation "goose_db_version" does not exist at character 3612302026-08-29 17:01:56.020 UTC [760] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12312026/08/29 17:01:56 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1232--- PASS: TestService_AuthMiddleware (2.47s)1233=== CONT TestClientWithDependencies12342026-08-29 17:01:56.038 UTC [762] ERROR: relation "goose_db_version" does not exist at character 3612352026-08-29 17:01:56.038 UTC [762] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12362026/08/29 17:01:56 OK 20241026095416_initial_model.sql (17.9ms)12372026/08/29 17:01:56 OK 20251210153512_drop_unused_gin_index.sql (5.89ms)12382026-08-29 17:01:56.056 UTC [782] ERROR: relation "goose_db_version" does not exist at character 3612392026-08-29 17:01:56.056 UTC [782] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12402026/08/29 17:01:56 OK 20251218171726_add_pins.sql (6.6ms)1241=== NAME TestClientCADerivations1242 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1969891515/001/store/rchl8p7azpf57wld0c14agzs4v4b0ws1-ca-test12432026/08/29 17:01:56 OK 20241026095416_initial_model.sql (13.11ms)12442026/08/29 17:01:56 OK 20260628120000_add_object_size_and_stats.sql (6.5ms)12452026/08/29 17:01:56 goose: successfully migrated database to version: 2026062812000012462026/08/29 17:01:56 OK 20251210153512_drop_unused_gin_index.sql (3.5ms)12472026/08/29 17:01:56 OK 1_commit_pending_closure.sql (3.26ms)12482026/08/29 17:01:56 OK 2_object_stats_trigger.sql (2.66ms)12492026/08/29 17:01:56 goose: up to current file version: 212502026/08/29 17:01:56 OK 20251218171726_add_pins.sql (4.8ms)12512026/08/29 17:01:56 OK 20241026095416_initial_model.sql (11.78ms)1252=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1253=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1254=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1255=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1256=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1257=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1258=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1259=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1260=== CONT TestGCBugBareHashReferences1261--- PASS: TestCacheStatsHandler (2.41s)1262=== CONT TestResolveDBConnectionString1263=== RUN TestResolveDBConnectionString/flag_wins12642026/08/29 17:01:56 OK 20260628120000_add_object_size_and_stats.sql (5.53ms)1265=== PAUSE TestResolveDBConnectionString/flag_wins12662026/08/29 17:01:56 goose: successfully migrated database to version: 202606281200001267=== RUN TestResolveDBConnectionString/file_when_flag_empty1268=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1269=== RUN TestResolveDBConnectionString/missing_file_is_an_error1270=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1271=== RUN TestResolveDBConnectionString/PGHOST_allows_empty12722026/08/29 17:01:56 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)1273=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1274=== RUN TestResolveDBConnectionString/nothing_configured1275=== PAUSE TestResolveDBConnectionString/nothing_configured1276=== CONT TestPinProtectsFromGC12772026-08-29 17:01:56.081 UTC [784] ERROR: relation "goose_db_version" does not exist at character 3612782026-08-29 17:01:56.081 UTC [784] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12792026/08/29 17:01:56 OK 1_commit_pending_closure.sql (4.25ms)12802026/08/29 17:01:56 OK 20251218171726_add_pins.sql (5.45ms)12812026/08/29 17:01:56 OK 2_object_stats_trigger.sql (2.9ms)12822026/08/29 17:01:56 goose: up to current file version: 212832026/08/29 17:01:56 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)12842026/08/29 17:01:56 goose: successfully migrated database to version: 2026062812000012852026/08/29 17:01:56 OK 1_commit_pending_closure.sql (5.35ms)1286=== NAME TestClientCADerivations1287 client_ca_test.go:139: Found 1 dependencies (including self)12882026/08/29 17:01:56 OK 2_object_stats_trigger.sql (4.16ms)12892026/08/29 17:01:56 goose: up to current file version: 212902026/08/29 17:01:56 OK 20241026095416_initial_model.sql (15.09ms)1291--- PASS: TestService_ReadScope_PublicByDefault (1.70s)1292=== CONT TestObjectStatsTrigger12932026/08/29 17:01:56 OK 20251210153512_drop_unused_gin_index.sql (2.22ms)12942026-08-29 17:01:56.109 UTC [805] ERROR: relation "goose_db_version" does not exist at character 3612952026-08-29 17:01:56.109 UTC [805] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12962026/08/29 17:01:56 OK 20251218171726_add_pins.sql (4.1ms)12972026-08-29 17:01:56.115 UTC [808] ERROR: relation "goose_db_version" does not exist at character 3612982026-08-29 17:01:56.115 UTC [808] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12992026/08/29 17:01:56 OK 20260628120000_add_object_size_and_stats.sql (5.76ms)13002026/08/29 17:01:56 goose: successfully migrated database to version: 2026062812000013012026/08/29 17:01:56 OK 1_commit_pending_closure.sql (4.72ms)13022026/08/29 17:01:56 OK 2_object_stats_trigger.sql (2.77ms)13032026/08/29 17:01:56 goose: up to current file version: 213042026/08/29 17:01:56 OK 20241026095416_initial_model.sql (15.69ms)13052026/08/29 17:01:56 OK 20241026095416_initial_model.sql (19.09ms)13062026/08/29 17:01:56 OK 20251210153512_drop_unused_gin_index.sql (11.58ms)13072026/08/29 17:01:56 OK 20251210153512_drop_unused_gin_index.sql (5.26ms)13082026/08/29 17:01:56 OK 20251218171726_add_pins.sql (6.22ms)13092026/08/29 17:01:56 OK 20251218171726_add_pins.sql (5.19ms)13102026/08/29 17:01:56 OK 20260628120000_add_object_size_and_stats.sql (6.54ms)13112026/08/29 17:01:56 goose: successfully migrated database to version: 2026062812000013122026/08/29 17:01:56 OK 20260628120000_add_object_size_and_stats.sql (5.85ms)13132026/08/29 17:01:56 goose: successfully migrated database to version: 2026062812000013142026/08/29 17:01:56 OK 1_commit_pending_closure.sql (4.54ms)13152026/08/29 17:01:56 OK 1_commit_pending_closure.sql (5.72ms)13162026/08/29 17:01:56 OK 2_object_stats_trigger.sql (4.5ms)13172026/08/29 17:01:56 goose: up to current file version: 213182026/08/29 17:01:56 OK 2_object_stats_trigger.sql (3.95ms)13192026/08/29 17:01:56 goose: up to current file version: 213202026/08/29 17:01:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13212026-08-29 17:01:56.180 UTC [834] ERROR: relation "goose_db_version" does not exist at character 3613222026-08-29 17:01:56.180 UTC [834] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13232026-08-29 17:01:56.183 UTC [846] ERROR: relation "goose_db_version" does not exist at character 3613242026-08-29 17:01:56.183 UTC [846] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13252026-08-29 17:01:56.199 UTC [848] ERROR: relation "goose_db_version" does not exist at character 3613262026-08-29 17:01:56.199 UTC [848] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13272026/08/29 17:01:56 OK 20241026095416_initial_model.sql (11.49ms)13282026/08/29 17:01:56 OK 20241026095416_initial_model.sql (11.88ms)13292026/08/29 17:01:56 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)13302026/08/29 17:01:56 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)13312026/08/29 17:01:56 OK 20251218171726_add_pins.sql (3.9ms)13322026/08/29 17:01:56 OK 20251218171726_add_pins.sql (3.98ms)13332026/08/29 17:01:56 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)13342026/08/29 17:01:56 goose: successfully migrated database to version: 2026062812000013352026/08/29 17:01:56 OK 20260628120000_add_object_size_and_stats.sql (4.27ms)13362026/08/29 17:01:56 goose: successfully migrated database to version: 2026062812000013372026/08/29 17:01:56 OK 1_commit_pending_closure.sql (2.04ms)13382026/08/29 17:01:56 OK 1_commit_pending_closure.sql (2.14ms)13392026/08/29 17:01:56 OK 2_object_stats_trigger.sql (1.26ms)13402026/08/29 17:01:56 goose: up to current file version: 213412026/08/29 17:01:56 OK 2_object_stats_trigger.sql (1.5ms)13422026/08/29 17:01:56 goose: up to current file version: 213432026/08/29 17:01:56 OK 20241026095416_initial_model.sql (9.9ms)13442026/08/29 17:01:56 INFO Received uploads request method=POST path=/api/pending_closures13452026/08/29 17:01:56 OK 20251210153512_drop_unused_gin_index.sql (1.47ms)13462026/08/29 17:01:56 OK 20251218171726_add_pins.sql (2.87ms)13472026/08/29 17:01:56 OK 20260628120000_add_object_size_and_stats.sql (2.71ms)13482026/08/29 17:01:56 goose: successfully migrated database to version: 2026062812000013492026/08/29 17:01:56 OK 1_commit_pending_closure.sql (2.88ms)13502026/08/29 17:01:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13512026/08/29 17:01:56 INFO Uploading rchl8p7azpf57wld0c14agzs4v4b0ws1-ca-test (144B)13522026/08/29 17:01:56 OK 2_object_stats_trigger.sql (1.25ms)13532026/08/29 17:01:56 goose: up to current file version: 213542026/08/29 17:01:56 WARN Failed to register uploaded object key=log/zvh87jk9zgw6a84md30ilbz26a4d56f7-ca-test.drv error="server returned 404: 404 page not found\n"13552026/08/29 17:01:56 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13562026/08/29 17:01:56 WARN Failed to register uploaded object key=rchl8p7azpf57wld0c14agzs4v4b0ws1.ls error="server returned 404: 404 page not found\n"13572026/08/29 17:01:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13582026/08/29 17:01:56 INFO Signed narinfos id=1 count=113592026/08/29 17:01:56 INFO Uploading 1 narinfos13602026/08/29 17:01:56 WARN Failed to register uploaded object key=rchl8p7azpf57wld0c14agzs4v4b0ws1.narinfo error="server returned 404: 404 page not found\n"13612026/08/29 17:01:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13622026/08/29 17:01:56 INFO Completed upload id=113632026/08/29 17:01:56 INFO Upload complete. (303ms)1364=== NAME TestClientCADerivations1365 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1969891515/001/store/rchl8p7azpf57wld0c14agzs4v4b0ws1-ca-test1366 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1367 Compression: zstd1368 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1369 NarSize: 1441370 References: 1371 Deriver: /build/TestClientCADerivations1969891515/001/store/zvh87jk9zgw6a84md30ilbz26a4d56f7-ca-test.drv1372 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1373 client_ca_test.go:185: Checking for realisation files in S3...1374 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1375 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1376 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1377 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1378 error: binary cache 's3://bucket19?endpoint=http://localhost:45641®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1969891515/001/store'1379 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11380--- PASS: TestClientCADerivations (3.10s)1381=== CONT TestGCTaskStore_DeduplicateSameParams1382--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1383=== CONT TestGCTaskStore_ConflictDifferentParams1384--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1385=== CONT TestReadRedirectKeepsNarinfoProxied13862026/08/29 17:01:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13872026/08/29 17:01:56 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NTQ2YzZhYTgtZmEzNy00ZDhkLTg5NjEtZjMyOTI3M2U2ZTQ3LmZjYzdjOWE1LTQzNmMtNDAyMi04YWY4LWI2NzM5ZDc4NjljNXgxNzg4MDIyOTE0NTQzNjUxMDQ4 parts=1013882026/08/29 17:01:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13892026/08/29 17:01:56 INFO Completed upload id=113902026/08/29 17:01:56 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013912026/08/29 17:01:56 INFO Received uploads request method=POST path=/api/pending_closures13922026/08/29 17:01:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures13932026/08/29 17:01:56 INFO Aborted multipart uploads count=013942026/08/29 17:01:56 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=013952026/08/29 17:01:56 INFO Vacuumed table table=pending_closures13962026/08/29 17:01:56 INFO Vacuumed table table=pending_objects13972026/08/29 17:01:56 INFO Vacuumed table table=multipart_uploads13982026/08/29 17:01:56 INFO Vacuumed table table=closures13992026/08/29 17:01:56 INFO Vacuumed table table=objects14002026-08-29 17:01:56.703 UTC [999] ERROR: relation "goose_db_version" does not exist at character 3614012026-08-29 17:01:56.703 UTC [999] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14022026/08/29 17:01:56 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001403--- PASS: TestService_createPendingClosureHandler (3.21s)1404=== CONT TestReadProxyRangeRequest14052026/08/29 17:01:56 OK 20241026095416_initial_model.sql (11.29ms)14062026/08/29 17:01:56 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)14072026/08/29 17:01:56 OK 20251218171726_add_pins.sql (4.36ms)14082026/08/29 17:01:56 OK 20260628120000_add_object_size_and_stats.sql (5.13ms)14092026/08/29 17:01:56 goose: successfully migrated database to version: 2026062812000014102026/08/29 17:01:56 OK 1_commit_pending_closure.sql (2.79ms)14112026/08/29 17:01:56 OK 2_object_stats_trigger.sql (2.56ms)14122026/08/29 17:01:56 goose: up to current file version: 214132026-08-29 17:01:56.809 UTC [1002] ERROR: relation "goose_db_version" does not exist at character 3614142026-08-29 17:01:56.809 UTC [1002] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14152026/08/29 17:01:56 OK 20241026095416_initial_model.sql (10.37ms)14162026/08/29 17:01:56 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)14172026/08/29 17:01:56 OK 20251218171726_add_pins.sql (3.27ms)1418--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.42s)1419=== CONT TestGCTaskStore_StartNew1420--- PASS: TestGCTaskStore_StartNew (0.00s)1421=== CONT TestClientIntegration14222026/08/29 17:01:56 OK 20260628120000_add_object_size_and_stats.sql (5.95ms)14232026/08/29 17:01:56 goose: successfully migrated database to version: 2026062812000014242026/08/29 17:01:56 OK 1_commit_pending_closure.sql (2.06ms)14252026/08/29 17:01:56 OK 2_object_stats_trigger.sql (1.11ms)14262026/08/29 17:01:56 goose: up to current file version: 21427--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.37s)1428=== CONT TestClientMultipleUploads1429--- PASS: TestReadProxyConditionalGet (2.38s)1430=== CONT TestReadRedirectNar1431--- PASS: TestReadProxyHead (2.36s)1432=== CONT TestClientErrorHandling1433=== RUN TestClientErrorHandling/InvalidStorePath1434=== PAUSE TestClientErrorHandling/InvalidStorePath1435=== RUN TestClientErrorHandling/InvalidAuthToken1436=== PAUSE TestClientErrorHandling/InvalidAuthToken1437=== RUN TestClientErrorHandling/ServerNotAvailable1438=== PAUSE TestClientErrorHandling/ServerNotAvailable1439=== CONT TestService_RequireScope_OIDC14402026/08/29 17:01:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39879/oidc1441--- PASS: TestReadProxyInvalidPath (2.32s)1442=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14432026/08/29 17:01:56 INFO Received uploads request method=POST path=/1444=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14452026/08/29 17:01:56 INFO Received complete multipart upload request method=POST path=/1446=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14472026/08/29 17:01:56 INFO Received request for more parts method=POST path=/1448=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14492026/08/29 17:01:56 INFO Received uploads request method=POST path=/1450--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1451 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1452 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1453 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1454 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1455=== CONT TestServerTLSConfig/no_client_CA1456=== CONT TestServerTLSConfig/not_a_PEM_file1457=== CONT TestServerTLSConfig/missing_CA_file1458--- PASS: TestServerTLSConfig (0.06s)1459 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1460 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1461 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1462=== CONT TestIsValidUploadKey/narinfo1463=== CONT TestIsValidUploadKey/unknown_type1464=== CONT TestIsValidUploadKey/empty_key1465=== CONT TestIsValidUploadKey/absolute1466=== CONT TestIsValidUploadKey/traversal_nar1467=== CONT TestIsValidUploadKey/traversal1468=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1469=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1470=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1471=== CONT TestIsValidUploadKey/index.html1472=== CONT TestIsValidUploadKey/nix-cache-info1473=== CONT TestIsValidUploadKey/realisation_plus_in_output1474=== CONT TestIsValidUploadKey/realisation1475=== CONT TestIsValidUploadKey/build_log_equals1476=== CONT TestIsValidUploadKey/build_log_question_mark1477=== CONT TestIsValidUploadKey/build_log_plus_in_name1478=== CONT TestIsValidUploadKey/build_log_home-manager_file1479=== CONT TestIsValidUploadKey/build_log1480=== CONT TestIsValidUploadKey/listing1481=== CONT TestIsValidUploadKey/nar_plain1482=== CONT TestIsValidUploadKey/nar_xz1483=== CONT TestIsValidUploadKey/nar_zst1484--- PASS: TestIsValidUploadKey (0.00s)1485 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1486 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1487 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1488 --- PASS: TestIsValidUploadKey/absolute (0.00s)1489 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1490 --- PASS: TestIsValidUploadKey/traversal (0.00s)1491 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1492 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1493 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1494 --- PASS: TestIsValidUploadKey/index.html (0.00s)1495 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1496 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1497 --- PASS: TestIsValidUploadKey/realisation (0.00s)1498 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1499 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1500 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1501 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1502 --- PASS: TestIsValidUploadKey/build_log (0.00s)1503 --- PASS: TestIsValidUploadKey/listing (0.00s)1504 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1505 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1506 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1507=== CONT TestProxyWriteTimeout/narinfo1508=== CONT TestProxyWriteTimeout/10_GiB_nar1509=== CONT TestProxyWriteTimeout/unknown_size1510=== CONT TestProxyWriteTimeout/1_GiB_nar1511--- PASS: TestProxyWriteTimeout (0.00s)1512 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1513 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1514 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1515 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1516=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15172026/08/29 17:01:56 INFO Received uploads request method=POST path=/1518--- PASS: TestReadProxy404 (2.33s)1519=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15202026/08/29 17:01:56 INFO Received request for more parts method=POST path=/15212026-08-29 17:01:56.918 UTC [1011] ERROR: relation "goose_db_version" does not exist at character 3615222026-08-29 17:01:56.918 UTC [1011] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1523--- PASS: TestReadProxyNarStreaming (2.03s)1524=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15252026/08/29 17:01:56 INFO Received complete multipart upload request method=POST path=/15262026-08-29 17:01:56.937 UTC [1012] ERROR: relation "goose_db_version" does not exist at character 3615272026-08-29 17:01:56.937 UTC [1012] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1528--- PASS: TestReadProxyNarinfo (1.68s)1529=== CONT TestCacheConfigHandler/full_config,_no_issuer1530=== CONT TestCacheConfigHandler/no_signing_keys1531=== CONT TestCacheConfigHandler/no_cache_url_configured1532=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1533--- PASS: TestCacheConfigHandler (0.00s)1534 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1535 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1536 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1537 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1538=== CONT TestIsValidCachePath/wrong_extension1539=== CONT TestIsValidCachePath/narinfo1540=== CONT TestIsValidCachePath/leading_slash1541=== CONT TestIsValidCachePath/empty1542=== CONT TestIsValidCachePath/random_path1543=== CONT TestIsValidCachePath/invalid_char_u1544=== CONT TestIsValidCachePath/short_hash1545=== CONT TestIsValidCachePath/invalid_char_e1546=== CONT TestIsValidCachePath/traversal_in_middle1547=== CONT TestIsValidCachePath/nar_uncompressed1548=== CONT TestIsValidCachePath/ls1549=== CONT TestIsValidCachePath/nar_bz21550=== CONT TestIsValidCachePath/traversal_parent1551=== CONT TestIsValidCachePath/nar_xz1552=== CONT TestIsValidCachePath/index.html1553=== CONT TestIsValidCachePath/nar_zst1554=== CONT TestIsValidCachePath/nix-cache-info1555=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1556=== CONT TestIsValidCachePath/realisation1557=== CONT TestIsValidCachePath/log1558--- PASS: TestIsValidCachePath (0.00s)1559 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1560 --- PASS: TestIsValidCachePath/narinfo (0.00s)1561 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1562 --- PASS: TestIsValidCachePath/empty (0.00s)1563 --- PASS: TestIsValidCachePath/random_path (0.00s)1564 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1565 --- PASS: TestIsValidCachePath/short_hash (0.00s)1566 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1567 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1568 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1569 --- PASS: TestIsValidCachePath/ls (0.00s)1570 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1571 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1572 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1573 --- PASS: TestIsValidCachePath/index.html (0.00s)1574 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1575 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1576 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1577 --- PASS: TestIsValidCachePath/realisation (0.00s)1578 --- PASS: TestIsValidCachePath/log (0.00s)1579=== CONT TestParseSingleRange/none1580=== CONT TestParseSingleRange/open-ended1581=== CONT TestParseSingleRange/start_far_past_EOF1582=== CONT TestParseSingleRange/start_past_EOF1583=== CONT TestParseSingleRange/single_byte1584=== CONT TestParseSingleRange/suffix_exceeds_size1585=== CONT TestParseSingleRange/suffix1586=== CONT TestParseSingleRange/end_clamped_to_size1587=== CONT TestParseSingleRange/malformed_both_empty1588=== CONT TestParseSingleRange/closed1589=== CONT TestParseSingleRange/multi-range_ignored1590=== CONT TestParseSingleRange/malformed_end_before_start1591=== CONT TestParseSingleRange/malformed_no_dash1592=== CONT TestParseSingleRange/unknown_unit1593--- PASS: TestParseSingleRange (0.00s)1594 --- PASS: TestParseSingleRange/none (0.00s)1595 --- PASS: TestParseSingleRange/open-ended (0.00s)1596 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1597 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1598 --- PASS: TestParseSingleRange/single_byte (0.00s)1599 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1600 --- PASS: TestParseSingleRange/suffix (0.00s)1601 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1602 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1603 --- PASS: TestParseSingleRange/closed (0.00s)1604 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1605 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1606 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1607 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1608=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token16092026/08/29 17:01:56 OK 20241026095416_initial_model.sql (19.18ms)16102026/08/29 17:01:56 OK 20251210153512_drop_unused_gin_index.sql (3.82ms)16112026/08/29 17:01:56 INFO OIDC auth successful provider=test scopes=[write]1612=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1613=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected16142026/08/29 17:01:56 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]1615=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16162026/08/29 17:01:56 OK 20251218171726_add_pins.sql (5.81ms)16172026-08-29 17:01:56.961 UTC [1013] ERROR: relation "goose_db_version" does not exist at character 3616182026-08-29 17:01:56.961 UTC [1013] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16192026/08/29 17:01:56 OK 20241026095416_initial_model.sql (12.1ms)16202026/08/29 17:01:56 WARN Authentication failed token_preview=eyJhbGciOi...NPTsznpSLA token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]16212026/08/29 17:01:56 OK 20260628120000_add_object_size_and_stats.sql (5.62ms)1622=== CONT TestResolveDBConnectionString/flag_wins16232026/08/29 17:01:56 goose: successfully migrated database to version: 202606281200001624=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1625=== CONT TestResolveDBConnectionString/nothing_configured1626=== CONT TestResolveDBConnectionString/missing_file_is_an_error1627=== CONT TestResolveDBConnectionString/file_when_flag_empty1628=== CONT TestClientErrorHandling/InvalidStorePath1629--- PASS: TestService_AuthMiddleware_OIDC (2.50s)1630 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)1631 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1632 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1633 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)1634--- PASS: TestResolveDBConnectionString (0.00s)1635 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1636 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1637 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1638 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1639 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)16402026/08/29 17:01:56 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)16412026/08/29 17:01:56 OK 1_commit_pending_closure.sql (2.1ms)16422026/08/29 17:01:56 OK 2_object_stats_trigger.sql (1.24ms)16432026/08/29 17:01:56 goose: up to current file version: 21644=== CONT TestClientErrorHandling/ServerNotAvailable16452026/08/29 17:01:56 OK 20251218171726_add_pins.sql (2.9ms)16462026/08/29 17:01:56 OK 20260628120000_add_object_size_and_stats.sql (5.63ms)16472026/08/29 17:01:56 goose: successfully migrated database to version: 2026062812000016482026/08/29 17:01:56 OK 20241026095416_initial_model.sql (8.84ms)16492026/08/29 17:01:56 OK 1_commit_pending_closure.sql (2.23ms)16502026-08-29 17:01:56.976 UTC [1017] ERROR: relation "goose_db_version" does not exist at character 3616512026-08-29 17:01:56.976 UTC [1017] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16522026/08/29 17:01:56 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)16532026/08/29 17:01:56 OK 2_object_stats_trigger.sql (1.21ms)16542026/08/29 17:01:56 goose: up to current file version: 216552026/08/29 17:01:56 OK 20251218171726_add_pins.sql (5.01ms)16562026/08/29 17:01:56 OK 20260628120000_add_object_size_and_stats.sql (4.17ms)16572026/08/29 17:01:56 goose: successfully migrated database to version: 2026062812000016582026/08/29 17:01:56 OK 1_commit_pending_closure.sql (3.34ms)16592026/08/29 17:01:56 OK 2_object_stats_trigger.sql (2.19ms)16602026/08/29 17:01:56 goose: up to current file version: 216612026/08/29 17:01:56 OK 20241026095416_initial_model.sql (11.47ms)16622026/08/29 17:01:56 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)1663=== CONT TestClientErrorHandling/InvalidAuthToken16642026/08/29 17:01:57 OK 20251218171726_add_pins.sql (3.88ms)16652026/08/29 17:01:57 OK 20260628120000_add_object_size_and_stats.sql (5.03ms)16662026/08/29 17:01:57 goose: successfully migrated database to version: 2026062812000016672026/08/29 17:01:57 OK 1_commit_pending_closure.sql (2.92ms)16682026/08/29 17:01:57 OK 2_object_stats_trigger.sql (1.81ms)16692026/08/29 17:01:57 goose: up to current file version: 216702026-08-29 17:01:57.040 UTC [1037] ERROR: relation "goose_db_version" does not exist at character 3616712026-08-29 17:01:57.040 UTC [1037] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16722026/08/29 17:01:57 OK 20241026095416_initial_model.sql (12.73ms)16732026/08/29 17:01:57 OK 20251210153512_drop_unused_gin_index.sql (1.61ms)16742026/08/29 17:01:57 OK 20251218171726_add_pins.sql (3.02ms)16752026/08/29 17:01:57 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)16762026/08/29 17:01:57 goose: successfully migrated database to version: 2026062812000016772026/08/29 17:01:57 OK 1_commit_pending_closure.sql (2.1ms)16782026/08/29 17:01:57 OK 2_object_stats_trigger.sql (1.91ms)16792026-08-29 17:01:57.073 UTC [1056] ERROR: relation "goose_db_version" does not exist at character 3616802026-08-29 17:01:57.073 UTC [1056] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16812026/08/29 17:01:57 goose: up to current file version: 216822026/08/29 17:01:57 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-config16832026/08/29 17:01:57 OK 20241026095416_initial_model.sql (10.93ms)16842026/08/29 17:01:57 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)16852026/08/29 17:01:57 OK 20251218171726_add_pins.sql (3.22ms)16862026/08/29 17:01:57 OK 20260628120000_add_object_size_and_stats.sql (2.99ms)16872026/08/29 17:01:57 goose: successfully migrated database to version: 2026062812000016882026/08/29 17:01:57 OK 1_commit_pending_closure.sql (1.85ms)16892026/08/29 17:01:57 OK 2_object_stats_trigger.sql (820.25µs)16902026/08/29 17:01:57 goose: up to current file version: 216912026/08/29 17:01:57 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=216.376287ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config16922026/08/29 17:01:57 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=425.125029ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config16932026/08/29 17:01:57 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16942026/08/29 17:01:57 WARN mTLS auth: bound subjects configured but subject DN unavailable16952026/08/29 17:01:57 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1696--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.67s)1697--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.68s)1698--- PASS: TestResurrectedObjectNotDeleted (2.37s)1699--- PASS: TestService_Rustfstest (1.64s)17002026/08/29 17:01:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17012026/08/29 17:01:57 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NTQ2YzZhYTgtZmEzNy00ZDhkLTg5NjEtZjMyOTI3M2U2ZTQ3LmM3OTJhNjc2LWI0MzYtNDkyMy05NDE4LTk2MzYyNGNkNGJhMngxNzg4MDIyOTE0NTYxMzU0MjYw parts=121702--- PASS: TestRedundantMultipartUpload (4.19s)1703--- PASS: TestObjectStatsTrigger (1.61s)1704--- PASS: TestReadRedirectKeepsNarinfoProxied (1.11s)17052026/08/29 17:01:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1706--- PASS: TestReadProxyRangeRequest (1.03s)1707=== NAME TestClientWithDependencies1708 client_integration_test.go:594: Built derivation: /build/TestClientWithDependencies1888515871/001/store/zfb4pr2rpkxbvzpf1w6h259jg842bsli-test-script17092026/08/29 17:01:57 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NTQ2YzZhYTgtZmEzNy00ZDhkLTg5NjEtZjMyOTI3M2U2ZTQ3LjEyMTUxMWFiLTA2NTgtNGJiZS04MmMyLWZiOGQ2MTM1OWViN3gxNzg4MDIyOTE1OTkxOTM4NTE1 parts=1017102026/08/29 17:01:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17112026/08/29 17:01:57 INFO Completed upload id=11712=== NAME TestClientIntegration1713 client_integration_test.go:277: Created store path: /build/TestClientIntegration505768983/002/store/a3c9b9if9h36gmpz23zqb0hy4imxvx4r-test-file.txt1714=== NAME TestPinProtectsFromGC1715 client_integration_test.go:648: Pinned store path: /build/TestPinProtectsFromGC990197491/001/store/wa8bsb4lky1nl6r4chf1cn4zf5hl66mj-pinned-file.txt1716 client_integration_test.go:649: Unpinned store path: /build/TestPinProtectsFromGC990197491/001/store/8divp92lzafscrqfvf8vc71kmvwyfhqi-unpinned-file.txt1717=== NAME TestClientMultipleUploads17182026/08/29 17:01:57 INFO Received uploads request method=POST path=/api/pending_closures1719 client_integration_test.go:339: Created store path 0: /build/TestClientMultipleUploads2254217147/001/store/w4ccba61h8zcnhrakcnfv55jnj2wrik2-test-file-0.txt1720--- PASS: TestUploadHandlersRejectOversizedBody (0.16s)1721 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1722 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)1723 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.01s)1724=== NAME TestClientWithDependencies1725 client_integration_test.go:596: Found 1 dependencies (including self)17262026/08/29 17:01:57 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=847.463572ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17272026/08/29 17:01:57 INFO Received uploads request method=POST path=/api/pending_closures17282026/08/29 17:01:57 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo17292026/08/29 17:01:57 WARN Found objects in DB but missing from S3, will re-upload count=11730--- PASS: TestService_verifyS3Integrity (4.40s)1731--- PASS: TestReadRedirectNar (1.04s)1732=== NAME TestClientMultipleUploads1733 client_integration_test.go:339: Created store path 1: /build/TestClientMultipleUploads2254217147/001/store/vyvqfiqm14wk487bm8y5g52y03997pmb-test-file-1.txt1734=== RUN TestService_RequireScope_OIDC/builder_may_write1735=== PAUSE TestService_RequireScope_OIDC/builder_may_write1736=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1737=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1738=== RUN TestService_RequireScope_OIDC/ops_may_admin1739=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1740=== RUN TestService_RequireScope_OIDC/ops_may_not_write1741=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1742=== RUN TestService_RequireScope_OIDC/reader_may_not_write1743=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1744=== RUN TestService_RequireScope_OIDC/static_token_may_admin1745=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1746=== RUN TestService_RequireScope_OIDC/static_token_may_write1747=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1748=== RUN TestService_RequireScope_OIDC/reader_may_read1749=== PAUSE TestService_RequireScope_OIDC/reader_may_read1750=== RUN TestService_RequireScope_OIDC/writer_implies_read1751=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1752=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1753=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1754=== CONT TestService_RequireScope_OIDC/builder_may_write1755=== CONT TestService_RequireScope_OIDC/static_token_may_admin1756=== CONT TestService_RequireScope_OIDC/writer_implies_read1757=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1758=== CONT TestService_RequireScope_OIDC/reader_may_read1759=== CONT TestService_RequireScope_OIDC/static_token_may_write1760=== CONT TestService_RequireScope_OIDC/ops_may_not_write1761=== CONT TestService_RequireScope_OIDC/ops_may_admin1762=== CONT TestService_RequireScope_OIDC/reader_may_not_write1763=== CONT TestService_RequireScope_OIDC/builder_may_not_admin17642026/08/29 17:01:57 INFO OIDC auth successful provider=test scopes=[admin]17652026/08/29 17:01:57 INFO OIDC auth successful provider=test scopes=[write]17662026/08/29 17:01:57 INFO OIDC auth successful provider=test scopes=[admin]17672026/08/29 17:01:57 INFO OIDC auth successful provider=test scopes=[read]17682026/08/29 17:01:57 INFO OIDC auth successful provider=test scopes=[write]17692026/08/29 17:01:57 INFO OIDC auth successful provider=test scopes=[read]17702026/08/29 17:01:57 INFO OIDC auth successful provider=test scopes=[write]1771--- PASS: TestService_RequireScope_OIDC (1.06s)1772 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1773 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1774 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1775 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1776 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1777 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1778 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1779 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1780 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1781 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)17822026/08/29 17:01:57 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17832026/08/29 17:01:57 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17842026/08/29 17:01:57 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17852026/08/29 17:01:57 INFO Received uploads request method=POST path=/api/pending_closures17862026/08/29 17:01:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17872026/08/29 17:01:57 INFO Uploading zfb4pr2rpkxbvzpf1w6h259jg842bsli-test-script (136B)17882026/08/29 17:01:57 WARN Failed to register uploaded object key=log/v6ib38dh4ii4pdb5x4zxfzwlsmsy616i-test-script.drv error="server returned 404: 404 page not found\n"17892026/08/29 17:01:57 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17902026/08/29 17:01:57 WARN Failed to register uploaded object key=zfb4pr2rpkxbvzpf1w6h259jg842bsli.ls error="server returned 404: 404 page not found\n"17912026/08/29 17:01:57 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17922026/08/29 17:01:57 INFO Signed narinfos id=1 count=117932026/08/29 17:01:57 INFO Uploading 1 narinfos1794=== NAME TestOrphanedObjectsGC1795 orphaned_objects_gc_test.go:290: GC Test Summary:1796 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1797 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1798 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1799 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1800 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1801--- PASS: TestOrphanedObjectsGC (2.01s)18022026/08/29 17:01:57 WARN Failed to register uploaded object key=zfb4pr2rpkxbvzpf1w6h259jg842bsli.narinfo error="server returned 404: 404 page not found\n"18032026/08/29 17:01:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18042026/08/29 17:01:57 INFO Completed upload id=118052026/08/29 17:01:57 INFO Upload complete. (55ms)1806=== NAME TestClientWithDependencies1807 client_integration_test.go:598: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1888515871/001/store) requires matching store prefix18082026/08/29 17:01:57 INFO Received uploads request method=POST path=/api/pending_closures18092026/08/29 17:01:57 INFO Received uploads request method=POST path=/api/pending_closures1810--- PASS: TestClientWithDependencies (1.96s)1811=== NAME TestClientMultipleUploads1812 client_integration_test.go:339: Created store path 2: /build/TestClientMultipleUploads2254217147/001/store/3fzqqyv44xnyx2k1bpln2ybs2a3w4gdf-test-file-2.txt18132026/08/29 17:01:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18142026/08/29 17:01:57 INFO Uploading wa8bsb4lky1nl6r4chf1cn4zf5hl66mj-pinned-file.txt (128B)18152026/08/29 17:01:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18162026/08/29 17:01:57 INFO Uploading a3c9b9if9h36gmpz23zqb0hy4imxvx4r-test-file.txt (152B)18172026/08/29 17:01:57 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"18182026/08/29 17:01:58 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18192026/08/29 17:01:58 WARN Failed to register uploaded object key=wa8bsb4lky1nl6r4chf1cn4zf5hl66mj.ls error="server returned 404: 404 page not found\n"18202026/08/29 17:01:58 WARN Failed to register uploaded object key=a3c9b9if9h36gmpz23zqb0hy4imxvx4r.ls error="server returned 404: 404 page not found\n"18212026/08/29 17:01:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18222026/08/29 17:01:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18232026/08/29 17:01:58 INFO Signed narinfos id=1 count=118242026/08/29 17:01:58 INFO Signed narinfos id=1 count=118252026/08/29 17:01:58 INFO Uploading 1 narinfos18262026/08/29 17:01:58 INFO Uploading 1 narinfos18272026/08/29 17:01:58 WARN Failed to register uploaded object key=wa8bsb4lky1nl6r4chf1cn4zf5hl66mj.narinfo error="server returned 404: 404 page not found\n"18282026/08/29 17:01:58 WARN Failed to register uploaded object key=a3c9b9if9h36gmpz23zqb0hy4imxvx4r.narinfo error="server returned 404: 404 page not found\n"1829--- PASS: TestGCBugBareHashReferences (1.93s)18302026/08/29 17:01:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18312026/08/29 17:01:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18322026/08/29 17:01:58 INFO Completed upload id=118332026/08/29 17:01:58 INFO Completed upload id=118342026/08/29 17:01:58 INFO Upload complete. (86ms)18352026/08/29 17:01:58 INFO Upload complete. (86ms)1836=== NAME TestClientIntegration1837 client_integration_test.go:293: Retrieved narinfo from S3:1838 StorePath: /build/TestClientIntegration505768983/002/store/a3c9b9if9h36gmpz23zqb0hy4imxvx4r-test-file.txt1839 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1840 Compression: zstd1841 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11842 NarSize: 1521843 References: 1844 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11845 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1846 client_integration_test.go:294: Decompressed .ls content (64 bytes):1847 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1848 client_integration_test.go:297: Testing garbage collection...18492026/08/29 17:01:58 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18502026/08/29 17:01:58 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18512026/08/29 17:01:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures18522026/08/29 17:01:58 INFO Garbage collection started18532026/08/29 17:01:58 INFO Aborted multipart uploads count=018542026/08/29 17:01:58 WARN Force mode enabled - objects will be deleted immediately without grace period18552026/08/29 17:01:58 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18562026/08/29 17:01:58 INFO Received uploads request method=POST path=/api/pending_closures18572026/08/29 17:01:58 INFO Received uploads request method=POST path=/api/pending_closures18582026/08/29 17:01:58 INFO Received uploads request method=POST path=/api/pending_closures18592026/08/29 17:01:58 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18602026/08/29 17:01:58 INFO Uploading w4ccba61h8zcnhrakcnfv55jnj2wrik2-test-file-0.txt (160B)18612026/08/29 17:01:58 INFO Uploading vyvqfiqm14wk487bm8y5g52y03997pmb-test-file-1.txt (160B)18622026/08/29 17:01:58 INFO Uploading 3fzqqyv44xnyx2k1bpln2ybs2a3w4gdf-test-file-2.txt (160B)18632026/08/29 17:01:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18642026/08/29 17:01:58 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18652026/08/29 17:01:58 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18662026/08/29 17:01:58 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18672026/08/29 17:01:58 WARN Failed to register uploaded object key=w4ccba61h8zcnhrakcnfv55jnj2wrik2.ls error="server returned 404: 404 page not found\n"18682026/08/29 17:01:58 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18692026/08/29 17:01:58 WARN Failed to register uploaded object key=vyvqfiqm14wk487bm8y5g52y03997pmb.ls error="server returned 404: 404 page not found\n"18702026/08/29 17:01:58 WARN Failed to register uploaded object key=3fzqqyv44xnyx2k1bpln2ybs2a3w4gdf.ls error="server returned 404: 404 page not found\n"18712026/08/29 17:01:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18722026/08/29 17:01:58 INFO Signed narinfos id=1 count=118732026/08/29 17:01:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18742026/08/29 17:01:58 INFO Signed narinfos id=2 count=118752026/08/29 17:01:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign18762026/08/29 17:01:58 INFO Signed narinfos id=3 count=118772026/08/29 17:01:58 INFO Uploading 3 narinfos18782026/08/29 17:01:58 WARN Failed to register uploaded object key=vyvqfiqm14wk487bm8y5g52y03997pmb.narinfo error="server returned 404: 404 page not found\n"18792026/08/29 17:01:58 WARN Failed to register uploaded object key=3fzqqyv44xnyx2k1bpln2ybs2a3w4gdf.narinfo error="server returned 404: 404 page not found\n"18802026/08/29 17:01:58 WARN Failed to register uploaded object key=w4ccba61h8zcnhrakcnfv55jnj2wrik2.narinfo error="server returned 404: 404 page not found\n"18812026/08/29 17:01:58 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete18822026/08/29 17:01:58 INFO Completed upload id=318832026/08/29 17:01:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18842026/08/29 17:01:58 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NTQ2YzZhYTgtZmEzNy00ZDhkLTg5NjEtZjMyOTI3M2U2ZTQ3LmU4NGQ0YTJkLTFlY2MtNDE2Ny1iMWY2LTQ1NzhmYjA2YmU1NXgxNzg4MDIyOTE1MjM2MzQ2MTkz parts=1218852026/08/29 17:01:58 INFO Completed upload id=118862026/08/29 17:01:58 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18872026/08/29 17:01:58 INFO Received uploads request method=POST path=/api/pending_closures18882026/08/29 17:01:58 INFO Completed upload id=218892026/08/29 17:01:58 INFO Upload complete. (88ms)1890=== NAME TestClientMultipleUploads1891 client_integration_test.go:350: Uploaded 3 paths in 122.79825ms1892--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.61s)1893--- PASS: TestClientMultipleUploads (1.28s)18942026/08/29 17:01:58 INFO Received uploads request method=POST path=/api/pending_closures18952026/08/29 17:01:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18962026/08/29 17:01:58 INFO Uploading 8divp92lzafscrqfvf8vc71kmvwyfhqi-unpinned-file.txt (128B)18972026/08/29 17:01:58 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18982026/08/29 17:01:58 WARN Failed to register uploaded object key=8divp92lzafscrqfvf8vc71kmvwyfhqi.ls error="server returned 404: 404 page not found\n"18992026/08/29 17:01:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19002026/08/29 17:01:58 INFO Signed narinfos id=2 count=119012026/08/29 17:01:58 INFO Uploading 1 narinfos19022026/08/29 17:01:58 WARN Failed to register uploaded object key=8divp92lzafscrqfvf8vc71kmvwyfhqi.narinfo error="server returned 404: 404 page not found\n"19032026/08/29 17:01:58 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19042026/08/29 17:01:58 INFO Completed upload id=219052026/08/29 17:01:58 INFO Upload complete. (99ms)19062026/08/29 17:01:58 INFO Received create pin request method=POST path=/api/pins/myapp19072026/08/29 17:01:58 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC990197491/001/store/wa8bsb4lky1nl6r4chf1cn4zf5hl66mj-pinned-file.txt narinfo_key=wa8bsb4lky1nl6r4chf1cn4zf5hl66mj.narinfo19082026/08/29 17:01:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures19092026/08/29 17:01:58 INFO Garbage collection started19102026/08/29 17:01:58 INFO Aborted multipart uploads count=019112026/08/29 17:01:58 WARN Force mode enabled - objects will be deleted immediately without grace period1912=== NAME TestOrphanedObjectsGCStressTest1913 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1914 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19152026/08/29 17:01:58 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.583143699s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19162026/08/29 17:01:59 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=019172026/08/29 17:01:59 INFO Vacuumed table table=pending_closures19182026/08/29 17:01:59 INFO Vacuumed table table=pending_objects19192026/08/29 17:01:59 INFO Vacuumed table table=multipart_uploads19202026/08/29 17:01:59 INFO Vacuumed table table=closures19212026/08/29 17:01:59 INFO Vacuumed table table=objects19222026/08/29 17:01:59 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=019232026/08/29 17:01:59 INFO Vacuumed table table=pending_closures19242026/08/29 17:01:59 INFO Vacuumed table table=pending_objects19252026/08/29 17:01:59 INFO Vacuumed table table=multipart_uploads19262026/08/29 17:01:59 INFO Vacuumed table table=closures19272026/08/29 17:01:59 INFO Vacuumed table table=objects1928 orphaned_objects_gc_test.go:509: Stress test completed successfully:1929 orphaned_objects_gc_test.go:510: - Active objects preserved: 201930 orphaned_objects_gc_test.go:511: - Objects deleted: 2101931 orphaned_objects_gc_test.go:512: - Total GC'd: 2101932--- PASS: TestOrphanedObjectsGCStressTest (3.34s)19332026/08/29 17:01:59 WARN Rate limiter enabled after throttle name=s3-test rate=519342026/08/29 17:01:59 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1935=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1936 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101937 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001938--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.47s)19392026/08/29 17:02:00 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01940=== NAME TestClientIntegration1941 client_integration_test.go:304: Objects in database after GC:1942 client_integration_test.go:304: Successfully deleted all objects with GC --force1943--- PASS: TestClientIntegration (3.23s)19442026/08/29 17:02:00 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01945=== NAME TestPinProtectsFromGC1946 client_integration_test.go:711: Pin successfully protected closure from garbage collection1947--- PASS: TestPinProtectsFromGC (4.12s)19482026/08/29 17:02:00 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"19492026/08/29 17:02:00 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_closures19502026/08/29 17:02:00 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.23235ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19512026/08/29 17:02:00 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.800581ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19522026/08/29 17:02:01 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=747.393388ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19532026/08/29 17:02:01 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.628206092s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1954--- PASS: TestClientErrorHandling (0.00s)1955 --- PASS: TestClientErrorHandling/InvalidStorePath (0.99s)1956 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.07s)1957 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.46s)1958PASS19592026-08-29 17:02:03.712 UTC [110] LOG: received smart shutdown request19602026-08-29 17:02:03.718 UTC [110] LOG: background worker "logical replication launcher" (PID 120) exited with exit code 119612026-08-29 17:02:03.728 UTC [115] LOG: shutting down19622026-08-29 17:02:03.728 UTC [115] LOG: checkpoint starting: shutdown immediate19632026-08-29 17:02:04.795 UTC [115] LOG: checkpoint complete: wrote 12072 buffers (73.7%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 14 recycled; write=0.218 s, sync=0.840 s, total=1.068 s; sync files=17141, longest=0.002 s, average=0.001 s; distance=236074 kB, estimate=236074 kB; lsn=0/FDEE598, redo lsn=0/FDEE59819642026-08-29 17:02:04.889 UTC [110] LOG: database system is shut down1965Running OIDC tests...1966=== RUN TestGlobMatch1967=== PAUSE TestGlobMatch1968=== RUN TestAudienceForIssuer1969=== PAUSE TestAudienceForIssuer1970=== RUN TestValidateToken_ValidToken1971=== PAUSE TestValidateToken_ValidToken1972=== RUN TestValidateToken_WrongAudience1973=== PAUSE TestValidateToken_WrongAudience1974=== RUN TestValidateToken_Expired1975=== PAUSE TestValidateToken_Expired1976=== RUN TestValidateToken_BoundClaimsMismatch1977=== PAUSE TestValidateToken_BoundClaimsMismatch1978=== RUN TestValidateToken_BoundSubjectMismatch1979=== PAUSE TestValidateToken_BoundSubjectMismatch1980=== RUN TestValidateToken_MultipleProviders1981=== PAUSE TestValidateToken_MultipleProviders1982=== RUN TestValidateToken_NoMatchingProvider1983=== PAUSE TestValidateToken_NoMatchingProvider1984=== RUN TestValidateToken_KubernetesServiceAccount1985=== PAUSE TestValidateToken_KubernetesServiceAccount1986=== RUN TestNewValidator_KubernetesRequiresCA1987=== PAUSE TestNewValidator_KubernetesRequiresCA1988=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1989=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1990=== RUN TestScopes_LegacyProviderDefaultsToWrite1991=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1992=== RUN TestScopes_Rules1993=== PAUSE TestScopes_Rules1994=== RUN TestScopes_ConfigValidation1995=== PAUSE TestScopes_ConfigValidation1996=== CONT TestGlobMatch1997=== CONT TestScopes_LegacyProviderDefaultsToWrite1998=== CONT TestValidateToken_NoMatchingProvider1999=== CONT TestNewValidator_KubernetesRequiresCA2000=== RUN TestGlobMatch/foo_foo2001=== PAUSE TestGlobMatch/foo_foo2002=== RUN TestGlobMatch/foo_bar2003=== PAUSE TestGlobMatch/foo_bar2004=== RUN TestGlobMatch/*_2005=== PAUSE TestGlobMatch/*_2006=== RUN TestGlobMatch/*_anything2007=== PAUSE TestGlobMatch/*_anything2008=== RUN TestGlobMatch/foo*_foo2009=== PAUSE TestGlobMatch/foo*_foo2010=== RUN TestGlobMatch/foo*_foobar2011=== CONT TestValidateToken_MultipleProviders2012=== CONT TestValidateToken_BoundSubjectMismatch2013=== CONT TestValidateToken_BoundClaimsMismatch2014=== CONT TestValidateToken_Expired2015=== CONT TestValidateToken_WrongAudience2016=== CONT TestValidateToken_ValidToken2017=== CONT TestAudienceForIssuer2018=== CONT TestValidateToken_KubernetesServiceAccount2019=== CONT TestScopes_ConfigValidation2020=== CONT TestScopes_Rules2021=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2022=== PAUSE TestGlobMatch/foo*_foobar2023--- PASS: TestAudienceForIssuer (0.00s)2024=== RUN TestGlobMatch/foo*_bar2025=== PAUSE TestGlobMatch/foo*_bar2026=== RUN TestGlobMatch/*bar_bar2027=== PAUSE TestGlobMatch/*bar_bar2028=== RUN TestGlobMatch/*bar_foobar2029=== PAUSE TestGlobMatch/*bar_foobar2030=== RUN TestGlobMatch/*bar_foo2031=== PAUSE TestGlobMatch/*bar_foo2032=== RUN TestGlobMatch/foo*bar_foobar2033=== PAUSE TestGlobMatch/foo*bar_foobar2034=== RUN TestGlobMatch/foo*bar_foo123bar2035=== PAUSE TestGlobMatch/foo*bar_foo123bar2036=== RUN TestGlobMatch/foo*bar_foobarbaz2037=== PAUSE TestGlobMatch/foo*bar_foobarbaz2038=== RUN TestGlobMatch/*/*_foo/bar2039=== PAUSE TestGlobMatch/*/*_foo/bar2040=== RUN TestGlobMatch/*/*_foo2041=== PAUSE TestGlobMatch/*/*_foo2042=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2043=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2044=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02045=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02046=== RUN TestGlobMatch/refs/*/main_refs/heads/main2047=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2048=== RUN TestGlobMatch/fo?_foo2049=== PAUSE TestGlobMatch/fo?_foo2050=== RUN TestGlobMatch/fo?_fo2051=== PAUSE TestGlobMatch/fo?_fo2052=== RUN TestGlobMatch/fo?_fooo2053=== PAUSE TestGlobMatch/fo?_fooo2054=== RUN TestGlobMatch/?oo_foo2055=== PAUSE TestGlobMatch/?oo_foo2056=== RUN TestGlobMatch/?oo_boo2057=== PAUSE TestGlobMatch/?oo_boo2058=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2059=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2060=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2061=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2062=== CONT TestGlobMatch/foo_foo2063=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2064=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2065=== CONT TestGlobMatch/?oo_boo2066=== CONT TestGlobMatch/foo*bar_foobar2067=== CONT TestGlobMatch/refs/*/main_refs/heads/main2068=== CONT TestGlobMatch/foo*_bar2069=== CONT TestGlobMatch/fo?_fooo2070=== CONT TestGlobMatch/foo*_foo2071=== CONT TestGlobMatch/?oo_foo2072=== CONT TestGlobMatch/*_anything2073=== CONT TestGlobMatch/*/*_foo/bar2074=== CONT TestGlobMatch/foo_bar2075=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02076=== CONT TestGlobMatch/fo?_foo2077=== CONT TestGlobMatch/fo?_fo2078=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2079=== CONT TestGlobMatch/*/*_foo2080=== CONT TestGlobMatch/foo*bar_foobarbaz2081=== CONT TestGlobMatch/*bar_foobar2082=== CONT TestGlobMatch/*bar_foo2083=== CONT TestGlobMatch/foo*_foobar2084=== CONT TestGlobMatch/*bar_bar2085=== CONT TestGlobMatch/foo*bar_foo123bar2086=== CONT TestGlobMatch/*_2087--- PASS: TestScopes_ConfigValidation (0.00s)2088--- PASS: TestGlobMatch (0.00s)2089 --- PASS: TestGlobMatch/foo_foo (0.00s)2090 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2091 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2092 --- PASS: TestGlobMatch/?oo_boo (0.00s)2093 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2094 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2095 --- PASS: TestGlobMatch/foo*_bar (0.00s)2096 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2097 --- PASS: TestGlobMatch/foo*_foo (0.00s)2098 --- PASS: TestGlobMatch/?oo_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/refs/heads/*_refs/tags/v1.0 (0.00s)2103 --- PASS: TestGlobMatch/fo?_foo (0.00s)2104 --- PASS: TestGlobMatch/fo?_fo (0.00s)2105 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2106 --- PASS: TestGlobMatch/*/*_foo (0.00s)2107 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2108 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2109 --- PASS: TestGlobMatch/*bar_foo (0.00s)2110 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2111 --- PASS: TestGlobMatch/*bar_bar (0.00s)2112 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2113 --- PASS: TestGlobMatch/*_ (0.00s)21142026/08/29 17:02:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41301/oidc21152026/08/29 17:02:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46831/oidc21162026/08/29 17:02:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42675/oidc21172026/08/29 17:02:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40273/oidc21182026/08/29 17:02:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36679/oidc21192026/08/29 17:02:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45479/oidc21202026/08/29 17:02:05 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36975/oidc21212026/08/29 17:02:05 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45701/oidc21222026/08/29 17:02:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35057/oidc21232026/08/29 17:02:05 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:33799/oidc21242026/08/29 17:02:05 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232125--- PASS: TestValidateToken_ValidToken (0.01s)2126--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2127--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2128--- PASS: TestValidateToken_Expired (0.01s)2129--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2130--- PASS: TestValidateToken_MultipleProviders (0.01s)2131--- PASS: TestValidateToken_NoMatchingProvider (0.02s)2132--- PASS: TestValidateToken_WrongAudience (0.01s)21332026/08/29 17:02:05 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:442732134--- PASS: TestScopes_Rules (0.02s)2135--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)21362026/08/29 17:02:05 http: TLS handshake error from 127.0.0.1:58528: remote error: tls: bad certificate2137--- PASS: TestNewValidator_KubernetesRequiresCA (0.03s)2138--- PASS: TestValidateToken_KubernetesServiceAccount (0.03s)2139PASS2140Running hook tests...2141=== RUN TestSendPathsEmpty2142=== PAUSE TestSendPathsEmpty2143=== RUN TestQueueEnqueueAndFetch2144=== PAUSE TestQueueEnqueueAndFetch2145=== RUN TestQueueDeduplication2146=== PAUSE TestQueueDeduplication2147=== RUN TestQueueRemove2148=== PAUSE TestQueueRemove2149=== RUN TestQueueFetchBatchLimit2150=== PAUSE TestQueueFetchBatchLimit2151=== RUN TestQueueRetryMovesToBack2152=== PAUSE TestQueueRetryMovesToBack2153=== RUN TestQueueFetchRemoveLifecycle2154=== PAUSE TestQueueFetchRemoveLifecycle2155=== RUN TestQueueConcurrentWriters2156=== PAUSE TestQueueConcurrentWriters2157=== RUN TestQueueRemoveLargeClosure2158=== PAUSE TestQueueRemoveLargeClosure2159=== RUN TestServerClientIntegration2160=== PAUSE TestServerClientIntegration2161=== RUN TestServerQueueError2162=== PAUSE TestServerQueueError2163=== RUN TestGetListenerSocketActivation2164 server_test.go:210: === RUN TestGetListenerSocketActivation2165 --- PASS: TestGetListenerSocketActivation (0.00s)2166 PASS2167 2168--- PASS: TestGetListenerSocketActivation (0.01s)2169=== RUN TestDrainIsolatesPoisonPath2170=== PAUSE TestDrainIsolatesPoisonPath2171=== RUN TestRunNotBlockedByPoisonHead2172=== PAUSE TestRunNotBlockedByPoisonHead2173=== RUN TestDrainGivesUpWhenServerDown2174=== PAUSE TestDrainGivesUpWhenServerDown2175=== RUN TestFailedPathPrunedByLaterClosure2176=== PAUSE TestFailedPathPrunedByLaterClosure2177=== RUN TestWorkerUploadsAndRemoves2178=== PAUSE TestWorkerUploadsAndRemoves2179=== RUN TestWorkerSkipsGCdPaths2180=== PAUSE TestWorkerSkipsGCdPaths2181=== RUN TestWorkerPrunesClosureDeps2182=== PAUSE TestWorkerPrunesClosureDeps2183=== RUN TestDrainTimeout2184=== PAUSE TestDrainTimeout2185=== CONT TestSendPathsEmpty2186=== CONT TestServerQueueError2187=== CONT TestQueueFetchRemoveLifecycle2188--- PASS: TestSendPathsEmpty (0.00s)2189=== CONT TestQueueFetchBatchLimit2190=== CONT TestQueueRemove2191=== CONT TestQueueDeduplication2192=== CONT TestQueueEnqueueAndFetch2193=== CONT TestQueueRetryMovesToBack2194=== CONT TestWorkerUploadsAndRemoves2195=== CONT TestServerClientIntegration2196=== CONT TestDrainTimeout2197=== CONT TestWorkerPrunesClosureDeps21982026/08/29 17:02:05 ERROR Failed to queue paths error="permission denied" count=12199=== CONT TestQueueRemoveLargeClosure2200=== CONT TestWorkerSkipsGCdPaths2201=== CONT TestQueueConcurrentWriters2202=== CONT TestDrainGivesUpWhenServerDown2203=== CONT TestFailedPathPrunedByLaterClosure2204=== CONT TestRunNotBlockedByPoisonHead2205--- PASS: TestServerQueueError (0.00s)2206=== CONT TestDrainIsolatesPoisonPath2207--- PASS: TestServerClientIntegration (0.00s)22082026/08/29 17:02:05 INFO Uploading batch count=122092026/08/29 17:02:05 INFO Uploading batch count=422102026/08/29 17:02:05 ERROR Upload failed error="upload failed" count=422112026/08/29 17:02:05 ERROR Upload failed error="upload failed" count=122122026/08/29 17:02:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3321409655/002/bbb22132026/08/29 17:02:05 INFO Upload queue status pending=322142026/08/29 17:02:05 INFO Uploading batch count=122152026/08/29 17:02:05 INFO Uploading batch count=122162026/08/29 17:02:05 ERROR Upload failed error="upload failed" count=122172026/08/29 17:02:05 INFO Uploading batch count=222182026/08/29 17:02:05 INFO Upload queue status pending=222192026/08/29 17:02:05 INFO Uploading batch count=222202026/08/29 17:02:05 INFO Uploading batch count=122212026/08/29 17:02:05 INFO Upload queue status pending=22222--- PASS: TestQueueEnqueueAndFetch (0.01s)22232026/08/29 17:02:05 INFO Upload queue status pending=22224--- PASS: TestQueueFetchBatchLimit (0.02s)22252026/08/29 17:02:05 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2865668337/002/nonexistent22262026/08/29 17:02:05 INFO Uploading batch count=122272026/08/29 17:02:05 INFO Uploading batch count=222282026/08/29 17:02:05 ERROR Upload failed error="upload failed" count=222292026/08/29 17:02:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4007919579/002/a2230--- PASS: TestQueueFetchRemoveLifecycle (0.02s)22312026/08/29 17:02:05 INFO Uploading batch count=12232--- PASS: TestQueueRemove (0.02s)2233--- PASS: TestQueueRetryMovesToBack (0.02s)22342026/08/29 17:02:05 INFO Uploading batch count=122352026/08/29 17:02:05 ERROR Upload failed error="upload failed" count=122362026/08/29 17:02:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4007919579/002/b2237--- PASS: TestQueueDeduplication (0.02s)22382026/08/29 17:02:05 INFO Uploading batch count=122392026/08/29 17:02:05 ERROR Upload failed error="upload failed" count=122402026/08/29 17:02:05 INFO Uploading batch count=122412026/08/29 17:02:05 ERROR Upload failed error="upload failed" count=122422026/08/29 17:02:05 INFO Uploading batch count=222432026/08/29 17:02:05 ERROR Upload failed error="upload failed" count=222442026/08/29 17:02:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4007919579/002/c22452026/08/29 17:02:05 ERROR Drain finished with paths left in queue remaining=12246--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)22472026/08/29 17:02:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4007919579/002/d22482026/08/29 17:02:05 INFO Uploading batch count=222492026/08/29 17:02:05 ERROR Upload failed error="upload failed" count=222502026/08/29 17:02:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4007919579/002/e22512026/08/29 17:02:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4007919579/002/f2252--- PASS: TestDrainIsolatesPoisonPath (0.02s)22532026/08/29 17:02:05 ERROR Drain finished with paths left in queue remaining=102254--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2255--- PASS: TestWorkerUploadsAndRemoves (0.03s)2256--- PASS: TestWorkerSkipsGCdPaths (0.03s)2257--- PASS: TestWorkerPrunesClosureDeps (0.03s)22582026/08/29 17:02:06 ERROR Upload failed error="context deadline exceeded" count=222592026/08/29 17:02:06 ERROR Drain finished with paths left in queue remaining=42260--- PASS: TestDrainTimeout (0.21s)2261--- PASS: TestQueueConcurrentWriters (0.22s)2262--- PASS: TestQueueRemoveLargeClosure (0.33s)22632026/08/29 17:02:06 INFO Uploading batch count=122642026/08/29 17:02:06 INFO Uploading batch count=122652026/08/29 17:02:06 INFO Uploading batch count=122662026/08/29 17:02:06 ERROR Upload failed error="upload failed" count=122672026/08/29 17:02:06 INFO Uploading batch count=122682026/08/29 17:02:06 ERROR Upload failed error="upload failed" count=122692026/08/29 17:02:06 INFO Uploading batch count=122702026/08/29 17:02:06 ERROR Upload failed error="upload failed" count=122712026/08/29 17:02:06 INFO Uploading batch count=122722026/08/29 17:02:06 ERROR Upload failed error="upload failed" count=122732026/08/29 17:02:06 ERROR Drain finished with paths left in queue remaining=12274--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2275PASS