niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #157
· 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 TestResolveStorePath74=== CONT TestEncodeNixBase32WithRealHash75--- PASS: TestEncodeNixBase32WithRealHash (0.00s)76=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess772026/08/27 11:04:19 WARN Rate limiter enabled after throttle name=server-test rate=578=== CONT TestFileTokenMissing79=== CONT TestScriptTokenEmptyToken80=== CONT TestSetClientTLSDoesNotMutateDefaultTransport81=== CONT TestRateLimiterFeedback82=== CONT TestFilterOversizedClosures83=== RUN TestFilterOversizedClosures/no_limit_keeps_everything84=== RUN TestRateLimiterFeedback/429_enables_limiter85=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything86=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped87=== CONT TestPathInfoCACompatibility88=== RUN TestPathInfoCACompatibility/null_ca_field89=== PAUSE TestPathInfoCACompatibility/null_ca_field90=== RUN TestPathInfoCACompatibility/old_string_format_-_text91=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text92=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive93=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive94=== RUN TestPathInfoCACompatibility/new_structured_format_-_text95=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text96=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method97=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method98=== CONT TestPartSizeForNAR99=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped100=== CONT TestCaseHackSuffix101=== PAUSE TestRateLimiterFeedback/429_enables_limiter102=== RUN TestRateLimiterFeedback/503_enables_limiter103=== PAUSE TestRateLimiterFeedback/503_enables_limiter104=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter105=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter106=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter107=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter108=== RUN TestFilterOversizedClosures/all_closures_skipped109=== PAUSE TestFilterOversizedClosures/all_closures_skipped110=== CONT TestUploadMultipart_SupersededByPeer111=== RUN TestUploadMultipart_SupersededByPeer/exists112=== PAUSE TestUploadMultipart_SupersededByPeer/exists113=== RUN TestUploadMultipart_SupersededByPeer/missing114=== PAUSE TestUploadMultipart_SupersededByPeer/missing115=== RUN TestPartSizeForNAR/zero_stays_at_minimum116=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum117=== RUN TestPartSizeForNAR/small_stays_at_minimum118=== PAUSE TestPartSizeForNAR/small_stays_at_minimum119=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum120=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum121=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts122=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts123=== RUN TestPartSizeForNAR/1_TiB124=== PAUSE TestPartSizeForNAR/1_TiB125=== RUN TestPartSizeForNAR/5_TiB_S3_max_object126=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object127=== RUN TestPartSizeForNAR/capped_at_5_GiB128=== PAUSE TestPartSizeForNAR/capped_at_5_GiB129=== CONT TestEncodeNixBase32130=== RUN TestEncodeNixBase32/test_string_hash131=== PAUSE TestEncodeNixBase32/test_string_hash132=== RUN TestEncodeNixBase32/empty_input133=== PAUSE TestEncodeNixBase32/empty_input134=== CONT TestDumpPathWriterError135=== CONT TestDumpPathSingleFile136--- PASS: TestFileTokenMissing (0.00s)137=== CONT TestPathInfoCACompatibility/null_ca_field138=== CONT TestDumpPathMatchesNix139=== CONT TestParsePathInfoJSONMultiplePaths140=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths141=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths142=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths143=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths144=== CONT TestParsePathInfoJSON145=== RUN TestParsePathInfoJSON/Nix_format146=== PAUSE TestParsePathInfoJSON/Nix_format147=== RUN TestParsePathInfoJSON/Lix_format148=== PAUSE TestParsePathInfoJSON/Lix_format149=== RUN TestParsePathInfoJSON/empty_input150=== PAUSE TestParsePathInfoJSON/empty_input151=== RUN TestParsePathInfoJSON/whitespace_only152=== PAUSE TestParsePathInfoJSON/whitespace_only153=== RUN TestParsePathInfoJSON/invalid_JSON154--- PASS: TestResolveStorePath (0.00s)155=== CONT TestPathInfoHashCompatibility156=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)157=== PAUSE TestParsePathInfoJSON/invalid_JSON158=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)159=== CONT TestGetStorePathHash160=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon161=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon162=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI163=== RUN TestGetStorePathHash/valid_store_path164=== PAUSE TestGetStorePathHash/valid_store_path165=== RUN TestGetStorePathHash/basename_without_hyphen_should_error166=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI167=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error168=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512169=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512170=== CONT TestConvertHashToNix32171=== RUN TestConvertHashToNix32/SRI_format_to_Nix32172=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32173=== RUN TestConvertHashToNix32/already_Nix32_format174=== PAUSE TestConvertHashToNix32/already_Nix32_format175=== RUN TestConvertHashToNix32/invalid_format176--- PASS: TestDoServerRequestAttachesToken (0.00s)177=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error178=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error179=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error180=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error181=== CONT TestScriptTokenEmptyCommand182=== PAUSE TestConvertHashToNix32/invalid_format183--- PASS: TestScriptTokenEmptyCommand (0.00s)184=== CONT TestScriptTokenCachesUntilRefresh185=== CONT TestScriptTokenScriptFails186=== CONT TestShellSplitErrors187--- PASS: TestShellSplitErrors (0.00s)188=== CONT TestSetClientTLS189--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)190=== CONT TestShellSplit191--- PASS: TestShellSplit (0.00s)192=== CONT TestDoWithRetry_BodyReplayedViaGetBody1932026/08/27 11:04:19 WARN Rate limiter enabled after throttle name=server-test rate=51942026/08/27 11:04:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:557791952026/08/27 11:04:19 WARN Rate limiter backed off name=server-test rate=51962026/08/27 11:04:19 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:55779197--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)198=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method199--- PASS: TestScriptTokenScriptFails (0.00s)200=== CONT TestPathInfoCACompatibility/new_structured_format_-_text201=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive202=== CONT TestPathInfoCACompatibility/old_string_format_-_text203=== CONT TestFileTokenEmpty204--- PASS: TestPathInfoCACompatibility (0.00s)205 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)206 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)207 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)208 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)209 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)210=== CONT TestScriptTokenBadJSON211--- PASS: TestFileTokenEmpty (0.00s)212=== CONT TestStaticToken213--- PASS: TestStaticToken (0.00s)214=== CONT TestFileTokenReadsAndCaches215=== RUN TestSetClientTLS/rejects_connection_without_client_cert216=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert217=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA218=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA219--- PASS: TestFileTokenReadsAndCaches (0.00s)220=== CONT TestSetClientTLSErrors221=== RUN TestSetClientTLS/preserves_debug_logging_transport222=== PAUSE TestSetClientTLS/preserves_debug_logging_transport223=== CONT TestRateLimiterFeedback/429_enables_limiter2242026/08/27 11:04:19 WARN Rate limiter enabled after throttle name=server-test rate=52252026/08/27 11:04:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:557822262026/08/27 11:04:19 WARN Rate limiter backed off name=server-test rate=5227=== CONT TestFilterOversizedClosures/no_limit_keeps_everything228=== CONT TestUploadMultipart_SupersededByPeer/exists229=== RUN TestSetClientTLSErrors/missing_cert_file230=== PAUSE TestSetClientTLSErrors/missing_cert_file231=== RUN TestSetClientTLSErrors/missing_key_file232=== PAUSE TestSetClientTLSErrors/missing_key_file233=== RUN TestSetClientTLSErrors/missing_ca_file234=== PAUSE TestSetClientTLSErrors/missing_ca_file235=== RUN TestSetClientTLSErrors/invalid_ca_file236=== PAUSE TestSetClientTLSErrors/invalid_ca_file237=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter238=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter239=== CONT TestRateLimiterFeedback/503_enables_limiter240--- PASS: TestScriptTokenEmptyToken (0.01s)241=== CONT TestPartSizeForNAR/zero_stays_at_minimum242=== CONT TestEncodeNixBase32/test_string_hash243=== CONT TestFilterOversizedClosures/all_closures_skipped2442026/08/27 11:04:19 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=50245=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2462026/08/27 11:04:19 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=2000247--- PASS: TestFilterOversizedClosures (0.00s)248 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)249 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)250 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)251=== CONT TestScriptTokenNoExpiryRerunsEveryCall252=== CONT TestPartSizeForNAR/1_TiB253=== CONT TestUploadMultipart_SupersededByPeer/missing2542026/08/27 11:04:19 WARN Rate limiter enabled after throttle name=server-test rate=52552026/08/27 11:04:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:557892562026/08/27 11:04:19 WARN Rate limiter backed off name=server-test rate=5257--- PASS: TestRateLimiterFeedback (0.00s)258 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)259 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)260 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)261 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)262=== CONT TestPartSizeForNAR/small_stays_at_minimum263=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts264=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum265=== CONT TestEncodeNixBase32/empty_input266--- PASS: TestEncodeNixBase32 (0.00s)267 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)268 --- PASS: TestEncodeNixBase32/empty_input (0.00s)269=== CONT TestPartSizeForNAR/capped_at_5_GiB270=== CONT TestPartSizeForNAR/5_TiB_S3_max_object271=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths272=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths273=== CONT TestParsePathInfoJSON/Nix_format274=== CONT TestParsePathInfoJSON/invalid_JSON275=== CONT TestParsePathInfoJSON/whitespace_only276=== CONT TestParsePathInfoJSON/empty_input277=== CONT TestParsePathInfoJSON/Lix_format278--- PASS: TestPartSizeForNAR (0.00s)279 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)280 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)281 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)282 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)283 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)284 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)285 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)286=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)287--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)288 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)289 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)290--- PASS: TestParsePathInfoJSON (0.00s)291 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)292 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)293 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)294 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)295 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)296=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI297=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512298=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon299--- PASS: TestPathInfoHashCompatibility (0.00s)300 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)301 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)302 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)303 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)304=== CONT TestGetStorePathHash/valid_store_path305=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error306=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error307=== CONT TestGetStorePathHash/basename_without_hyphen_should_error308--- PASS: TestGetStorePathHash (0.00s)309 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)310 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)311 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)312 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)313=== CONT TestConvertHashToNix32/SRI_format_to_Nix32314=== CONT TestConvertHashToNix32/invalid_format315=== CONT TestConvertHashToNix32/already_Nix32_format316--- PASS: TestConvertHashToNix32 (0.00s)317 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)318 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)319 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)320=== CONT TestSetClientTLS/rejects_connection_without_client_cert321--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)322 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)323 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)324=== CONT TestSetClientTLS/preserves_debug_logging_transport325--- PASS: TestScriptTokenBadJSON (0.01s)326=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA327=== CONT TestSetClientTLSErrors/missing_cert_file328=== CONT TestSetClientTLSErrors/missing_ca_file329=== CONT TestSetClientTLSErrors/invalid_ca_file330=== CONT TestSetClientTLSErrors/missing_key_file331--- PASS: TestSetClientTLSErrors (0.00s)332 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)333 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)334 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)335 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3362026/08/27 11:04:19 http: TLS handshake error from 127.0.0.1:55795: remote error: tls: bad certificate337--- PASS: TestSetClientTLS (0.01s)338 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)339 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)340 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)341--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)342--- PASS: TestDumpPathWriterError (0.04s)343--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)344--- PASS: TestDumpPathSingleFile (0.10s)345--- PASS: TestCaseHackSuffix (0.10s)346--- PASS: TestDumpPathMatchesNix (0.11s)347--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)348PASS349Running server tests...350The files belonging to this database system will be owned by user "_nixbld10".351This user must also own the server process.352353The database cluster will be initialized with locale "C".354The default database encoding has accordingly been set to "SQL_ASCII".355The default text search configuration will be set to "english".356357Data page checksums are enabled.358359creating directory /nix/var/nix/builds/nix-62096-2608994286/postgres2204501435/data ... ok360creating subdirectories ... ok361selecting dynamic shared memory implementation ... posix362selecting default "max_connections" ... 100363selecting default "shared_buffers" ... 128MB364selecting default time zone ... UTC365creating configuration files ... ok366running bootstrap script ... ok367performing post-bootstrap initialization ... ok368syncing data to disk ... ok369370initdb: warning: enabling "trust" authentication for local connections371initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.372373Success. You can now start the database server using:374375 pg_ctl -D /nix/var/nix/builds/nix-62096-2608994286/postgres2204501435/data -l logfile start3763772026-08-27 11:04:21.588 UTC [62163] LOG: starting PostgreSQL 18.4 on aarch64-apple-darwin25.5.0, compiled by clang version 21.1.8, 64-bit3782026-08-27 11:04:21.588 UTC [62163] LOG: listening on Unix socket "/nix/var/nix/builds/nix-62096-2608994286/postgres2204501435/.s.PGSQL.5432"3792026-08-27 11:04:21.590 UTC [62170] LOG: database system was shut down at 2026-08-27 11:04:21 UTC3802026-08-27 11:04:21.591 UTC [62171] FATAL: the database system is starting up381/nix/var/nix/builds/nix-62096-2608994286/postgres2204501435:5432 - rejecting connections3822026-08-27 11:04:21.591 UTC [62163] LOG: database system is ready to accept connections383/nix/var/nix/builds/nix-62096-2608994286/postgres2204501435:5432 - accepting connections384=== RUN TestService_AuthMiddleware385=== PAUSE TestService_AuthMiddleware386=== RUN TestService_AuthMiddleware_MTLSProxyHeader387=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader388=== RUN TestService_AuthMiddleware_MTLSBoundSubjects389=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects390=== RUN TestService_ReadAuthMiddleware391=== PAUSE TestService_ReadAuthMiddleware392=== RUN TestService_AuthMiddleware_OIDC393=== PAUSE TestService_AuthMiddleware_OIDC394=== RUN TestService_RequireScope_OIDC395=== PAUSE TestService_RequireScope_OIDC396=== RUN TestService_ReadScope_PublicByDefault397=== PAUSE TestService_ReadScope_PublicByDefault398=== RUN TestCacheConfigHandler399=== PAUSE TestCacheConfigHandler400=== RUN TestCacheStatsHandler401=== PAUSE TestCacheStatsHandler402=== RUN TestClientCADerivations403=== PAUSE TestClientCADerivations404=== RUN TestClientErrorHandling405=== PAUSE TestClientErrorHandling406=== RUN TestClientIntegration407=== PAUSE TestClientIntegration408=== RUN TestClientMultipleUploads409=== PAUSE TestClientMultipleUploads410=== RUN TestClientWithDependencies411=== PAUSE TestClientWithDependencies412=== RUN TestPinProtectsFromGC413=== PAUSE TestPinProtectsFromGC414=== RUN TestResolveDBConnectionString415=== PAUSE TestResolveDBConnectionString416=== RUN TestGCAdvisoryLockBlocksConcurrentRun4172026-08-27 11:04:22.016 UTC [62183] ERROR: relation "goose_db_version" does not exist at character 364182026-08-27 11:04:22.016 UTC [62183] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4192026/08/27 11:04:22 OK 20241026095416_initial_model.sql (6ms)4202026/08/27 11:04:22 OK 20251210153512_drop_unused_gin_index.sql (7.45ms)4212026/08/27 11:04:22 OK 20251218171726_add_pins.sql (5.1ms)4222026/08/27 11:04:22 OK 20260628120000_add_object_size_and_stats.sql (1.78ms)4232026/08/27 11:04:22 goose: successfully migrated database to version: 202606281200004242026/08/27 11:04:22 OK 1_commit_pending_closure.sql (2.26ms)4252026/08/27 11:04:22 OK 2_object_stats_trigger.sql (319.58µs)4262026/08/27 11:04:22 goose: up to current file version: 2427--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.36s)428=== RUN TestGCBugBareHashReferences429=== PAUSE TestGCBugBareHashReferences430=== RUN TestGCMetrics431=== PAUSE TestGCMetrics432=== RUN TestGCTaskStore_StartNew433=== PAUSE TestGCTaskStore_StartNew434=== RUN TestGCTaskStore_DeduplicateSameParams435=== PAUSE TestGCTaskStore_DeduplicateSameParams436=== RUN TestGCTaskStore_ConflictDifferentParams437=== PAUSE TestGCTaskStore_ConflictDifferentParams438=== RUN TestGCTaskStore_GetEmpty439=== PAUSE TestGCTaskStore_GetEmpty440=== RUN TestGCTaskStore_GetReturnsLatest441=== PAUSE TestGCTaskStore_GetReturnsLatest442=== RUN TestGCTaskStore_CompletedAllowsNewTask443=== PAUSE TestGCTaskStore_CompletedAllowsNewTask444=== RUN TestGCTaskStore_PhaseUpdates445=== PAUSE TestGCTaskStore_PhaseUpdates446=== RUN TestGCTaskStore_Fail447=== PAUSE TestGCTaskStore_Fail448=== RUN TestGracefulShutdownDrainsInflight449=== PAUSE TestGracefulShutdownDrainsInflight450=== RUN TestService_healthCheckHandler451=== PAUSE TestService_healthCheckHandler452=== RUN TestService_readinessHandler453=== PAUSE TestService_readinessHandler454=== RUN TestGenerateLandingPage455=== PAUSE TestGenerateLandingPage456=== RUN TestCacheConfigHandlerMaxNarSize457=== PAUSE TestCacheConfigHandlerMaxNarSize458=== RUN TestCreatePendingClosureRejectsOversizedNAR459=== PAUSE TestCreatePendingClosureRejectsOversizedNAR460=== RUN TestNARDeduplicationMetadataUploadBug461=== PAUSE TestNARDeduplicationMetadataUploadBug462=== RUN TestMetricsInventory463=== PAUSE TestMetricsInventory464=== RUN TestService_NativeMTLS465=== PAUSE TestService_NativeMTLS466=== RUN TestServerTLSConfig467=== PAUSE TestServerTLSConfig468=== RUN TestMultipartCleanup469=== PAUSE TestMultipartCleanup470=== RUN TestObjectStatsTrigger471=== PAUSE TestObjectStatsTrigger472=== RUN TestOrphanedObjectsGC473=== PAUSE TestOrphanedObjectsGC474=== RUN TestOrphanedObjectsGCStressTest475=== PAUSE TestOrphanedObjectsGCStressTest476=== RUN TestResurrectedObjectNotDeleted477=== PAUSE TestResurrectedObjectNotDeleted478=== RUN TestParseSingleRange479=== PAUSE TestParseSingleRange480=== RUN TestIsValidCachePath481=== PAUSE TestIsValidCachePath482=== RUN TestReadProxyNarinfo483=== PAUSE TestReadProxyNarinfo484=== RUN TestReadProxyNarinfoAlreadyDecompressed485=== PAUSE TestReadProxyNarinfoAlreadyDecompressed486=== RUN TestReadProxyNarStreaming487=== PAUSE TestReadProxyNarStreaming488=== RUN TestReadProxy404489=== PAUSE TestReadProxy404490=== RUN TestReadProxyInvalidPath491=== PAUSE TestReadProxyInvalidPath492=== RUN TestReadProxyHead493=== PAUSE TestReadProxyHead494=== RUN TestReadProxyConditionalGet495=== PAUSE TestReadProxyConditionalGet496=== RUN TestReadProxyRootRedirectsToIndexHTML497=== PAUSE TestReadProxyRootRedirectsToIndexHTML498=== RUN TestReadProxyDisabled499=== PAUSE TestReadProxyDisabled500=== RUN TestReadRedirectNar501=== PAUSE TestReadRedirectNar502=== RUN TestReadRedirectKeepsNarinfoProxied503=== PAUSE TestReadRedirectKeepsNarinfoProxied504=== RUN TestReadProxyRangeRequest505=== PAUSE TestReadProxyRangeRequest506=== RUN TestRedundantMultipartUpload507=== PAUSE TestRedundantMultipartUpload508=== RUN TestCompleteMultipartUpload_ErrorButObjectExists509=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists510=== RUN TestCompletedNarNotReofferedAcrossClosures511=== PAUSE TestCompletedNarNotReofferedAcrossClosures512=== RUN TestPresignedUploadRegisteredBeforeCommit513=== PAUSE TestPresignedUploadRegisteredBeforeCommit514=== RUN TestService_Rustfstest515=== PAUSE TestService_Rustfstest516=== RUN TestParseSize517=== PAUSE TestParseSize518=== RUN TestSkippedUploadsHandler519=== PAUSE TestSkippedUploadsHandler520=== RUN TestSystemdListenerNotActivated521--- PASS: TestSystemdListenerNotActivated (0.00s)522=== RUN TestWatchdogBeatsWhenHealthy523--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)524=== RUN TestWatchdogSkipsWhenUnhealthy5252026/08/27 11:04:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5262026/08/27 11:04:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5272026/08/27 11:04:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5282026/08/27 11:04:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5292026/08/27 11:04:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5302026/08/27 11:04:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5312026/08/27 11:04:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5322026/08/27 11:04:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5332026/08/27 11:04:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5342026/08/27 11:04:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"535--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)536=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle537=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle538=== RUN TestProxyWriteTimeout539=== PAUSE TestProxyWriteTimeout540=== RUN TestIsValidUploadKey541=== PAUSE TestIsValidUploadKey542=== RUN TestUploadHandlersRejectInvalidKeys543=== PAUSE TestUploadHandlersRejectInvalidKeys544=== RUN TestUploadHandlersRejectOversizedBody545=== PAUSE TestUploadHandlersRejectOversizedBody546=== RUN TestService_cleanupPendingClosuresHandler547=== PAUSE TestService_cleanupPendingClosuresHandler548=== RUN TestService_createPendingClosureHandler549=== PAUSE TestService_createPendingClosureHandler550=== RUN TestService_verifyS3Integrity551=== PAUSE TestService_verifyS3Integrity552=== RUN TestCompleteMultipartUnregistered553=== PAUSE TestCompleteMultipartUnregistered554=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT555=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT556=== CONT TestResurrectedObjectNotDeleted557=== CONT TestMultipartCleanup558=== CONT TestGCTaskStore_StartNew559--- PASS: TestGCTaskStore_StartNew (0.00s)560=== CONT TestServerTLSConfig561=== CONT TestClientCADerivations562=== CONT TestService_AuthMiddleware563=== RUN TestServerTLSConfig/no_client_CA564=== PAUSE TestServerTLSConfig/no_client_CA565=== CONT TestOrphanedObjectsGCStressTest566=== CONT TestOrphanedObjectsGC567=== CONT TestObjectStatsTrigger568=== CONT TestService_NativeMTLS569=== RUN TestServerTLSConfig/missing_CA_file570=== PAUSE TestServerTLSConfig/missing_CA_file571=== RUN TestServerTLSConfig/not_a_PEM_file572=== PAUSE TestServerTLSConfig/not_a_PEM_file573=== CONT TestNARDeduplicationMetadataUploadBug574=== CONT TestMetricsInventory5752026-08-27 11:04:22.719 UTC [62276] ERROR: relation "goose_db_version" does not exist at character 365762026-08-27 11:04:22.719 UTC [62276] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5772026-08-27 11:04:22.725 UTC [62277] ERROR: relation "goose_db_version" does not exist at character 365782026-08-27 11:04:22.725 UTC [62277] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5792026-08-27 11:04:22.727 UTC [62279] ERROR: relation "goose_db_version" does not exist at character 365802026-08-27 11:04:22.727 UTC [62279] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5812026-08-27 11:04:22.727 UTC [62278] ERROR: relation "goose_db_version" does not exist at character 365822026-08-27 11:04:22.727 UTC [62278] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5832026-08-27 11:04:22.728 UTC [62281] ERROR: relation "goose_db_version" does not exist at character 365842026-08-27 11:04:22.728 UTC [62281] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5852026-08-27 11:04:22.728 UTC [62280] ERROR: relation "goose_db_version" does not exist at character 365862026-08-27 11:04:22.728 UTC [62280] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5872026-08-27 11:04:22.729 UTC [62285] ERROR: relation "goose_db_version" does not exist at character 365882026-08-27 11:04:22.729 UTC [62285] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5892026-08-27 11:04:22.730 UTC [62283] ERROR: relation "goose_db_version" does not exist at character 365902026-08-27 11:04:22.730 UTC [62283] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5912026-08-27 11:04:22.730 UTC [62282] ERROR: relation "goose_db_version" does not exist at character 365922026-08-27 11:04:22.730 UTC [62282] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5932026-08-27 11:04:22.731 UTC [62284] ERROR: relation "goose_db_version" does not exist at character 365942026-08-27 11:04:22.731 UTC [62284] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5952026/08/27 11:04:22 OK 20241026095416_initial_model.sql (8.58ms)5962026/08/27 11:04:22 OK 20251210153512_drop_unused_gin_index.sql (1.09ms)5972026/08/27 11:04:22 OK 20241026095416_initial_model.sql (15.11ms)5982026/08/27 11:04:22 OK 20251218171726_add_pins.sql (9.82ms)5992026/08/27 11:04:22 OK 20241026095416_initial_model.sql (13.99ms)6002026/08/27 11:04:22 OK 20251210153512_drop_unused_gin_index.sql (702.88µs)6012026/08/27 11:04:22 OK 20241026095416_initial_model.sql (14.14ms)6022026/08/27 11:04:22 OK 20241026095416_initial_model.sql (15.12ms)6032026/08/27 11:04:22 OK 20260628120000_add_object_size_and_stats.sql (1.58ms)6042026/08/27 11:04:22 goose: successfully migrated database to version: 202606281200006052026/08/27 11:04:22 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)6062026/08/27 11:04:22 OK 20251210153512_drop_unused_gin_index.sql (832.21µs)6072026/08/27 11:04:22 OK 20241026095416_initial_model.sql (14.72ms)6082026/08/27 11:04:22 OK 20251210153512_drop_unused_gin_index.sql (989.33µs)6092026/08/27 11:04:22 OK 20251218171726_add_pins.sql (2.02ms)6102026/08/27 11:04:22 OK 20241026095416_initial_model.sql (17.01ms)6112026/08/27 11:04:22 OK 1_commit_pending_closure.sql (1.53ms)6122026/08/27 11:04:22 OK 20251210153512_drop_unused_gin_index.sql (923.58µs)6132026/08/27 11:04:22 OK 20251218171726_add_pins.sql (1.69ms)6142026/08/27 11:04:22 OK 20251218171726_add_pins.sql (1.37ms)6152026/08/27 11:04:22 OK 2_object_stats_trigger.sql (560.83µs)6162026/08/27 11:04:22 goose: up to current file version: 26172026/08/27 11:04:22 OK 20260628120000_add_object_size_and_stats.sql (1.32ms)6182026/08/27 11:04:22 goose: successfully migrated database to version: 202606281200006192026/08/27 11:04:22 OK 20251210153512_drop_unused_gin_index.sql (766.08µs)6202026/08/27 11:04:22 OK 20241026095416_initial_model.sql (14.07ms)6212026/08/27 11:04:22 OK 20241026095416_initial_model.sql (14.36ms)6222026/08/27 11:04:22 OK 20241026095416_initial_model.sql (15.59ms)6232026/08/27 11:04:22 OK 20251218171726_add_pins.sql (2.13ms)6242026/08/27 11:04:22 OK 20251210153512_drop_unused_gin_index.sql (633.29µs)6252026/08/27 11:04:22 OK 20251210153512_drop_unused_gin_index.sql (492.38µs)6262026/08/27 11:04:22 OK 20251210153512_drop_unused_gin_index.sql (829.92µs)6272026/08/27 11:04:22 OK 20251218171726_add_pins.sql (2.02ms)6282026/08/27 11:04:22 OK 20251218171726_add_pins.sql (1.44ms)6292026/08/27 11:04:22 OK 1_commit_pending_closure.sql (1.7ms)6302026/08/27 11:04:22 OK 20260628120000_add_object_size_and_stats.sql (1.94ms)6312026/08/27 11:04:22 goose: successfully migrated database to version: 202606281200006322026/08/27 11:04:22 OK 20251218171726_add_pins.sql (998.17µs)6332026/08/27 11:04:22 OK 20260628120000_add_object_size_and_stats.sql (2.54ms)6342026/08/27 11:04:22 goose: successfully migrated database to version: 202606281200006352026/08/27 11:04:22 OK 2_object_stats_trigger.sql (308.67µs)6362026/08/27 11:04:22 goose: up to current file version: 26372026/08/27 11:04:22 OK 20251218171726_add_pins.sql (1.26ms)6382026/08/27 11:04:22 OK 20260628120000_add_object_size_and_stats.sql (1.54ms)6392026/08/27 11:04:22 goose: successfully migrated database to version: 202606281200006402026/08/27 11:04:22 OK 20260628120000_add_object_size_and_stats.sql (1.22ms)6412026/08/27 11:04:22 goose: successfully migrated database to version: 202606281200006422026/08/27 11:04:22 OK 1_commit_pending_closure.sql (933.96µs)6432026/08/27 11:04:22 OK 1_commit_pending_closure.sql (899.83µs)6442026/08/27 11:04:22 OK 2_object_stats_trigger.sql (359.38µs)6452026/08/27 11:04:22 goose: up to current file version: 26462026/08/27 11:04:22 OK 20251218171726_add_pins.sql (1.94ms)6472026/08/27 11:04:22 OK 2_object_stats_trigger.sql (267.46µs)6482026/08/27 11:04:22 goose: up to current file version: 26492026/08/27 11:04:22 OK 20260628120000_add_object_size_and_stats.sql (1.96ms)6502026/08/27 11:04:22 goose: successfully migrated database to version: 202606281200006512026/08/27 11:04:22 OK 20260628120000_add_object_size_and_stats.sql (1.56ms)6522026/08/27 11:04:22 goose: successfully migrated database to version: 202606281200006532026/08/27 11:04:22 OK 20260628120000_add_object_size_and_stats.sql (1.33ms)6542026/08/27 11:04:22 goose: successfully migrated database to version: 202606281200006552026/08/27 11:04:22 OK 1_commit_pending_closure.sql (1.42ms)6562026/08/27 11:04:22 OK 1_commit_pending_closure.sql (1.04ms)6572026/08/27 11:04:22 OK 2_object_stats_trigger.sql (247.17µs)6582026/08/27 11:04:22 goose: up to current file version: 26592026/08/27 11:04:22 OK 2_object_stats_trigger.sql (174.25µs)6602026/08/27 11:04:22 goose: up to current file version: 26612026/08/27 11:04:22 OK 1_commit_pending_closure.sql (752.5µs)6622026/08/27 11:04:22 OK 20260628120000_add_object_size_and_stats.sql (1.01ms)6632026/08/27 11:04:22 goose: successfully migrated database to version: 202606281200006642026/08/27 11:04:22 OK 2_object_stats_trigger.sql (240.96µs)6652026/08/27 11:04:22 goose: up to current file version: 26662026/08/27 11:04:22 OK 1_commit_pending_closure.sql (1.18ms)6672026/08/27 11:04:22 OK 1_commit_pending_closure.sql (1.26ms)6682026/08/27 11:04:22 OK 2_object_stats_trigger.sql (211.04µs)6692026/08/27 11:04:22 goose: up to current file version: 26702026/08/27 11:04:22 OK 2_object_stats_trigger.sql (208.83µs)6712026/08/27 11:04:22 goose: up to current file version: 26722026/08/27 11:04:22 OK 1_commit_pending_closure.sql (731.79µs)6732026/08/27 11:04:22 OK 2_object_stats_trigger.sql (189.21µs)6742026/08/27 11:04:22 goose: up to current file version: 26752026/08/27 11:04:22 INFO Received uploads request method=POST path=/api/pending_closures6762026/08/27 11:04:23 INFO Received cleanup request method=DELETE path=/api/pending_closures6772026/08/27 11:04:23 INFO Aborted multipart uploads count=1678--- PASS: TestMultipartCleanup (0.66s)679=== CONT TestCreatePendingClosureRejectsOversizedNAR6802026/08/27 11:04:23 INFO Received uploads request method=POST path=/api/pending_closures681--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)682=== CONT TestCacheConfigHandlerMaxNarSize683--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)684=== CONT TestGenerateLandingPage685--- PASS: TestGenerateLandingPage (0.00s)686=== CONT TestService_readinessHandler6872026/08/27 11:04:23 WARN mTLS auth: subject not in bound subjects subject="CN=reader"6882026/08/27 11:04:23 WARN mTLS auth: subject not in bound subjects subject="CN=reader"689--- PASS: TestService_NativeMTLS (0.72s)690=== CONT TestService_healthCheckHandler691=== NAME TestClientCADerivations692 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-62096-2608994286/TestClientCADerivations3857500456/001/store/dw556hm46x3h4a55mzg3ldjk048snc2a-ca-test693 client_ca_test.go:139: Found 1 dependencies (including self)6942026/08/27 11:04:23 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"6952026/08/27 11:04:23 INFO Received uploads request method=POST path=/api/pending_closures6962026/08/27 11:04:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)6972026/08/27 11:04:23 INFO Uploading dw556hm46x3h4a55mzg3ldjk048snc2a-ca-test (144B)6982026/08/27 11:04:23 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"6992026/08/27 11:04:23 WARN Failed to register uploaded object key=log/ws76li57qq6wg2wacrh9gihv1n6b2161-ca-test.drv error="server returned 404: 404 page not found\n"7002026/08/27 11:04:23 WARN Failed to register uploaded object key=dw556hm46x3h4a55mzg3ldjk048snc2a.ls error="server returned 404: 404 page not found\n"7012026/08/27 11:04:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign7022026/08/27 11:04:23 INFO Signed narinfos id=1 count=17032026/08/27 11:04:23 INFO Uploading 1 narinfos7042026/08/27 11:04:23 WARN Failed to register uploaded object key=dw556hm46x3h4a55mzg3ldjk048snc2a.narinfo error="server returned 404: 404 page not found\n"7052026/08/27 11:04:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7062026/08/27 11:04:23 INFO Completed upload id=17072026/08/27 11:04:23 INFO Upload complete. (236ms)708 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-62096-2608994286/TestClientCADerivations3857500456/001/store/dw556hm46x3h4a55mzg3ldjk048snc2a-ca-test709 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst710 Compression: zstd711 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n712 NarSize: 144713 References: 714 Deriver: /nix/var/nix/builds/nix-62096-2608994286/TestClientCADerivations3857500456/001/store/ws76li57qq6wg2wacrh9gihv1n6b2161-ca-test.drv715 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n716 client_ca_test.go:185: Checking for realisation files in S3...717--- PASS: TestResurrectedObjectNotDeleted (1.07s)718=== CONT TestGracefulShutdownDrainsInflight7192026/08/27 11:04:23 INFO Starting HTTP server address=127.0.0.1:558317202026/08/27 11:04:23 INFO Shutdown signal received, draining in-flight requests timeout=10s721=== NAME TestClientCADerivations722 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations723 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache7242026/08/27 11:04:23 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"725--- PASS: TestService_AuthMiddleware (1.11s)726=== CONT TestGCTaskStore_Fail727--- PASS: TestGCTaskStore_Fail (0.00s)728=== CONT TestGCTaskStore_PhaseUpdates729--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)730=== CONT TestGCTaskStore_CompletedAllowsNewTask731--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)732=== CONT TestGCTaskStore_GetReturnsLatest733--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)734=== CONT TestGCTaskStore_GetEmpty735--- PASS: TestGCTaskStore_GetEmpty (0.00s)736=== CONT TestGCTaskStore_ConflictDifferentParams737--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)738=== CONT TestGCTaskStore_DeduplicateSameParams739--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)740=== CONT TestPinProtectsFromGC741--- PASS: TestGracefulShutdownDrainsInflight (0.07s)742=== CONT TestGCMetrics743=== NAME TestClientCADerivations744 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket2?endpoint=http://localhost:55800®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-62096-2608994286/TestClientCADerivations3857500456/001/store'745 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 1746--- PASS: TestClientCADerivations (1.33s)747=== CONT TestGCBugBareHashReferences748--- PASS: TestMetricsInventory (1.37s)749=== CONT TestResolveDBConnectionString750=== RUN TestResolveDBConnectionString/flag_wins751=== PAUSE TestResolveDBConnectionString/flag_wins752=== RUN TestResolveDBConnectionString/file_when_flag_empty753=== PAUSE TestResolveDBConnectionString/file_when_flag_empty754=== RUN TestResolveDBConnectionString/missing_file_is_an_error755=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error756=== RUN TestResolveDBConnectionString/PGHOST_allows_empty757=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty758=== RUN TestResolveDBConnectionString/nothing_configured759=== PAUSE TestResolveDBConnectionString/nothing_configured760=== CONT TestService_RequireScope_OIDC7612026/08/27 11:04:23 INFO OIDC provider initialized name=test762--- PASS: TestObjectStatsTrigger (1.64s)763=== CONT TestClientMultipleUploads764=== NAME TestNARDeduplicationMetadataUploadBug765 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-62096-2608994286/TestNARDeduplicationMetadataUploadBug377295194/001/store/nd3id71ky1xa2rr6k92z0kkf8kddi1ng-file1.txt766=== NAME TestOrphanedObjectsGC767 orphaned_objects_gc_test.go:290: GC Test Summary:768 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A769 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B770 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)771 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)772 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects773--- PASS: TestOrphanedObjectsGC (1.75s)774=== CONT TestCacheStatsHandler7752026/08/27 11:04:24 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"7762026/08/27 11:04:24 INFO Received uploads request method=POST path=/api/pending_closures7772026/08/27 11:04:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)7782026/08/27 11:04:24 INFO Uploading nd3id71ky1xa2rr6k92z0kkf8kddi1ng-file1.txt (160B)7792026/08/27 11:04:24 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"7802026/08/27 11:04:24 WARN Failed to register uploaded object key=nd3id71ky1xa2rr6k92z0kkf8kddi1ng.ls error="server returned 404: 404 page not found\n"7812026/08/27 11:04:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign7822026/08/27 11:04:24 INFO Signed narinfos id=1 count=17832026/08/27 11:04:24 INFO Uploading 1 narinfos7842026-08-27 11:04:24.338 UTC [62352] ERROR: relation "goose_db_version" does not exist at character 367852026-08-27 11:04:24.338 UTC [62352] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7862026/08/27 11:04:24 WARN Failed to register uploaded object key=nd3id71ky1xa2rr6k92z0kkf8kddi1ng.narinfo error="server returned 404: 404 page not found\n"7872026/08/27 11:04:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7882026/08/27 11:04:24 INFO Completed upload id=17892026/08/27 11:04:24 INFO Upload complete. (265ms)790=== NAME TestNARDeduplicationMetadataUploadBug791 metadata_upload_test.go:54: Retrieved narinfo from S3:792 StorePath: /nix/var/nix/builds/nix-62096-2608994286/TestNARDeduplicationMetadataUploadBug377295194/001/store/nd3id71ky1xa2rr6k92z0kkf8kddi1ng-file1.txt793 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst794 Compression: zstd795 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf796 NarSize: 160797 References: 798 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf799 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)800 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):801 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}802 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-62096-2608994286/TestNARDeduplicationMetadataUploadBug377295194/001/store/ksvd9vqhdmhyg2h359c8p8lj159z2xli-file2.txt8032026/08/27 11:04:24 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8042026-08-27 11:04:24.564 UTC [62360] ERROR: relation "goose_db_version" does not exist at character 368052026-08-27 11:04:24.564 UTC [62360] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8062026/08/27 11:04:24 OK 20241026095416_initial_model.sql (173.2ms)8072026/08/27 11:04:24 OK 20251210153512_drop_unused_gin_index.sql (6.56ms)8082026/08/27 11:04:24 INFO Received uploads request method=POST path=/api/pending_closures8092026/08/27 11:04:24 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)8102026/08/27 11:04:24 OK 20251218171726_add_pins.sql (48.19ms)8112026/08/27 11:04:24 WARN Failed to register uploaded object key=ksvd9vqhdmhyg2h359c8p8lj159z2xli.ls error="server returned 404: 404 page not found\n"8122026/08/27 11:04:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign8132026/08/27 11:04:24 INFO Signed narinfos id=2 count=18142026/08/27 11:04:24 INFO Uploading 1 narinfos8152026/08/27 11:04:24 OK 20260628120000_add_object_size_and_stats.sql (45.77ms)8162026/08/27 11:04:24 goose: successfully migrated database to version: 202606281200008172026/08/27 11:04:24 OK 1_commit_pending_closure.sql (4.7ms)8182026/08/27 11:04:24 OK 2_object_stats_trigger.sql (237.71µs)8192026/08/27 11:04:24 goose: up to current file version: 28202026/08/27 11:04:24 WARN Failed to register uploaded object key=ksvd9vqhdmhyg2h359c8p8lj159z2xli.narinfo error="server returned 404: 404 page not found\n"8212026/08/27 11:04:24 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete8222026/08/27 11:04:24 INFO Completed upload id=28232026/08/27 11:04:24 INFO Upload complete. (194ms)824 metadata_upload_test.go:76: Retrieved narinfo from S3:825 StorePath: /nix/var/nix/builds/nix-62096-2608994286/TestNARDeduplicationMetadataUploadBug377295194/001/store/ksvd9vqhdmhyg2h359c8p8lj159z2xli-file2.txt826 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst827 Compression: zstd828 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf829 NarSize: 160830 References: 831 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf832 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)833 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):834 {"version":1,"root":{"type":"regular","size":44}}835--- PASS: TestNARDeduplicationMetadataUploadBug (2.40s)836=== CONT TestClientWithDependencies8372026/08/27 11:04:24 OK 20241026095416_initial_model.sql (171.98ms)8382026/08/27 11:04:24 OK 20251210153512_drop_unused_gin_index.sql (13.12ms)8392026/08/27 11:04:24 WARN readiness check failed error="closed pool"840--- PASS: TestService_readinessHandler (1.77s)841=== CONT TestCacheConfigHandler842=== RUN TestCacheConfigHandler/full_config,_no_issuer843=== PAUSE TestCacheConfigHandler/full_config,_no_issuer844=== RUN TestCacheConfigHandler/no_cache_url_configured845=== PAUSE TestCacheConfigHandler/no_cache_url_configured846=== RUN TestCacheConfigHandler/no_signing_keys847=== PAUSE TestCacheConfigHandler/no_signing_keys848=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator849=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator850=== CONT TestCompleteMultipartUpload_ErrorButObjectExists8512026/08/27 11:04:24 OK 20251218171726_add_pins.sql (19.71ms)8522026/08/27 11:04:24 OK 20260628120000_add_object_size_and_stats.sql (26.08ms)8532026/08/27 11:04:24 goose: successfully migrated database to version: 202606281200008542026/08/27 11:04:24 OK 1_commit_pending_closure.sql (11.99ms)8552026/08/27 11:04:24 OK 2_object_stats_trigger.sql (554.13µs)8562026/08/27 11:04:24 goose: up to current file version: 2857--- PASS: TestService_healthCheckHandler (1.89s)858=== CONT TestService_ReadScope_PublicByDefault8592026-08-27 11:04:25.223 UTC [62370] ERROR: relation "goose_db_version" does not exist at character 368602026-08-27 11:04:25.223 UTC [62370] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8612026-08-27 11:04:25.223 UTC [62371] ERROR: relation "goose_db_version" does not exist at character 368622026-08-27 11:04:25.223 UTC [62371] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8632026-08-27 11:04:25.401 UTC [62372] ERROR: relation "goose_db_version" does not exist at character 368642026-08-27 11:04:25.401 UTC [62372] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8652026/08/27 11:04:25 OK 20241026095416_initial_model.sql (129.27ms)8662026/08/27 11:04:25 OK 20241026095416_initial_model.sql (126.32ms)8672026/08/27 11:04:25 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)8682026/08/27 11:04:25 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)8692026/08/27 11:04:25 OK 20251218171726_add_pins.sql (21.39ms)8702026/08/27 11:04:25 OK 20251218171726_add_pins.sql (29.12ms)8712026-08-27 11:04:25.460 UTC [62373] ERROR: relation "goose_db_version" does not exist at character 368722026-08-27 11:04:25.460 UTC [62373] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8732026/08/27 11:04:25 OK 20260628120000_add_object_size_and_stats.sql (39.58ms)8742026/08/27 11:04:25 goose: successfully migrated database to version: 202606281200008752026/08/27 11:04:25 OK 1_commit_pending_closure.sql (1.86ms)8762026/08/27 11:04:25 OK 2_object_stats_trigger.sql (225.46µs)8772026/08/27 11:04:25 goose: up to current file version: 28782026/08/27 11:04:25 OK 20260628120000_add_object_size_and_stats.sql (38.18ms)8792026/08/27 11:04:25 goose: successfully migrated database to version: 202606281200008802026/08/27 11:04:25 OK 1_commit_pending_closure.sql (16.43ms)8812026/08/27 11:04:25 OK 2_object_stats_trigger.sql (245.96µs)8822026/08/27 11:04:25 goose: up to current file version: 28832026/08/27 11:04:25 OK 20241026095416_initial_model.sql (188.07ms)8842026/08/27 11:04:25 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)8852026/08/27 11:04:25 OK 20241026095416_initial_model.sql (149.73ms)8862026/08/27 11:04:25 OK 20251210153512_drop_unused_gin_index.sql (18.22ms)8872026/08/27 11:04:25 OK 20251218171726_add_pins.sql (47.02ms)8882026/08/27 11:04:25 OK 20251218171726_add_pins.sql (2.31ms)8892026/08/27 11:04:25 OK 20260628120000_add_object_size_and_stats.sql (41.08ms)8902026/08/27 11:04:25 goose: successfully migrated database to version: 202606281200008912026/08/27 11:04:25 OK 20260628120000_add_object_size_and_stats.sql (47.86ms)8922026/08/27 11:04:25 goose: successfully migrated database to version: 202606281200008932026/08/27 11:04:25 OK 1_commit_pending_closure.sql (13.53ms)8942026/08/27 11:04:25 OK 1_commit_pending_closure.sql (7.5ms)8952026/08/27 11:04:25 OK 2_object_stats_trigger.sql (347.88µs)8962026/08/27 11:04:25 goose: up to current file version: 28972026/08/27 11:04:25 OK 2_object_stats_trigger.sql (449.46µs)8982026/08/27 11:04:25 goose: up to current file version: 28992026-08-27 11:04:25.781 UTC [62378] ERROR: relation "goose_db_version" does not exist at character 369002026-08-27 11:04:25.781 UTC [62378] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9012026/08/27 11:04:25 INFO Aborted multipart uploads count=09022026/08/27 11:04:25 WARN Force mode enabled - objects will be deleted immediately without grace period9032026/08/27 11:04:25 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=09042026/08/27 11:04:25 INFO Vacuumed table table=pending_closures9052026/08/27 11:04:25 INFO Vacuumed table table=pending_objects9062026/08/27 11:04:25 INFO Vacuumed table table=multipart_uploads9072026/08/27 11:04:25 INFO Vacuumed table table=closures9082026/08/27 11:04:25 INFO Vacuumed table table=objects909--- PASS: TestGCMetrics (2.29s)910=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT9112026-08-27 11:04:25.849 UTC [62380] ERROR: relation "goose_db_version" does not exist at character 369122026-08-27 11:04:25.849 UTC [62380] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC913=== NAME TestPinProtectsFromGC914 client_integration_test.go:647: Pinned store path: /nix/var/nix/builds/nix-62096-2608994286/TestPinProtectsFromGC403513045/001/store/wrk0dk0l0sz1l1mb6d1cb38hx011gqgr-pinned-file.txt915 client_integration_test.go:648: Unpinned store path: /nix/var/nix/builds/nix-62096-2608994286/TestPinProtectsFromGC403513045/001/store/3g9dvnbq00ycllg7yz51q7bvnshq0iyf-unpinned-file.txt9162026/08/27 11:04:25 OK 20241026095416_initial_model.sql (100.68ms)9172026/08/27 11:04:25 OK 20251210153512_drop_unused_gin_index.sql (8.38ms)9182026/08/27 11:04:25 OK 20251218171726_add_pins.sql (24.4ms)9192026/08/27 11:04:26 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9202026/08/27 11:04:26 OK 20260628120000_add_object_size_and_stats.sql (37.39ms)9212026/08/27 11:04:26 goose: successfully migrated database to version: 202606281200009222026/08/27 11:04:26 OK 1_commit_pending_closure.sql (1.47ms)9232026/08/27 11:04:26 OK 2_object_stats_trigger.sql (240.58µs)9242026/08/27 11:04:26 goose: up to current file version: 29252026/08/27 11:04:26 OK 20241026095416_initial_model.sql (130ms)9262026/08/27 11:04:26 OK 20251210153512_drop_unused_gin_index.sql (10.49ms)9272026/08/27 11:04:26 OK 20251218171726_add_pins.sql (25.81ms)9282026/08/27 11:04:26 INFO Received uploads request method=POST path=/api/pending_closures929=== RUN TestService_RequireScope_OIDC/builder_may_write930=== PAUSE TestService_RequireScope_OIDC/builder_may_write931=== RUN TestService_RequireScope_OIDC/builder_may_not_admin932=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin933=== RUN TestService_RequireScope_OIDC/ops_may_admin934=== PAUSE TestService_RequireScope_OIDC/ops_may_admin935=== RUN TestService_RequireScope_OIDC/ops_may_not_write936=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write937=== RUN TestService_RequireScope_OIDC/reader_may_not_write938=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write939=== RUN TestService_RequireScope_OIDC/static_token_may_admin940=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin941=== RUN TestService_RequireScope_OIDC/static_token_may_write942=== PAUSE TestService_RequireScope_OIDC/static_token_may_write943=== RUN TestService_RequireScope_OIDC/reader_may_read944=== PAUSE TestService_RequireScope_OIDC/reader_may_read945=== RUN TestService_RequireScope_OIDC/writer_implies_read946=== PAUSE TestService_RequireScope_OIDC/writer_implies_read947=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read948=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read949=== CONT TestCompleteMultipartUnregistered9502026/08/27 11:04:26 OK 20260628120000_add_object_size_and_stats.sql (33.74ms)9512026/08/27 11:04:26 goose: successfully migrated database to version: 202606281200009522026/08/27 11:04:26 OK 1_commit_pending_closure.sql (10.55ms)9532026/08/27 11:04:26 OK 2_object_stats_trigger.sql (259.04µs)9542026/08/27 11:04:26 goose: up to current file version: 29552026/08/27 11:04:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9562026/08/27 11:04:26 INFO Uploading wrk0dk0l0sz1l1mb6d1cb38hx011gqgr-pinned-file.txt (128B)9572026/08/27 11:04:26 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"958--- PASS: TestGCBugBareHashReferences (2.44s)959=== CONT TestService_verifyS3Integrity9602026/08/27 11:04:26 WARN Failed to register uploaded object key=wrk0dk0l0sz1l1mb6d1cb38hx011gqgr.ls error="server returned 404: 404 page not found\n"9612026/08/27 11:04:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9622026/08/27 11:04:26 INFO Signed narinfos id=1 count=19632026/08/27 11:04:26 INFO Uploading 1 narinfos9642026/08/27 11:04:26 WARN Failed to register uploaded object key=wrk0dk0l0sz1l1mb6d1cb38hx011gqgr.narinfo error="server returned 404: 404 page not found\n"9652026/08/27 11:04:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9662026/08/27 11:04:26 INFO Completed upload id=19672026/08/27 11:04:26 INFO Upload complete. (325ms)9682026/08/27 11:04:26 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9692026/08/27 11:04:26 INFO Received uploads request method=POST path=/api/pending_closures9702026/08/27 11:04:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9712026/08/27 11:04:26 INFO Uploading 3g9dvnbq00ycllg7yz51q7bvnshq0iyf-unpinned-file.txt (128B)9722026/08/27 11:04:26 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"9732026/08/27 11:04:26 WARN Failed to register uploaded object key=3g9dvnbq00ycllg7yz51q7bvnshq0iyf.ls error="server returned 404: 404 page not found\n"9742026/08/27 11:04:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9752026/08/27 11:04:26 INFO Signed narinfos id=2 count=19762026/08/27 11:04:26 INFO Uploading 1 narinfos977--- PASS: TestCacheStatsHandler (2.39s)978=== CONT TestClientIntegration9792026/08/27 11:04:26 WARN Failed to register uploaded object key=3g9dvnbq00ycllg7yz51q7bvnshq0iyf.narinfo error="server returned 404: 404 page not found\n"9802026/08/27 11:04:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9812026/08/27 11:04:26 INFO Completed upload id=29822026/08/27 11:04:26 INFO Upload complete. (257ms)983=== NAME TestClientMultipleUploads984 client_integration_test.go:339: Created store path 0: /nix/var/nix/builds/nix-62096-2608994286/TestClientMultipleUploads1564285604/001/store/r7nvgmmicc0ldlxr2knpv2ckbcv354m1-test-file-0.txt9852026/08/27 11:04:26 INFO Received create pin request method=POST path=/api/pins/myapp9862026/08/27 11:04:26 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-62096-2608994286/TestPinProtectsFromGC403513045/001/store/wrk0dk0l0sz1l1mb6d1cb38hx011gqgr-pinned-file.txt narinfo_key=wrk0dk0l0sz1l1mb6d1cb38hx011gqgr.narinfo9872026/08/27 11:04:26 INFO Starting cleanup of old closures method=DELETE path=/api/closures9882026/08/27 11:04:26 INFO Garbage collection started9892026/08/27 11:04:26 INFO Aborted multipart uploads count=09902026/08/27 11:04:26 WARN Force mode enabled - objects will be deleted immediately without grace period9912026-08-27 11:04:26.653 UTC [62409] ERROR: relation "goose_db_version" does not exist at character 369922026-08-27 11:04:26.653 UTC [62409] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC993 client_integration_test.go:339: Created store path 1: /nix/var/nix/builds/nix-62096-2608994286/TestClientMultipleUploads1564285604/001/store/shx8d7y6xgxqk2zzpx4mx50scf4ksp20-test-file-1.txt9942026-08-27 11:04:26.716 UTC [62412] ERROR: relation "goose_db_version" does not exist at character 369952026-08-27 11:04:26.716 UTC [62412] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC996 client_integration_test.go:339: Created store path 2: /nix/var/nix/builds/nix-62096-2608994286/TestClientMultipleUploads1564285604/001/store/kriz4niws942lpfvrdgsjv4p179hn76d-test-file-2.txt9972026-08-27 11:04:26.757 UTC [62415] ERROR: relation "goose_db_version" does not exist at character 369982026-08-27 11:04:26.757 UTC [62415] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9992026/08/27 11:04:26 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10002026/08/27 11:04:26 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3003 objects-failed-to-delete=010012026/08/27 11:04:26 OK 20241026095416_initial_model.sql (135.16ms)10022026/08/27 11:04:26 OK 20251210153512_drop_unused_gin_index.sql (15.36ms)10032026/08/27 11:04:26 INFO Vacuumed table table=pending_closures10042026/08/27 11:04:26 INFO Vacuumed table table=pending_objects10052026/08/27 11:04:26 INFO Vacuumed table table=multipart_uploads10062026/08/27 11:04:26 OK 20251218171726_add_pins.sql (18.23ms)10072026/08/27 11:04:26 INFO Received uploads request method=POST path=/api/pending_closures10082026/08/27 11:04:26 INFO Vacuumed table table=closures10092026/08/27 11:04:26 OK 20260628120000_add_object_size_and_stats.sql (27.4ms)10102026/08/27 11:04:26 goose: successfully migrated database to version: 2026062812000010112026/08/27 11:04:26 INFO Received uploads request method=POST path=/api/pending_closures10122026/08/27 11:04:26 INFO Received uploads request method=POST path=/api/pending_closures10132026/08/27 11:04:26 INFO Vacuumed table table=objects10142026/08/27 11:04:26 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)10152026/08/27 11:04:26 INFO Uploading shx8d7y6xgxqk2zzpx4mx50scf4ksp20-test-file-1.txt (160B)10162026/08/27 11:04:26 INFO Uploading kriz4niws942lpfvrdgsjv4p179hn76d-test-file-2.txt (160B)10172026/08/27 11:04:26 INFO Uploading r7nvgmmicc0ldlxr2knpv2ckbcv354m1-test-file-0.txt (160B)10182026/08/27 11:04:26 OK 1_commit_pending_closure.sql (1.51ms)10192026/08/27 11:04:26 OK 2_object_stats_trigger.sql (265.46µs)10202026/08/27 11:04:26 goose: up to current file version: 210212026/08/27 11:04:26 OK 20241026095416_initial_model.sql (178.78ms)10222026/08/27 11:04:26 OK 20251210153512_drop_unused_gin_index.sql (18.64ms)10232026/08/27 11:04:26 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"10242026/08/27 11:04:26 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"10252026/08/27 11:04:26 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"10262026/08/27 11:04:26 OK 20251218171726_add_pins.sql (34.06ms)10272026/08/27 11:04:27 WARN Failed to register uploaded object key=shx8d7y6xgxqk2zzpx4mx50scf4ksp20.ls error="server returned 404: 404 page not found\n"10282026/08/27 11:04:27 WARN Failed to register uploaded object key=r7nvgmmicc0ldlxr2knpv2ckbcv354m1.ls error="server returned 404: 404 page not found\n"10292026/08/27 11:04:27 WARN Failed to register uploaded object key=kriz4niws942lpfvrdgsjv4p179hn76d.ls error="server returned 404: 404 page not found\n"10302026/08/27 11:04:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10312026/08/27 11:04:27 INFO Signed narinfos id=1 count=110322026/08/27 11:04:27 OK 20241026095416_initial_model.sql (215.55ms)10332026/08/27 11:04:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10342026/08/27 11:04:27 INFO Signed narinfos id=2 count=110352026/08/27 11:04:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign10362026/08/27 11:04:27 INFO Signed narinfos id=3 count=110372026/08/27 11:04:27 INFO Uploading 3 narinfos10382026/08/27 11:04:27 OK 20260628120000_add_object_size_and_stats.sql (54.54ms)10392026/08/27 11:04:27 goose: successfully migrated database to version: 2026062812000010402026/08/27 11:04:27 OK 20251210153512_drop_unused_gin_index.sql (14.54ms)10412026/08/27 11:04:27 OK 1_commit_pending_closure.sql (10.51ms)10422026/08/27 11:04:27 OK 2_object_stats_trigger.sql (349.13µs)10432026/08/27 11:04:27 goose: up to current file version: 210442026/08/27 11:04:27 WARN Failed to register uploaded object key=r7nvgmmicc0ldlxr2knpv2ckbcv354m1.narinfo error="server returned 404: 404 page not found\n"10452026/08/27 11:04:27 WARN Failed to register uploaded object key=kriz4niws942lpfvrdgsjv4p179hn76d.narinfo error="server returned 404: 404 page not found\n"10462026/08/27 11:04:27 WARN Failed to register uploaded object key=shx8d7y6xgxqk2zzpx4mx50scf4ksp20.narinfo error="server returned 404: 404 page not found\n"10472026/08/27 11:04:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10482026/08/27 11:04:27 OK 20251218171726_add_pins.sql (54.7ms)10492026/08/27 11:04:27 INFO Received uploads request method=POST path=/api/pending_closures10502026/08/27 11:04:27 INFO Completed upload id=110512026/08/27 11:04:27 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10522026/08/27 11:04:27 INFO Completed upload id=210532026/08/27 11:04:27 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete10542026/08/27 11:04:27 INFO Completed upload id=310552026/08/27 11:04:27 INFO Upload complete. (349ms)1056 client_integration_test.go:350: Uploaded 3 paths in 381.40975ms10572026/08/27 11:04:27 OK 20260628120000_add_object_size_and_stats.sql (35.78ms)10582026/08/27 11:04:27 goose: successfully migrated database to version: 2026062812000010592026/08/27 11:04:27 OK 1_commit_pending_closure.sql (14.7ms)10602026/08/27 11:04:27 OK 2_object_stats_trigger.sql (419.38µs)10612026/08/27 11:04:27 goose: up to current file version: 21062--- PASS: TestClientMultipleUploads (3.22s)1063=== CONT TestService_createPendingClosureHandler10642026/08/27 11:04:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10652026/08/27 11:04:27 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTdkMmUzYzItZjEyZC00YWNjLTk2NDUtZDViNjA3NzRmYzRhLmFjYzM2ZTVlLTM3ZjctNDhlNy04ODgzLWVjZWIxYjBiMzQzOHgxNzg3ODI4NjY3MTYzOTEzMDAw10662026/08/27 11:04:27 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTdkMmUzYzItZjEyZC00YWNjLTk2NDUtZDViNjA3NzRmYzRhLmFjYzM2ZTVlLTM3ZjctNDhlNy04ODgzLWVjZWIxYjBiMzQzOHgxNzg3ODI4NjY3MTYzOTEzMDAw parts=11067--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.58s)1068=== CONT TestService_cleanupPendingClosuresHandler1069--- PASS: TestService_ReadScope_PublicByDefault (2.48s)1070=== CONT TestUploadHandlersRejectOversizedBody1071=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1072=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1073=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1074=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1075=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1076=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1077=== CONT TestService_ReadAuthMiddleware10782026-08-27 11:04:27.706 UTC [62435] ERROR: relation "goose_db_version" does not exist at character 3610792026-08-27 11:04:27.706 UTC [62435] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1080=== NAME TestClientWithDependencies1081 client_integration_test.go:594: Built derivation: /nix/var/nix/builds/nix-62096-2608994286/TestClientWithDependencies2545988100/001/store/mzykz46jix27v2diqnrd8586bszm3lk3-test-script1082 client_integration_test.go:596: Found 1 dependencies (including self)10832026/08/27 11:04:27 OK 20241026095416_initial_model.sql (139.63ms)10842026/08/27 11:04:27 OK 20251210153512_drop_unused_gin_index.sql (13.89ms)10852026/08/27 11:04:27 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10862026/08/27 11:04:27 INFO Received uploads request method=POST path=/api/pending_closures10872026/08/27 11:04:27 OK 20251218171726_add_pins.sql (21.33ms)10882026/08/27 11:04:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10892026/08/27 11:04:27 INFO Uploading mzykz46jix27v2diqnrd8586bszm3lk3-test-script (136B)10902026/08/27 11:04:27 OK 20260628120000_add_object_size_and_stats.sql (43.52ms)10912026/08/27 11:04:27 goose: successfully migrated database to version: 2026062812000010922026/08/27 11:04:27 OK 1_commit_pending_closure.sql (1.26ms)10932026/08/27 11:04:27 OK 2_object_stats_trigger.sql (224.79µs)10942026/08/27 11:04:27 goose: up to current file version: 210952026/08/27 11:04:27 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"10962026/08/27 11:04:28 WARN Failed to register uploaded object key=log/r2pfizbxrnz4wglk3rhqnk1n8qbk2yn3-test-script.drv error="server returned 404: 404 page not found\n"10972026/08/27 11:04:28 WARN Failed to register uploaded object key=mzykz46jix27v2diqnrd8586bszm3lk3.ls error="server returned 404: 404 page not found\n"10982026/08/27 11:04:28 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10992026/08/27 11:04:28 INFO Signed narinfos id=1 count=111002026/08/27 11:04:28 INFO Uploading 1 narinfos11012026-08-27 11:04:28.068 UTC [62444] ERROR: relation "goose_db_version" does not exist at character 3611022026-08-27 11:04:28.068 UTC [62444] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11032026/08/27 11:04:28 WARN Failed to register uploaded object key=mzykz46jix27v2diqnrd8586bszm3lk3.narinfo error="server returned 404: 404 page not found\n"11042026/08/27 11:04:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11052026/08/27 11:04:28 INFO Completed upload id=111062026/08/27 11:04:28 INFO Upload complete. (259ms)1107 client_integration_test.go:598: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-62096-2608994286/TestClientWithDependencies2545988100/001/store) requires matching store prefix11082026/08/27 11:04:28 INFO Received uploads request method=POST path=/api/pending_closures1109--- PASS: TestClientWithDependencies (3.37s)1110=== CONT TestUploadHandlersRejectInvalidKeys1111=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1112=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1113=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1114=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1115=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1116=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1117=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1118=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1119=== CONT TestIsValidUploadKey1120=== RUN TestIsValidUploadKey/narinfo1121=== PAUSE TestIsValidUploadKey/narinfo1122=== RUN TestIsValidUploadKey/nar_zst1123=== PAUSE TestIsValidUploadKey/nar_zst1124=== RUN TestIsValidUploadKey/nar_xz1125=== PAUSE TestIsValidUploadKey/nar_xz1126=== RUN TestIsValidUploadKey/nar_plain1127=== PAUSE TestIsValidUploadKey/nar_plain1128=== RUN TestIsValidUploadKey/listing1129=== PAUSE TestIsValidUploadKey/listing1130=== RUN TestIsValidUploadKey/build_log1131=== PAUSE TestIsValidUploadKey/build_log1132=== RUN TestIsValidUploadKey/build_log_home-manager_file1133=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1134=== RUN TestIsValidUploadKey/build_log_plus_in_name1135=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1136=== RUN TestIsValidUploadKey/build_log_question_mark1137=== PAUSE TestIsValidUploadKey/build_log_question_mark1138=== RUN TestIsValidUploadKey/build_log_equals1139=== PAUSE TestIsValidUploadKey/build_log_equals1140=== RUN TestIsValidUploadKey/realisation1141=== PAUSE TestIsValidUploadKey/realisation1142=== RUN TestIsValidUploadKey/realisation_plus_in_output1143=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1144=== RUN TestIsValidUploadKey/nix-cache-info1145=== PAUSE TestIsValidUploadKey/nix-cache-info1146=== RUN TestIsValidUploadKey/index.html1147=== PAUSE TestIsValidUploadKey/index.html1148=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1149=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1150=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1151=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1152=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1153=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1154=== RUN TestIsValidUploadKey/traversal1155=== PAUSE TestIsValidUploadKey/traversal1156=== RUN TestIsValidUploadKey/traversal_nar1157=== PAUSE TestIsValidUploadKey/traversal_nar1158=== RUN TestIsValidUploadKey/absolute1159=== PAUSE TestIsValidUploadKey/absolute1160=== RUN TestIsValidUploadKey/empty_key1161=== PAUSE TestIsValidUploadKey/empty_key1162=== RUN TestIsValidUploadKey/unknown_type1163=== PAUSE TestIsValidUploadKey/unknown_type1164=== CONT TestService_AuthMiddleware_OIDC11652026/08/27 11:04:28 INFO OIDC provider initialized name=test1166--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.38s)1167=== CONT TestProxyWriteTimeout1168=== RUN TestProxyWriteTimeout/narinfo1169=== PAUSE TestProxyWriteTimeout/narinfo1170=== RUN TestProxyWriteTimeout/1_GiB_nar1171=== PAUSE TestProxyWriteTimeout/1_GiB_nar1172=== RUN TestProxyWriteTimeout/10_GiB_nar1173=== PAUSE TestProxyWriteTimeout/10_GiB_nar1174=== RUN TestProxyWriteTimeout/unknown_size1175=== PAUSE TestProxyWriteTimeout/unknown_size1176=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle11772026-08-27 11:04:28.215 UTC [62445] ERROR: relation "goose_db_version" does not exist at character 3611782026-08-27 11:04:28.215 UTC [62445] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11792026/08/27 11:04:28 OK 20241026095416_initial_model.sql (99.87ms)11802026/08/27 11:04:28 OK 20251210153512_drop_unused_gin_index.sql (7.1ms)11812026/08/27 11:04:28 OK 20251218171726_add_pins.sql (23.64ms)11822026/08/27 11:04:28 OK 20260628120000_add_object_size_and_stats.sql (18.8ms)11832026/08/27 11:04:28 goose: successfully migrated database to version: 2026062812000011842026/08/27 11:04:28 OK 1_commit_pending_closure.sql (2.16ms)11852026/08/27 11:04:28 OK 2_object_stats_trigger.sql (377.96µs)11862026/08/27 11:04:28 goose: up to current file version: 211872026-08-27 11:04:28.346 UTC [62450] ERROR: relation "goose_db_version" does not exist at character 3611882026-08-27 11:04:28.346 UTC [62450] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11892026/08/27 11:04:28 OK 20241026095416_initial_model.sql (108.72ms)11902026/08/27 11:04:28 OK 20251210153512_drop_unused_gin_index.sql (11.71ms)11912026/08/27 11:04:28 OK 20251218171726_add_pins.sql (26.79ms)11922026/08/27 11:04:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11932026/08/27 11:04:28 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1194--- PASS: TestCompleteMultipartUnregistered (2.33s)1195=== CONT TestService_AuthMiddleware_MTLSBoundSubjects11962026/08/27 11:04:28 OK 20260628120000_add_object_size_and_stats.sql (22.13ms)11972026/08/27 11:04:28 goose: successfully migrated database to version: 2026062812000011982026/08/27 11:04:28 OK 1_commit_pending_closure.sql (3.75ms)11992026/08/27 11:04:28 OK 2_object_stats_trigger.sql (530.88µs)12002026/08/27 11:04:28 goose: up to current file version: 212012026/08/27 11:04:28 OK 20241026095416_initial_model.sql (131.96ms)12022026/08/27 11:04:28 OK 20251210153512_drop_unused_gin_index.sql (13.92ms)12032026/08/27 11:04:28 OK 20251218171726_add_pins.sql (16.99ms)12042026/08/27 11:04:28 INFO Received uploads request method=POST path=/api/pending_closures12052026/08/27 11:04:28 OK 20260628120000_add_object_size_and_stats.sql (31.33ms)12062026/08/27 11:04:28 goose: successfully migrated database to version: 2026062812000012072026/08/27 11:04:28 OK 1_commit_pending_closure.sql (5.56ms)12082026/08/27 11:04:28 OK 2_object_stats_trigger.sql (920.58µs)12092026/08/27 11:04:28 goose: up to current file version: 212102026/08/27 11:04:28 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3003 objects_failed=01211=== NAME TestPinProtectsFromGC1212 client_integration_test.go:710: Pin successfully protected closure from garbage collection1213--- PASS: TestPinProtectsFromGC (5.19s)1214=== CONT TestSkippedUploadsHandler12152026/08/27 11:04:28 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001216--- PASS: TestSkippedUploadsHandler (0.00s)1217=== CONT TestPresignedUploadRegisteredBeforeCommit1218=== NAME TestClientIntegration1219 client_integration_test.go:277: Created store path: /nix/var/nix/builds/nix-62096-2608994286/TestClientIntegration3893062034/002/store/b544vdpxa4ss9glm0yb28psafbyjvzwl-test-file.txt12202026-08-27 11:04:28.966 UTC [62457] ERROR: relation "goose_db_version" does not exist at character 3612212026-08-27 11:04:28.966 UTC [62457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12222026/08/27 11:04:29 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12232026-08-27 11:04:29.072 UTC [62462] ERROR: relation "goose_db_version" does not exist at character 3612242026-08-27 11:04:29.072 UTC [62462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12252026/08/27 11:04:29 INFO Received uploads request method=POST path=/api/pending_closures12262026/08/27 11:04:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12272026/08/27 11:04:29 INFO Uploading b544vdpxa4ss9glm0yb28psafbyjvzwl-test-file.txt (152B)12282026/08/27 11:04:29 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12292026-08-27 11:04:29.192 UTC [62465] ERROR: relation "goose_db_version" does not exist at character 3612302026-08-27 11:04:29.192 UTC [62465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12312026/08/27 11:04:29 WARN Failed to register uploaded object key=b544vdpxa4ss9glm0yb28psafbyjvzwl.ls error="server returned 404: 404 page not found\n"12322026/08/27 11:04:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12332026/08/27 11:04:29 INFO Signed narinfos id=1 count=112342026/08/27 11:04:29 INFO Uploading 1 narinfos12352026/08/27 11:04:29 WARN Failed to register uploaded object key=b544vdpxa4ss9glm0yb28psafbyjvzwl.narinfo error="server returned 404: 404 page not found\n"12362026/08/27 11:04:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12372026/08/27 11:04:29 INFO Completed upload id=112382026/08/27 11:04:29 INFO Upload complete. (291ms)1239 client_integration_test.go:293: Retrieved narinfo from S3:1240 StorePath: /nix/var/nix/builds/nix-62096-2608994286/TestClientIntegration3893062034/002/store/b544vdpxa4ss9glm0yb28psafbyjvzwl-test-file.txt1241 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1242 Compression: zstd1243 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11244 NarSize: 1521245 References: 1246 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11247 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1248 client_integration_test.go:294: Decompressed .ls content (64 bytes):1249 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1250 client_integration_test.go:297: Testing garbage collection...12512026/08/27 11:04:29 OK 20241026095416_initial_model.sql (231.01ms)12522026/08/27 11:04:29 OK 20251210153512_drop_unused_gin_index.sql (9.64ms)12532026/08/27 11:04:29 OK 20251218171726_add_pins.sql (29.69ms)12542026/08/27 11:04:29 INFO Starting cleanup of old closures method=DELETE path=/api/closures12552026/08/27 11:04:29 INFO Garbage collection started12562026/08/27 11:04:29 INFO Aborted multipart uploads count=012572026/08/27 11:04:29 WARN Force mode enabled - objects will be deleted immediately without grace period12582026/08/27 11:04:29 OK 20241026095416_initial_model.sql (209.8ms)12592026/08/27 11:04:29 OK 20260628120000_add_object_size_and_stats.sql (36.12ms)12602026/08/27 11:04:29 goose: successfully migrated database to version: 2026062812000012612026/08/27 11:04:29 OK 1_commit_pending_closure.sql (5.18ms)12622026/08/27 11:04:29 OK 20251210153512_drop_unused_gin_index.sql (5.62ms)12632026/08/27 11:04:29 OK 2_object_stats_trigger.sql (440.21µs)12642026/08/27 11:04:29 goose: up to current file version: 212652026/08/27 11:04:29 OK 20251218171726_add_pins.sql (45.24ms)12662026/08/27 11:04:29 OK 20260628120000_add_object_size_and_stats.sql (47.4ms)12672026/08/27 11:04:29 goose: successfully migrated database to version: 2026062812000012682026/08/27 11:04:29 OK 20241026095416_initial_model.sql (196.53ms)12692026/08/27 11:04:29 OK 1_commit_pending_closure.sql (5.81ms)12702026/08/27 11:04:29 OK 2_object_stats_trigger.sql (253.79µs)12712026/08/27 11:04:29 goose: up to current file version: 212722026/08/27 11:04:29 OK 20251210153512_drop_unused_gin_index.sql (10.59ms)12732026/08/27 11:04:29 OK 20251218171726_add_pins.sql (26.41ms)12742026/08/27 11:04:29 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=012752026/08/27 11:04:29 INFO Received uploads request method=POST path=/api/pending_closures12762026/08/27 11:04:29 INFO Received uploads request method=POST path=/api/pending_closures12772026/08/27 11:04:29 INFO Received uploads request method=POST path=/api/pending_closures12782026/08/27 11:04:29 OK 20260628120000_add_object_size_and_stats.sql (46.69ms)12792026/08/27 11:04:29 goose: successfully migrated database to version: 2026062812000012802026/08/27 11:04:29 INFO Vacuumed table table=pending_closures12812026/08/27 11:04:29 OK 1_commit_pending_closure.sql (18.27ms)12822026/08/27 11:04:29 OK 2_object_stats_trigger.sql (241.83µs)12832026/08/27 11:04:29 goose: up to current file version: 212842026/08/27 11:04:29 INFO Vacuumed table table=pending_objects12852026/08/27 11:04:29 INFO Vacuumed table table=multipart_uploads12862026/08/27 11:04:29 INFO Vacuumed table table=closures12872026/08/27 11:04:29 INFO Vacuumed table table=objects1288--- PASS: TestService_ReadAuthMiddleware (2.26s)1289=== CONT TestParseSize1290--- PASS: TestParseSize (0.00s)1291=== CONT TestService_Rustfstest12922026/08/27 11:04:30 INFO Received cleanup request method=DELETE path=/api/pending_closures12932026/08/27 11:04:30 INFO Aborted multipart uploads count=012942026/08/27 11:04:30 INFO Received uploads request method=POST path=/api/pending_closures12952026/08/27 11:04:30 INFO Received cleanup request method=DELETE path=/api/pending_closures12962026/08/27 11:04:30 INFO Aborted multipart uploads count=112972026/08/27 11:04:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12982026/08/27 11:04:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12992026-08-27 11:04:30.155 UTC [62465] ERROR: Closure does not exist: id=113002026-08-27 11:04:30.155 UTC [62465] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE13012026-08-27 11:04:30.155 UTC [62465] STATEMENT: -- name: CommitPendingClosure :exec1302 SELECT commit_pending_closure($1::bigint)1303 1304--- PASS: TestService_cleanupPendingClosuresHandler (2.74s)1305=== CONT TestCompletedNarNotReofferedAcrossClosures13062026/08/27 11:04:30 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZTdkMmUzYzItZjEyZC00YWNjLTk2NDUtZDViNjA3NzRmYzRhLmRjYjI5ZTU0LTVjYzEtNGE4OS05ZWFmLWUzMWRkNWEzN2I1OHgxNzg3ODI4NjY4NjA4ODg3MDAw parts=1013072026/08/27 11:04:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13082026/08/27 11:04:30 INFO Completed upload id=113092026/08/27 11:04:30 INFO Received uploads request method=POST path=/api/pending_closures13102026/08/27 11:04:30 INFO Received uploads request method=POST path=/api/pending_closures13112026/08/27 11:04:30 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13122026/08/27 11:04:30 WARN Found objects in DB but missing from S3, will re-upload count=11313--- PASS: TestService_verifyS3Integrity (4.09s)1314=== CONT TestClientErrorHandling1315=== RUN TestClientErrorHandling/InvalidStorePath1316=== PAUSE TestClientErrorHandling/InvalidStorePath1317=== RUN TestClientErrorHandling/InvalidAuthToken1318=== PAUSE TestClientErrorHandling/InvalidAuthToken1319=== RUN TestClientErrorHandling/ServerNotAvailable1320=== PAUSE TestClientErrorHandling/ServerNotAvailable1321=== CONT TestService_AuthMiddleware_MTLSProxyHeader13222026-08-27 11:04:30.347 UTC [62474] ERROR: relation "goose_db_version" does not exist at character 3613232026-08-27 11:04:30.347 UTC [62474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13242026-08-27 11:04:30.407 UTC [62477] ERROR: relation "goose_db_version" does not exist at character 3613252026-08-27 11:04:30.407 UTC [62477] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13262026/08/27 11:04:30 OK 20241026095416_initial_model.sql (231.05ms)13272026/08/27 11:04:30 OK 20251210153512_drop_unused_gin_index.sql (15.5ms)13282026/08/27 11:04:30 OK 20251218171726_add_pins.sql (12.18ms)13292026/08/27 11:04:30 OK 20241026095416_initial_model.sql (189.24ms)13302026/08/27 11:04:30 OK 20251210153512_drop_unused_gin_index.sql (9.49ms)13312026/08/27 11:04:30 OK 20251218171726_add_pins.sql (87.05ms)13322026/08/27 11:04:30 OK 20260628120000_add_object_size_and_stats.sql (99.15ms)13332026/08/27 11:04:30 goose: successfully migrated database to version: 2026062812000013342026/08/27 11:04:30 OK 1_commit_pending_closure.sql (9.68ms)13352026/08/27 11:04:30 OK 2_object_stats_trigger.sql (795.88µs)13362026/08/27 11:04:30 goose: up to current file version: 213372026/08/27 11:04:30 OK 20260628120000_add_object_size_and_stats.sql (44.53ms)13382026/08/27 11:04:30 goose: successfully migrated database to version: 2026062812000013392026/08/27 11:04:30 OK 1_commit_pending_closure.sql (4.48ms)13402026/08/27 11:04:30 OK 2_object_stats_trigger.sql (915.67µs)13412026/08/27 11:04:30 goose: up to current file version: 213422026-08-27 11:04:30.910 UTC [62478] ERROR: relation "goose_db_version" does not exist at character 3613432026-08-27 11:04:30.910 UTC [62478] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13442026/08/27 11:04:30 INFO Received uploads request method=POST path=/api/pending_closures13452026-08-27 11:04:31.169 UTC [62479] ERROR: relation "goose_db_version" does not exist at character 3613462026-08-27 11:04:31.169 UTC [62479] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1347=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1348=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1349=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1350=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1351=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1352=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1353=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1354=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1355=== CONT TestReadProxyHead13562026/08/27 11:04:31 OK 20241026095416_initial_model.sql (269.77ms)13572026/08/27 11:04:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13582026/08/27 11:04:31 OK 20251210153512_drop_unused_gin_index.sql (26.16ms)13592026/08/27 11:04:31 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01360=== NAME TestClientIntegration1361 client_integration_test.go:304: Objects in database after GC:1362 client_integration_test.go:304: Successfully deleted all objects with GC --force13632026/08/27 11:04:31 OK 20251218171726_add_pins.sql (43.55ms)13642026/08/27 11:04:31 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZTdkMmUzYzItZjEyZC00YWNjLTk2NDUtZDViNjA3NzRmYzRhLmY2MGUyZmEzLWY0ZGEtNDI5Yi05M2QyLTBmNGE0N2MxYTA1NXgxNzg3ODI4NjY5NTc2NjkwMDAw parts=1013652026/08/27 11:04:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13662026/08/27 11:04:31 OK 20260628120000_add_object_size_and_stats.sql (46.7ms)13672026/08/27 11:04:31 goose: successfully migrated database to version: 2026062812000013682026/08/27 11:04:31 INFO Completed upload id=113692026/08/27 11:04:31 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013702026/08/27 11:04:31 INFO Received uploads request method=POST path=/api/pending_closures13712026/08/27 11:04:31 INFO Starting cleanup of old closures method=DELETE path=/api/closures13722026/08/27 11:04:31 OK 1_commit_pending_closure.sql (9.42ms)13732026/08/27 11:04:31 OK 2_object_stats_trigger.sql (740.88µs)13742026/08/27 11:04:31 goose: up to current file version: 213752026/08/27 11:04:31 INFO Aborted multipart uploads count=013762026/08/27 11:04:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13772026/08/27 11:04:31 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=01378--- PASS: TestClientIntegration (4.87s)1379=== CONT TestReadProxyDisabled13802026/08/27 11:04:31 INFO Vacuumed table table=pending_closures13812026/08/27 11:04:31 INFO Vacuumed table table=pending_objects13822026/08/27 11:04:31 INFO Vacuumed table table=multipart_uploads13832026/08/27 11:04:31 OK 20241026095416_initial_model.sql (231.42ms)13842026/08/27 11:04:31 OK 20251210153512_drop_unused_gin_index.sql (16.57ms)13852026/08/27 11:04:31 INFO Vacuumed table table=closures13862026/08/27 11:04:31 OK 20251218171726_add_pins.sql (28.75ms)13872026/08/27 11:04:31 INFO Vacuumed table table=objects13882026/08/27 11:04:31 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001389--- PASS: TestService_createPendingClosureHandler (4.28s)1390=== CONT TestReadRedirectNar13912026/08/27 11:04:31 OK 20260628120000_add_object_size_and_stats.sql (36.2ms)13922026/08/27 11:04:31 goose: successfully migrated database to version: 2026062812000013932026/08/27 11:04:31 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13942026/08/27 11:04:31 WARN mTLS auth: bound subjects configured but subject DN unavailable13952026/08/27 11:04:31 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1396--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (3.15s)1397=== CONT TestReadProxyRootRedirectsToIndexHTML13982026/08/27 11:04:31 OK 1_commit_pending_closure.sql (14.53ms)13992026/08/27 11:04:31 OK 2_object_stats_trigger.sql (449.96µs)14002026/08/27 11:04:31 goose: up to current file version: 214012026/08/27 11:04:31 INFO Received uploads request method=POST path=/api/pending_closures14022026/08/27 11:04:31 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst14032026/08/27 11:04:31 INFO Received uploads request method=POST path=/api/pending_closures1404--- PASS: TestPresignedUploadRegisteredBeforeCommit (3.21s)1405=== CONT TestRedundantMultipartUpload14062026-08-27 11:04:32.353 UTC [62491] ERROR: relation "goose_db_version" does not exist at character 3614072026-08-27 11:04:32.353 UTC [62491] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14082026-08-27 11:04:32.651 UTC [62492] ERROR: relation "goose_db_version" does not exist at character 3614092026-08-27 11:04:32.651 UTC [62492] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14102026/08/27 11:04:32 OK 20241026095416_initial_model.sql (240ms)14112026/08/27 11:04:32 OK 20251210153512_drop_unused_gin_index.sql (15.24ms)14122026/08/27 11:04:32 OK 20251218171726_add_pins.sql (45.15ms)14132026/08/27 11:04:32 OK 20260628120000_add_object_size_and_stats.sql (47.11ms)14142026/08/27 11:04:32 goose: successfully migrated database to version: 2026062812000014152026/08/27 11:04:32 OK 1_commit_pending_closure.sql (7.35ms)14162026/08/27 11:04:32 OK 2_object_stats_trigger.sql (1.55ms)14172026/08/27 11:04:32 goose: up to current file version: 214182026/08/27 11:04:32 OK 20241026095416_initial_model.sql (193.51ms)14192026/08/27 11:04:32 OK 20251210153512_drop_unused_gin_index.sql (16.58ms)14202026-08-27 11:04:32.961 UTC [62493] ERROR: relation "goose_db_version" does not exist at character 3614212026-08-27 11:04:32.961 UTC [62493] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1422--- PASS: TestService_Rustfstest (3.20s)1423=== CONT TestReadProxyConditionalGet1424=== NAME TestOrphanedObjectsGCStressTest1425 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains14262026/08/27 11:04:32 OK 20251218171726_add_pins.sql (26.06ms)14272026/08/27 11:04:32 OK 20260628120000_add_object_size_and_stats.sql (6.07ms)14282026/08/27 11:04:32 goose: successfully migrated database to version: 2026062812000014292026/08/27 11:04:32 OK 1_commit_pending_closure.sql (3.22ms)14302026/08/27 11:04:32 OK 2_object_stats_trigger.sql (953.33µs)14312026/08/27 11:04:32 goose: up to current file version: 21432 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion14332026/08/27 11:04:33 OK 20241026095416_initial_model.sql (40.43ms)14342026/08/27 11:04:33 OK 20251210153512_drop_unused_gin_index.sql (2ms)14352026/08/27 11:04:33 OK 20251218171726_add_pins.sql (17.33ms)14362026/08/27 11:04:33 OK 20260628120000_add_object_size_and_stats.sql (13.2ms)14372026/08/27 11:04:33 goose: successfully migrated database to version: 2026062812000014382026/08/27 11:04:33 OK 1_commit_pending_closure.sql (2.19ms)14392026/08/27 11:04:33 OK 2_object_stats_trigger.sql (341.67µs)14402026/08/27 11:04:33 goose: up to current file version: 214412026/08/27 11:04:33 INFO Received uploads request method=POST path=/api/pending_closures1442--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.97s)1443=== CONT TestReadProxyRangeRequest14442026-08-27 11:04:33.239 UTC [62496] ERROR: relation "goose_db_version" does not exist at character 3614452026-08-27 11:04:33.239 UTC [62496] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14462026/08/27 11:04:33 OK 20241026095416_initial_model.sql (16.74ms)14472026/08/27 11:04:33 OK 20251210153512_drop_unused_gin_index.sql (11.4ms)14482026/08/27 11:04:33 OK 20251218171726_add_pins.sql (15.55ms)14492026-08-27 11:04:33.334 UTC [62499] ERROR: relation "goose_db_version" does not exist at character 3614502026-08-27 11:04:33.334 UTC [62499] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14512026/08/27 11:04:33 OK 20260628120000_add_object_size_and_stats.sql (31ms)14522026/08/27 11:04:33 goose: successfully migrated database to version: 2026062812000014532026/08/27 11:04:33 OK 1_commit_pending_closure.sql (2.92ms)14542026/08/27 11:04:33 OK 2_object_stats_trigger.sql (753.46µs)14552026/08/27 11:04:33 goose: up to current file version: 214562026-08-27 11:04:33.378 UTC [62500] ERROR: relation "goose_db_version" does not exist at character 3614572026-08-27 11:04:33.378 UTC [62500] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14582026-08-27 11:04:33.385 UTC [62501] ERROR: relation "goose_db_version" does not exist at character 3614592026-08-27 11:04:33.385 UTC [62501] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14602026/08/27 11:04:33 OK 20241026095416_initial_model.sql (99.77ms)14612026/08/27 11:04:33 OK 20251210153512_drop_unused_gin_index.sql (9.91ms)1462--- PASS: TestReadProxyHead (2.31s)1463=== CONT TestReadRedirectKeepsNarinfoProxied14642026/08/27 11:04:33 OK 20251218171726_add_pins.sql (23.15ms)14652026/08/27 11:04:33 OK 20260628120000_add_object_size_and_stats.sql (31.01ms)14662026/08/27 11:04:33 goose: successfully migrated database to version: 2026062812000014672026/08/27 11:04:33 OK 1_commit_pending_closure.sql (2.62ms)14682026/08/27 11:04:33 OK 20241026095416_initial_model.sql (109.24ms)14692026/08/27 11:04:33 OK 2_object_stats_trigger.sql (470.67µs)14702026/08/27 11:04:33 goose: up to current file version: 214712026/08/27 11:04:33 OK 20241026095416_initial_model.sql (114.25ms)14722026/08/27 11:04:33 OK 20251210153512_drop_unused_gin_index.sql (6.51ms)14732026/08/27 11:04:33 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)14742026/08/27 11:04:33 OK 20251218171726_add_pins.sql (24.23ms)14752026/08/27 11:04:33 OK 20251218171726_add_pins.sql (32.56ms)14762026/08/27 11:04:33 OK 20260628120000_add_object_size_and_stats.sql (9.2ms)14772026/08/27 11:04:33 goose: successfully migrated database to version: 2026062812000014782026/08/27 11:04:33 OK 1_commit_pending_closure.sql (3.84ms)14792026/08/27 11:04:33 OK 2_object_stats_trigger.sql (392.29µs)14802026/08/27 11:04:33 goose: up to current file version: 214812026/08/27 11:04:33 OK 20260628120000_add_object_size_and_stats.sql (21.66ms)14822026/08/27 11:04:33 goose: successfully migrated database to version: 2026062812000014832026/08/27 11:04:33 OK 1_commit_pending_closure.sql (9.16ms)14842026/08/27 11:04:33 OK 2_object_stats_trigger.sql (384.21µs)14852026/08/27 11:04:33 goose: up to current file version: 21486--- PASS: TestReadProxyDisabled (2.24s)1487=== CONT TestReadProxyNarinfoAlreadyDecompressed14882026-08-27 11:04:33.687 UTC [62504] ERROR: relation "goose_db_version" does not exist at character 3614892026-08-27 11:04:33.687 UTC [62504] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1490--- PASS: TestReadRedirectNar (2.28s)1491=== CONT TestReadProxyInvalidPath14922026/08/27 11:04:33 OK 20241026095416_initial_model.sql (147.37ms)14932026/08/27 11:04:33 OK 20251210153512_drop_unused_gin_index.sql (5.97ms)14942026/08/27 11:04:33 OK 20251218171726_add_pins.sql (14.63ms)14952026/08/27 11:04:33 OK 20260628120000_add_object_size_and_stats.sql (29.67ms)14962026/08/27 11:04:33 goose: successfully migrated database to version: 2026062812000014972026/08/27 11:04:33 OK 1_commit_pending_closure.sql (2.01ms)14982026/08/27 11:04:33 OK 2_object_stats_trigger.sql (397.71µs)14992026/08/27 11:04:33 goose: up to current file version: 21500--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.37s)1501=== CONT TestReadProxy40415022026/08/27 11:04:34 INFO Received uploads request method=POST path=/api/pending_closures15032026/08/27 11:04:34 INFO Received uploads request method=POST path=/api/pending_closures15042026-08-27 11:04:34.156 UTC [62511] ERROR: relation "goose_db_version" does not exist at character 3615052026-08-27 11:04:34.156 UTC [62511] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15062026/08/27 11:04:34 OK 20241026095416_initial_model.sql (84.77ms)15072026/08/27 11:04:34 OK 20251210153512_drop_unused_gin_index.sql (1.18ms)15082026/08/27 11:04:34 OK 20251218171726_add_pins.sql (2.3ms)15092026/08/27 11:04:34 WARN Rate limiter enabled after throttle name=s3-test rate=515102026/08/27 11:04:34 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1511=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1512 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101513 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001514--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.12s)1515=== CONT TestReadProxyNarStreaming15162026/08/27 11:04:34 OK 20260628120000_add_object_size_and_stats.sql (16.14ms)15172026/08/27 11:04:34 goose: successfully migrated database to version: 2026062812000015182026/08/27 11:04:34 OK 1_commit_pending_closure.sql (15.41ms)15192026/08/27 11:04:34 OK 2_object_stats_trigger.sql (290.17µs)15202026/08/27 11:04:34 goose: up to current file version: 215212026/08/27 11:04:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15222026/08/27 11:04:34 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZTdkMmUzYzItZjEyZC00YWNjLTk2NDUtZDViNjA3NzRmYzRhLjNhMmQ3N2EyLTgzMDMtNDQxZS1hNWUwLTA5Nzc2NDFmNThhYngxNzg3ODI4NjczMTEzMTU0MDAw parts=1215232026/08/27 11:04:34 INFO Received uploads request method=POST path=/api/pending_closures1524--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.37s)1525=== CONT TestIsValidCachePath1526=== RUN TestIsValidCachePath/narinfo1527=== PAUSE TestIsValidCachePath/narinfo1528=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1529=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1530=== RUN TestIsValidCachePath/nar_zst1531=== PAUSE TestIsValidCachePath/nar_zst1532=== RUN TestIsValidCachePath/nar_xz1533=== PAUSE TestIsValidCachePath/nar_xz1534=== RUN TestIsValidCachePath/nar_bz21535=== PAUSE TestIsValidCachePath/nar_bz21536=== RUN TestIsValidCachePath/nar_uncompressed1537=== PAUSE TestIsValidCachePath/nar_uncompressed1538=== RUN TestIsValidCachePath/ls1539=== PAUSE TestIsValidCachePath/ls1540=== RUN TestIsValidCachePath/log1541=== PAUSE TestIsValidCachePath/log1542=== RUN TestIsValidCachePath/realisation1543=== PAUSE TestIsValidCachePath/realisation1544=== RUN TestIsValidCachePath/nix-cache-info1545=== PAUSE TestIsValidCachePath/nix-cache-info1546=== RUN TestIsValidCachePath/index.html1547=== PAUSE TestIsValidCachePath/index.html1548=== RUN TestIsValidCachePath/traversal_parent1549=== PAUSE TestIsValidCachePath/traversal_parent1550=== RUN TestIsValidCachePath/traversal_in_middle1551=== PAUSE TestIsValidCachePath/traversal_in_middle1552=== RUN TestIsValidCachePath/invalid_char_e1553=== PAUSE TestIsValidCachePath/invalid_char_e1554=== RUN TestIsValidCachePath/invalid_char_u1555=== PAUSE TestIsValidCachePath/invalid_char_u1556=== RUN TestIsValidCachePath/random_path1557=== PAUSE TestIsValidCachePath/random_path1558=== RUN TestIsValidCachePath/empty1559=== PAUSE TestIsValidCachePath/empty1560=== RUN TestIsValidCachePath/leading_slash1561=== PAUSE TestIsValidCachePath/leading_slash1562=== RUN TestIsValidCachePath/wrong_extension1563=== PAUSE TestIsValidCachePath/wrong_extension1564=== RUN TestIsValidCachePath/short_hash1565=== PAUSE TestIsValidCachePath/short_hash1566=== CONT TestParseSingleRange1567=== RUN TestParseSingleRange/none1568=== PAUSE TestParseSingleRange/none1569=== RUN TestParseSingleRange/unknown_unit1570=== PAUSE TestParseSingleRange/unknown_unit1571=== RUN TestParseSingleRange/multi-range_ignored1572=== PAUSE TestParseSingleRange/multi-range_ignored1573=== RUN TestParseSingleRange/malformed_no_dash1574=== PAUSE TestParseSingleRange/malformed_no_dash1575=== RUN TestParseSingleRange/malformed_both_empty1576=== PAUSE TestParseSingleRange/malformed_both_empty1577=== RUN TestParseSingleRange/malformed_end_before_start1578=== PAUSE TestParseSingleRange/malformed_end_before_start1579=== RUN TestParseSingleRange/closed1580=== PAUSE TestParseSingleRange/closed1581=== RUN TestParseSingleRange/open-ended1582=== PAUSE TestParseSingleRange/open-ended1583=== RUN TestParseSingleRange/end_clamped_to_size1584=== PAUSE TestParseSingleRange/end_clamped_to_size1585=== RUN TestParseSingleRange/suffix1586=== PAUSE TestParseSingleRange/suffix1587=== RUN TestParseSingleRange/suffix_exceeds_size1588=== PAUSE TestParseSingleRange/suffix_exceeds_size1589=== RUN TestParseSingleRange/single_byte1590=== PAUSE TestParseSingleRange/single_byte1591=== RUN TestParseSingleRange/start_past_EOF1592=== PAUSE TestParseSingleRange/start_past_EOF1593=== RUN TestParseSingleRange/start_far_past_EOF1594=== PAUSE TestParseSingleRange/start_far_past_EOF1595=== CONT TestReadProxyNarinfo1596--- PASS: TestReadProxyConditionalGet (1.61s)1597=== CONT TestServerTLSConfig/no_client_CA1598=== CONT TestServerTLSConfig/not_a_PEM_file1599=== CONT TestServerTLSConfig/missing_CA_file1600--- PASS: TestServerTLSConfig (0.00s)1601 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1602 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1603 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1604=== CONT TestResolveDBConnectionString/flag_wins1605=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1606=== CONT TestResolveDBConnectionString/nothing_configured1607=== CONT TestResolveDBConnectionString/missing_file_is_an_error1608=== CONT TestResolveDBConnectionString/file_when_flag_empty1609=== CONT TestCacheConfigHandler/full_config,_no_issuer1610=== CONT TestCacheConfigHandler/no_signing_keys1611=== CONT TestCacheConfigHandler/no_cache_url_configured1612=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1613--- PASS: TestCacheConfigHandler (0.00s)1614 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1615 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1616 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1617 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1618=== CONT TestService_RequireScope_OIDC/builder_may_write16192026/08/27 11:04:34 INFO OIDC auth successful provider=test scopes=[write]1620=== CONT TestService_RequireScope_OIDC/static_token_may_admin1621=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1622=== CONT TestService_RequireScope_OIDC/writer_implies_read16232026/08/27 11:04:34 INFO OIDC auth successful provider=test scopes=[write]1624=== CONT TestService_RequireScope_OIDC/reader_may_read16252026/08/27 11:04:34 INFO OIDC auth successful provider=test scopes=[read]1626=== CONT TestService_RequireScope_OIDC/static_token_may_write1627=== CONT TestService_RequireScope_OIDC/ops_may_not_write16282026/08/27 11:04:34 INFO OIDC auth successful provider=test scopes=[admin]1629=== CONT TestService_RequireScope_OIDC/reader_may_not_write16302026/08/27 11:04:34 INFO OIDC auth successful provider=test scopes=[read]1631=== CONT TestService_RequireScope_OIDC/ops_may_admin16322026/08/27 11:04:34 INFO OIDC auth successful provider=test scopes=[admin]1633=== CONT TestService_RequireScope_OIDC/builder_may_not_admin16342026/08/27 11:04:34 INFO OIDC auth successful provider=test scopes=[write]1635=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16362026/08/27 11:04:34 INFO Received uploads request method=POST path=/1637--- PASS: TestResolveDBConnectionString (0.02s)1638 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1639 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1640 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1641 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1642 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1643--- PASS: TestService_RequireScope_OIDC (2.30s)1644 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1645 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1646 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1647 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1648 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1649 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1650 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1651 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1652 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1653 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)16542026-08-27 11:04:34.680 UTC [62516] ERROR: relation "goose_db_version" does not exist at character 3616552026-08-27 11:04:34.680 UTC [62516] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16562026/08/27 11:04:34 OK 20241026095416_initial_model.sql (140.91ms)16572026/08/27 11:04:34 OK 20251210153512_drop_unused_gin_index.sql (5.57ms)1658=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16592026/08/27 11:04:34 INFO Received request for more parts method=POST path=/16602026/08/27 11:04:34 OK 20251218171726_add_pins.sql (25.52ms)16612026/08/27 11:04:34 OK 20260628120000_add_object_size_and_stats.sql (10.07ms)16622026/08/27 11:04:34 goose: successfully migrated database to version: 2026062812000016632026-08-27 11:04:34.903 UTC [62517] ERROR: relation "goose_db_version" does not exist at character 3616642026-08-27 11:04:34.903 UTC [62517] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16652026/08/27 11:04:34 OK 1_commit_pending_closure.sql (7.26ms)16662026/08/27 11:04:34 OK 2_object_stats_trigger.sql (287.5µs)16672026/08/27 11:04:34 goose: up to current file version: 21668=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16692026/08/27 11:04:34 INFO Received complete multipart upload request method=POST path=/1670--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)1671 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)1672 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1673 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1674=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16752026/08/27 11:04:34 INFO Received uploads request method=POST path=/1676=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16772026/08/27 11:04:34 INFO Received complete multipart upload request method=POST path=/1678=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16792026/08/27 11:04:34 INFO Received request for more parts method=POST path=/1680=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16812026/08/27 11:04:34 INFO Received uploads request method=POST path=/1682--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1683 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1684 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1685 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1686 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1687=== CONT TestIsValidUploadKey/narinfo1688=== CONT TestIsValidUploadKey/realisation_plus_in_output1689=== CONT TestIsValidUploadKey/unknown_type1690=== CONT TestIsValidUploadKey/empty_key1691=== CONT TestIsValidUploadKey/absolute1692=== CONT TestIsValidUploadKey/traversal_nar1693=== CONT TestIsValidUploadKey/traversal1694=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1695=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1696=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1697=== CONT TestIsValidUploadKey/index.html1698=== CONT TestIsValidUploadKey/nix-cache-info1699=== CONT TestIsValidUploadKey/build_log_home-manager_file1700=== CONT TestIsValidUploadKey/realisation1701=== CONT TestIsValidUploadKey/build_log_equals1702=== CONT TestIsValidUploadKey/build_log_question_mark1703=== CONT TestIsValidUploadKey/build_log_plus_in_name1704=== CONT TestIsValidUploadKey/nar_plain1705=== CONT TestIsValidUploadKey/build_log1706=== CONT TestIsValidUploadKey/listing1707=== CONT TestIsValidUploadKey/nar_xz1708=== CONT TestIsValidUploadKey/nar_zst1709--- PASS: TestIsValidUploadKey (0.00s)1710 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1711 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1712 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1713 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1714 --- PASS: TestIsValidUploadKey/absolute (0.00s)1715 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1716 --- PASS: TestIsValidUploadKey/traversal (0.00s)1717 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1718 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1719 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1720 --- PASS: TestIsValidUploadKey/index.html (0.00s)1721 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1722 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1723 --- PASS: TestIsValidUploadKey/realisation (0.00s)1724 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1725 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1726 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1727 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1728 --- PASS: TestIsValidUploadKey/build_log (0.00s)1729 --- PASS: TestIsValidUploadKey/listing (0.00s)1730 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1731 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1732=== CONT TestProxyWriteTimeout/narinfo1733=== CONT TestProxyWriteTimeout/10_GiB_nar1734=== CONT TestProxyWriteTimeout/unknown_size1735=== CONT TestProxyWriteTimeout/1_GiB_nar1736--- PASS: TestProxyWriteTimeout (0.00s)1737 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1738 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1739 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1740 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1741=== CONT TestClientErrorHandling/InvalidStorePath1742--- PASS: TestReadProxyRangeRequest (1.91s)1743=== CONT TestClientErrorHandling/ServerNotAvailable17442026/08/27 11:04:35 OK 20241026095416_initial_model.sql (209.53ms)17452026/08/27 11:04:35 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)17462026/08/27 11:04:35 OK 20251218171726_add_pins.sql (98.89ms)17472026/08/27 11:04:35 OK 20260628120000_add_object_size_and_stats.sql (39.88ms)17482026/08/27 11:04:35 goose: successfully migrated database to version: 2026062812000017492026/08/27 11:04:35 OK 1_commit_pending_closure.sql (13.12ms)17502026/08/27 11:04:35 OK 2_object_stats_trigger.sql (371.17µs)17512026/08/27 11:04:35 goose: up to current file version: 217522026-08-27 11:04:35.434 UTC [62522] ERROR: relation "goose_db_version" does not exist at character 3617532026-08-27 11:04:35.434 UTC [62522] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17542026/08/27 11:04:35 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-config1755--- PASS: TestReadRedirectKeepsNarinfoProxied (2.08s)1756=== CONT TestClientErrorHandling/InvalidAuthToken17572026/08/27 11:04:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17582026/08/27 11:04:35 OK 20241026095416_initial_model.sql (96.19ms)17592026-08-27 11:04:35.598 UTC [62529] ERROR: relation "goose_db_version" does not exist at character 3617602026-08-27 11:04:35.598 UTC [62529] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17612026-08-27 11:04:35.599 UTC [62530] ERROR: relation "goose_db_version" does not exist at character 3617622026-08-27 11:04:35.599 UTC [62530] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17632026/08/27 11:04:35 OK 20251210153512_drop_unused_gin_index.sql (1.55ms)17642026/08/27 11:04:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.20953ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17652026/08/27 11:04:35 OK 20251218171726_add_pins.sql (43.76ms)17662026/08/27 11:04:35 OK 20260628120000_add_object_size_and_stats.sql (29.28ms)17672026/08/27 11:04:35 goose: successfully migrated database to version: 2026062812000017682026/08/27 11:04:35 OK 1_commit_pending_closure.sql (2.13ms)17692026/08/27 11:04:35 OK 2_object_stats_trigger.sql (608.79µs)17702026/08/27 11:04:35 goose: up to current file version: 217712026/08/27 11:04:35 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZTdkMmUzYzItZjEyZC00YWNjLTk2NDUtZDViNjA3NzRmYzRhLjJiOTUzZDcwLTMwZGQtNDllNS1iYTc1LTZmN2JkMjVhYmI0MngxNzg3ODI4Njc0MDc4MDc4MDAw parts=121772--- PASS: TestRedundantMultipartUpload (3.77s)1773=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token17742026/08/27 11:04:35 INFO OIDC auth successful provider=test scopes=[write]1775=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17762026/08/27 11:04:35 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]1777=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1778=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17792026/08/27 11:04:35 WARN Authentication failed token_preview=eyJhbGciOi...Ioh5_Pz7fQ token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1780=== CONT TestIsValidCachePath/narinfo1781=== CONT TestIsValidCachePath/index.html1782=== CONT TestIsValidCachePath/short_hash1783=== CONT TestIsValidCachePath/wrong_extension1784=== CONT TestIsValidCachePath/leading_slash1785=== CONT TestIsValidCachePath/empty1786=== CONT TestIsValidCachePath/random_path1787=== CONT TestIsValidCachePath/invalid_char_u1788=== CONT TestIsValidCachePath/invalid_char_e1789=== CONT TestIsValidCachePath/traversal_in_middle1790=== CONT TestIsValidCachePath/traversal_parent1791=== CONT TestIsValidCachePath/nar_uncompressed1792=== CONT TestIsValidCachePath/nix-cache-info1793=== CONT TestIsValidCachePath/realisation1794=== CONT TestIsValidCachePath/log1795=== CONT TestIsValidCachePath/ls1796=== CONT TestIsValidCachePath/nar_xz1797=== CONT TestIsValidCachePath/nar_bz21798=== CONT TestIsValidCachePath/nar_zst1799=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1800--- PASS: TestIsValidCachePath (0.00s)1801 --- PASS: TestIsValidCachePath/narinfo (0.00s)1802 --- PASS: TestIsValidCachePath/index.html (0.00s)1803 --- PASS: TestIsValidCachePath/short_hash (0.00s)1804 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1805 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1806 --- PASS: TestIsValidCachePath/empty (0.00s)1807 --- PASS: TestIsValidCachePath/random_path (0.00s)1808 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1809 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1810 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1811 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1812 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1813 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1814 --- PASS: TestIsValidCachePath/realisation (0.00s)1815 --- PASS: TestIsValidCachePath/log (0.00s)1816 --- PASS: TestIsValidCachePath/ls (0.00s)1817 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1818 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1819 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1820 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1821=== CONT TestParseSingleRange/none1822=== CONT TestParseSingleRange/open-ended1823=== CONT TestParseSingleRange/start_far_past_EOF1824=== CONT TestParseSingleRange/start_past_EOF1825=== CONT TestParseSingleRange/single_byte1826=== CONT TestParseSingleRange/suffix_exceeds_size1827=== CONT TestParseSingleRange/suffix1828=== CONT TestParseSingleRange/end_clamped_to_size1829=== CONT TestParseSingleRange/malformed_both_empty1830=== CONT TestParseSingleRange/closed1831=== CONT TestParseSingleRange/malformed_end_before_start1832=== CONT TestParseSingleRange/multi-range_ignored1833=== CONT TestParseSingleRange/malformed_no_dash1834=== CONT TestParseSingleRange/unknown_unit1835--- PASS: TestParseSingleRange (0.00s)1836 --- PASS: TestParseSingleRange/none (0.00s)1837 --- PASS: TestParseSingleRange/open-ended (0.00s)1838 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1839 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1840 --- PASS: TestParseSingleRange/single_byte (0.00s)1841 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1842 --- PASS: TestParseSingleRange/suffix (0.00s)1843 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1844 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1845 --- PASS: TestParseSingleRange/closed (0.00s)1846 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1847 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1848 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1849 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1850--- PASS: TestService_AuthMiddleware_OIDC (3.04s)1851 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1852 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1853 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1854 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)18552026/08/27 11:04:35 OK 20241026095416_initial_model.sql (83.88ms)18562026/08/27 11:04:35 OK 20251210153512_drop_unused_gin_index.sql (13.85ms)18572026/08/27 11:04:35 OK 20241026095416_initial_model.sql (115.44ms)18582026/08/27 11:04:35 OK 20251218171726_add_pins.sql (8.7ms)18592026/08/27 11:04:35 OK 20251210153512_drop_unused_gin_index.sql (4.04ms)18602026/08/27 11:04:35 OK 20260628120000_add_object_size_and_stats.sql (11.67ms)18612026/08/27 11:04:35 goose: successfully migrated database to version: 2026062812000018622026/08/27 11:04:35 OK 1_commit_pending_closure.sql (9.93ms)18632026/08/27 11:04:35 OK 2_object_stats_trigger.sql (371.38µs)18642026/08/27 11:04:35 goose: up to current file version: 218652026/08/27 11:04:35 OK 20251218171726_add_pins.sql (25.67ms)18662026/08/27 11:04:35 OK 20260628120000_add_object_size_and_stats.sql (44.06ms)18672026/08/27 11:04:35 goose: successfully migrated database to version: 2026062812000018682026/08/27 11:04:35 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=438.47842ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1869--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.19s)18702026/08/27 11:04:35 OK 1_commit_pending_closure.sql (8.59ms)18712026/08/27 11:04:35 OK 2_object_stats_trigger.sql (740.79µs)18722026/08/27 11:04:35 goose: up to current file version: 21873=== NAME TestOrphanedObjectsGCStressTest1874 orphaned_objects_gc_test.go:509: Stress test completed successfully:1875 orphaned_objects_gc_test.go:510: - Active objects preserved: 201876 orphaned_objects_gc_test.go:511: - Objects deleted: 2101877 orphaned_objects_gc_test.go:512: - Total GC'd: 2101878--- PASS: TestOrphanedObjectsGCStressTest (13.56s)1879--- PASS: TestReadProxyInvalidPath (2.16s)18802026-08-27 11:04:36.130 UTC [62531] ERROR: relation "goose_db_version" does not exist at character 3618812026-08-27 11:04:36.130 UTC [62531] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1882--- PASS: TestReadProxy404 (2.19s)18832026-08-27 11:04:36.146 UTC [62532] ERROR: relation "goose_db_version" does not exist at character 3618842026-08-27 11:04:36.146 UTC [62532] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18852026/08/27 11:04:36 OK 20241026095416_initial_model.sql (10.02ms)18862026/08/27 11:04:36 OK 20251210153512_drop_unused_gin_index.sql (772.54µs)18872026/08/27 11:04:36 OK 20251218171726_add_pins.sql (1.73ms)18882026/08/27 11:04:36 OK 20260628120000_add_object_size_and_stats.sql (10.11ms)18892026/08/27 11:04:36 goose: successfully migrated database to version: 2026062812000018902026/08/27 11:04:36 OK 1_commit_pending_closure.sql (1.78ms)18912026/08/27 11:04:36 OK 2_object_stats_trigger.sql (360.5µs)18922026/08/27 11:04:36 goose: up to current file version: 218932026/08/27 11:04:36 OK 20241026095416_initial_model.sql (16.17ms)18942026/08/27 11:04:36 OK 20251210153512_drop_unused_gin_index.sql (637.5µs)18952026/08/27 11:04:36 OK 20251218171726_add_pins.sql (42.12ms)18962026/08/27 11:04:36 OK 20260628120000_add_object_size_and_stats.sql (20.47ms)18972026/08/27 11:04:36 goose: successfully migrated database to version: 2026062812000018982026/08/27 11:04:36 OK 1_commit_pending_closure.sql (6.9ms)18992026/08/27 11:04:36 OK 2_object_stats_trigger.sql (707.17µs)19002026/08/27 11:04:36 goose: up to current file version: 219012026/08/27 11:04:36 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=795.524442ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19022026-08-27 11:04:36.312 UTC [62533] ERROR: relation "goose_db_version" does not exist at character 3619032026-08-27 11:04:36.312 UTC [62533] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1904--- PASS: TestReadProxyNarStreaming (2.02s)1905--- PASS: TestReadProxyNarinfo (1.92s)19062026/08/27 11:04:36 OK 20241026095416_initial_model.sql (104.99ms)19072026/08/27 11:04:36 OK 20251210153512_drop_unused_gin_index.sql (12.91ms)19082026/08/27 11:04:36 OK 20251218171726_add_pins.sql (17.5ms)19092026/08/27 11:04:36 OK 20260628120000_add_object_size_and_stats.sql (14.82ms)19102026/08/27 11:04:36 goose: successfully migrated database to version: 2026062812000019112026/08/27 11:04:36 OK 1_commit_pending_closure.sql (4.97ms)19122026/08/27 11:04:36 OK 2_object_stats_trigger.sql (1.03ms)19132026/08/27 11:04:36 goose: up to current file version: 219142026-08-27 11:04:36.644 UTC [62535] ERROR: relation "goose_db_version" does not exist at character 3619152026-08-27 11:04:36.644 UTC [62535] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19162026/08/27 11:04:36 OK 20241026095416_initial_model.sql (30.68ms)19172026/08/27 11:04:36 OK 20251210153512_drop_unused_gin_index.sql (7.99ms)19182026/08/27 11:04:36 OK 20251218171726_add_pins.sql (9.8ms)19192026/08/27 11:04:36 OK 20260628120000_add_object_size_and_stats.sql (5ms)19202026/08/27 11:04:36 goose: successfully migrated database to version: 2026062812000019212026/08/27 11:04:36 OK 1_commit_pending_closure.sql (1.04ms)19222026/08/27 11:04:36 OK 2_object_stats_trigger.sql (235.63µs)19232026/08/27 11:04:36 goose: up to current file version: 219242026/08/27 11:04:36 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19252026/08/27 11:04:36 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19262026/08/27 11:04:37 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.745653585s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19272026/08/27 11:04:38 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"19282026/08/27 11:04:38 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_closures19292026/08/27 11:04:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.563961ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19302026/08/27 11:04:39 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=383.39399ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19312026/08/27 11:04:39 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=869.382368ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19322026/08/27 11:04:40 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.618265698s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1933--- PASS: TestClientErrorHandling (0.00s)1934 --- PASS: TestClientErrorHandling/InvalidStorePath (1.77s)1935 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.40s)1936 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.96s)1937PASS1938{"timestamp":"2026-08-27T11:04:42.114515Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:55917","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1836,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}19392026-08-27 11:04:42.231 UTC [62163] LOG: received smart shutdown request19402026-08-27 11:04:42.231 UTC [62163] LOG: background worker "logical replication launcher" (PID 62174) exited with exit code 119412026-08-27 11:04:42.234 UTC [62168] LOG: shutting down19422026-08-27 11:04:42.234 UTC [62168] LOG: checkpoint starting: shutdown immediate19432026-08-27 11:04:43.305 UTC [62168] LOG: checkpoint complete: wrote 13345 buffers (81.5%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 14 recycled; write=0.783 s, sync=0.285 s, total=1.071 s; sync files=16812, longest=0.001 s, average=0.001 s; distance=235561 kB, estimate=235561 kB; lsn=0/FD955C0, redo lsn=0/FD955C019442026-08-27 11:04:43.309 UTC [62163] LOG: database system is shut down1945Running OIDC tests...1946=== RUN TestGlobMatch1947=== PAUSE TestGlobMatch1948=== RUN TestAudienceForIssuer1949=== PAUSE TestAudienceForIssuer1950=== RUN TestValidateToken_ValidToken1951=== PAUSE TestValidateToken_ValidToken1952=== RUN TestValidateToken_WrongAudience1953=== PAUSE TestValidateToken_WrongAudience1954=== RUN TestValidateToken_Expired1955=== PAUSE TestValidateToken_Expired1956=== RUN TestValidateToken_BoundClaimsMismatch1957=== PAUSE TestValidateToken_BoundClaimsMismatch1958=== RUN TestValidateToken_BoundSubjectMismatch1959=== PAUSE TestValidateToken_BoundSubjectMismatch1960=== RUN TestValidateToken_MultipleProviders1961=== PAUSE TestValidateToken_MultipleProviders1962=== RUN TestValidateToken_NoMatchingProvider1963=== PAUSE TestValidateToken_NoMatchingProvider1964=== RUN TestValidateToken_KubernetesServiceAccount1965=== PAUSE TestValidateToken_KubernetesServiceAccount1966=== RUN TestNewValidator_KubernetesRequiresCA1967=== PAUSE TestNewValidator_KubernetesRequiresCA1968=== RUN TestScopes_LegacyProviderDefaultsToWrite1969=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1970=== RUN TestScopes_Rules1971=== PAUSE TestScopes_Rules1972=== RUN TestScopes_ConfigValidation1973=== PAUSE TestScopes_ConfigValidation1974=== CONT TestGlobMatch1975=== RUN TestGlobMatch/foo_foo1976=== CONT TestValidateToken_MultipleProviders1977=== PAUSE TestGlobMatch/foo_foo1978=== CONT TestValidateToken_BoundSubjectMismatch1979=== CONT TestValidateToken_BoundClaimsMismatch1980=== CONT TestValidateToken_Expired1981=== CONT TestValidateToken_WrongAudience1982=== CONT TestValidateToken_ValidToken1983=== CONT TestAudienceForIssuer1984--- PASS: TestAudienceForIssuer (0.00s)1985=== CONT TestValidateToken_KubernetesServiceAccount1986=== CONT TestScopes_ConfigValidation1987=== CONT TestScopes_LegacyProviderDefaultsToWrite1988=== RUN TestGlobMatch/foo_bar1989=== PAUSE TestGlobMatch/foo_bar1990=== RUN TestGlobMatch/*_1991=== PAUSE TestGlobMatch/*_1992=== RUN TestGlobMatch/*_anything1993=== PAUSE TestGlobMatch/*_anything1994=== RUN TestGlobMatch/foo*_foo1995=== PAUSE TestGlobMatch/foo*_foo1996=== RUN TestGlobMatch/foo*_foobar1997=== PAUSE TestGlobMatch/foo*_foobar1998=== RUN TestGlobMatch/foo*_bar1999=== PAUSE TestGlobMatch/foo*_bar2000=== RUN TestGlobMatch/*bar_bar2001=== PAUSE TestGlobMatch/*bar_bar2002=== RUN TestGlobMatch/*bar_foobar2003=== PAUSE TestGlobMatch/*bar_foobar2004=== RUN TestGlobMatch/*bar_foo2005=== PAUSE TestGlobMatch/*bar_foo2006=== RUN TestGlobMatch/foo*bar_foobar2007=== PAUSE TestGlobMatch/foo*bar_foobar2008=== RUN TestGlobMatch/foo*bar_foo123bar2009=== PAUSE TestGlobMatch/foo*bar_foo123bar2010=== RUN TestGlobMatch/foo*bar_foobarbaz2011=== PAUSE TestGlobMatch/foo*bar_foobarbaz2012=== RUN TestGlobMatch/*/*_foo/bar2013=== PAUSE TestGlobMatch/*/*_foo/bar2014=== RUN TestGlobMatch/*/*_foo2015=== PAUSE TestGlobMatch/*/*_foo2016=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2017=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2018=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02019=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02020=== RUN TestGlobMatch/refs/*/main_refs/heads/main2021=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2022=== RUN TestGlobMatch/fo?_foo2023=== PAUSE TestGlobMatch/fo?_foo2024=== RUN TestGlobMatch/fo?_fo2025=== PAUSE TestGlobMatch/fo?_fo2026=== RUN TestGlobMatch/fo?_fooo2027=== PAUSE TestGlobMatch/fo?_fooo2028=== RUN TestGlobMatch/?oo_foo2029=== PAUSE TestGlobMatch/?oo_foo2030=== RUN TestGlobMatch/?oo_boo2031=== PAUSE TestGlobMatch/?oo_boo2032=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2033=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2034=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2035=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2036=== CONT TestNewValidator_KubernetesRequiresCA20372026/08/27 11:04:44 INFO OIDC provider initialized name=test20382026/08/27 11:04:44 INFO OIDC provider initialized name=test20392026/08/27 11:04:44 INFO OIDC provider initialized name=test20402026/08/27 11:04:44 INFO OIDC provider initialized name=test20412026/08/27 11:04:44 INFO OIDC provider initialized name=provider120422026/08/27 11:04:44 INFO OIDC provider initialized name=test2043--- PASS: TestScopes_ConfigValidation (0.00s)2044=== CONT TestScopes_Rules20452026/08/27 11:04:44 INFO OIDC provider initialized name=test20462026/08/27 11:04:44 INFO OIDC provider initialized name=test20472026/08/27 11:04:44 INFO OIDC provider initialized name=provider22048--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2049=== CONT TestValidateToken_NoMatchingProvider2050--- PASS: TestValidateToken_WrongAudience (0.01s)2051=== CONT TestGlobMatch/foo_foo2052=== CONT TestGlobMatch/*/*_foo/bar2053=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2054=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2055=== CONT TestGlobMatch/?oo_boo2056=== CONT TestGlobMatch/?oo_foo2057=== CONT TestGlobMatch/fo?_fooo2058=== CONT TestGlobMatch/fo?_fo2059=== CONT TestGlobMatch/fo?_foo2060=== CONT TestGlobMatch/refs/*/main_refs/heads/main2061=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02062=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2063=== CONT TestGlobMatch/*/*_foo2064=== CONT TestGlobMatch/*bar_bar2065=== CONT TestGlobMatch/foo*bar_foobarbaz2066=== CONT TestGlobMatch/foo*bar_foo123bar2067=== CONT TestGlobMatch/foo*bar_foobar2068=== CONT TestGlobMatch/*bar_foo2069=== CONT TestGlobMatch/*bar_foobar2070=== CONT TestGlobMatch/foo*_foo2071=== CONT TestGlobMatch/foo*_bar2072=== CONT TestGlobMatch/foo*_foobar2073=== CONT TestGlobMatch/*_2074=== CONT TestGlobMatch/*_anything2075=== CONT TestGlobMatch/foo_bar2076--- PASS: TestGlobMatch (0.00s)2077 --- PASS: TestGlobMatch/foo_foo (0.00s)2078 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2079 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2080 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2081 --- PASS: TestGlobMatch/?oo_boo (0.00s)2082 --- PASS: TestGlobMatch/?oo_foo (0.00s)2083 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2084 --- PASS: TestGlobMatch/fo?_fo (0.00s)2085 --- PASS: TestGlobMatch/fo?_foo (0.00s)2086 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2087 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2088 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2089 --- PASS: TestGlobMatch/*/*_foo (0.00s)2090 --- PASS: TestGlobMatch/*bar_bar (0.00s)2091 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2092 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2093 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2094 --- PASS: TestGlobMatch/*bar_foo (0.00s)2095 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2096 --- PASS: TestGlobMatch/foo*_foo (0.00s)2097 --- PASS: TestGlobMatch/foo*_bar (0.00s)2098 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2099 --- PASS: TestGlobMatch/*_ (0.00s)2100 --- PASS: TestGlobMatch/*_anything (0.00s)2101 --- PASS: TestGlobMatch/foo_bar (0.00s)2102--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2103--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2104--- PASS: TestValidateToken_Expired (0.01s)2105--- PASS: TestValidateToken_ValidToken (0.01s)21062026/08/27 11:04:44 INFO OIDC provider initialized name=provider12107--- PASS: TestValidateToken_MultipleProviders (0.01s)21082026/08/27 11:04:44 INFO OIDC provider initialized name=kubernetes2109--- PASS: TestValidateToken_NoMatchingProvider (0.00s)2110--- PASS: TestScopes_Rules (0.01s)2111--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)21122026/08/27 11:04:44 http: TLS handshake error from 127.0.0.1:56055: remote error: tls: bad certificate2113--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2114PASS2115Running hook tests...2116=== RUN TestSendPathsEmpty2117=== PAUSE TestSendPathsEmpty2118=== RUN TestQueueEnqueueAndFetch2119=== PAUSE TestQueueEnqueueAndFetch2120=== RUN TestQueueDeduplication2121=== PAUSE TestQueueDeduplication2122=== RUN TestQueueRemove2123=== PAUSE TestQueueRemove2124=== RUN TestQueueFetchBatchLimit2125=== PAUSE TestQueueFetchBatchLimit2126=== RUN TestQueueRetryMovesToBack2127=== PAUSE TestQueueRetryMovesToBack2128=== RUN TestQueueFetchRemoveLifecycle2129=== PAUSE TestQueueFetchRemoveLifecycle2130=== RUN TestQueueConcurrentWriters2131=== PAUSE TestQueueConcurrentWriters2132=== RUN TestQueueRemoveLargeClosure2133=== PAUSE TestQueueRemoveLargeClosure2134=== RUN TestServerClientIntegration2135=== PAUSE TestServerClientIntegration2136=== RUN TestServerQueueError2137=== PAUSE TestServerQueueError2138=== RUN TestGetListenerSocketActivation2139 server_test.go:210: === RUN TestGetListenerSocketActivation2140 --- PASS: TestGetListenerSocketActivation (0.00s)2141 PASS2142 2143--- PASS: TestGetListenerSocketActivation (0.01s)2144=== RUN TestDrainIsolatesPoisonPath2145=== PAUSE TestDrainIsolatesPoisonPath2146=== RUN TestRunNotBlockedByPoisonHead2147=== PAUSE TestRunNotBlockedByPoisonHead2148=== RUN TestDrainGivesUpWhenServerDown2149=== PAUSE TestDrainGivesUpWhenServerDown2150=== RUN TestFailedPathPrunedByLaterClosure2151=== PAUSE TestFailedPathPrunedByLaterClosure2152=== RUN TestWorkerUploadsAndRemoves2153=== PAUSE TestWorkerUploadsAndRemoves2154=== RUN TestWorkerSkipsGCdPaths2155=== PAUSE TestWorkerSkipsGCdPaths2156=== RUN TestWorkerPrunesClosureDeps2157=== PAUSE TestWorkerPrunesClosureDeps2158=== RUN TestDrainTimeout2159=== PAUSE TestDrainTimeout2160=== CONT TestSendPathsEmpty2161=== CONT TestServerQueueError2162--- PASS: TestSendPathsEmpty (0.00s)2163=== CONT TestQueueFetchBatchLimit2164=== CONT TestQueueRetryMovesToBack2165=== CONT TestQueueDeduplication2166=== CONT TestQueueRemoveLargeClosure2167=== CONT TestQueueEnqueueAndFetch2168=== CONT TestQueueFetchRemoveLifecycle2169=== CONT TestQueueRemove2170=== CONT TestWorkerUploadsAndRemoves2171=== CONT TestServerClientIntegration21722026/08/27 11:04:44 ERROR Failed to queue paths error="permission denied" count=12173--- PASS: TestServerQueueError (0.00s)2174=== CONT TestDrainTimeout2175--- PASS: TestServerClientIntegration (0.00s)2176=== CONT TestWorkerPrunesClosureDeps21772026/08/27 11:04:44 INFO Upload queue status pending=221782026/08/27 11:04:44 INFO Uploading batch count=12179--- PASS: TestQueueEnqueueAndFetch (0.01s)2180=== CONT TestWorkerSkipsGCdPaths2181--- PASS: TestQueueFetchBatchLimit (0.01s)2182=== CONT TestDrainGivesUpWhenServerDown2183--- PASS: TestQueueRemove (0.01s)2184=== CONT TestFailedPathPrunedByLaterClosure21852026/08/27 11:04:44 INFO Upload queue status pending=22186--- PASS: TestQueueDeduplication (0.01s)21872026/08/27 11:04:44 INFO Uploading batch count=22188=== CONT TestRunNotBlockedByPoisonHead21892026/08/27 11:04:44 INFO Uploading batch count=22190--- PASS: TestQueueRetryMovesToBack (0.01s)2191=== CONT TestDrainIsolatesPoisonPath2192--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2193=== CONT TestQueueConcurrentWriters21942026/08/27 11:04:44 INFO Upload queue status pending=221952026/08/27 11:04:44 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-62096-2608994286/TestWorkerSkipsGCdPaths1628357179/002/nonexistent21962026/08/27 11:04:44 INFO Uploading batch count=121972026/08/27 11:04:44 INFO Uploading batch count=121982026/08/27 11:04:44 ERROR Upload failed error="upload failed" count=121992026/08/27 11:04:44 INFO Uploading batch count=222002026/08/27 11:04:44 ERROR Upload failed error="upload failed" count=222012026/08/27 11:04:44 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62096-2608994286/TestDrainGivesUpWhenServerDown1676119814/002/a22022026/08/27 11:04:44 INFO Uploading batch count=122032026/08/27 11:04:44 INFO Upload queue status pending=322042026/08/27 11:04:44 INFO Uploading batch count=122052026/08/27 11:04:44 ERROR Upload failed error="upload failed" count=122062026/08/27 11:04:44 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62096-2608994286/TestDrainGivesUpWhenServerDown1676119814/002/b22072026/08/27 11:04:44 INFO Uploading batch count=122082026/08/27 11:04:44 INFO Uploading batch count=422092026/08/27 11:04:44 ERROR Upload failed error="upload failed" count=422102026/08/27 11:04:44 INFO Uploading batch count=222112026/08/27 11:04:44 ERROR Upload failed error="upload failed" count=222122026/08/27 11:04:44 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62096-2608994286/TestDrainGivesUpWhenServerDown1676119814/002/c22132026/08/27 11:04:44 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62096-2608994286/TestDrainIsolatesPoisonPath3939519735/002/bbb22142026/08/27 11:04:44 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62096-2608994286/TestDrainGivesUpWhenServerDown1676119814/002/d22152026/08/27 11:04:44 INFO Uploading batch count=222162026/08/27 11:04:44 ERROR Upload failed error="upload failed" count=222172026/08/27 11:04:44 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62096-2608994286/TestDrainGivesUpWhenServerDown1676119814/002/e22182026/08/27 11:04:44 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62096-2608994286/TestDrainGivesUpWhenServerDown1676119814/002/f22192026/08/27 11:04:44 ERROR Drain finished with paths left in queue remaining=1022202026/08/27 11:04:44 INFO Uploading batch count=122212026/08/27 11:04:44 ERROR Upload failed error="upload failed" count=122222026/08/27 11:04:44 INFO Uploading batch count=122232026/08/27 11:04:44 ERROR Upload failed error="upload failed" count=12224--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)22252026/08/27 11:04:44 INFO Uploading batch count=122262026/08/27 11:04:44 ERROR Upload failed error="upload failed" count=122272026/08/27 11:04:44 ERROR Drain finished with paths left in queue remaining=12228--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2229--- PASS: TestDrainIsolatesPoisonPath (0.01s)2230--- PASS: TestWorkerPrunesClosureDeps (0.03s)2231--- PASS: TestWorkerUploadsAndRemoves (0.03s)2232--- PASS: TestWorkerSkipsGCdPaths (0.02s)2233--- PASS: TestQueueRemoveLargeClosure (0.06s)2234--- PASS: TestQueueConcurrentWriters (0.12s)22352026/08/27 11:04:44 ERROR Upload failed error="context deadline exceeded" count=222362026/08/27 11:04:44 ERROR Drain finished with paths left in queue remaining=42237--- PASS: TestDrainTimeout (0.21s)22382026/08/27 11:04:45 INFO Uploading batch count=122392026/08/27 11:04:45 INFO Uploading batch count=122402026/08/27 11:04:45 INFO Uploading batch count=122412026/08/27 11:04:45 ERROR Upload failed error="upload failed" count=122422026/08/27 11:04:45 INFO Uploading batch count=122432026/08/27 11:04:45 ERROR Upload failed error="upload failed" count=122442026/08/27 11:04:45 INFO Uploading batch count=122452026/08/27 11:04:45 ERROR Upload failed error="upload failed" count=122462026/08/27 11:04:45 INFO Uploading batch count=122472026/08/27 11:04:45 ERROR Upload failed error="upload failed" count=122482026/08/27 11:04:45 ERROR Drain finished with paths left in queue remaining=12249--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2250PASS