niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #177
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestCaseHackSuffix5=== PAUSE TestCaseHackSuffix6=== RUN TestFilterOversizedClosures7=== PAUSE TestFilterOversizedClosures8=== RUN TestPartSizeForNAR9=== PAUSE TestPartSizeForNAR10=== RUN TestUploadMultipart_SupersededByPeer11=== PAUSE TestUploadMultipart_SupersededByPeer12=== RUN TestDumpPathMatchesNix13=== PAUSE TestDumpPathMatchesNix14=== RUN TestDumpPathSingleFile15=== PAUSE TestDumpPathSingleFile16=== RUN TestDumpPathWriterError17=== PAUSE TestDumpPathWriterError18=== RUN TestEncodeNixBase3219=== PAUSE TestEncodeNixBase3220=== RUN TestEncodeNixBase32WithRealHash21=== PAUSE TestEncodeNixBase32WithRealHash22=== RUN TestConvertHashToNix3223=== PAUSE TestConvertHashToNix3224=== RUN TestGetStorePathHash25=== PAUSE TestGetStorePathHash26=== RUN TestPathInfoHashCompatibility27=== PAUSE TestPathInfoHashCompatibility28=== RUN TestParsePathInfoJSON29=== PAUSE TestParsePathInfoJSON30=== RUN TestParsePathInfoJSONMultiplePaths31=== PAUSE TestParsePathInfoJSONMultiplePaths32=== RUN TestPathInfoCACompatibility33=== PAUSE TestPathInfoCACompatibility34=== RUN TestRateLimiterFeedback35=== PAUSE TestRateLimiterFeedback36=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess37=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess38=== RUN TestResolveStorePath39=== PAUSE TestResolveStorePath40=== RUN TestDoWithRetry_BodyReplayedViaGetBody41=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody42=== RUN TestShellSplit43=== PAUSE TestShellSplit44=== RUN TestShellSplitErrors45=== PAUSE TestShellSplitErrors46=== RUN TestSetClientTLS47=== PAUSE TestSetClientTLS48=== RUN TestSetClientTLSDoesNotMutateDefaultTransport49=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport50=== RUN TestSetClientTLSErrors51=== PAUSE TestSetClientTLSErrors52=== RUN TestStaticToken53=== PAUSE TestStaticToken54=== RUN TestFileTokenReadsAndCaches55=== PAUSE TestFileTokenReadsAndCaches56=== RUN TestFileTokenMissing57=== PAUSE TestFileTokenMissing58=== RUN TestFileTokenEmpty59=== PAUSE TestFileTokenEmpty60=== RUN TestScriptTokenNoExpiryRerunsEveryCall61=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall62=== RUN TestScriptTokenCachesUntilRefresh63=== PAUSE TestScriptTokenCachesUntilRefresh64=== RUN TestScriptTokenEmptyToken65=== PAUSE TestScriptTokenEmptyToken66=== RUN TestScriptTokenBadJSON67=== PAUSE TestScriptTokenBadJSON68=== RUN TestScriptTokenScriptFails69=== PAUSE TestScriptTokenScriptFails70=== RUN TestScriptTokenEmptyCommand71=== PAUSE TestScriptTokenEmptyCommand72=== CONT TestDoServerRequestAttachesToken73=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess74=== CONT TestRateLimiterFeedback75=== RUN TestRateLimiterFeedback/429_enables_limiter76=== PAUSE TestRateLimiterFeedback/429_enables_limiter77=== RUN TestRateLimiterFeedback/503_enables_limiter78=== PAUSE TestRateLimiterFeedback/503_enables_limiter79=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter802026/08/31 09:07:46 WARN Rate limiter enabled after throttle name=server-test rate=581=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter82=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter83=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter84=== CONT TestRateLimiterFeedback/429_enables_limiter85=== CONT TestScriptTokenEmptyCommand86=== CONT TestPathInfoCACompatibility87=== RUN TestPathInfoCACompatibility/null_ca_field88=== PAUSE TestPathInfoCACompatibility/null_ca_field89=== RUN TestPathInfoCACompatibility/old_string_format_-_text90=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text91=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive92=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive93=== CONT TestScriptTokenBadJSON94=== CONT TestGetStorePathHash95=== RUN TestGetStorePathHash/valid_store_path96=== PAUSE TestGetStorePathHash/valid_store_path97=== RUN TestGetStorePathHash/basename_without_hyphen_should_error98=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error99=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error100=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error101=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error102=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error103=== CONT TestGetStorePathHash/valid_store_path104=== CONT TestConvertHashToNix32105=== RUN TestConvertHashToNix32/SRI_format_to_Nix32106=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32107=== RUN TestConvertHashToNix32/already_Nix32_format108=== PAUSE TestConvertHashToNix32/already_Nix32_format109=== RUN TestConvertHashToNix32/invalid_format110=== PAUSE TestConvertHashToNix32/invalid_format111=== CONT TestConvertHashToNix32/SRI_format_to_Nix32112=== CONT TestEncodeNixBase32WithRealHash113=== CONT TestEncodeNixBase32114=== RUN TestEncodeNixBase32/test_string_hash115=== PAUSE TestEncodeNixBase32/test_string_hash116=== RUN TestEncodeNixBase32/empty_input117=== PAUSE TestEncodeNixBase32/empty_input118=== CONT TestEncodeNixBase32/test_string_hash119=== CONT TestDumpPathWriterError120=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter121=== CONT TestDumpPathSingleFile122=== CONT TestSetClientTLSDoesNotMutateDefaultTransport123=== CONT TestSetClientTLS124=== CONT TestScriptTokenEmptyToken125=== CONT TestFileTokenMissing126=== CONT TestScriptTokenCachesUntilRefresh127=== CONT TestScriptTokenNoExpiryRerunsEveryCall128=== RUN TestSetClientTLS/rejects_connection_without_client_cert129=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert130=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA131=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA132=== RUN TestSetClientTLS/preserves_debug_logging_transport133=== PAUSE TestSetClientTLS/preserves_debug_logging_transport134=== CONT TestSetClientTLS/rejects_connection_without_client_cert135=== CONT TestShellSplitErrors136=== CONT TestShellSplit137=== CONT TestDoWithRetry_BodyReplayedViaGetBody138=== CONT TestResolveStorePath139=== RUN TestPathInfoCACompatibility/new_structured_format_-_text140=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text141=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method142=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method143=== CONT TestPathInfoCACompatibility/null_ca_field144=== CONT TestDumpPathMatchesNix145=== CONT TestScriptTokenScriptFails1462026/08/31 09:07:46 WARN Rate limiter enabled after throttle name=server-test rate=51472026/08/31 09:07:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:424051482026/08/31 09:07:46 WARN Rate limiter backed off name=server-test rate=5149--- PASS: TestScriptTokenEmptyCommand (0.00s)150--- PASS: TestScriptTokenScriptFails (0.01s)151=== CONT TestUploadMultipart_SupersededByPeer152=== RUN TestUploadMultipart_SupersededByPeer/exists153=== PAUSE TestUploadMultipart_SupersededByPeer/exists154=== RUN TestUploadMultipart_SupersededByPeer/missing155=== PAUSE TestUploadMultipart_SupersededByPeer/missing156=== CONT TestPartSizeForNAR157=== RUN TestPartSizeForNAR/zero_stays_at_minimum158=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum159=== RUN TestPartSizeForNAR/small_stays_at_minimum160=== PAUSE TestPartSizeForNAR/small_stays_at_minimum161=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum162=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum163=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts164=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts165=== RUN TestPartSizeForNAR/1_TiB166=== PAUSE TestPartSizeForNAR/1_TiB167=== RUN TestPartSizeForNAR/5_TiB_S3_max_object168=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object169=== RUN TestPartSizeForNAR/capped_at_5_GiB170=== PAUSE TestPartSizeForNAR/capped_at_5_GiB171=== CONT TestFilterOversizedClosures172=== RUN TestFilterOversizedClosures/no_limit_keeps_everything173=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything174=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped175=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped176=== RUN TestFilterOversizedClosures/all_closures_skipped177=== PAUSE TestFilterOversizedClosures/all_closures_skipped178=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter179=== CONT TestParsePathInfoJSONMultiplePaths180=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths181=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths182=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths183=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths184=== CONT TestParsePathInfoJSON185=== RUN TestParsePathInfoJSON/Nix_format186=== PAUSE TestParsePathInfoJSON/Nix_format187=== RUN TestParsePathInfoJSON/Lix_format188=== PAUSE TestParsePathInfoJSON/Lix_format189=== RUN TestParsePathInfoJSON/empty_input190=== PAUSE TestParsePathInfoJSON/empty_input191=== RUN TestParsePathInfoJSON/whitespace_only192=== PAUSE TestParsePathInfoJSON/whitespace_only193=== RUN TestParsePathInfoJSON/invalid_JSON194=== PAUSE TestParsePathInfoJSON/invalid_JSON195=== CONT TestPathInfoCACompatibility/old_string_format_-_text196=== CONT TestRateLimiterFeedback/503_enables_limiter197=== CONT TestPathInfoHashCompatibility198=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)199=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)200=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error201=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error202=== CONT TestConvertHashToNix32/invalid_format203=== CONT TestConvertHashToNix32/already_Nix32_format204=== CONT TestGetStorePathHash/basename_without_hyphen_should_error205=== CONT TestUploadMultipart_SupersededByPeer/exists206=== CONT TestStaticToken207=== CONT TestPartSizeForNAR/zero_stays_at_minimum208=== CONT TestUploadMultipart_SupersededByPeer/missing209=== CONT TestEncodeNixBase32/empty_input210=== CONT TestFilterOversizedClosures/no_limit_keeps_everything211=== CONT TestPartSizeForNAR/capped_at_5_GiB212=== CONT TestPartSizeForNAR/5_TiB_S3_max_object213=== CONT TestPartSizeForNAR/1_TiB214=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts215=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum216=== CONT TestPartSizeForNAR/small_stays_at_minimum217=== CONT TestFilterOversizedClosures/all_closures_skipped218=== CONT TestFileTokenReadsAndCaches219=== CONT TestSetClientTLSErrors220=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon221--- PASS: TestGetStorePathHash (0.00s)222 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)223 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)224 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)225 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)226--- PASS: TestStaticToken (0.00s)227--- PASS: TestEncodeNixBase32WithRealHash (0.00s)228=== CONT TestSetClientTLS/preserves_debug_logging_transport229=== CONT TestPathInfoCACompatibility/new_structured_format_-_text230=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method231=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive232=== CONT TestFileTokenEmpty233=== CONT TestCaseHackSuffix234--- PASS: TestFileTokenMissing (0.00s)235=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA2362026/08/31 09:07:46 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50237--- PASS: TestShellSplitErrors (0.00s)238--- PASS: TestShellSplit (0.00s)239--- PASS: TestResolveStorePath (0.00s)240--- PASS: TestScriptTokenBadJSON (0.03s)241--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)242=== CONT TestParsePathInfoJSON/empty_input243=== CONT TestParsePathInfoJSON/Lix_format244=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths245--- PASS: TestDoServerRequestAttachesToken (0.04s)246--- PASS: TestEncodeNixBase32 (0.00s)247 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)248 --- PASS: TestEncodeNixBase32/empty_input (0.00s)249--- PASS: TestConvertHashToNix32 (0.00s)250 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)251 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)252 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)253--- PASS: TestFileTokenEmpty (0.00s)254--- PASS: TestScriptTokenEmptyToken (0.05s)255--- PASS: TestPathInfoCACompatibility (0.02s)256 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.03s)257 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)258 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)259 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)260 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)261--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.05s)262=== RUN TestSetClientTLSErrors/missing_cert_file263=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon264=== CONT TestParsePathInfoJSON/Nix_format265=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths266=== CONT TestParsePathInfoJSON/invalid_JSON267=== CONT TestParsePathInfoJSON/whitespace_only268=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped269--- PASS: TestFileTokenReadsAndCaches (0.02s)270--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)271 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.02s)272 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.02s)273=== PAUSE TestSetClientTLSErrors/missing_cert_file274=== RUN TestSetClientTLSErrors/missing_key_file275=== PAUSE TestSetClientTLSErrors/missing_key_file276=== RUN TestSetClientTLSErrors/missing_ca_file277=== PAUSE TestSetClientTLSErrors/missing_ca_file278=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI279=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI280=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512281--- PASS: TestPartSizeForNAR (0.00s)282 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)283 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)284 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)285 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)286 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)287 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)288 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)289=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512290=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)291=== RUN TestSetClientTLSErrors/invalid_ca_file292=== PAUSE TestSetClientTLSErrors/invalid_ca_file293=== CONT TestSetClientTLSErrors/missing_cert_file294=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512295=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI296=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon297--- PASS: TestPathInfoHashCompatibility (0.02s)298 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)299 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)300 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)301 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)302=== CONT TestSetClientTLSErrors/invalid_ca_file303=== CONT TestSetClientTLSErrors/missing_ca_file304=== CONT TestSetClientTLSErrors/missing_key_file3052026/08/31 09:07:46 WARN Rate limiter enabled after throttle name=server-test rate=53062026/08/31 09:07:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:449973072026/08/31 09:07:46 WARN Rate limiter enabled after throttle name=server-test rate=53082026/08/31 09:07:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:342853092026/08/31 09:07:46 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000310--- PASS: TestFilterOversizedClosures (0.00s)311 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)312 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.02s)313 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)314--- PASS: TestSetClientTLSErrors (0.04s)315 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)316 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)317 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)318 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3192026/08/31 09:07:47 WARN Rate limiter backed off name=server-test rate=53202026/08/31 09:07:47 WARN Rate limiter backed off name=server-test rate=53212026/08/31 09:07:47 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:342853222026/08/31 09:07:47 http: TLS handshake error from 127.0.0.1:59300: remote error: tls: bad certificate323--- PASS: TestParsePathInfoJSON (0.00s)324 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)325 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)326 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)327 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)328 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)329--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)330 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)331 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)332--- PASS: TestRateLimiterFeedback (0.00s)333 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.04s)334 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.04s)335 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)336 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.05s)337--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.08s)338--- PASS: TestSetClientTLS (0.01s)339 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.03s)340 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.04s)341 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.09s)342--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.09s)343--- PASS: TestDumpPathWriterError (0.12s)344--- PASS: TestCaseHackSuffix (0.20s)345--- PASS: TestDumpPathSingleFile (0.26s)346--- PASS: TestDumpPathMatchesNix (0.28s)347--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)348PASS349Running server tests...350The files belonging to this database system will be owned by user "nixbld".351This user must also own the server process.352353The database cluster will be initialized with locale "C".354The default database encoding has accordingly been set to "SQL_ASCII".355The default text search configuration will be set to "english".356357Data page checksums are enabled.358359creating directory /build/postgres2899741546/data ... ok360creating subdirectories ... ok361selecting dynamic shared memory implementation ... posix362selecting default "max_connections" ... 100363selecting default "shared_buffers" ... 128MB364selecting default time zone ... UTC365creating configuration files ... ok366running bootstrap script ... ok367performing post-bootstrap initialization ... ok368syncing data to disk ... ok369370initdb: warning: enabling "trust" authentication for local connections371initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.372373Success. You can now start the database server using:374375 pg_ctl -D /build/postgres2899741546/data -l logfile start376377/build/postgres2899741546:5432 - no response3782026-08-31 09:07:50.884 UTC [107] LOG: starting PostgreSQL 18.4 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit3792026-08-31 09:07:50.887 UTC [107] LOG: listening on Unix socket "/build/postgres2899741546/.s.PGSQL.5432"3802026-08-31 09:07:50.906 UTC [114] LOG: database system was shut down at 2026-08-31 09:07:49 UTC3812026-08-31 09:07:50.910 UTC [107] LOG: database system is ready to accept connections382/build/postgres2899741546:5432 - accepting connections383=== RUN TestService_AuthMiddleware384=== PAUSE TestService_AuthMiddleware385=== RUN TestService_AuthMiddleware_MTLSProxyHeader386=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader387=== RUN TestService_AuthMiddleware_MTLSBoundSubjects388=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects389=== RUN TestService_ReadAuthMiddleware390=== PAUSE TestService_ReadAuthMiddleware391=== RUN TestService_AuthMiddleware_OIDC392=== PAUSE TestService_AuthMiddleware_OIDC393=== RUN TestService_RequireScope_OIDC394=== PAUSE TestService_RequireScope_OIDC395=== RUN TestService_ReadScope_PublicByDefault396=== PAUSE TestService_ReadScope_PublicByDefault397=== RUN TestCacheConfigHandler398=== PAUSE TestCacheConfigHandler399=== RUN TestCacheStatsHandler400=== PAUSE TestCacheStatsHandler401=== RUN TestClientCADerivations402=== PAUSE TestClientCADerivations403=== RUN TestClientErrorHandling404=== PAUSE TestClientErrorHandling405=== RUN TestClientIntegration406=== PAUSE TestClientIntegration407=== RUN TestClientMultipleUploads408=== PAUSE TestClientMultipleUploads409=== RUN TestClientWithDependencies410=== PAUSE TestClientWithDependencies411=== RUN TestPinProtectsFromGC412=== PAUSE TestPinProtectsFromGC413=== RUN TestResolveDBConnectionString414=== PAUSE TestResolveDBConnectionString415=== RUN TestGCAdvisoryLockBlocksConcurrentRun4162026-08-31 09:07:52.346 UTC [177] ERROR: relation "goose_db_version" does not exist at character 364172026-08-31 09:07:52.346 UTC [177] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4182026/08/31 09:07:52 OK 20241026095416_initial_model.sql (17.88ms)4192026/08/31 09:07:52 OK 20251210153512_drop_unused_gin_index.sql (4.99ms)4202026/08/31 09:07:52 OK 20251218171726_add_pins.sql (4.82ms)4212026/08/31 09:07:52 OK 20260628120000_add_object_size_and_stats.sql (4.95ms)4222026/08/31 09:07:52 goose: successfully migrated database to version: 202606281200004232026/08/31 09:07:52 OK 1_commit_pending_closure.sql (8.68ms)4242026/08/31 09:07:52 OK 2_object_stats_trigger.sql (3.73ms)4252026/08/31 09:07:52 goose: up to current file version: 2426--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.61s)427=== RUN TestGCBugBareHashReferences428=== PAUSE TestGCBugBareHashReferences429=== RUN TestGCMetrics430=== PAUSE TestGCMetrics431=== RUN TestGCTaskStore_StartNew432=== PAUSE TestGCTaskStore_StartNew433=== RUN TestGCTaskStore_DeduplicateSameParams434=== PAUSE TestGCTaskStore_DeduplicateSameParams435=== RUN TestGCTaskStore_ConflictDifferentParams436=== PAUSE TestGCTaskStore_ConflictDifferentParams437=== RUN TestGCTaskStore_GetEmpty438=== PAUSE TestGCTaskStore_GetEmpty439=== RUN TestGCTaskStore_GetReturnsLatest440=== PAUSE TestGCTaskStore_GetReturnsLatest441=== RUN TestGCTaskStore_CompletedAllowsNewTask442=== PAUSE TestGCTaskStore_CompletedAllowsNewTask443=== RUN TestGCTaskStore_PhaseUpdates444=== PAUSE TestGCTaskStore_PhaseUpdates445=== RUN TestGCTaskStore_Fail446=== PAUSE TestGCTaskStore_Fail447=== RUN TestGracefulShutdownDrainsInflight448=== PAUSE TestGracefulShutdownDrainsInflight449=== RUN TestService_healthCheckHandler450=== PAUSE TestService_healthCheckHandler451=== RUN TestService_readinessHandler452=== PAUSE TestService_readinessHandler453=== RUN TestGenerateLandingPage454=== PAUSE TestGenerateLandingPage455=== RUN TestCacheConfigHandlerMaxNarSize456=== PAUSE TestCacheConfigHandlerMaxNarSize457=== RUN TestCreatePendingClosureRejectsOversizedNAR458=== PAUSE TestCreatePendingClosureRejectsOversizedNAR459=== RUN TestNARDeduplicationMetadataUploadBug460=== PAUSE TestNARDeduplicationMetadataUploadBug461=== RUN TestMetricsInventory462=== PAUSE TestMetricsInventory463=== RUN TestService_NativeMTLS464=== PAUSE TestService_NativeMTLS465=== RUN TestServerTLSConfig466=== PAUSE TestServerTLSConfig467=== RUN TestMultipartCleanup468=== PAUSE TestMultipartCleanup469=== RUN TestObjectStatsTrigger470=== PAUSE TestObjectStatsTrigger471=== RUN TestOrphanedObjectsGC472=== PAUSE TestOrphanedObjectsGC473=== RUN TestOrphanedObjectsGCStressTest474=== PAUSE TestOrphanedObjectsGCStressTest475=== RUN TestResurrectedObjectNotDeleted476=== PAUSE TestResurrectedObjectNotDeleted477=== RUN TestParseSingleRange478=== PAUSE TestParseSingleRange479=== RUN TestIsValidCachePath480=== PAUSE TestIsValidCachePath481=== RUN TestReadProxyNarinfo482=== PAUSE TestReadProxyNarinfo483=== RUN TestReadProxyNarinfoAlreadyDecompressed484=== PAUSE TestReadProxyNarinfoAlreadyDecompressed485=== RUN TestReadProxyNarStreaming486=== PAUSE TestReadProxyNarStreaming487=== RUN TestReadProxy404488=== PAUSE TestReadProxy404489=== RUN TestReadProxyInvalidPath490=== PAUSE TestReadProxyInvalidPath491=== RUN TestReadProxyHead492=== PAUSE TestReadProxyHead493=== RUN TestReadProxyConditionalGet494=== PAUSE TestReadProxyConditionalGet495=== RUN TestReadProxyRootRedirectsToIndexHTML496=== PAUSE TestReadProxyRootRedirectsToIndexHTML497=== RUN TestReadProxyDisabled498=== PAUSE TestReadProxyDisabled499=== RUN TestReadRedirectNar500=== PAUSE TestReadRedirectNar501=== RUN TestReadRedirectKeepsNarinfoProxied502=== PAUSE TestReadRedirectKeepsNarinfoProxied503=== RUN TestReadProxyRangeRequest504=== PAUSE TestReadProxyRangeRequest505=== RUN TestReadRedirectUsesPublicS3URL506=== PAUSE TestReadRedirectUsesPublicS3URL507=== RUN TestRedundantMultipartUpload508=== PAUSE TestRedundantMultipartUpload509=== RUN TestCompleteMultipartUpload_ErrorButObjectExists510=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists511=== RUN TestCompletedNarNotReofferedAcrossClosures512=== PAUSE TestCompletedNarNotReofferedAcrossClosures513=== RUN TestPresignedUploadRegisteredBeforeCommit514=== PAUSE TestPresignedUploadRegisteredBeforeCommit515=== RUN TestService_Rustfstest516=== PAUSE TestService_Rustfstest517=== RUN TestParseSize518=== PAUSE TestParseSize519=== RUN TestSkippedUploadsHandler520=== PAUSE TestSkippedUploadsHandler521=== RUN TestSystemdListenerNotActivated522--- PASS: TestSystemdListenerNotActivated (0.00s)523=== RUN TestWatchdogBeatsWhenHealthy524--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)525=== RUN TestWatchdogSkipsWhenUnhealthy5262026/08/31 09:07:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5272026/08/31 09:07:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5282026/08/31 09:07:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5292026/08/31 09:07:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5302026/08/31 09:07:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5312026/08/31 09:07:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5322026/08/31 09:07:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5332026/08/31 09:07:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5342026/08/31 09:07:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5352026/08/31 09:07:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"536--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)537=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle538=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle539=== RUN TestProxyWriteTimeout540=== PAUSE TestProxyWriteTimeout541=== RUN TestIsValidUploadKey542=== PAUSE TestIsValidUploadKey543=== RUN TestUploadHandlersRejectInvalidKeys544=== PAUSE TestUploadHandlersRejectInvalidKeys545=== RUN TestUploadHandlersRejectOversizedBody546=== PAUSE TestUploadHandlersRejectOversizedBody547=== RUN TestService_cleanupPendingClosuresHandler548=== PAUSE TestService_cleanupPendingClosuresHandler549=== RUN TestService_createPendingClosureHandler550=== PAUSE TestService_createPendingClosureHandler551=== RUN TestService_verifyS3Integrity552=== PAUSE TestService_verifyS3Integrity553=== RUN TestCompleteMultipartUnregistered554=== PAUSE TestCompleteMultipartUnregistered555=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT556=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT557=== CONT TestService_AuthMiddleware558=== CONT TestObjectStatsTrigger559=== CONT TestGCTaskStore_DeduplicateSameParams560--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)561=== CONT TestMultipartCleanup562=== CONT TestReadRedirectUsesPublicS3URL563=== CONT TestReadProxy404564=== CONT TestProxyWriteTimeout565=== RUN TestProxyWriteTimeout/narinfo566=== PAUSE TestProxyWriteTimeout/narinfo567=== RUN TestProxyWriteTimeout/1_GiB_nar568=== PAUSE TestProxyWriteTimeout/1_GiB_nar569=== RUN TestProxyWriteTimeout/10_GiB_nar570=== PAUSE TestProxyWriteTimeout/10_GiB_nar571=== RUN TestProxyWriteTimeout/unknown_size572=== PAUSE TestProxyWriteTimeout/unknown_size573=== CONT TestProxyWriteTimeout/narinfo574=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT575=== CONT TestReadProxyDisabled576=== CONT TestService_readinessHandler577=== CONT TestGCTaskStore_PhaseUpdates578--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)579=== CONT TestService_healthCheckHandler580=== CONT TestGracefulShutdownDrainsInflight581=== CONT TestGCTaskStore_Fail582=== CONT TestClientErrorHandling583=== CONT TestGCTaskStore_StartNew584=== CONT TestGCMetrics585=== CONT TestGCBugBareHashReferences586=== CONT TestResolveDBConnectionString587=== CONT TestPinProtectsFromGC588=== CONT TestClientWithDependencies589=== CONT TestClientMultipleUploads590=== CONT TestClientIntegration591=== CONT TestReadProxyConditionalGet592=== CONT TestReadProxyRootRedirectsToIndexHTML593=== CONT TestService_RequireScope_OIDC594=== CONT TestClientCADerivations5952026/08/31 09:07:53 INFO Starting HTTP server address=127.0.0.1:41295596--- PASS: TestGCTaskStore_StartNew (0.00s)597=== CONT TestCacheStatsHandler5982026/08/31 09:07:53 INFO Shutdown signal received, draining in-flight requests timeout=10s599--- PASS: TestGCTaskStore_Fail (0.00s)600=== CONT TestCacheConfigHandler601=== RUN TestCacheConfigHandler/full_config,_no_issuer602=== PAUSE TestCacheConfigHandler/full_config,_no_issuer603=== RUN TestCacheConfigHandler/no_cache_url_configured604=== PAUSE TestCacheConfigHandler/no_cache_url_configured605=== RUN TestCacheConfigHandler/no_signing_keys606=== PAUSE TestCacheConfigHandler/no_signing_keys607=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator608=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator609=== CONT TestService_ReadScope_PublicByDefault610=== RUN TestClientErrorHandling/InvalidStorePath611=== PAUSE TestClientErrorHandling/InvalidStorePath612=== RUN TestClientErrorHandling/InvalidAuthToken613=== PAUSE TestClientErrorHandling/InvalidAuthToken614=== RUN TestClientErrorHandling/ServerNotAvailable615=== PAUSE TestClientErrorHandling/ServerNotAvailable616=== CONT TestReadRedirectKeepsNarinfoProxied617=== RUN TestResolveDBConnectionString/flag_wins618=== PAUSE TestResolveDBConnectionString/flag_wins619=== RUN TestResolveDBConnectionString/file_when_flag_empty620=== PAUSE TestResolveDBConnectionString/file_when_flag_empty621=== RUN TestResolveDBConnectionString/missing_file_is_an_error622=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error623=== RUN TestResolveDBConnectionString/PGHOST_allows_empty624=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty625=== RUN TestResolveDBConnectionString/nothing_configured626=== PAUSE TestResolveDBConnectionString/nothing_configured627=== CONT TestReadProxyRangeRequest6282026/08/31 09:07:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41991/oidc629--- PASS: TestGracefulShutdownDrainsInflight (0.15s)630=== CONT TestService_ReadAuthMiddleware6312026-08-31 09:07:53.239 UTC [253] ERROR: relation "goose_db_version" does not exist at character 366322026-08-31 09:07:53.239 UTC [253] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6332026-08-31 09:07:53.239 UTC [255] ERROR: relation "goose_db_version" does not exist at character 366342026-08-31 09:07:53.239 UTC [255] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6352026/08/31 09:07:53 OK 20241026095416_initial_model.sql (81.35ms)6362026-08-31 09:07:53.361 UTC [257] ERROR: relation "goose_db_version" does not exist at character 366372026-08-31 09:07:53.361 UTC [257] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6382026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (9.17ms)6392026-08-31 09:07:53.389 UTC [262] ERROR: relation "goose_db_version" does not exist at character 366402026-08-31 09:07:53.389 UTC [262] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6412026/08/31 09:07:53 OK 20241026095416_initial_model.sql (122.14ms)6422026/08/31 09:07:53 OK 20251218171726_add_pins.sql (60.59ms)6432026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (28.48ms)6442026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (22.68ms)6452026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200006462026/08/31 09:07:53 OK 1_commit_pending_closure.sql (4.34ms)6472026/08/31 09:07:53 OK 2_object_stats_trigger.sql (2.94ms)6482026/08/31 09:07:53 goose: up to current file version: 26492026-08-31 09:07:53.468 UTC [263] ERROR: relation "goose_db_version" does not exist at character 366502026-08-31 09:07:53.468 UTC [263] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6512026-08-31 09:07:53.472 UTC [264] ERROR: relation "goose_db_version" does not exist at character 366522026-08-31 09:07:53.472 UTC [264] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6532026-08-31 09:07:53.486 UTC [265] ERROR: relation "goose_db_version" does not exist at character 366542026-08-31 09:07:53.486 UTC [265] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6552026/08/31 09:07:53 WARN readiness check failed error="closed pool"656--- PASS: TestService_readinessHandler (0.45s)657=== CONT TestService_AuthMiddleware_OIDC6582026/08/31 09:07:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39543/oidc6592026/08/31 09:07:53 OK 20251218171726_add_pins.sql (104ms)6602026/08/31 09:07:53 OK 20241026095416_initial_model.sql (59.89ms)6612026/08/31 09:07:53 OK 20241026095416_initial_model.sql (51.25ms)6622026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (15.12ms)6632026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (16.06ms)6642026/08/31 09:07:53 OK 20241026095416_initial_model.sql (102.42ms)6652026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (51.17ms)6662026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200006672026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (17.47ms)6682026/08/31 09:07:53 OK 20241026095416_initial_model.sql (109.08ms)6692026/08/31 09:07:53 OK 20241026095416_initial_model.sql (110.52ms)6702026-08-31 09:07:53.628 UTC [268] ERROR: relation "goose_db_version" does not exist at character 366712026-08-31 09:07:53.628 UTC [268] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6722026/08/31 09:07:53 OK 1_commit_pending_closure.sql (19.69ms)6732026/08/31 09:07:53 OK 20251218171726_add_pins.sql (50.32ms)6742026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (16.07ms)6752026/08/31 09:07:53 OK 2_object_stats_trigger.sql (16.41ms)6762026/08/31 09:07:53 goose: up to current file version: 26772026-08-31 09:07:53.650 UTC [269] ERROR: relation "goose_db_version" does not exist at character 366782026-08-31 09:07:53.650 UTC [269] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6792026-08-31 09:07:53.650 UTC [270] ERROR: relation "goose_db_version" does not exist at character 366802026-08-31 09:07:53.650 UTC [270] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6812026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (35.11ms)6822026/08/31 09:07:53 OK 20251218171726_add_pins.sql (73.54ms)6832026-08-31 09:07:53.658 UTC [271] ERROR: relation "goose_db_version" does not exist at character 366842026-08-31 09:07:53.658 UTC [271] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6852026-08-31 09:07:53.666 UTC [272] ERROR: relation "goose_db_version" does not exist at character 366862026-08-31 09:07:53.666 UTC [272] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6872026/08/31 09:07:53 OK 20251218171726_add_pins.sql (47.52ms)6882026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (40.12ms)6892026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200006902026/08/31 09:07:53 OK 20251218171726_add_pins.sql (41.19ms)6912026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (58.92ms)6922026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200006932026/08/31 09:07:53 OK 20251218171726_add_pins.sql (85.2ms)6942026-08-31 09:07:53.711 UTC [273] ERROR: relation "goose_db_version" does not exist at character 366952026-08-31 09:07:53.711 UTC [273] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6962026/08/31 09:07:53 OK 1_commit_pending_closure.sql (21.37ms)6972026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (21.47ms)6982026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200006992026/08/31 09:07:53 OK 1_commit_pending_closure.sql (19.92ms)7002026/08/31 09:07:53 OK 2_object_stats_trigger.sql (5.98ms)7012026/08/31 09:07:53 goose: up to current file version: 27022026/08/31 09:07:53 OK 2_object_stats_trigger.sql (8.75ms)7032026/08/31 09:07:53 goose: up to current file version: 27042026-08-31 09:07:53.730 UTC [274] ERROR: relation "goose_db_version" does not exist at character 367052026-08-31 09:07:53.730 UTC [274] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7062026/08/31 09:07:53 OK 1_commit_pending_closure.sql (16.87ms)7072026-08-31 09:07:53.740 UTC [275] ERROR: relation "goose_db_version" does not exist at character 367082026-08-31 09:07:53.740 UTC [275] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7092026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (40.48ms)7102026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200007112026/08/31 09:07:53 OK 2_object_stats_trigger.sql (16.13ms)7122026/08/31 09:07:53 goose: up to current file version: 27132026/08/31 09:07:53 OK 20241026095416_initial_model.sql (42.29ms)7142026/08/31 09:07:53 OK 20241026095416_initial_model.sql (35.04ms)7152026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (6.45ms)7162026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (9.94ms)7172026/08/31 09:07:53 OK 20241026095416_initial_model.sql (22.06ms)7182026/08/31 09:07:53 OK 1_commit_pending_closure.sql (25.95ms)7192026/08/31 09:07:53 OK 20241026095416_initial_model.sql (70.12ms)7202026-08-31 09:07:53.782 UTC [276] ERROR: relation "goose_db_version" does not exist at character 367212026-08-31 09:07:53.782 UTC [276] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7222026-08-31 09:07:53.784 UTC [279] ERROR: relation "goose_db_version" does not exist at character 367232026-08-31 09:07:53.784 UTC [279] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7242026-08-31 09:07:53.788 UTC [277] ERROR: relation "goose_db_version" does not exist at character 367252026-08-31 09:07:53.788 UTC [277] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7262026-08-31 09:07:53.789 UTC [280] ERROR: relation "goose_db_version" does not exist at character 367272026-08-31 09:07:53.789 UTC [280] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7282026-08-31 09:07:53.791 UTC [278] ERROR: relation "goose_db_version" does not exist at character 367292026-08-31 09:07:53.791 UTC [278] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7302026/08/31 09:07:53 OK 2_object_stats_trigger.sql (49.96ms)7312026/08/31 09:07:53 goose: up to current file version: 27322026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (50.45ms)7332026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (136.66ms)7342026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200007352026/08/31 09:07:53 OK 20251218171726_add_pins.sql (62.1ms)7362026/08/31 09:07:53 OK 20241026095416_initial_model.sql (105.67ms)7372026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (55.49ms)7382026/08/31 09:07:53 OK 1_commit_pending_closure.sql (9.04ms)7392026/08/31 09:07:53 OK 20241026095416_initial_model.sql (103.53ms)7402026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (10.73ms)7412026-08-31 09:07:53.841 UTC [281] ERROR: relation "goose_db_version" does not exist at character 367422026-08-31 09:07:53.841 UTC [281] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7432026/08/31 09:07:53 OK 20251218171726_add_pins.sql (75.46ms)7442026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (9.3ms)7452026/08/31 09:07:53 OK 20241026095416_initial_model.sql (157.6ms)7462026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (27.01ms)7472026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200007482026/08/31 09:07:53 OK 2_object_stats_trigger.sql (26.76ms)7492026/08/31 09:07:53 goose: up to current file version: 27502026/08/31 09:07:53 OK 20251218171726_add_pins.sql (27.52ms)7512026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (20.61ms)7522026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200007532026/08/31 09:07:53 OK 1_commit_pending_closure.sql (12.28ms)7542026/08/31 09:07:53 OK 20251218171726_add_pins.sql (46.64ms)7552026/08/31 09:07:53 OK 20251218171726_add_pins.sql (19.65ms)7562026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (15.52ms)7572026/08/31 09:07:53 OK 20241026095416_initial_model.sql (44.11ms)7582026/08/31 09:07:53 OK 1_commit_pending_closure.sql (8.81ms)7592026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (11.85ms)7602026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200007612026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (4.36ms)7622026/08/31 09:07:53 OK 2_object_stats_trigger.sql (10.06ms)7632026/08/31 09:07:53 goose: up to current file version: 27642026/08/31 09:07:53 OK 20241026095416_initial_model.sql (53.59ms)7652026/08/31 09:07:53 OK 20241026095416_initial_model.sql (53.43ms)7662026/08/31 09:07:53 OK 1_commit_pending_closure.sql (3.87ms)7672026-08-31 09:07:53.888 UTC [282] ERROR: relation "goose_db_version" does not exist at character 367682026-08-31 09:07:53.888 UTC [282] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7692026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (19.66ms)7702026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200007712026/08/31 09:07:53 OK 2_object_stats_trigger.sql (13.53ms)7722026/08/31 09:07:53 goose: up to current file version: 27732026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (10.37ms)7742026-08-31 09:07:53.893 UTC [283] ERROR: relation "goose_db_version" does not exist at character 367752026-08-31 09:07:53.893 UTC [283] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7762026/08/31 09:07:53 OK 2_object_stats_trigger.sql (12.33ms)7772026/08/31 09:07:53 goose: up to current file version: 27782026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (12.64ms)7792026/08/31 09:07:53 OK 20251218171726_add_pins.sql (17.5ms)7802026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (31.99ms)7812026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200007822026/08/31 09:07:53 OK 1_commit_pending_closure.sql (8.75ms)7832026/08/31 09:07:53 OK 20251218171726_add_pins.sql (71.25ms)7842026/08/31 09:07:53 OK 20241026095416_initial_model.sql (29.98ms)7852026/08/31 09:07:53 OK 20251218171726_add_pins.sql (35.4ms)7862026/08/31 09:07:53 OK 20251218171726_add_pins.sql (14.32ms)7872026/08/31 09:07:53 OK 20241026095416_initial_model.sql (46.46ms)7882026/08/31 09:07:53 OK 1_commit_pending_closure.sql (8.93ms)7892026/08/31 09:07:53 OK 2_object_stats_trigger.sql (9.42ms)7902026/08/31 09:07:53 goose: up to current file version: 27912026/08/31 09:07:53 OK 20241026095416_initial_model.sql (81.59ms)7922026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (6.57ms)7932026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200007942026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (13.87ms)7952026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200007962026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (13.35ms)7972026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200007982026/08/31 09:07:53 OK 2_object_stats_trigger.sql (4.51ms)7992026/08/31 09:07:53 goose: up to current file version: 28002026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (13.38ms)8012026/08/31 09:07:53 OK 20251218171726_add_pins.sql (24.98ms)8022026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (10.31ms)8032026-08-31 09:07:53.921 UTC [284] ERROR: relation "goose_db_version" does not exist at character 368042026-08-31 09:07:53.921 UTC [284] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8052026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200008062026/08/31 09:07:53 OK 20241026095416_initial_model.sql (93.75ms)8072026/08/31 09:07:53 OK 1_commit_pending_closure.sql (7.84ms)8082026/08/31 09:07:53 OK 1_commit_pending_closure.sql (9ms)8092026/08/31 09:07:53 OK 1_commit_pending_closure.sql (6.96ms)8102026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (4.16ms)8112026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (8.59ms)8122026/08/31 09:07:53 OK 2_object_stats_trigger.sql (4.84ms)8132026/08/31 09:07:53 goose: up to current file version: 28142026/08/31 09:07:53 OK 2_object_stats_trigger.sql (5.04ms)8152026/08/31 09:07:53 goose: up to current file version: 28162026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (8.12ms)8172026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200008182026/08/31 09:07:53 OK 20251218171726_add_pins.sql (10.09ms)8192026-08-31 09:07:53.930 UTC [285] ERROR: relation "goose_db_version" does not exist at character 368202026-08-31 09:07:53.930 UTC [285] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8212026/08/31 09:07:53 OK 1_commit_pending_closure.sql (8.71ms)8222026/08/31 09:07:53 OK 20251218171726_add_pins.sql (8.1ms)8232026/08/31 09:07:53 OK 2_object_stats_trigger.sql (10.9ms)8242026/08/31 09:07:53 goose: up to current file version: 28252026/08/31 09:07:53 OK 1_commit_pending_closure.sql (5.81ms)8262026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (10.94ms)8272026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (8.63ms)8282026/08/31 09:07:53 OK 2_object_stats_trigger.sql (5.47ms)8292026/08/31 09:07:53 goose: up to current file version: 28302026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200008312026/08/31 09:07:53 OK 2_object_stats_trigger.sql (3.8ms)8322026/08/31 09:07:53 goose: up to current file version: 28332026/08/31 09:07:53 OK 20251218171726_add_pins.sql (14.83ms)8342026/08/31 09:07:53 OK 20241026095416_initial_model.sql (18.57ms)8352026/08/31 09:07:53 OK 1_commit_pending_closure.sql (4.19ms)8362026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)8372026/08/31 09:07:53 OK 20251218171726_add_pins.sql (8.27ms)8382026/08/31 09:07:53 OK 20251218171726_add_pins.sql (5.28ms)8392026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (10.14ms)8402026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200008412026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (14.56ms)8422026/08/31 09:07:53 OK 20241026095416_initial_model.sql (26.88ms)8432026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (9.55ms)8442026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200008452026/08/31 09:07:53 OK 2_object_stats_trigger.sql (7.03ms)8462026/08/31 09:07:53 goose: up to current file version: 28472026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200008482026/08/31 09:07:53 OK 1_commit_pending_closure.sql (3.04ms)8492026/08/31 09:07:53 OK 1_commit_pending_closure.sql (7.34ms)8502026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (8.46ms)8512026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200008522026/08/31 09:07:53 OK 20241026095416_initial_model.sql (15.6ms)8532026/08/31 09:07:53 OK 1_commit_pending_closure.sql (4.71ms)8542026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (4.85ms)8552026/08/31 09:07:53 OK 2_object_stats_trigger.sql (5.3ms)8562026/08/31 09:07:53 goose: up to current file version: 28572026/08/31 09:07:53 OK 2_object_stats_trigger.sql (4.02ms)8582026/08/31 09:07:53 goose: up to current file version: 28592026/08/31 09:07:53 OK 1_commit_pending_closure.sql (4.58ms)8602026/08/31 09:07:53 OK 2_object_stats_trigger.sql (4.97ms)8612026/08/31 09:07:53 goose: up to current file version: 28622026/08/31 09:07:53 OK 20241026095416_initial_model.sql (18.21ms)8632026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (6.53ms)8642026/08/31 09:07:53 OK 2_object_stats_trigger.sql (5.3ms)8652026/08/31 09:07:53 goose: up to current file version: 28662026/08/31 09:07:53 OK 20251218171726_add_pins.sql (9.42ms)8672026/08/31 09:07:53 OK 20251210153512_drop_unused_gin_index.sql (4.84ms)8682026/08/31 09:07:53 OK 20251218171726_add_pins.sql (6.91ms)8692026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (7.21ms)8702026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200008712026/08/31 09:07:53 OK 20251218171726_add_pins.sql (4.91ms)8722026/08/31 09:07:53 OK 1_commit_pending_closure.sql (2.98ms)8732026/08/31 09:07:53 OK 2_object_stats_trigger.sql (1.68ms)8742026/08/31 09:07:53 goose: up to current file version: 28752026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (7.28ms)8762026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200008772026/08/31 09:07:53 OK 1_commit_pending_closure.sql (2.41ms)8782026/08/31 09:07:53 OK 20260628120000_add_object_size_and_stats.sql (13.01ms)8792026/08/31 09:07:53 goose: successfully migrated database to version: 202606281200008802026/08/31 09:07:53 OK 2_object_stats_trigger.sql (2.09ms)8812026/08/31 09:07:53 goose: up to current file version: 28822026/08/31 09:07:53 OK 1_commit_pending_closure.sql (2.19ms)8832026/08/31 09:07:53 OK 2_object_stats_trigger.sql (2.04ms)8842026/08/31 09:07:53 goose: up to current file version: 2885--- PASS: TestService_healthCheckHandler (0.99s)886=== CONT TestReadRedirectNar887--- PASS: TestReadProxy404 (1.04s)888=== CONT TestReadProxyHead8892026/08/31 09:07:54 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"890--- PASS: TestService_AuthMiddleware (1.06s)891=== CONT TestNARDeduplicationMetadataUploadBug8922026-08-31 09:07:54.150 UTC [309] ERROR: relation "goose_db_version" does not exist at character 368932026-08-31 09:07:54.150 UTC [309] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC894=== NAME TestClientMultipleUploads895 client_integration_test.go:339: Created store path 0: /build/TestClientMultipleUploads1946167085/001/store/29vg57nbmx80qlq7g8bf5mhb8q26mli9-test-file-0.txt8962026/08/31 09:07:54 INFO Aborted multipart uploads count=08972026/08/31 09:07:54 OK 20241026095416_initial_model.sql (24.48ms)8982026/08/31 09:07:54 WARN Force mode enabled - objects will be deleted immediately without grace period8992026/08/31 09:07:54 OK 20251210153512_drop_unused_gin_index.sql (4.97ms)900--- PASS: TestObjectStatsTrigger (1.14s)901=== CONT TestServerTLSConfig902=== RUN TestServerTLSConfig/no_client_CA903=== PAUSE TestServerTLSConfig/no_client_CA904=== RUN TestServerTLSConfig/missing_CA_file905=== PAUSE TestServerTLSConfig/missing_CA_file906=== RUN TestServerTLSConfig/not_a_PEM_file907=== PAUSE TestServerTLSConfig/not_a_PEM_file908=== CONT TestService_NativeMTLS9092026/08/31 09:07: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=09102026/08/31 09:07:54 OK 20251218171726_add_pins.sql (5.56ms)9112026/08/31 09:07:54 INFO Vacuumed table table=pending_closures9122026/08/31 09:07:54 INFO Vacuumed table table=pending_objects913--- PASS: TestService_ReadScope_PublicByDefault (1.13s)914=== CONT TestMetricsInventory9152026/08/31 09:07:54 INFO Vacuumed table table=multipart_uploads9162026/08/31 09:07:54 INFO Vacuumed table table=closures9172026/08/31 09:07:54 OK 20260628120000_add_object_size_and_stats.sql (13.34ms)9182026/08/31 09:07:54 goose: successfully migrated database to version: 202606281200009192026/08/31 09:07:54 INFO Vacuumed table table=objects9202026-08-31 09:07:54.230 UTC [315] ERROR: relation "goose_db_version" does not exist at character 369212026-08-31 09:07:54.230 UTC [315] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9222026/08/31 09:07:54 OK 1_commit_pending_closure.sql (6.9ms)923--- PASS: TestGCMetrics (1.15s)924=== CONT TestCacheConfigHandlerMaxNarSize925--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)926=== CONT TestCreatePendingClosureRejectsOversizedNAR9272026/08/31 09:07:54 INFO Received uploads request method=POST path=/api/pending_closures928--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)929=== CONT TestGCTaskStore_GetReturnsLatest930--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)931=== CONT TestGCTaskStore_CompletedAllowsNewTask932--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)933=== CONT TestGCTaskStore_GetEmpty934--- PASS: TestGCTaskStore_GetEmpty (0.00s)935=== CONT TestGenerateLandingPage9362026/08/31 09:07:54 OK 2_object_stats_trigger.sql (6.74ms)9372026/08/31 09:07:54 goose: up to current file version: 2938--- PASS: TestGenerateLandingPage (0.00s)939=== CONT TestService_AuthMiddleware_MTLSBoundSubjects9402026-08-31 09:07:54.244 UTC [332] ERROR: relation "goose_db_version" does not exist at character 369412026-08-31 09:07:54.244 UTC [332] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC942=== NAME TestClientMultipleUploads943 client_integration_test.go:339: Created store path 1: /build/TestClientMultipleUploads1946167085/001/store/d0g4s04j068kkg4r5nklsvfav570yn7f-test-file-1.txt9442026/08/31 09:07:54 OK 20241026095416_initial_model.sql (16.97ms)9452026/08/31 09:07:54 OK 20251210153512_drop_unused_gin_index.sql (4.18ms)9462026/08/31 09:07:54 OK 20251218171726_add_pins.sql (11.55ms)947--- PASS: TestReadProxyDisabled (1.22s)948=== CONT TestReadProxyInvalidPath9492026/08/31 09:07:54 OK 20260628120000_add_object_size_and_stats.sql (23.06ms)9502026/08/31 09:07:54 goose: successfully migrated database to version: 202606281200009512026/08/31 09:07:54 OK 20241026095416_initial_model.sql (43.38ms)9522026/08/31 09:07:54 OK 20251210153512_drop_unused_gin_index.sql (4.8ms)9532026/08/31 09:07:54 OK 1_commit_pending_closure.sql (8.6ms)9542026/08/31 09:07:54 OK 2_object_stats_trigger.sql (2.74ms)9552026/08/31 09:07:54 goose: up to current file version: 2956=== NAME TestClientMultipleUploads957 client_integration_test.go:339: Created store path 2: /build/TestClientMultipleUploads1946167085/001/store/dx2wbn78ncgrjcplbw0agq1npavcxcfb-test-file-2.txt9582026/08/31 09:07:54 INFO Received uploads request method=POST path=/api/pending_closures9592026/08/31 09:07:54 OK 20251218171726_add_pins.sql (21.26ms)9602026/08/31 09:07:54 OK 20260628120000_add_object_size_and_stats.sql (6.5ms)9612026/08/31 09:07:54 goose: successfully migrated database to version: 202606281200009622026/08/31 09:07:54 OK 1_commit_pending_closure.sql (4.64ms)9632026/08/31 09:07:54 OK 2_object_stats_trigger.sql (4.44ms)9642026/08/31 09:07:54 goose: up to current file version: 29652026-08-31 09:07:54.344 UTC [373] ERROR: relation "goose_db_version" does not exist at character 369662026-08-31 09:07:54.344 UTC [373] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9672026-08-31 09:07:54.358 UTC [375] ERROR: relation "goose_db_version" does not exist at character 369682026-08-31 09:07:54.358 UTC [375] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9692026-08-31 09:07:54.368 UTC [377] ERROR: relation "goose_db_version" does not exist at character 369702026-08-31 09:07:54.368 UTC [377] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9712026/08/31 09:07:54 OK 20241026095416_initial_model.sql (20.35ms)9722026/08/31 09:07:54 OK 20251210153512_drop_unused_gin_index.sql (5.38ms)973--- PASS: TestReadRedirectUsesPublicS3URL (1.33s)974=== CONT TestUploadHandlersRejectOversizedBody9752026/08/31 09:07:54 INFO Received uploads request method=POST path=/api/pending_closures9762026/08/31 09:07:54 INFO Received cleanup request method=DELETE path=/api/pending_closures977=== NAME TestClientWithDependencies978 client_integration_test.go:594: Built derivation: /build/TestClientWithDependencies3852193802/001/store/3f7fljiwrxdyvlaqn3csf11kgd03z3ar-test-script9792026/08/31 09:07:54 OK 20241026095416_initial_model.sql (117.34ms)9802026-08-31 09:07:54.489 UTC [411] ERROR: relation "goose_db_version" does not exist at character 369812026-08-31 09:07:54.489 UTC [411] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9822026/08/31 09:07:54 OK 20251218171726_add_pins.sql (104.31ms)9832026/08/31 09:07:54 OK 20251210153512_drop_unused_gin_index.sql (5.48ms)9842026/08/31 09:07:54 OK 20260628120000_add_object_size_and_stats.sql (10.81ms)9852026/08/31 09:07:54 goose: successfully migrated database to version: 202606281200009862026/08/31 09:07:54 INFO Aborted multipart uploads count=19872026/08/31 09:07:54 OK 20251218171726_add_pins.sql (7.06ms)9882026/08/31 09:07:54 OK 20241026095416_initial_model.sql (15.29ms)9892026/08/31 09:07:54 OK 1_commit_pending_closure.sql (4.11ms)990--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.44s)991=== CONT TestCompleteMultipartUnregistered9922026/08/31 09:07:54 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)9932026/08/31 09:07:54 goose: successfully migrated database to version: 202606281200009942026/08/31 09:07:54 OK 20251210153512_drop_unused_gin_index.sql (2.6ms)9952026/08/31 09:07:54 OK 2_object_stats_trigger.sql (3.18ms)9962026/08/31 09:07:54 goose: up to current file version: 2997--- PASS: TestMultipartCleanup (1.45s)998=== CONT TestService_verifyS3Integrity9992026/08/31 09:07:54 OK 1_commit_pending_closure.sql (4.91ms)10002026/08/31 09:07:54 OK 20251218171726_add_pins.sql (8.37ms)10012026/08/31 09:07:54 OK 2_object_stats_trigger.sql (8.51ms)10022026/08/31 09:07:54 goose: up to current file version: 210032026/08/31 09:07:54 OK 20241026095416_initial_model.sql (16.22ms)10042026/08/31 09:07:54 OK 20260628120000_add_object_size_and_stats.sql (6.14ms)10052026/08/31 09:07:54 goose: successfully migrated database to version: 2026062812000010062026/08/31 09:07:54 OK 1_commit_pending_closure.sql (2.24ms)10072026/08/31 09:07:54 OK 2_object_stats_trigger.sql (1.85ms)10082026/08/31 09:07:54 goose: up to current file version: 210092026/08/31 09:07:54 OK 20251210153512_drop_unused_gin_index.sql (5.54ms)1010=== NAME TestClientWithDependencies1011 client_integration_test.go:596: Found 1 dependencies (including self)10122026/08/31 09:07:54 OK 20251218171726_add_pins.sql (17.78ms)10132026/08/31 09:07:54 OK 20260628120000_add_object_size_and_stats.sql (71.04ms)10142026/08/31 09:07:54 goose: successfully migrated database to version: 202606281200001015--- PASS: TestReadRedirectKeepsNarinfoProxied (1.53s)1016=== CONT TestService_createPendingClosureHandler1017=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1018=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1019=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1020=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1021=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1022=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1023=== CONT TestService_cleanupPendingClosuresHandler10242026/08/31 09:07:54 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10252026/08/31 09:07:54 OK 1_commit_pending_closure.sql (5.7ms)10262026/08/31 09:07:54 OK 2_object_stats_trigger.sql (5.11ms)10272026/08/31 09:07:54 goose: up to current file version: 210282026-08-31 09:07:54.633 UTC [476] ERROR: relation "goose_db_version" does not exist at character 3610292026-08-31 09:07:54.633 UTC [476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10302026-08-31 09:07:54.635 UTC [478] ERROR: relation "goose_db_version" does not exist at character 3610312026-08-31 09:07:54.635 UTC [478] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1032--- PASS: TestCacheStatsHandler (1.59s)1033=== CONT TestProxyWriteTimeout/unknown_size1034=== CONT TestUploadHandlersRejectInvalidKeys1035=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1036=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1037=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1038=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1039=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1040=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1041=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1042=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1043=== CONT TestIsValidUploadKey1044=== RUN TestIsValidUploadKey/narinfo1045=== PAUSE TestIsValidUploadKey/narinfo1046=== RUN TestIsValidUploadKey/nar_zst1047=== PAUSE TestIsValidUploadKey/nar_zst1048=== RUN TestIsValidUploadKey/nar_xz1049=== PAUSE TestIsValidUploadKey/nar_xz1050=== RUN TestIsValidUploadKey/nar_plain1051=== PAUSE TestIsValidUploadKey/nar_plain1052=== RUN TestIsValidUploadKey/listing1053=== PAUSE TestIsValidUploadKey/listing1054=== RUN TestIsValidUploadKey/build_log1055=== PAUSE TestIsValidUploadKey/build_log1056=== RUN TestIsValidUploadKey/build_log_home-manager_file1057=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1058=== RUN TestIsValidUploadKey/build_log_plus_in_name1059=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1060=== RUN TestIsValidUploadKey/build_log_question_mark1061=== PAUSE TestIsValidUploadKey/build_log_question_mark1062=== RUN TestIsValidUploadKey/build_log_equals1063=== PAUSE TestIsValidUploadKey/build_log_equals1064=== RUN TestIsValidUploadKey/realisation1065=== PAUSE TestIsValidUploadKey/realisation1066=== RUN TestIsValidUploadKey/realisation_plus_in_output1067=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1068=== RUN TestIsValidUploadKey/nix-cache-info1069=== PAUSE TestIsValidUploadKey/nix-cache-info1070=== RUN TestIsValidUploadKey/index.html1071=== PAUSE TestIsValidUploadKey/index.html1072=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1073=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1074=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1075=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1076=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1077=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1078=== RUN TestIsValidUploadKey/traversal1079=== PAUSE TestIsValidUploadKey/traversal1080=== RUN TestIsValidUploadKey/traversal_nar1081=== PAUSE TestIsValidUploadKey/traversal_nar1082=== RUN TestIsValidUploadKey/absolute1083=== PAUSE TestIsValidUploadKey/absolute1084=== RUN TestIsValidUploadKey/empty_key1085=== PAUSE TestIsValidUploadKey/empty_key1086=== RUN TestIsValidUploadKey/unknown_type1087=== PAUSE TestIsValidUploadKey/unknown_type1088=== CONT TestGCTaskStore_ConflictDifferentParams1089--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1090=== CONT TestIsValidCachePath1091=== RUN TestIsValidCachePath/narinfo1092=== PAUSE TestIsValidCachePath/narinfo1093=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1094=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1095=== RUN TestIsValidCachePath/nar_zst1096=== PAUSE TestIsValidCachePath/nar_zst1097=== RUN TestIsValidCachePath/nar_xz1098=== PAUSE TestIsValidCachePath/nar_xz1099=== RUN TestIsValidCachePath/nar_bz21100=== PAUSE TestIsValidCachePath/nar_bz21101=== RUN TestIsValidCachePath/nar_uncompressed1102=== PAUSE TestIsValidCachePath/nar_uncompressed1103=== RUN TestIsValidCachePath/ls1104=== PAUSE TestIsValidCachePath/ls1105=== RUN TestIsValidCachePath/log1106=== PAUSE TestIsValidCachePath/log1107=== RUN TestIsValidCachePath/realisation1108=== PAUSE TestIsValidCachePath/realisation1109=== RUN TestIsValidCachePath/nix-cache-info1110=== PAUSE TestIsValidCachePath/nix-cache-info1111=== RUN TestIsValidCachePath/index.html1112=== PAUSE TestIsValidCachePath/index.html1113=== RUN TestIsValidCachePath/traversal_parent1114=== PAUSE TestIsValidCachePath/traversal_parent1115=== RUN TestIsValidCachePath/traversal_in_middle1116=== PAUSE TestIsValidCachePath/traversal_in_middle1117=== RUN TestIsValidCachePath/invalid_char_e1118=== PAUSE TestIsValidCachePath/invalid_char_e1119=== RUN TestIsValidCachePath/invalid_char_u1120=== PAUSE TestIsValidCachePath/invalid_char_u1121=== RUN TestIsValidCachePath/random_path1122=== PAUSE TestIsValidCachePath/random_path1123=== RUN TestIsValidCachePath/empty1124=== PAUSE TestIsValidCachePath/empty1125=== RUN TestIsValidCachePath/leading_slash1126=== PAUSE TestIsValidCachePath/leading_slash1127=== RUN TestIsValidCachePath/wrong_extension1128=== PAUSE TestIsValidCachePath/wrong_extension1129=== RUN TestIsValidCachePath/short_hash1130=== PAUSE TestIsValidCachePath/short_hash1131=== CONT TestReadProxyNarStreaming11322026/08/31 09:07:54 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11332026/08/31 09:07:54 INFO Received uploads request method=POST path=/api/pending_closures11342026/08/31 09:07:54 OK 20241026095416_initial_model.sql (35.14ms)11352026/08/31 09:07:54 OK 20251210153512_drop_unused_gin_index.sql (4.11ms)11362026/08/31 09:07:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11372026/08/31 09:07:54 INFO Uploading 3f7fljiwrxdyvlaqn3csf11kgd03z3ar-test-script (136B)11382026/08/31 09:07:54 INFO Received uploads request method=POST path=/api/pending_closures11392026/08/31 09:07:54 OK 20251218171726_add_pins.sql (4.18ms)11402026/08/31 09:07:54 OK 20241026095416_initial_model.sql (38.98ms)11412026/08/31 09:07:54 OK 20260628120000_add_object_size_and_stats.sql (7.63ms)11422026/08/31 09:07:54 goose: successfully migrated database to version: 2026062812000011432026/08/31 09:07:54 OK 20251210153512_drop_unused_gin_index.sql (8.28ms)11442026/08/31 09:07:54 OK 1_commit_pending_closure.sql (4.5ms)11452026/08/31 09:07:54 WARN Failed to register uploaded object key=log/qs8dclldf2x68jmpsa0dj3my6y09s7gw-test-script.drv error="server returned 404: 404 page not found\n"11462026/08/31 09:07:54 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"1147=== RUN TestService_RequireScope_OIDC/builder_may_write1148=== PAUSE TestService_RequireScope_OIDC/builder_may_write1149=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1150=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1151=== RUN TestService_RequireScope_OIDC/ops_may_admin1152=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1153=== RUN TestService_RequireScope_OIDC/ops_may_not_write1154=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1155=== RUN TestService_RequireScope_OIDC/reader_may_not_write1156=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1157=== RUN TestService_RequireScope_OIDC/static_token_may_admin1158=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1159=== RUN TestService_RequireScope_OIDC/static_token_may_write1160=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1161=== RUN TestService_RequireScope_OIDC/reader_may_read1162=== PAUSE TestService_RequireScope_OIDC/reader_may_read1163=== RUN TestService_RequireScope_OIDC/writer_implies_read1164=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1165=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1166=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1167=== CONT TestReadProxyNarinfoAlreadyDecompressed11682026/08/31 09:07:54 INFO Received uploads request method=POST path=/api/pending_closures11692026/08/31 09:07:54 WARN Failed to register uploaded object key=3f7fljiwrxdyvlaqn3csf11kgd03z3ar.ls error="server returned 404: 404 page not found\n"11702026/08/31 09:07:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11712026/08/31 09:07:54 INFO Signed narinfos id=1 count=111722026/08/31 09:07:54 INFO Uploading 1 narinfos11732026/08/31 09:07:54 OK 2_object_stats_trigger.sql (11.45ms)11742026/08/31 09:07:54 goose: up to current file version: 211752026/08/31 09:07:54 INFO Received uploads request method=POST path=/api/pending_closures11762026/08/31 09:07:54 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)11772026/08/31 09:07:54 INFO Uploading dx2wbn78ncgrjcplbw0agq1npavcxcfb-test-file-2.txt (160B)11782026/08/31 09:07:54 INFO Uploading 29vg57nbmx80qlq7g8bf5mhb8q26mli9-test-file-0.txt (160B)11792026/08/31 09:07:54 INFO Uploading d0g4s04j068kkg4r5nklsvfav570yn7f-test-file-1.txt (160B)11802026/08/31 09:07:54 WARN Failed to register uploaded object key=3f7fljiwrxdyvlaqn3csf11kgd03z3ar.narinfo error="server returned 404: 404 page not found\n"11812026/08/31 09:07:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11822026/08/31 09:07:54 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"11832026/08/31 09:07:54 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"11842026/08/31 09:07:54 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"11852026/08/31 09:07:54 WARN Failed to register uploaded object key=dx2wbn78ncgrjcplbw0agq1npavcxcfb.ls error="server returned 404: 404 page not found\n"11862026/08/31 09:07:54 WARN Failed to register uploaded object key=29vg57nbmx80qlq7g8bf5mhb8q26mli9.ls error="server returned 404: 404 page not found\n"11872026/08/31 09:07:54 OK 20251218171726_add_pins.sql (24.46ms)11882026/08/31 09:07:54 WARN Failed to register uploaded object key=d0g4s04j068kkg4r5nklsvfav570yn7f.ls error="server returned 404: 404 page not found\n"11892026/08/31 09:07:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign11902026/08/31 09:07:54 INFO Signed narinfos id=3 count=111912026/08/31 09:07:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11922026/08/31 09:07:54 INFO Signed narinfos id=1 count=111932026/08/31 09:07:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11942026/08/31 09:07:54 INFO Completed upload id=111952026/08/31 09:07:54 INFO Upload complete. (134ms)11962026/08/31 09:07:54 INFO Signed narinfos id=2 count=111972026/08/31 09:07:54 INFO Uploading 3 narinfos11982026/08/31 09:07:54 OK 20260628120000_add_object_size_and_stats.sql (11.7ms)11992026/08/31 09:07:54 goose: successfully migrated database to version: 2026062812000012002026-08-31 09:07:54.757 UTC [538] ERROR: relation "goose_db_version" does not exist at character 3612012026-08-31 09:07:54.757 UTC [538] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1202=== NAME TestClientWithDependencies1203 client_integration_test.go:598: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3852193802/001/store) requires matching store prefix12042026/08/31 09:07:54 OK 1_commit_pending_closure.sql (5.87ms)12052026/08/31 09:07:54 WARN Failed to register uploaded object key=d0g4s04j068kkg4r5nklsvfav570yn7f.narinfo error="server returned 404: 404 page not found\n"1206--- PASS: TestClientWithDependencies (1.68s)1207=== CONT TestReadProxyNarinfo12082026/08/31 09:07:54 WARN Failed to register uploaded object key=dx2wbn78ncgrjcplbw0agq1npavcxcfb.narinfo error="server returned 404: 404 page not found\n"12092026/08/31 09:07:54 WARN Failed to register uploaded object key=29vg57nbmx80qlq7g8bf5mhb8q26mli9.narinfo error="server returned 404: 404 page not found\n"12102026/08/31 09:07:54 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12112026/08/31 09:07:54 OK 2_object_stats_trigger.sql (13.15ms)12122026/08/31 09:07:54 goose: up to current file version: 212132026/08/31 09:07:54 INFO Completed upload id=212142026/08/31 09:07:54 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete12152026/08/31 09:07:54 INFO Completed upload id=312162026/08/31 09:07:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12172026/08/31 09:07:54 INFO Completed upload id=112182026/08/31 09:07:54 INFO Upload complete. (304ms)1219=== NAME TestClientMultipleUploads1220 client_integration_test.go:350: Uploaded 3 paths in 474.694058ms12212026-08-31 09:07:54.803 UTC [541] ERROR: relation "goose_db_version" does not exist at character 3612222026-08-31 09:07:54.803 UTC [541] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1223--- PASS: TestReadProxyRangeRequest (1.72s)1224=== CONT TestProxyWriteTimeout/10_GiB_nar1225=== CONT TestService_AuthMiddleware_MTLSProxyHeader1226--- PASS: TestClientMultipleUploads (1.75s)1227=== CONT TestResurrectedObjectNotDeleted12282026/08/31 09:07:54 OK 20241026095416_initial_model.sql (70.72ms)1229--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.77s)1230=== CONT TestParseSingleRange1231=== RUN TestParseSingleRange/none1232=== PAUSE TestParseSingleRange/none1233=== RUN TestParseSingleRange/unknown_unit1234=== PAUSE TestParseSingleRange/unknown_unit1235=== RUN TestParseSingleRange/multi-range_ignored1236=== PAUSE TestParseSingleRange/multi-range_ignored1237=== RUN TestParseSingleRange/malformed_no_dash1238=== PAUSE TestParseSingleRange/malformed_no_dash1239=== RUN TestParseSingleRange/malformed_both_empty1240=== PAUSE TestParseSingleRange/malformed_both_empty1241=== RUN TestParseSingleRange/malformed_end_before_start1242=== PAUSE TestParseSingleRange/malformed_end_before_start1243=== RUN TestParseSingleRange/closed1244=== PAUSE TestParseSingleRange/closed1245=== RUN TestParseSingleRange/open-ended1246=== PAUSE TestParseSingleRange/open-ended1247=== RUN TestParseSingleRange/end_clamped_to_size1248=== PAUSE TestParseSingleRange/end_clamped_to_size1249=== RUN TestParseSingleRange/suffix1250=== PAUSE TestParseSingleRange/suffix1251=== RUN TestParseSingleRange/suffix_exceeds_size1252=== PAUSE TestParseSingleRange/suffix_exceeds_size1253=== RUN TestParseSingleRange/single_byte1254=== PAUSE TestParseSingleRange/single_byte1255=== RUN TestParseSingleRange/start_past_EOF1256=== PAUSE TestParseSingleRange/start_past_EOF1257=== RUN TestParseSingleRange/start_far_past_EOF1258=== PAUSE TestParseSingleRange/start_far_past_EOF1259=== CONT TestProxyWriteTimeout/1_GiB_nar1260--- PASS: TestProxyWriteTimeout (0.00s)1261 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1262 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1263 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1264 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1265=== CONT TestService_Rustfstest12662026/08/31 09:07:54 OK 20251210153512_drop_unused_gin_index.sql (12.52ms)12672026-08-31 09:07:54.900 UTC [549] ERROR: relation "goose_db_version" does not exist at character 3612682026-08-31 09:07:54.900 UTC [549] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12692026/08/31 09:07:54 OK 20251218171726_add_pins.sql (36.41ms)1270--- PASS: TestReadProxyConditionalGet (1.83s)1271=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle12722026/08/31 09:07:54 OK 20260628120000_add_object_size_and_stats.sql (9.76ms)12732026/08/31 09:07:54 goose: successfully migrated database to version: 2026062812000012742026/08/31 09:07:54 OK 1_commit_pending_closure.sql (3.31ms)12752026/08/31 09:07:54 OK 2_object_stats_trigger.sql (4.96ms)12762026/08/31 09:07:54 goose: up to current file version: 212772026/08/31 09:07:54 OK 20241026095416_initial_model.sql (62.66ms)12782026/08/31 09:07:54 OK 20251210153512_drop_unused_gin_index.sql (8.19ms)1279=== NAME TestPinProtectsFromGC1280 client_integration_test.go:648: Pinned store path: /build/TestPinProtectsFromGC4128181755/001/store/g7zdh15356hi325lms8h0lw8xj05qbx6-pinned-file.txt1281 client_integration_test.go:649: Unpinned store path: /build/TestPinProtectsFromGC4128181755/001/store/rj6qpizjb6y4y37w29fwqmsccakp0jl5-unpinned-file.txt12822026/08/31 09:07:54 OK 20251218171726_add_pins.sql (14.35ms)12832026/08/31 09:07:54 OK 20241026095416_initial_model.sql (47.91ms)12842026/08/31 09:07:54 OK 20260628120000_add_object_size_and_stats.sql (24.94ms)12852026/08/31 09:07:54 goose: successfully migrated database to version: 2026062812000012862026/08/31 09:07:54 OK 20251210153512_drop_unused_gin_index.sql (11.62ms)12872026/08/31 09:07:54 OK 1_commit_pending_closure.sql (10.89ms)12882026/08/31 09:07:54 INFO Received cleanup request method=DELETE path=/api/pending_closures12892026/08/31 09:07:54 INFO Aborted multipart uploads count=012902026/08/31 09:07:54 INFO Received uploads request method=POST path=/api/pending_closures12912026/08/31 09:07:55 OK 2_object_stats_trigger.sql (16.78ms)12922026/08/31 09:07:55 goose: up to current file version: 212932026/08/31 09:07:55 OK 20251218171726_add_pins.sql (25.06ms)12942026/08/31 09:07:55 OK 20260628120000_add_object_size_and_stats.sql (5.33ms)12952026/08/31 09:07:55 goose: successfully migrated database to version: 2026062812000012962026-08-31 09:07:55.021 UTC [571] ERROR: relation "goose_db_version" does not exist at character 3612972026-08-31 09:07:55.021 UTC [571] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12982026/08/31 09:07:55 OK 1_commit_pending_closure.sql (25.3ms)1299--- PASS: TestService_ReadAuthMiddleware (1.82s)1300=== CONT TestSkippedUploadsHandler13012026/08/31 09:07:55 INFO Received cleanup request method=DELETE path=/api/pending_closures13022026/08/31 09:07:55 OK 2_object_stats_trigger.sql (8.79ms)13032026/08/31 09:07:55 goose: up to current file version: 213042026/08/31 09:07:55 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001305--- PASS: TestSkippedUploadsHandler (0.01s)1306=== CONT TestParseSize1307--- PASS: TestParseSize (0.00s)1308=== CONT TestOrphanedObjectsGCStressTest13092026-08-31 09:07:55.047 UTC [605] ERROR: relation "goose_db_version" does not exist at character 3613102026-08-31 09:07:55.047 UTC [605] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13112026/08/31 09:07:55 INFO Aborted multipart uploads count=113122026-08-31 09:07:55.072 UTC [609] ERROR: relation "goose_db_version" does not exist at character 3613132026-08-31 09:07:55.072 UTC [609] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13142026/08/31 09:07:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13152026-08-31 09:07:55.080 UTC [538] ERROR: Closure does not exist: id=113162026-08-31 09:07:55.080 UTC [538] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE13172026-08-31 09:07:55.080 UTC [538] STATEMENT: -- name: CommitPendingClosure :exec1318 SELECT commit_pending_closure($1::bigint)1319 1320--- PASS: TestService_cleanupPendingClosuresHandler (0.46s)1321=== CONT TestCompletedNarNotReofferedAcrossClosures13222026/08/31 09:07:55 OK 20241026095416_initial_model.sql (51.4ms)13232026/08/31 09:07:55 OK 20251210153512_drop_unused_gin_index.sql (5.36ms)13242026/08/31 09:07:55 OK 20251218171726_add_pins.sql (18.68ms)13252026/08/31 09:07:55 OK 20241026095416_initial_model.sql (41.21ms)13262026-08-31 09:07:55.133 UTC [647] ERROR: relation "goose_db_version" does not exist at character 3613272026-08-31 09:07:55.133 UTC [647] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13282026-08-31 09:07:55.134 UTC [648] ERROR: relation "goose_db_version" does not exist at character 3613292026-08-31 09:07:55.134 UTC [648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13302026/08/31 09:07:55 OK 20260628120000_add_object_size_and_stats.sql (11.07ms)13312026/08/31 09:07:55 goose: successfully migrated database to version: 2026062812000013322026/08/31 09:07:55 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1333=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1334=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1335=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1336=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1337=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1338=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1339=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1340=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1341=== CONT TestPresignedUploadRegisteredBeforeCommit13422026/08/31 09:07:55 OK 20251210153512_drop_unused_gin_index.sql (22.46ms)13432026/08/31 09:07:55 OK 20241026095416_initial_model.sql (72.44ms)1344=== NAME TestClientCADerivations1345 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2182464460/001/store/yn26vjksxl07qfpaqd5a7wf4637dvvfa-ca-test13462026/08/31 09:07:55 OK 1_commit_pending_closure.sql (17.68ms)13472026-08-31 09:07:55.156 UTC [649] ERROR: relation "goose_db_version" does not exist at character 3613482026-08-31 09:07:55.156 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13492026/08/31 09:07:55 OK 20251210153512_drop_unused_gin_index.sql (9.44ms)13502026/08/31 09:07:55 OK 20251218171726_add_pins.sql (14.81ms)13512026/08/31 09:07:55 OK 2_object_stats_trigger.sql (8.75ms)13522026/08/31 09:07:55 goose: up to current file version: 213532026/08/31 09:07:55 OK 20251218171726_add_pins.sql (8.47ms)13542026/08/31 09:07:55 OK 20260628120000_add_object_size_and_stats.sql (7.27ms)13552026/08/31 09:07:55 goose: successfully migrated database to version: 2026062812000013562026/08/31 09:07:55 OK 1_commit_pending_closure.sql (6.11ms)13572026/08/31 09:07:55 OK 20260628120000_add_object_size_and_stats.sql (12ms)13582026/08/31 09:07:55 goose: successfully migrated database to version: 2026062812000013592026/08/31 09:07:55 OK 20241026095416_initial_model.sql (17.44ms)13602026/08/31 09:07:55 OK 20241026095416_initial_model.sql (24.95ms)13612026/08/31 09:07:55 OK 20251210153512_drop_unused_gin_index.sql (14.12ms)13622026/08/31 09:07:55 OK 2_object_stats_trigger.sql (18.18ms)13632026/08/31 09:07:55 goose: up to current file version: 213642026/08/31 09:07:55 OK 1_commit_pending_closure.sql (16.49ms)13652026/08/31 09:07:55 OK 20251210153512_drop_unused_gin_index.sql (18.73ms)13662026/08/31 09:07:55 OK 2_object_stats_trigger.sql (16.06ms)13672026/08/31 09:07:55 goose: up to current file version: 213682026/08/31 09:07:55 OK 20251218171726_add_pins.sql (17.8ms)13692026/08/31 09:07:55 OK 20251218171726_add_pins.sql (18.11ms)13702026/08/31 09:07:55 OK 20260628120000_add_object_size_and_stats.sql (19.06ms)13712026/08/31 09:07:55 goose: successfully migrated database to version: 2026062812000013722026/08/31 09:07:55 INFO Received uploads request method=POST path=/api/pending_closures13732026/08/31 09:07:55 OK 1_commit_pending_closure.sql (4.31ms)13742026/08/31 09:07:55 OK 2_object_stats_trigger.sql (1.59ms)13752026/08/31 09:07:55 goose: up to current file version: 21376 client_ca_test.go:139: Found 1 dependencies (including self)13772026/08/31 09:07:55 OK 20241026095416_initial_model.sql (83.69ms)13782026/08/31 09:07:55 OK 20251210153512_drop_unused_gin_index.sql (9.2ms)13792026/08/31 09:07:55 OK 20251218171726_add_pins.sql (10.06ms)13802026/08/31 09:07:55 OK 20260628120000_add_object_size_and_stats.sql (49.51ms)13812026/08/31 09:07:55 goose: successfully migrated database to version: 2026062812000013822026/08/31 09:07:55 OK 1_commit_pending_closure.sql (4.28ms)13832026/08/31 09:07:55 OK 2_object_stats_trigger.sql (1.75ms)13842026/08/31 09:07:55 goose: up to current file version: 213852026/08/31 09:07:55 OK 20260628120000_add_object_size_and_stats.sql (7.45ms)13862026/08/31 09:07:55 goose: successfully migrated database to version: 202606281200001387--- PASS: TestReadRedirectNar (1.23s)1388=== CONT TestCompleteMultipartUpload_ErrorButObjectExists13892026/08/31 09:07:55 OK 1_commit_pending_closure.sql (27.21ms)13902026/08/31 09:07:55 OK 2_object_stats_trigger.sql (1.84ms)13912026/08/31 09:07:55 goose: up to current file version: 213922026/08/31 09:07:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13932026/08/31 09:07:55 INFO Uploading g7zdh15356hi325lms8h0lw8xj05qbx6-pinned-file.txt (128B)13942026/08/31 09:07:55 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13952026/08/31 09:07:55 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1396=== NAME TestClientIntegration1397 client_integration_test.go:277: Created store path: /build/TestClientIntegration1479270660/002/store/rqb1b5l5p2pv2fj1b3h2cc9xayqrydll-test-file.txt13982026/08/31 09:07:55 WARN Failed to register uploaded object key=g7zdh15356hi325lms8h0lw8xj05qbx6.ls error="server returned 404: 404 page not found\n"13992026/08/31 09:07:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14002026/08/31 09:07:55 INFO Signed narinfos id=1 count=114012026/08/31 09:07:55 INFO Uploading 1 narinfos14022026/08/31 09:07:55 WARN Failed to register uploaded object key=g7zdh15356hi325lms8h0lw8xj05qbx6.narinfo error="server returned 404: 404 page not found\n"14032026/08/31 09:07:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14042026-08-31 09:07:55.382 UTC [744] ERROR: relation "goose_db_version" does not exist at character 3614052026-08-31 09:07:55.382 UTC [744] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1406--- PASS: TestGCBugBareHashReferences (2.31s)1407=== CONT TestRedundantMultipartUpload14082026/08/31 09:07:55 INFO Completed upload id=114092026/08/31 09:07:55 INFO Upload complete. (361ms)1410--- PASS: TestReadProxyHead (1.30s)1411=== CONT TestOrphanedObjectsGC14122026/08/31 09:07:55 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14132026/08/31 09:07:55 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1414--- PASS: TestService_NativeMTLS (1.24s)1415=== CONT TestCacheConfigHandler/full_config,_no_issuer1416=== CONT TestCacheConfigHandler/no_signing_keys1417=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1418=== CONT TestCacheConfigHandler/no_cache_url_configured1419--- PASS: TestCacheConfigHandler (0.00s)1420 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1421 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1422 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1423 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1424=== CONT TestClientErrorHandling/InvalidStorePath14252026/08/31 09:07:55 INFO Received uploads request method=POST path=/api/pending_closures1426=== NAME TestNARDeduplicationMetadataUploadBug1427 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2906384737/001/store/22zh3jphcaaqm68l4v3d5sxqf8ps1jsj-file1.txt14282026/08/31 09:07:55 OK 20241026095416_initial_model.sql (47.59ms)14292026/08/31 09:07:55 OK 20251210153512_drop_unused_gin_index.sql (6.87ms)14302026-08-31 09:07:55.483 UTC [839] ERROR: relation "goose_db_version" does not exist at character 3614312026-08-31 09:07:55.483 UTC [839] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14322026-08-31 09:07:55.485 UTC [840] ERROR: relation "goose_db_version" does not exist at character 3614332026-08-31 09:07:55.485 UTC [840] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14342026/08/31 09:07:55 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14352026-08-31 09:07:55.495 UTC [842] ERROR: relation "goose_db_version" does not exist at character 3614362026-08-31 09:07:55.495 UTC [842] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14372026/08/31 09:07:55 OK 20251218171726_add_pins.sql (22.1ms)14382026/08/31 09:07:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14392026/08/31 09:07:55 INFO Uploading yn26vjksxl07qfpaqd5a7wf4637dvvfa-ca-test (144B)14402026/08/31 09:07:55 OK 20260628120000_add_object_size_and_stats.sql (9.15ms)14412026/08/31 09:07:55 goose: successfully migrated database to version: 2026062812000014422026/08/31 09:07:55 WARN Failed to register uploaded object key=log/1ank6ifzk27zzd6aixkyn6nld40gv8hm-ca-test.drv error="server returned 404: 404 page not found\n"14432026/08/31 09:07:55 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14442026/08/31 09:07:55 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14452026/08/31 09:07:55 OK 1_commit_pending_closure.sql (8.88ms)1446--- PASS: TestMetricsInventory (1.31s)1447=== CONT TestClientErrorHandling/ServerNotAvailable14482026/08/31 09:07:55 OK 2_object_stats_trigger.sql (3.41ms)14492026/08/31 09:07:55 goose: up to current file version: 214502026/08/31 09:07:55 WARN Failed to register uploaded object key=yn26vjksxl07qfpaqd5a7wf4637dvvfa.ls error="server returned 404: 404 page not found\n"14512026/08/31 09:07:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14522026/08/31 09:07:55 INFO Signed narinfos id=1 count=114532026/08/31 09:07:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14542026/08/31 09:07:55 WARN mTLS auth: bound subjects configured but subject DN unavailable14552026/08/31 09:07:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1456--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.28s)1457=== CONT TestClientErrorHandling/InvalidAuthToken14582026/08/31 09:07:55 INFO Uploading 1 narinfos14592026/08/31 09:07:55 WARN Failed to register uploaded object key=yn26vjksxl07qfpaqd5a7wf4637dvvfa.narinfo error="server returned 404: 404 page not found\n"14602026/08/31 09:07:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1461--- PASS: TestReadProxyInvalidPath (1.27s)1462=== CONT TestResolveDBConnectionString/flag_wins1463=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1464=== CONT TestResolveDBConnectionString/nothing_configured1465=== CONT TestResolveDBConnectionString/missing_file_is_an_error1466=== CONT TestResolveDBConnectionString/file_when_flag_empty1467--- PASS: TestResolveDBConnectionString (0.00s)1468 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1469 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1470 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1471 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1472 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1473=== CONT TestServerTLSConfig/no_client_CA1474=== CONT TestServerTLSConfig/not_a_PEM_file1475=== CONT TestServerTLSConfig/missing_CA_file1476--- PASS: TestServerTLSConfig (0.00s)1477 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1478 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1479 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1480=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14812026/08/31 09:07:55 INFO Received uploads request method=POST path=/14822026/08/31 09:07:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14832026/08/31 09:07:55 INFO Completed upload id=114842026/08/31 09:07:55 INFO Received uploads request method=POST path=/api/pending_closures14852026/08/31 09:07:55 INFO Upload complete. (282ms)14862026/08/31 09:07:55 INFO Received uploads request method=POST path=/api/pending_closures14872026/08/31 09:07:55 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1488--- PASS: TestCompleteMultipartUnregistered (1.08s)1489=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14902026/08/31 09:07:55 INFO Received request for more parts method=POST path=/14912026/08/31 09:07:55 OK 20241026095416_initial_model.sql (72.61ms)1492=== NAME TestClientCADerivations1493 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2182464460/001/store/yn26vjksxl07qfpaqd5a7wf4637dvvfa-ca-test1494 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1495 Compression: zstd1496 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1497 NarSize: 1441498 References: 1499 Deriver: /build/TestClientCADerivations2182464460/001/store/1ank6ifzk27zzd6aixkyn6nld40gv8hm-ca-test.drv1500 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1501 client_ca_test.go:185: Checking for realisation files in S3...15022026/08/31 09:07:55 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15032026/08/31 09:07:55 OK 20251210153512_drop_unused_gin_index.sql (23.5ms)1504 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1505 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15062026/08/31 09:07:55 INFO Received uploads request method=POST path=/api/pending_closures15072026-08-31 09:07:55.624 UTC [952] ERROR: relation "goose_db_version" does not exist at character 3615082026-08-31 09:07:55.624 UTC [952] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15092026/08/31 09:07:55 OK 20241026095416_initial_model.sql (113.84ms)15102026/08/31 09:07:55 OK 20251210153512_drop_unused_gin_index.sql (4.14ms)15112026/08/31 09:07:55 OK 20251218171726_add_pins.sql (12.03ms)15122026/08/31 09:07:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15132026/08/31 09:07:55 INFO Uploading rj6qpizjb6y4y37w29fwqmsccakp0jl5-unpinned-file.txt (128B)15142026/08/31 09:07:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15152026/08/31 09:07:55 INFO Uploading rqb1b5l5p2pv2fj1b3h2cc9xayqrydll-test-file.txt (152B)15162026-08-31 09:07:55.645 UTC [971] ERROR: relation "goose_db_version" does not exist at character 3615172026-08-31 09:07:55.645 UTC [971] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15182026/08/31 09:07:55 OK 20251218171726_add_pins.sql (13.59ms)15192026/08/31 09:07:55 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15202026/08/31 09:07:55 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15212026/08/31 09:07:55 INFO Received uploads request method=POST path=/api/pending_closures15222026/08/31 09:07:55 INFO Received uploads request method=POST path=/api/pending_closures15232026/08/31 09:07:55 INFO Received uploads request method=POST path=/api/pending_closures15242026/08/31 09:07:55 OK 20260628120000_add_object_size_and_stats.sql (8.04ms)15252026/08/31 09:07:55 goose: successfully migrated database to version: 2026062812000015262026/08/31 09:07:55 OK 20241026095416_initial_model.sql (142.51ms)15272026/08/31 09:07:55 WARN Failed to register uploaded object key=rj6qpizjb6y4y37w29fwqmsccakp0jl5.ls error="server returned 404: 404 page not found\n"15282026/08/31 09:07:55 WARN Failed to register uploaded object key=rqb1b5l5p2pv2fj1b3h2cc9xayqrydll.ls error="server returned 404: 404 page not found\n"15292026/08/31 09:07:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15302026/08/31 09:07:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15312026/08/31 09:07:55 INFO Signed narinfos id=2 count=115322026/08/31 09:07:55 INFO Received uploads request method=POST path=/api/pending_closures15332026/08/31 09:07:55 OK 20260628120000_add_object_size_and_stats.sql (25.56ms)15342026/08/31 09:07:55 goose: successfully migrated database to version: 2026062812000015352026/08/31 09:07:55 INFO Signed narinfos id=1 count=115362026/08/31 09:07:55 INFO Uploading 1 narinfos15372026/08/31 09:07:55 INFO Uploading 1 narinfos15382026/08/31 09:07:55 OK 1_commit_pending_closure.sql (15.2ms)15392026/08/31 09:07:55 OK 20251210153512_drop_unused_gin_index.sql (11.75ms)15402026/08/31 09:07:55 OK 1_commit_pending_closure.sql (10.15ms)15412026/08/31 09:07:55 OK 20241026095416_initial_model.sql (26.3ms)1542=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15432026/08/31 09:07:55 INFO Received complete multipart upload request method=POST path=/15442026/08/31 09:07:55 WARN Failed to register uploaded object key=rj6qpizjb6y4y37w29fwqmsccakp0jl5.narinfo error="server returned 404: 404 page not found\n"15452026/08/31 09:07:55 WARN Failed to register uploaded object key=rqb1b5l5p2pv2fj1b3h2cc9xayqrydll.narinfo error="server returned 404: 404 page not found\n"15462026/08/31 09:07:55 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15472026/08/31 09:07:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15482026-08-31 09:07:55.721 UTC [1006] ERROR: relation "goose_db_version" does not exist at character 3615492026-08-31 09:07:55.721 UTC [1006] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15502026/08/31 09:07:55 OK 2_object_stats_trigger.sql (53.46ms)15512026/08/31 09:07:55 goose: up to current file version: 215522026/08/31 09:07:55 INFO Completed upload id=215532026/08/31 09:07:55 INFO Upload complete. (264ms)15542026/08/31 09:07:55 OK 20251218171726_add_pins.sql (56.54ms)15552026/08/31 09:07:55 OK 20251210153512_drop_unused_gin_index.sql (54ms)15562026/08/31 09:07:55 OK 2_object_stats_trigger.sql (62.34ms)15572026/08/31 09:07:55 goose: up to current file version: 21558=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15592026/08/31 09:07:55 INFO Received uploads request method=POST path=/1560=== CONT TestIsValidUploadKey/narinfo1561=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15622026/08/31 09:07:55 INFO Received request for more parts method=POST path=/1563=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15642026/08/31 09:07:55 INFO Received complete multipart upload request method=POST path=/1565=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15662026/08/31 09:07:55 INFO Received uploads request method=POST path=/1567--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1568 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1569 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1570 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1571 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1572=== CONT TestIsValidUploadKey/realisation_plus_in_output1573=== CONT TestIsValidUploadKey/unknown_type1574=== CONT TestIsValidUploadKey/empty_key1575=== CONT TestIsValidUploadKey/absolute1576=== CONT TestIsValidUploadKey/traversal_nar1577=== CONT TestIsValidUploadKey/traversal1578=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1579=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1580=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1581=== CONT TestIsValidUploadKey/index.html1582=== CONT TestIsValidUploadKey/nix-cache-info1583=== CONT TestIsValidUploadKey/build_log_home-manager_file1584=== CONT TestIsValidUploadKey/realisation1585=== CONT TestIsValidUploadKey/build_log_equals1586=== CONT TestIsValidUploadKey/build_log_question_mark1587=== CONT TestIsValidUploadKey/build_log_plus_in_name1588=== CONT TestIsValidUploadKey/nar_plain1589=== CONT TestIsValidUploadKey/build_log1590=== CONT TestIsValidUploadKey/listing1591=== CONT TestIsValidUploadKey/nar_xz1592=== CONT TestIsValidUploadKey/nar_zst1593--- PASS: TestIsValidUploadKey (0.00s)1594 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1595 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1596 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1597 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1598 --- PASS: TestIsValidUploadKey/absolute (0.00s)1599 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1600 --- PASS: TestIsValidUploadKey/traversal (0.00s)1601 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1602 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1603 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1604 --- PASS: TestIsValidUploadKey/index.html (0.00s)1605 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1606 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1607 --- PASS: TestIsValidUploadKey/realisation (0.00s)1608 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1609 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1610 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1611 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1612 --- PASS: TestIsValidUploadKey/build_log (0.00s)1613 --- PASS: TestIsValidUploadKey/listing (0.00s)1614 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1615 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1616=== CONT TestIsValidCachePath/narinfo1617=== CONT TestIsValidCachePath/index.html1618=== CONT TestIsValidCachePath/short_hash1619=== CONT TestIsValidCachePath/wrong_extension1620=== CONT TestIsValidCachePath/leading_slash1621=== CONT TestIsValidCachePath/empty1622=== CONT TestIsValidCachePath/random_path1623=== CONT TestIsValidCachePath/invalid_char_u1624=== CONT TestIsValidCachePath/invalid_char_e1625=== CONT TestIsValidCachePath/traversal_in_middle1626=== CONT TestIsValidCachePath/traversal_parent1627=== CONT TestIsValidCachePath/nar_uncompressed1628=== CONT TestIsValidCachePath/nix-cache-info1629=== CONT TestIsValidCachePath/realisation1630=== CONT TestIsValidCachePath/log1631=== CONT TestIsValidCachePath/ls1632=== CONT TestIsValidCachePath/nar_xz1633=== CONT TestIsValidCachePath/nar_bz21634=== CONT TestIsValidCachePath/nar_zst1635=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1636--- PASS: TestIsValidCachePath (0.00s)1637 --- PASS: TestIsValidCachePath/narinfo (0.00s)1638 --- PASS: TestIsValidCachePath/index.html (0.00s)1639 --- PASS: TestIsValidCachePath/short_hash (0.00s)1640 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1641 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1642 --- PASS: TestIsValidCachePath/empty (0.00s)1643 --- PASS: TestIsValidCachePath/random_path (0.00s)1644 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1645 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1646 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1647 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1648 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1649 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1650 --- PASS: TestIsValidCachePath/realisation (0.00s)1651 --- PASS: TestIsValidCachePath/log (0.00s)1652 --- PASS: TestIsValidCachePath/ls (0.00s)1653 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1654 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1655 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1656 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1657=== CONT TestService_RequireScope_OIDC/builder_may_write16582026/08/31 09:07:55 OK 20241026095416_initial_model.sql (69.65ms)16592026/08/31 09:07:55 OK 20260628120000_add_object_size_and_stats.sql (12.69ms)16602026/08/31 09:07:55 goose: successfully migrated database to version: 2026062812000016612026/08/31 09:07:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16622026/08/31 09:07:55 INFO Uploading 22zh3jphcaaqm68l4v3d5sxqf8ps1jsj-file1.txt (160B)16632026-08-31 09:07:55.741 UTC [1007] ERROR: relation "goose_db_version" does not exist at character 3616642026-08-31 09:07:55.741 UTC [1007] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16652026/08/31 09:07:55 INFO OIDC auth successful provider=test scopes=[write]1666=== CONT TestService_RequireScope_OIDC/static_token_may_admin1667=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1668=== CONT TestService_RequireScope_OIDC/writer_implies_read16692026/08/31 09:07:55 INFO OIDC auth successful provider=test scopes=[write]1670=== CONT TestService_RequireScope_OIDC/reader_may_read16712026/08/31 09:07:55 INFO OIDC auth successful provider=test scopes=[read]1672=== CONT TestService_RequireScope_OIDC/static_token_may_write1673=== CONT TestService_RequireScope_OIDC/ops_may_not_write16742026/08/31 09:07:55 INFO OIDC auth successful provider=test scopes=[admin]1675=== CONT TestService_RequireScope_OIDC/reader_may_not_write16762026/08/31 09:07:55 INFO OIDC auth successful provider=test scopes=[read]1677=== CONT TestService_RequireScope_OIDC/ops_may_admin16782026/08/31 09:07:55 INFO OIDC auth successful provider=test scopes=[admin]1679=== CONT TestService_RequireScope_OIDC/builder_may_not_admin16802026/08/31 09:07:55 INFO OIDC auth successful provider=test scopes=[write]1681=== CONT TestParseSingleRange/none1682=== CONT TestParseSingleRange/start_far_past_EOF1683=== CONT TestParseSingleRange/start_past_EOF1684=== CONT TestParseSingleRange/single_byte1685=== CONT TestParseSingleRange/suffix_exceeds_size1686=== CONT TestParseSingleRange/suffix1687=== CONT TestParseSingleRange/end_clamped_to_size1688=== CONT TestParseSingleRange/open-ended1689=== CONT TestParseSingleRange/closed1690=== CONT TestParseSingleRange/malformed_end_before_start1691=== CONT TestParseSingleRange/malformed_both_empty1692=== CONT TestParseSingleRange/malformed_no_dash1693=== CONT TestParseSingleRange/multi-range_ignored1694=== CONT TestParseSingleRange/unknown_unit1695--- PASS: TestParseSingleRange (0.00s)1696 --- PASS: TestParseSingleRange/none (0.00s)1697 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1698 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1699 --- PASS: TestParseSingleRange/single_byte (0.00s)1700 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1701 --- PASS: TestParseSingleRange/suffix (0.00s)1702 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1703 --- PASS: TestParseSingleRange/open-ended (0.00s)1704 --- PASS: TestParseSingleRange/closed (0.00s)1705 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1706 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1707 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1708 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1709 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1710=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1711--- PASS: TestService_RequireScope_OIDC (1.62s)1712 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.01s)1713 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1714 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1715 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1716 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1717 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1718 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1719 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1720 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1721 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)17222026/08/31 09:07:55 INFO Completed upload id=117232026/08/31 09:07:55 INFO Upload complete. (317ms)17242026/08/31 09:07:55 OK 20251210153512_drop_unused_gin_index.sql (6.9ms)17252026/08/31 09:07:55 OK 20251218171726_add_pins.sql (15.97ms)17262026/08/31 09:07:55 OK 1_commit_pending_closure.sql (10.8ms)1727=== NAME TestClientIntegration1728 client_integration_test.go:293: Retrieved narinfo from S3:1729 StorePath: /build/TestClientIntegration1479270660/002/store/rqb1b5l5p2pv2fj1b3h2cc9xayqrydll-test-file.txt1730 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1731 Compression: zstd1732 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11733 NarSize: 1521734 References: 1735 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk117362026/08/31 09:07:55 INFO OIDC auth successful provider=test scopes=[write]1737=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17382026/08/31 09:07:55 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]1739=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1740=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17412026/08/31 09:07:55 WARN Authentication failed token_preview=eyJhbGciOi...jhYLI6gqkw token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1742--- PASS: TestService_AuthMiddleware_OIDC (1.62s)1743 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)1744 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1745 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1746 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)17472026/08/31 09:07:55 OK 2_object_stats_trigger.sql (8.53ms)17482026/08/31 09:07:55 goose: up to current file version: 217492026/08/31 09:07:55 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"1750=== NAME TestClientIntegration1751 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1752 client_integration_test.go:294: Decompressed .ls content (64 bytes):1753 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1754 client_integration_test.go:297: Testing garbage collection...17552026/08/31 09:07:55 OK 20251218171726_add_pins.sql (19.61ms)17562026/08/31 09:07:55 OK 20260628120000_add_object_size_and_stats.sql (16.46ms)17572026/08/31 09:07:55 goose: successfully migrated database to version: 2026062812000017582026/08/31 09:07:55 WARN Failed to register uploaded object key=22zh3jphcaaqm68l4v3d5sxqf8ps1jsj.ls error="server returned 404: 404 page not found\n"17592026/08/31 09:07:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17602026/08/31 09:07:55 INFO Signed narinfos id=1 count=117612026/08/31 09:07:55 INFO Uploading 1 narinfos17622026/08/31 09:07:55 OK 20241026095416_initial_model.sql (19.71ms)17632026/08/31 09:07:55 OK 20260628120000_add_object_size_and_stats.sql (5.18ms)17642026/08/31 09:07:55 goose: successfully migrated database to version: 2026062812000017652026/08/31 09:07:55 OK 20251210153512_drop_unused_gin_index.sql (5.68ms)17662026/08/31 09:07:55 OK 1_commit_pending_closure.sql (5.73ms)17672026/08/31 09:07:55 OK 1_commit_pending_closure.sql (10.14ms)17682026/08/31 09:07:55 OK 2_object_stats_trigger.sql (3.34ms)17692026/08/31 09:07:55 goose: up to current file version: 217702026/08/31 09:07:55 OK 2_object_stats_trigger.sql (3.75ms)17712026/08/31 09:07:55 goose: up to current file version: 217722026/08/31 09:07:55 OK 20251218171726_add_pins.sql (4.49ms)17732026/08/31 09:07:55 WARN Failed to register uploaded object key=22zh3jphcaaqm68l4v3d5sxqf8ps1jsj.narinfo error="server returned 404: 404 page not found\n"17742026/08/31 09:07:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17752026/08/31 09:07:55 OK 20241026095416_initial_model.sql (28.03ms)17762026/08/31 09:07:55 OK 20260628120000_add_object_size_and_stats.sql (11.64ms)17772026/08/31 09:07:55 goose: successfully migrated database to version: 2026062812000017782026/08/31 09:07:55 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-config17792026/08/31 09:07:55 OK 1_commit_pending_closure.sql (2.66ms)17802026/08/31 09:07:55 OK 20251210153512_drop_unused_gin_index.sql (5.05ms)17812026/08/31 09:07:55 INFO Received create pin request method=POST path=/api/pins/myapp17822026/08/31 09:07:55 INFO Completed upload id=117832026/08/31 09:07:55 INFO Upload complete. (278ms)17842026/08/31 09:07:55 OK 2_object_stats_trigger.sql (2.98ms)17852026/08/31 09:07:55 goose: up to current file version: 217862026/08/31 09:07:55 OK 20251218171726_add_pins.sql (6.55ms)1787=== NAME TestNARDeduplicationMetadataUploadBug1788 metadata_upload_test.go:54: Retrieved narinfo from S3:1789 StorePath: /build/TestNARDeduplicationMetadataUploadBug2906384737/001/store/22zh3jphcaaqm68l4v3d5sxqf8ps1jsj-file1.txt1790 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1791 Compression: zstd1792 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1793 NarSize: 1601794 References: 1795 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf17962026/08/31 09:07:55 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4128181755/001/store/g7zdh15356hi325lms8h0lw8xj05qbx6-pinned-file.txt narinfo_key=g7zdh15356hi325lms8h0lw8xj05qbx6.narinfo17972026/08/31 09:07:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures17982026/08/31 09:07:55 INFO Garbage collection started17992026/08/31 09:07:55 OK 20260628120000_add_object_size_and_stats.sql (10.1ms)18002026/08/31 09:07:55 goose: successfully migrated database to version: 202606281200001801 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1802 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1803 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}18042026/08/31 09:07:55 OK 1_commit_pending_closure.sql (7.6ms)18052026/08/31 09:07:55 OK 2_object_stats_trigger.sql (2.83ms)18062026/08/31 09:07:55 goose: up to current file version: 218072026/08/31 09:07:55 INFO Aborted multipart uploads count=018082026/08/31 09:07:55 WARN Force mode enabled - objects will be deleted immediately without grace period1809=== NAME TestClientCADerivations1810 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1811 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1812 error: binary cache 's3://bucket22?endpoint=http://localhost:36881®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2182464460/001/store'1813 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11814--- PASS: TestClientCADerivations (2.77s)18152026/08/31 09:07:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures18162026/08/31 09:07:55 INFO Garbage collection started18172026/08/31 09:07:55 INFO Aborted multipart uploads count=018182026/08/31 09:07:55 WARN Force mode enabled - objects will be deleted immediately without grace period18192026/08/31 09:07:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.762142ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1820=== NAME TestNARDeduplicationMetadataUploadBug1821 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2906384737/001/store/45pc3lilz7i7xi4ql8vdy117l68bnf2g-file2.txt18222026/08/31 09:07:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18232026/08/31 09:07:56 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=401.64894ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18242026/08/31 09:07:56 INFO Received uploads request method=POST path=/api/pending_closures18252026/08/31 09:07:56 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18262026/08/31 09:07:56 WARN Failed to register uploaded object key=45pc3lilz7i7xi4ql8vdy117l68bnf2g.ls error="server returned 404: 404 page not found\n"18272026/08/31 09:07:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18282026/08/31 09:07:56 INFO Signed narinfos id=2 count=118292026/08/31 09:07:56 INFO Uploading 1 narinfos18302026/08/31 09:07:56 WARN Failed to register uploaded object key=45pc3lilz7i7xi4ql8vdy117l68bnf2g.narinfo error="server returned 404: 404 page not found\n"18312026/08/31 09:07:56 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18322026/08/31 09:07:56 INFO Completed upload id=218332026/08/31 09:07:56 INFO Upload complete. (337ms)1834 metadata_upload_test.go:76: Retrieved narinfo from S3:1835 StorePath: /build/TestNARDeduplicationMetadataUploadBug2906384737/001/store/45pc3lilz7i7xi4ql8vdy117l68bnf2g-file2.txt1836 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1837 Compression: zstd1838 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1839 NarSize: 1601840 References: 1841 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1842--- PASS: TestReadProxyNarStreaming (1.62s)1843=== NAME TestNARDeduplicationMetadataUploadBug1844 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1845 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1846 {"version":1,"root":{"type":"regular","size":44}}1847--- PASS: TestNARDeduplicationMetadataUploadBug (2.19s)18482026/08/31 09:07:56 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=797.165157ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1849--- PASS: TestUploadHandlersRejectOversizedBody (0.23s)1850 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.09s)1851 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1852 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.06s)1853--- PASS: TestReadProxyNarinfo (2.05s)1854--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.03s)1855--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.52s)1856--- PASS: TestService_Rustfstest (2.40s)18572026/08/31 09:07:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.579088856s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18582026/08/31 09:07:57 INFO Received uploads request method=POST path=/api/pending_closures1859--- PASS: TestResurrectedObjectNotDeleted (2.51s)18602026/08/31 09:07:57 INFO Received uploads request method=POST path=/api/pending_closures18612026/08/31 09:07:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18622026/08/31 09:07:57 INFO Received uploads request method=POST path=/api/pending_closures18632026/08/31 09:07:57 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst18642026/08/31 09:07:57 INFO Received uploads request method=POST path=/api/pending_closures1865--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.53s)18662026/08/31 09:07:57 INFO Received uploads request method=POST path=/api/pending_closures18672026/08/31 09:07:57 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=1000 objects_failed=018682026/08/31 09:07:57 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=1000 objects_failed=018692026/08/31 09:07:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18702026/08/31 09:07:57 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGQ4ZTEwOTEtOTkxMy00ZDgxLWI5ZTUtY2RiZTdiOTM2OWI0LmFlYWIwZjRjLTk3NDUtNDc4Yy05YjMwLTI3YTdmMTVjYTk4MHgxNzg4MTY3Mjc3NzI3Mzk2ODMz18712026/08/31 09:07:57 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGQ4ZTEwOTEtOTkxMy00ZDgxLWI5ZTUtY2RiZTdiOTM2OWI0LmFlYWIwZjRjLTk3NDUtNDc4Yy05YjMwLTI3YTdmMTVjYTk4MHgxNzg4MTY3Mjc3NzI3Mzk2ODMz parts=11872--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.70s)18732026/08/31 09:07:58 INFO Received uploads request method=POST path=/api/pending_closures18742026/08/31 09:07:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18752026/08/31 09:07:58 INFO Received uploads request method=POST path=/api/pending_closures18762026/08/31 09:07:58 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZGQ4ZTEwOTEtOTkxMy00ZDgxLWI5ZTUtY2RiZTdiOTM2OWI0LjFlNGE3MjA5LTVkZjQtNGE5ZC1iYWJkLTMzMGEyODlhNmIyOXgxNzg4MTY3Mjc1NzE2MTkyODk0 parts=1018772026/08/31 09:07:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18782026/08/31 09:07:58 INFO Completed upload id=118792026/08/31 09:07:58 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000018802026/08/31 09:07:58 INFO Received uploads request method=POST path=/api/pending_closures18812026/08/31 09:07:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures18822026/08/31 09:07:58 INFO Aborted multipart uploads count=018832026/08/31 09:07:58 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=018842026/08/31 09:07:58 INFO Vacuumed table table=pending_closures18852026/08/31 09:07:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18862026/08/31 09:07:58 INFO Vacuumed table table=pending_objects18872026/08/31 09:07:58 INFO Vacuumed table table=multipart_uploads18882026/08/31 09:07:58 INFO Vacuumed table table=closures18892026/08/31 09:07:58 INFO Vacuumed table table=objects18902026/08/31 09:07:58 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001891--- PASS: TestService_createPendingClosureHandler (3.68s)18922026/08/31 09:07:58 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=018932026/08/31 09:07:58 INFO Vacuumed table table=pending_closures18942026/08/31 09:07:58 INFO Vacuumed table table=pending_objects18952026/08/31 09:07:58 INFO Vacuumed table table=multipart_uploads18962026/08/31 09:07:58 INFO Vacuumed table table=closures18972026/08/31 09:07:58 INFO Vacuumed table table=objects18982026/08/31 09:07:58 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZGQ4ZTEwOTEtOTkxMy00ZDgxLWI5ZTUtY2RiZTdiOTM2OWI0Ljk4YWU2MGNkLTNkMjUtNDQwYS1iNzRkLWJiMmMyMjkyMDU0MXgxNzg4MTY3Mjc1NjUxOTQxMzUy parts=1018992026/08/31 09:07:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19002026/08/31 09:07:58 INFO Completed upload id=119012026/08/31 09:07:58 INFO Received uploads request method=POST path=/api/pending_closures19022026/08/31 09:07:58 INFO Received uploads request method=POST path=/api/pending_closures19032026/08/31 09:07:58 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo19042026/08/31 09:07:58 WARN Found objects in DB but missing from S3, will re-upload count=11905--- PASS: TestService_verifyS3Integrity (4.08s)19062026/08/31 09:07:58 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=019072026/08/31 09:07:58 INFO Vacuumed table table=pending_closures19082026/08/31 09:07:58 INFO Vacuumed table table=pending_objects19092026/08/31 09:07:58 INFO Vacuumed table table=multipart_uploads19102026/08/31 09:07:58 INFO Vacuumed table table=closures19112026/08/31 09:07:58 INFO Vacuumed table table=objects19122026/08/31 09:07:58 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1913=== NAME TestOrphanedObjectsGC1914 orphaned_objects_gc_test.go:290: GC Test Summary:1915 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1916 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1917 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1918 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1919 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1920--- PASS: TestOrphanedObjectsGC (3.32s)19212026/08/31 09:07:58 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19222026/08/31 09:07:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19232026/08/31 09:07:58 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZGQ4ZTEwOTEtOTkxMy00ZDgxLWI5ZTUtY2RiZTdiOTM2OWI0LmU1N2QxMmVlLWQ2MmUtNDExOS1hMWYwLWNjN2ZmMjBjYWU4MngxNzg4MTY3Mjc3MzcxOTU0NjA2 parts=1219242026/08/31 09:07:58 INFO Received uploads request method=POST path=/api/pending_closures1925--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.72s)19262026/08/31 09:07:58 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"19272026/08/31 09:07:58 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_closures19282026/08/31 09:07:59 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.800281ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19292026/08/31 09:07:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19302026/08/31 09:07:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZGQ4ZTEwOTEtOTkxMy00ZDgxLWI5ZTUtY2RiZTdiOTM2OWI0LjQxZjZmNDQyLTAwNmMtNGNmMS1hN2QzLWM4ZThhZjQxNzkxOXgxNzg4MTY3Mjc4MTMwMTg2OTAx parts=121931--- PASS: TestRedundantMultipartUpload (3.79s)19322026/08/31 09:07:59 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=408.677207ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19332026/08/31 09:07:59 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=868.382667ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19342026/08/31 09:07:59 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01935=== NAME TestPinProtectsFromGC1936 client_integration_test.go:711: Pin successfully protected closure from garbage collection1937--- PASS: TestPinProtectsFromGC (6.75s)19382026/08/31 09:07:59 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01939=== NAME TestClientIntegration1940 client_integration_test.go:304: Objects in database after GC:1941 client_integration_test.go:304: Successfully deleted all objects with GC --force1942--- PASS: TestClientIntegration (6.80s)1943=== NAME TestOrphanedObjectsGCStressTest1944 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1945 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19462026/08/31 09:08:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.504406782s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1947 orphaned_objects_gc_test.go:509: Stress test completed successfully:1948 orphaned_objects_gc_test.go:510: - Active objects preserved: 201949 orphaned_objects_gc_test.go:511: - Objects deleted: 2101950 orphaned_objects_gc_test.go:512: - Total GC'd: 2101951--- PASS: TestOrphanedObjectsGCStressTest (5.71s)19522026/08/31 09:08:01 WARN Rate limiter enabled after throttle name=s3-test rate=519532026/08/31 09:08:01 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1954=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1955 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101956 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001957--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.53s)1958--- PASS: TestClientErrorHandling (0.00s)1959 --- PASS: TestClientErrorHandling/InvalidStorePath (2.86s)1960 --- PASS: TestClientErrorHandling/InvalidAuthToken (3.24s)1961 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.49s)1962PASS19632026-08-31 09:08:02.293 UTC [107] LOG: received smart shutdown request19642026-08-31 09:08:02.304 UTC [107] LOG: background worker "logical replication launcher" (PID 117) exited with exit code 119652026-08-31 09:08:02.310 UTC [112] LOG: shutting down19662026-08-31 09:08:02.310 UTC [112] LOG: checkpoint starting: shutdown immediate19672026-08-31 09:08:03.841 UTC [112] LOG: checkpoint complete: wrote 12140 buffers (74.1%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 14 recycled; write=0.299 s, sync=1.216 s, total=1.532 s; sync files=17141, longest=0.003 s, average=0.001 s; distance=236074 kB, estimate=236074 kB; lsn=0/FDEE608, redo lsn=0/FDEE60819682026-08-31 09:08:03.921 UTC [107] LOG: database system is shut down1969Running OIDC tests...1970=== RUN TestGlobMatch1971=== PAUSE TestGlobMatch1972=== RUN TestAudienceForIssuer1973=== PAUSE TestAudienceForIssuer1974=== RUN TestValidateToken_ValidToken1975=== PAUSE TestValidateToken_ValidToken1976=== RUN TestValidateToken_WrongAudience1977=== PAUSE TestValidateToken_WrongAudience1978=== RUN TestValidateToken_Expired1979=== PAUSE TestValidateToken_Expired1980=== RUN TestValidateToken_BoundClaimsMismatch1981=== PAUSE TestValidateToken_BoundClaimsMismatch1982=== RUN TestValidateToken_BoundSubjectMismatch1983=== PAUSE TestValidateToken_BoundSubjectMismatch1984=== RUN TestValidateToken_MultipleProviders1985=== PAUSE TestValidateToken_MultipleProviders1986=== RUN TestValidateToken_NoMatchingProvider1987=== PAUSE TestValidateToken_NoMatchingProvider1988=== RUN TestValidateToken_KubernetesServiceAccount1989=== PAUSE TestValidateToken_KubernetesServiceAccount1990=== RUN TestNewValidator_KubernetesRequiresCA1991=== PAUSE TestNewValidator_KubernetesRequiresCA1992=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1993=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1994=== RUN TestScopes_LegacyProviderDefaultsToWrite1995=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1996=== RUN TestScopes_Rules1997=== PAUSE TestScopes_Rules1998=== RUN TestScopes_ConfigValidation1999=== PAUSE TestScopes_ConfigValidation2000=== CONT TestGlobMatch2001=== RUN TestGlobMatch/foo_foo2002=== PAUSE TestGlobMatch/foo_foo2003=== RUN TestGlobMatch/foo_bar2004=== PAUSE TestGlobMatch/foo_bar2005=== RUN TestGlobMatch/*_2006=== PAUSE TestGlobMatch/*_2007=== RUN TestGlobMatch/*_anything2008=== PAUSE TestGlobMatch/*_anything2009=== RUN TestGlobMatch/foo*_foo2010=== CONT TestScopes_LegacyProviderDefaultsToWrite2011=== PAUSE TestGlobMatch/foo*_foo2012=== RUN TestGlobMatch/foo*_foobar2013=== PAUSE TestGlobMatch/foo*_foobar2014=== RUN TestGlobMatch/foo*_bar2015=== PAUSE TestGlobMatch/foo*_bar2016=== RUN TestGlobMatch/*bar_bar2017=== PAUSE TestGlobMatch/*bar_bar2018=== RUN TestGlobMatch/*bar_foobar2019=== PAUSE TestGlobMatch/*bar_foobar2020=== RUN TestGlobMatch/*bar_foo2021=== PAUSE TestGlobMatch/*bar_foo2022=== RUN TestGlobMatch/foo*bar_foobar2023=== PAUSE TestGlobMatch/foo*bar_foobar2024=== RUN TestGlobMatch/foo*bar_foo123bar2025=== PAUSE TestGlobMatch/foo*bar_foo123bar2026=== RUN TestGlobMatch/foo*bar_foobarbaz2027=== PAUSE TestGlobMatch/foo*bar_foobarbaz2028=== RUN TestGlobMatch/*/*_foo/bar2029=== PAUSE TestGlobMatch/*/*_foo/bar2030=== RUN TestGlobMatch/*/*_foo2031=== PAUSE TestGlobMatch/*/*_foo2032=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2033=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2034=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02035=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02036=== RUN TestGlobMatch/refs/*/main_refs/heads/main2037=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2038=== RUN TestGlobMatch/fo?_foo2039=== PAUSE TestGlobMatch/fo?_foo2040=== RUN TestGlobMatch/fo?_fo2041=== PAUSE TestGlobMatch/fo?_fo2042=== RUN TestGlobMatch/fo?_fooo2043=== PAUSE TestGlobMatch/fo?_fooo2044=== RUN TestGlobMatch/?oo_foo2045=== PAUSE TestGlobMatch/?oo_foo2046=== RUN TestGlobMatch/?oo_boo2047=== PAUSE TestGlobMatch/?oo_boo2048=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2049=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2050=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2051=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2052=== CONT TestGlobMatch/foo_foo2053=== CONT TestValidateToken_MultipleProviders2054=== CONT TestGlobMatch/*/*_foo/bar2055=== CONT TestGlobMatch/fo?_foo2056=== CONT TestGlobMatch/refs/*/main_refs/heads/main2057=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02058=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2059=== CONT TestGlobMatch/*/*_foo2060=== CONT TestGlobMatch/?oo_boo2061=== CONT TestGlobMatch/?oo_foo2062=== CONT TestGlobMatch/*bar_foobar2063=== CONT TestGlobMatch/fo?_fo2064=== CONT TestGlobMatch/foo*_foo2065=== CONT TestGlobMatch/foo*_bar2066=== CONT TestGlobMatch/foo*_foobar2067=== CONT TestGlobMatch/*_2068=== CONT TestGlobMatch/*_anything2069=== CONT TestGlobMatch/foo_bar2070=== CONT TestValidateToken_BoundSubjectMismatch2071=== CONT TestValidateToken_BoundClaimsMismatch2072=== CONT TestValidateToken_Expired2073=== CONT TestValidateToken_NoMatchingProvider2074=== CONT TestValidateToken_WrongAudience2075=== CONT TestValidateToken_ValidToken2076=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2077=== CONT TestNewValidator_KubernetesRequiresCA2078=== CONT TestAudienceForIssuer2079--- PASS: TestAudienceForIssuer (0.00s)2080=== CONT TestValidateToken_KubernetesServiceAccount2081=== CONT TestScopes_ConfigValidation2082=== CONT TestScopes_Rules2083=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2084=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2085=== CONT TestGlobMatch/fo?_fooo2086=== CONT TestGlobMatch/*bar_bar2087=== CONT TestGlobMatch/foo*bar_foobarbaz2088=== CONT TestGlobMatch/foo*bar_foo123bar2089=== CONT TestGlobMatch/foo*bar_foobar2090=== CONT TestGlobMatch/*bar_foo2091--- PASS: TestGlobMatch (0.00s)2092 --- PASS: TestGlobMatch/foo_foo (0.00s)2093 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2094 --- PASS: TestGlobMatch/fo?_foo (0.00s)2095 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2096 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2097 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2098 --- PASS: TestGlobMatch/*/*_foo (0.00s)2099 --- PASS: TestGlobMatch/?oo_boo (0.00s)2100 --- PASS: TestGlobMatch/?oo_foo (0.00s)2101 --- PASS: TestGlobMatch/fo?_fo (0.00s)2102 --- PASS: TestGlobMatch/foo*_foo (0.00s)2103 --- PASS: TestGlobMatch/foo*_bar (0.00s)2104 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2105 --- PASS: TestGlobMatch/*_ (0.00s)2106 --- PASS: TestGlobMatch/*_anything (0.00s)2107 --- PASS: TestGlobMatch/foo_bar (0.00s)2108 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2109 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2110 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2111 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2112 --- PASS: TestGlobMatch/*bar_bar (0.00s)2113 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2114 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2115 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2116 --- PASS: TestGlobMatch/*bar_foo (0.00s)2117--- PASS: TestScopes_ConfigValidation (0.00s)21182026/08/31 09:08:04 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12321192026/08/31 09:08:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33877/oidc21202026/08/31 09:08:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46021/oidc21212026/08/31 09:08:04 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46833/oidc21222026/08/31 09:08:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38769/oidc21232026/08/31 09:08:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45617/oidc21242026/08/31 09:08:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41965/oidc21252026/08/31 09:08:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40461/oidc21262026/08/31 09:08:04 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:32879/oidc21272026/08/31 09:08:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44255/oidc21282026/08/31 09:08:04 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:39207/oidc2129--- PASS: TestValidateToken_WrongAudience (0.01s)2130--- PASS: TestValidateToken_ValidToken (0.01s)2131--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2132--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.02s)2133--- PASS: TestValidateToken_Expired (0.01s)2134--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2135--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)21362026/08/31 09:08:04 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:445512137--- PASS: TestValidateToken_MultipleProviders (0.02s)2138--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)2139--- PASS: TestScopes_Rules (0.02s)2140--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)21412026/08/31 09:08:04 http: TLS handshake error from 127.0.0.1:59264: read tcp 127.0.0.1:40169->127.0.0.1:59264: use of closed network connection2142--- PASS: TestNewValidator_KubernetesRequiresCA (0.03s)2143PASS2144Running hook tests...2145=== RUN TestSendPathsEmpty2146=== PAUSE TestSendPathsEmpty2147=== RUN TestQueueEnqueueAndFetch2148=== PAUSE TestQueueEnqueueAndFetch2149=== RUN TestQueueDeduplication2150=== PAUSE TestQueueDeduplication2151=== RUN TestQueueRemove2152=== PAUSE TestQueueRemove2153=== RUN TestQueueFetchBatchLimit2154=== PAUSE TestQueueFetchBatchLimit2155=== RUN TestQueueRetryMovesToBack2156=== PAUSE TestQueueRetryMovesToBack2157=== RUN TestQueueFetchRemoveLifecycle2158=== PAUSE TestQueueFetchRemoveLifecycle2159=== RUN TestQueueConcurrentWriters2160=== PAUSE TestQueueConcurrentWriters2161=== RUN TestQueueRemoveLargeClosure2162=== PAUSE TestQueueRemoveLargeClosure2163=== RUN TestServerClientIntegration2164=== PAUSE TestServerClientIntegration2165=== RUN TestServerQueueError2166=== PAUSE TestServerQueueError2167=== RUN TestGetListenerSocketActivation2168 server_test.go:210: === RUN TestGetListenerSocketActivation2169 --- PASS: TestGetListenerSocketActivation (0.00s)2170 PASS2171 2172--- PASS: TestGetListenerSocketActivation (0.01s)2173=== RUN TestDrainIsolatesPoisonPath2174=== PAUSE TestDrainIsolatesPoisonPath2175=== RUN TestRunNotBlockedByPoisonHead2176=== PAUSE TestRunNotBlockedByPoisonHead2177=== RUN TestDrainGivesUpWhenServerDown2178=== PAUSE TestDrainGivesUpWhenServerDown2179=== RUN TestFailedPathPrunedByLaterClosure2180=== PAUSE TestFailedPathPrunedByLaterClosure2181=== RUN TestWorkerUploadsAndRemoves2182=== PAUSE TestWorkerUploadsAndRemoves2183=== RUN TestWorkerSkipsGCdPaths2184=== PAUSE TestWorkerSkipsGCdPaths2185=== RUN TestWorkerPrunesClosureDeps2186=== PAUSE TestWorkerPrunesClosureDeps2187=== RUN TestDrainTimeout2188=== PAUSE TestDrainTimeout2189=== CONT TestSendPathsEmpty2190=== CONT TestDrainIsolatesPoisonPath2191--- PASS: TestSendPathsEmpty (0.00s)2192=== CONT TestWorkerUploadsAndRemoves2193=== CONT TestServerQueueError2194=== CONT TestDrainTimeout2195=== CONT TestServerClientIntegration2196=== CONT TestWorkerPrunesClosureDeps2197=== CONT TestQueueRemoveLargeClosure2198=== CONT TestQueueConcurrentWriters21992026/08/31 09:08:04 ERROR Failed to queue paths error="permission denied" count=12200=== CONT TestWorkerSkipsGCdPaths2201=== CONT TestQueueFetchRemoveLifecycle2202--- PASS: TestServerClientIntegration (0.00s)2203=== CONT TestDrainGivesUpWhenServerDown2204=== CONT TestQueueRetryMovesToBack2205=== CONT TestQueueFetchBatchLimit2206=== CONT TestFailedPathPrunedByLaterClosure2207--- PASS: TestServerQueueError (0.00s)2208=== CONT TestQueueRemove2209=== CONT TestQueueDeduplication2210=== CONT TestQueueEnqueueAndFetch2211=== CONT TestRunNotBlockedByPoisonHead22122026/08/31 09:08:04 INFO Uploading batch count=122132026/08/31 09:08:04 ERROR Upload failed error="upload failed" count=12214--- PASS: TestQueueFetchBatchLimit (0.02s)22152026/08/31 09:08:04 INFO Uploading batch count=12216--- PASS: TestQueueEnqueueAndFetch (0.02s)22172026/08/31 09:08:04 INFO Uploading batch count=222182026/08/31 09:08:04 ERROR Upload failed error="upload failed" count=222192026/08/31 09:08:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1423374786/002/a22202026/08/31 09:08:04 INFO Uploading batch count=22221--- PASS: TestQueueDeduplication (0.02s)22222026/08/31 09:08:04 INFO Uploading batch count=422232026/08/31 09:08:04 ERROR Upload failed error="upload failed" count=422242026/08/31 09:08:04 INFO Uploading batch count=122252026/08/31 09:08:04 INFO Upload queue status pending=322262026/08/31 09:08:04 INFO Uploading batch count=122272026/08/31 09:08:04 ERROR Upload failed error="upload failed" count=122282026/08/31 09:08:04 INFO Upload queue status pending=222292026/08/31 09:08:04 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3120262134/002/nonexistent22302026/08/31 09:08:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1423374786/002/b22312026/08/31 09:08:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2100961500/002/bbb22322026/08/31 09:08:04 INFO Upload queue status pending=22233--- PASS: TestQueueFetchRemoveLifecycle (0.02s)22342026/08/31 09:08:04 INFO Uploading batch count=222352026/08/31 09:08:04 ERROR Upload failed error="upload failed" count=222362026/08/31 09:08:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1423374786/002/c22372026/08/31 09:08:04 INFO Uploading batch count=222382026/08/31 09:08:04 INFO Uploading batch count=12239--- PASS: TestQueueRetryMovesToBack (0.02s)2240--- PASS: TestQueueRemove (0.02s)2241--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)22422026/08/31 09:08:04 INFO Upload queue status pending=222432026/08/31 09:08:04 INFO Uploading batch count=122442026/08/31 09:08:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1423374786/002/d22452026/08/31 09:08:04 INFO Uploading batch count=122462026/08/31 09:08:04 ERROR Upload failed error="upload failed" count=122472026/08/31 09:08:04 INFO Uploading batch count=222482026/08/31 09:08:04 ERROR Upload failed error="upload failed" count=222492026/08/31 09:08:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1423374786/002/e22502026/08/31 09:08:04 INFO Uploading batch count=122512026/08/31 09:08:04 ERROR Upload failed error="upload failed" count=122522026/08/31 09:08:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1423374786/002/f22532026/08/31 09:08:04 INFO Uploading batch count=122542026/08/31 09:08:04 ERROR Upload failed error="upload failed" count=122552026/08/31 09:08:04 ERROR Drain finished with paths left in queue remaining=1022562026/08/31 09:08:04 ERROR Drain finished with paths left in queue remaining=12257--- PASS: TestDrainIsolatesPoisonPath (0.03s)2258--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2259--- PASS: TestWorkerPrunesClosureDeps (0.04s)2260--- PASS: TestWorkerSkipsGCdPaths (0.04s)2261--- PASS: TestWorkerUploadsAndRemoves (0.04s)2262--- PASS: TestQueueRemoveLargeClosure (0.14s)22632026/08/31 09:08:05 ERROR Upload failed error="context deadline exceeded" count=222642026/08/31 09:08:05 ERROR Drain finished with paths left in queue remaining=42265--- PASS: TestDrainTimeout (0.22s)2266--- PASS: TestQueueConcurrentWriters (0.22s)22672026/08/31 09:08:05 INFO Uploading batch count=122682026/08/31 09:08:05 INFO Uploading batch count=122692026/08/31 09:08:05 INFO Uploading batch count=122702026/08/31 09:08:05 ERROR Upload failed error="upload failed" count=122712026/08/31 09:08:05 INFO Uploading batch count=122722026/08/31 09:08:05 ERROR Upload failed error="upload failed" count=122732026/08/31 09:08:05 INFO Uploading batch count=122742026/08/31 09:08:05 ERROR Upload failed error="upload failed" count=122752026/08/31 09:08:05 INFO Uploading batch count=122762026/08/31 09:08:05 ERROR Upload failed error="upload failed" count=122772026/08/31 09:08:05 ERROR Drain finished with paths left in queue remaining=12278--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2279PASS