niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #158
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestCaseHackSuffix6=== PAUSE TestCaseHackSuffix7=== RUN TestFilterOversizedClosures8=== PAUSE TestFilterOversizedClosures9=== RUN TestPartSizeForNAR10=== PAUSE TestPartSizeForNAR11=== RUN TestUploadMultipart_SupersededByPeer12=== PAUSE TestUploadMultipart_SupersededByPeer13=== RUN TestDumpPathMatchesNix14=== PAUSE TestDumpPathMatchesNix15=== RUN TestDumpPathSingleFile16=== PAUSE TestDumpPathSingleFile17=== RUN TestDumpPathWriterError18=== PAUSE TestDumpPathWriterError19=== RUN TestEncodeNixBase3220=== PAUSE TestEncodeNixBase3221=== RUN TestEncodeNixBase32WithRealHash22=== PAUSE TestEncodeNixBase32WithRealHash23=== RUN TestConvertHashToNix3224=== PAUSE TestConvertHashToNix3225=== RUN TestGetStorePathHash26=== PAUSE TestGetStorePathHash27=== RUN TestPathInfoHashCompatibility28=== PAUSE TestPathInfoHashCompatibility29=== RUN TestParsePathInfoJSON30=== PAUSE TestParsePathInfoJSON31=== RUN TestParsePathInfoJSONMultiplePaths32=== PAUSE TestParsePathInfoJSONMultiplePaths33=== RUN TestPathInfoCACompatibility34=== PAUSE TestPathInfoCACompatibility35=== RUN TestRateLimiterFeedback36=== PAUSE TestRateLimiterFeedback37=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess38=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess39=== RUN TestResolveStorePath40=== PAUSE TestResolveStorePath41=== RUN TestDoWithRetry_BodyReplayedViaGetBody42=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody43=== RUN TestShellSplit44=== PAUSE TestShellSplit45=== RUN TestShellSplitErrors46=== PAUSE TestShellSplitErrors47=== RUN TestSetClientTLS48=== PAUSE TestSetClientTLS49=== RUN TestSetClientTLSDoesNotMutateDefaultTransport50=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport51=== RUN TestSetClientTLSErrors52=== PAUSE TestSetClientTLSErrors53=== RUN TestStaticToken54=== PAUSE TestStaticToken55=== RUN TestFileTokenReadsAndCaches56=== PAUSE TestFileTokenReadsAndCaches57=== RUN TestFileTokenMissing58=== PAUSE TestFileTokenMissing59=== RUN TestFileTokenEmpty60=== PAUSE TestFileTokenEmpty61=== RUN TestScriptTokenNoExpiryRerunsEveryCall62=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall63=== RUN TestScriptTokenCachesUntilRefresh64=== PAUSE TestScriptTokenCachesUntilRefresh65=== RUN TestScriptTokenEmptyToken66=== PAUSE TestScriptTokenEmptyToken67=== RUN TestScriptTokenBadJSON68=== PAUSE TestScriptTokenBadJSON69=== RUN TestScriptTokenScriptFails70=== PAUSE TestScriptTokenScriptFails71=== RUN TestScriptTokenEmptyCommand72=== PAUSE TestScriptTokenEmptyCommand73=== CONT TestDoServerRequestAttachesToken74=== CONT TestFileTokenMissing75=== CONT TestPathInfoCACompatibility76=== RUN TestPathInfoCACompatibility/null_ca_field77=== CONT TestGetStorePathHash78=== CONT TestEncodeNixBase32WithRealHash79=== RUN TestGetStorePathHash/valid_store_path80=== CONT TestFileTokenReadsAndCaches81=== PAUSE TestGetStorePathHash/valid_store_path82--- PASS: TestEncodeNixBase32WithRealHash (0.00s)83=== PAUSE TestPathInfoCACompatibility/null_ca_field84=== CONT TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestGetStorePathHash/basename_without_hyphen_should_error86=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error87=== RUN TestPathInfoCACompatibility/old_string_format_-_text88=== CONT TestDumpPathWriterError89=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text90=== CONT TestSetClientTLSDoesNotMutateDefaultTransport91=== CONT TestSetClientTLS92=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error93=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error94=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error95=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error96=== CONT TestEncodeNixBase3297=== RUN TestEncodeNixBase32/test_string_hash98=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive99=== PAUSE TestEncodeNixBase32/test_string_hash100=== CONT TestShellSplit101=== CONT TestDoWithRetry_BodyReplayedViaGetBody102=== CONT TestConvertHashToNix32103=== RUN TestConvertHashToNix32/SRI_format_to_Nix32104=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32105=== RUN TestConvertHashToNix32/already_Nix32_format106=== PAUSE TestConvertHashToNix32/already_Nix32_format107=== CONT TestParsePathInfoJSONMultiplePaths108=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess109=== CONT TestRateLimiterFeedback110=== CONT TestParsePathInfoJSON111=== CONT TestPathInfoHashCompatibility112=== CONT TestScriptTokenEmptyCommand113=== CONT TestScriptTokenScriptFails114=== CONT TestScriptTokenBadJSON115=== CONT TestScriptTokenEmptyToken116=== CONT TestScriptTokenCachesUntilRefresh117=== CONT TestResolveStorePath118--- PASS: TestFileTokenMissing (0.00s)119--- PASS: TestFileTokenReadsAndCaches (0.00s)120--- PASS: TestShellSplit (0.00s)121=== CONT TestFileTokenEmpty122=== RUN TestRateLimiterFeedback/429_enables_limiter123=== CONT TestSetClientTLSErrors124=== CONT TestStaticToken125=== CONT TestShellSplitErrors126=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive127=== RUN TestEncodeNixBase32/empty_input128=== RUN TestConvertHashToNix32/invalid_format129--- PASS: TestShellSplitErrors (0.00s)130=== CONT TestDumpPathSingleFile131--- PASS: TestScriptTokenScriptFails (0.00s)1322026/08/27 11:06:09 WARN Rate limiter enabled after throttle name=server-test rate=5133=== CONT TestPartSizeForNAR1342026/08/27 11:06:09 WARN Rate limiter enabled after throttle name=server-test rate=5135--- PASS: TestScriptTokenEmptyCommand (0.00s)136=== RUN TestPathInfoCACompatibility/new_structured_format_-_text137=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text1382026/08/27 11:06:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:38727139=== CONT TestUploadMultipart_SupersededByPeer140=== PAUSE TestEncodeNixBase32/empty_input141=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method142=== CONT TestFilterOversizedClosures143=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method144=== RUN TestParsePathInfoJSON/Nix_format145=== RUN TestFilterOversizedClosures/no_limit_keeps_everything146--- PASS: TestDoServerRequestAttachesToken (0.01s)147--- PASS: TestScriptTokenBadJSON (0.01s)148=== CONT TestDumpPathMatchesNix149--- PASS: TestResolveStorePath (0.01s)150=== PAUSE TestConvertHashToNix32/invalid_format151=== PAUSE TestRateLimiterFeedback/429_enables_limiter152--- PASS: TestStaticToken (0.00s)153=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths154--- PASS: TestFileTokenEmpty (0.01s)155=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error156=== CONT TestGetStorePathHash/basename_without_hyphen_should_error1572026/08/27 11:06:09 WARN Rate limiter backed off name=server-test rate=51582026/08/27 11:06:09 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:38727159=== CONT TestEncodeNixBase32/test_string_hash160=== CONT TestConvertHashToNix32/already_Nix32_format161=== PAUSE TestParsePathInfoJSON/Nix_format162=== RUN TestRateLimiterFeedback/503_enables_limiter163=== RUN TestParsePathInfoJSON/Lix_format164=== CONT TestCaseHackSuffix165=== CONT TestGetStorePathHash/valid_store_path166=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)167=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error168=== RUN TestSetClientTLSErrors/missing_cert_file169=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything170=== CONT TestEncodeNixBase32/empty_input171=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths172=== RUN TestPartSizeForNAR/zero_stays_at_minimum173--- PASS: TestScriptTokenEmptyToken (0.01s)174=== CONT TestConvertHashToNix32/SRI_format_to_Nix32175=== RUN TestSetClientTLS/rejects_connection_without_client_cert176=== RUN TestUploadMultipart_SupersededByPeer/exists177=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths178=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum179=== CONT TestConvertHashToNix32/invalid_format180=== PAUSE TestUploadMultipart_SupersededByPeer/exists181=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths182=== CONT TestPathInfoCACompatibility/null_ca_field183=== PAUSE TestRateLimiterFeedback/503_enables_limiter184=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter185=== PAUSE TestParsePathInfoJSON/Lix_format186=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive187=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)188=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method189=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped190=== PAUSE TestSetClientTLSErrors/missing_cert_file191=== CONT TestPathInfoCACompatibility/new_structured_format_-_text192--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)193=== CONT TestPathInfoCACompatibility/old_string_format_-_text194=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert195=== RUN TestPartSizeForNAR/small_stays_at_minimum196=== RUN TestUploadMultipart_SupersededByPeer/missing197=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths198=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths199--- PASS: TestEncodeNixBase32 (0.01s)200 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)201 --- PASS: TestEncodeNixBase32/empty_input (0.00s)202--- PASS: TestGetStorePathHash (0.00s)203 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)204 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)205 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)206 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)207=== PAUSE TestPartSizeForNAR/small_stays_at_minimum208--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)209=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped210=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter211=== RUN TestParsePathInfoJSON/empty_input212=== RUN TestSetClientTLSErrors/missing_key_file213=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA214=== PAUSE TestUploadMultipart_SupersededByPeer/missing215--- PASS: TestConvertHashToNix32 (0.01s)216 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)217 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)218 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)219=== CONT TestUploadMultipart_SupersededByPeer/missing220--- PASS: TestPathInfoCACompatibility (0.01s)221 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)222 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)223 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)224 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)225 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)226=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon227=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon228=== RUN TestFilterOversizedClosures/all_closures_skipped229=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum230=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter231=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI232--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)233 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)234 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)235=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI236=== PAUSE TestFilterOversizedClosures/all_closures_skipped237=== CONT TestFilterOversizedClosures/no_limit_keeps_everything238=== PAUSE TestParsePathInfoJSON/empty_input239=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum240--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)241=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts242=== PAUSE TestSetClientTLSErrors/missing_key_file243=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA244=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter245=== RUN TestParsePathInfoJSON/whitespace_only246=== RUN TestSetClientTLS/preserves_debug_logging_transport247--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)248=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped249=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts250=== RUN TestPartSizeForNAR/1_TiB251=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha5122522026/08/27 11:06:09 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=2000253=== CONT TestUploadMultipart_SupersededByPeer/exists254=== RUN TestSetClientTLSErrors/missing_ca_file255=== PAUSE TestSetClientTLS/preserves_debug_logging_transport256=== CONT TestSetClientTLS/rejects_connection_without_client_cert257=== CONT TestSetClientTLS/preserves_debug_logging_transport258=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA259=== PAUSE TestPartSizeForNAR/1_TiB260=== PAUSE TestSetClientTLSErrors/missing_ca_file261=== RUN TestSetClientTLSErrors/invalid_ca_file262=== CONT TestFilterOversizedClosures/all_closures_skipped263=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512264=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)265=== CONT TestRateLimiterFeedback/429_enables_limiter266=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon2672026/08/27 11:06:09 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=50268=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter269=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI270=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter271=== CONT TestRateLimiterFeedback/503_enables_limiter272=== PAUSE TestParsePathInfoJSON/whitespace_only273=== RUN TestPartSizeForNAR/5_TiB_S3_max_object274=== PAUSE TestSetClientTLSErrors/invalid_ca_file2752026/08/27 11:06:09 WARN Rate limiter enabled after throttle name=server-test rate=5276=== CONT TestSetClientTLSErrors/missing_cert_file2772026/08/27 11:06:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:39781278=== CONT TestSetClientTLSErrors/invalid_ca_file279--- PASS: TestFilterOversizedClosures (0.01s)280 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)281 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)282 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)283=== RUN TestParsePathInfoJSON/invalid_JSON2842026/08/27 11:06:09 WARN Rate limiter backed off name=server-test rate=5285--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)286 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)287 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)288=== PAUSE TestParsePathInfoJSON/invalid_JSON2892026/08/27 11:06:09 WARN Rate limiter enabled after throttle name=server-test rate=5290=== CONT TestParsePathInfoJSON/Nix_format2912026/08/27 11:06:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:40927292=== CONT TestParsePathInfoJSON/empty_input293=== CONT TestParsePathInfoJSON/whitespace_only294=== CONT TestSetClientTLSErrors/missing_key_file295=== CONT TestSetClientTLSErrors/missing_ca_file296=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object2972026/08/27 11:06:09 WARN Rate limiter backed off name=server-test rate=5298=== RUN TestPartSizeForNAR/capped_at_5_GiB299=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512300=== CONT TestParsePathInfoJSON/invalid_JSON301=== PAUSE TestPartSizeForNAR/capped_at_5_GiB302=== CONT TestParsePathInfoJSON/Lix_format303--- PASS: TestPathInfoHashCompatibility (0.01s)304 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)305 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)306 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)307 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)308=== CONT TestPartSizeForNAR/zero_stays_at_minimum309=== CONT TestPartSizeForNAR/capped_at_5_GiB310=== CONT TestPartSizeForNAR/5_TiB_S3_max_object311=== CONT TestPartSizeForNAR/1_TiB312=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts313=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum314=== CONT TestPartSizeForNAR/small_stays_at_minimum315--- PASS: TestRateLimiterFeedback (0.01s)316 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)317 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)318 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)319 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)320--- PASS: TestParsePathInfoJSON (0.01s)321 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)322 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)323 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)324 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)325 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)326--- PASS: TestPartSizeForNAR (0.01s)327 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)328 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)329 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)330 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)331 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)332 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)333 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)334--- PASS: TestSetClientTLSErrors (0.02s)335 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)336 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)337 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)338 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)3392026/08/27 11:06:09 http: TLS handshake error from 127.0.0.1:57370: remote error: tls: bad certificate340--- PASS: TestSetClientTLS (0.02s)341 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)342 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)343 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)344--- PASS: TestDumpPathWriterError (0.03s)345--- PASS: TestDumpPathSingleFile (0.03s)346--- PASS: TestCaseHackSuffix (0.04s)347--- PASS: TestDumpPathMatchesNix (0.08s)348--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)349PASS350Running server tests...351The files belonging to this database system will be owned by user "nixbld".352This user must also own the server process.353354The database cluster will be initialized with locale "C".355The default database encoding has accordingly been set to "SQL_ASCII".356The default text search configuration will be set to "english".357358Data page checksums are enabled.359360creating directory /build/postgres4252112817/data ... ok361creating subdirectories ... ok362selecting dynamic shared memory implementation ... posix363selecting default "max_connections" ... 100364selecting default "shared_buffers" ... 128MB365selecting default time zone ... UTC366creating configuration files ... ok367running bootstrap script ... ok368performing post-bootstrap initialization ... ok369syncing data to disk ... ok370371initdb: warning: enabling "trust" authentication for local connections372initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.373374Success. You can now start the database server using:375376 pg_ctl -D /build/postgres4252112817/data -l logfile start377378/build/postgres4252112817:5432 - no response3792026-08-27 11:06:11.072 UTC [112] LOG: starting PostgreSQL 18.4 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit3802026-08-27 11:06:11.073 UTC [112] LOG: listening on Unix socket "/build/postgres4252112817/.s.PGSQL.5432"3812026-08-27 11:06:11.077 UTC [119] LOG: database system was shut down at 2026-08-27 11:06:10 UTC3822026-08-27 11:06:11.081 UTC [112] LOG: database system is ready to accept connections383/build/postgres4252112817: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:06:11.563 UTC [906] ERROR: relation "goose_db_version" does not exist at character 364182026-08-27 11:06:11.563 UTC [906] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4192026/08/27 11:06:11 OK 20241026095416_initial_model.sql (7.86ms)4202026/08/27 11:06:11 OK 20251210153512_drop_unused_gin_index.sql (1.71ms)4212026/08/27 11:06:11 OK 20251218171726_add_pins.sql (2.05ms)4222026/08/27 11:06:11 OK 20260628120000_add_object_size_and_stats.sql (1.75ms)4232026/08/27 11:06:11 goose: successfully migrated database to version: 202606281200004242026/08/27 11:06:11 OK 1_commit_pending_closure.sql (1.52ms)4252026/08/27 11:06:11 OK 2_object_stats_trigger.sql (714.44µs)4262026/08/27 11:06:11 goose: up to current file version: 2427--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.13s)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:06:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5262026/08/27 11:06:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5272026/08/27 11:06:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5282026/08/27 11:06:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5292026/08/27 11:06:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5302026/08/27 11:06:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5312026/08/27 11:06:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5322026/08/27 11:06:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5332026/08/27 11:06:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5342026/08/27 11:06:11 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 TestService_AuthMiddleware557=== CONT TestOrphanedObjectsGC558=== CONT TestService_readinessHandler559=== CONT TestGCTaskStore_DeduplicateSameParams560--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)561=== CONT TestUploadHandlersRejectInvalidKeys562=== CONT TestMultipartCleanup563=== CONT TestServerTLSConfig564=== CONT TestService_NativeMTLS565=== CONT TestMetricsInventory566=== CONT TestNARDeduplicationMetadataUploadBug567=== CONT TestCreatePendingClosureRejectsOversizedNAR568=== CONT TestCacheConfigHandlerMaxNarSize569=== CONT TestGenerateLandingPage5702026/08/27 11:06:11 INFO Received uploads request method=POST path=/api/pending_closures571--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)572=== CONT TestIsValidUploadKey573--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)574=== RUN TestIsValidUploadKey/narinfo575=== CONT TestGCTaskStore_PhaseUpdates576--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)577=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle578=== CONT TestGracefulShutdownDrainsInflight579=== CONT TestGCTaskStore_Fail580--- PASS: TestGCTaskStore_Fail (0.00s)581=== CONT TestRedundantMultipartUpload582=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT583=== CONT TestCompleteMultipartUnregistered584=== CONT TestService_verifyS3Integrity585=== CONT TestService_createPendingClosureHandler586=== CONT TestService_cleanupPendingClosuresHandler5872026/08/27 11:06:11 INFO Starting HTTP server address=127.0.0.1:43477588=== CONT TestUploadHandlersRejectOversizedBody589=== CONT TestObjectStatsTrigger590=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info591=== RUN TestServerTLSConfig/no_client_CA592=== CONT TestProxyWriteTimeout593=== PAUSE TestIsValidUploadKey/narinfo594=== CONT TestService_healthCheckHandler595=== CONT TestSkippedUploadsHandler5962026/08/27 11:06:11 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000597=== RUN TestProxyWriteTimeout/narinfo5982026/08/27 11:06:11 INFO Shutdown signal received, draining in-flight requests timeout=10s599=== PAUSE TestProxyWriteTimeout/narinfo600=== RUN TestProxyWriteTimeout/1_GiB_nar601=== PAUSE TestProxyWriteTimeout/1_GiB_nar602=== RUN TestIsValidUploadKey/nar_zst603=== RUN TestProxyWriteTimeout/10_GiB_nar604=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info605=== PAUSE TestProxyWriteTimeout/10_GiB_nar606=== PAUSE TestIsValidUploadKey/nar_zst607=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal608=== RUN TestProxyWriteTimeout/unknown_size609=== PAUSE TestProxyWriteTimeout/unknown_size610=== RUN TestIsValidUploadKey/nar_xz611=== PAUSE TestIsValidUploadKey/nar_xz612=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal613=== CONT TestParseSize614=== RUN TestIsValidUploadKey/nar_plain615=== PAUSE TestIsValidUploadKey/nar_plain616--- PASS: TestGenerateLandingPage (0.01s)617--- PASS: TestParseSize (0.00s)618=== CONT TestService_Rustfstest619=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key620=== CONT TestPresignedUploadRegisteredBeforeCommit621=== RUN TestIsValidUploadKey/listing622=== PAUSE TestIsValidUploadKey/listing623=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key624=== RUN TestIsValidUploadKey/build_log625=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key626=== PAUSE TestServerTLSConfig/no_client_CA627=== PAUSE TestIsValidUploadKey/build_log628=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key629=== RUN TestServerTLSConfig/missing_CA_file630=== RUN TestIsValidUploadKey/build_log_home-manager_file631=== PAUSE TestIsValidUploadKey/build_log_home-manager_file632=== CONT TestCompletedNarNotReofferedAcrossClosures633=== PAUSE TestServerTLSConfig/missing_CA_file634=== RUN TestIsValidUploadKey/build_log_plus_in_name635=== PAUSE TestIsValidUploadKey/build_log_plus_in_name636=== RUN TestServerTLSConfig/not_a_PEM_file637=== PAUSE TestServerTLSConfig/not_a_PEM_file638--- PASS: TestSkippedUploadsHandler (0.08s)639=== CONT TestCompleteMultipartUpload_ErrorButObjectExists640=== CONT TestGCTaskStore_GetReturnsLatest641--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)642=== CONT TestGCTaskStore_CompletedAllowsNewTask643--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)644=== RUN TestIsValidUploadKey/build_log_question_mark645=== PAUSE TestIsValidUploadKey/build_log_question_mark646=== CONT TestClientErrorHandling647=== RUN TestClientErrorHandling/InvalidStorePath648=== RUN TestIsValidUploadKey/build_log_equals649=== PAUSE TestIsValidUploadKey/build_log_equals650=== RUN TestIsValidUploadKey/realisation651=== PAUSE TestIsValidUploadKey/realisation652=== RUN TestIsValidUploadKey/realisation_plus_in_output653=== PAUSE TestIsValidUploadKey/realisation_plus_in_output654=== RUN TestIsValidUploadKey/nix-cache-info655=== PAUSE TestIsValidUploadKey/nix-cache-info656=== PAUSE TestClientErrorHandling/InvalidStorePath657=== RUN TestClientErrorHandling/InvalidAuthToken658=== PAUSE TestClientErrorHandling/InvalidAuthToken659=== RUN TestClientErrorHandling/ServerNotAvailable660=== PAUSE TestClientErrorHandling/ServerNotAvailable661=== RUN TestIsValidUploadKey/index.html662=== PAUSE TestIsValidUploadKey/index.html663=== CONT TestGCTaskStore_StartNew664--- PASS: TestGCTaskStore_StartNew (0.00s)665=== RUN TestIsValidUploadKey/narinfo_key,_nar_type666=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type667=== RUN TestIsValidUploadKey/nar_key,_narinfo_type668=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type669=== RUN TestIsValidUploadKey/listing_key,_narinfo_type670=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type671=== RUN TestIsValidUploadKey/traversal672=== PAUSE TestIsValidUploadKey/traversal673=== RUN TestIsValidUploadKey/traversal_nar674=== PAUSE TestIsValidUploadKey/traversal_nar675=== RUN TestIsValidUploadKey/absolute676=== PAUSE TestIsValidUploadKey/absolute677=== RUN TestIsValidUploadKey/empty_key678=== PAUSE TestIsValidUploadKey/empty_key679=== RUN TestIsValidUploadKey/unknown_type680=== PAUSE TestIsValidUploadKey/unknown_type681=== CONT TestGCMetrics682=== CONT TestGCBugBareHashReferences6832026-08-27 11:06:11.968 UTC [987] ERROR: relation "goose_db_version" does not exist at character 366842026-08-27 11:06:11.968 UTC [987] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6852026-08-27 11:06:11.969 UTC [988] ERROR: relation "goose_db_version" does not exist at character 366862026-08-27 11:06:11.969 UTC [988] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6872026-08-27 11:06:11.969 UTC [986] ERROR: relation "goose_db_version" does not exist at character 366882026-08-27 11:06:11.969 UTC [986] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6892026-08-27 11:06:11.969 UTC [989] ERROR: relation "goose_db_version" does not exist at character 366902026-08-27 11:06:11.969 UTC [989] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC691--- PASS: TestGracefulShutdownDrainsInflight (0.14s)692=== CONT TestResolveDBConnectionString693=== RUN TestResolveDBConnectionString/flag_wins694=== PAUSE TestResolveDBConnectionString/flag_wins695=== RUN TestResolveDBConnectionString/file_when_flag_empty696=== PAUSE TestResolveDBConnectionString/file_when_flag_empty697=== RUN TestResolveDBConnectionString/missing_file_is_an_error698=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error699=== RUN TestResolveDBConnectionString/PGHOST_allows_empty700=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty701=== RUN TestResolveDBConnectionString/nothing_configured702=== PAUSE TestResolveDBConnectionString/nothing_configured703=== CONT TestPinProtectsFromGC7042026-08-27 11:06:12.008 UTC [992] ERROR: relation "goose_db_version" does not exist at character 367052026-08-27 11:06:12.008 UTC [992] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC706=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure707=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure708=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart709=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart710=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts711=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts712=== CONT TestClientWithDependencies7132026/08/27 11:06:12 OK 20241026095416_initial_model.sql (94.83ms)7142026/08/27 11:06:12 OK 20241026095416_initial_model.sql (96.87ms)7152026/08/27 11:06:12 OK 20241026095416_initial_model.sql (86.11ms)7162026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (7.73ms)7172026-08-27 11:06:12.123 UTC [995] ERROR: relation "goose_db_version" does not exist at character 367182026-08-27 11:06:12.123 UTC [995] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7192026/08/27 11:06:12 OK 20241026095416_initial_model.sql (118.01ms)7202026/08/27 11:06:12 OK 20241026095416_initial_model.sql (118.07ms)7212026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (19.73ms)7222026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (18.38ms)7232026/08/27 11:06:12 OK 20251218171726_add_pins.sql (22.99ms)7242026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (8.48ms)7252026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (8.73ms)7262026/08/27 11:06:12 OK 20251218171726_add_pins.sql (17.95ms)7272026/08/27 11:06:12 OK 20251218171726_add_pins.sql (9.68ms)7282026/08/27 11:06:12 OK 20251218171726_add_pins.sql (17.86ms)7292026/08/27 11:06:12 OK 20251218171726_add_pins.sql (12.44ms)7302026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (14.01ms)7312026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200007322026/08/27 11:06:12 OK 1_commit_pending_closure.sql (8.07ms)7332026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (14.78ms)7342026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200007352026/08/27 11:06:12 OK 2_object_stats_trigger.sql (6.41ms)7362026/08/27 11:06:12 goose: up to current file version: 27372026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (33.12ms)7382026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200007392026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (33.26ms)7402026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200007412026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (30.55ms)7422026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200007432026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures7442026/08/27 11:06:12 OK 1_commit_pending_closure.sql (22.11ms)7452026/08/27 11:06:12 OK 20241026095416_initial_model.sql (40.26ms)7462026/08/27 11:06:12 OK 1_commit_pending_closure.sql (6.95ms)7472026/08/27 11:06:12 OK 2_object_stats_trigger.sql (5.12ms)7482026/08/27 11:06:12 goose: up to current file version: 27492026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (5.04ms)7502026/08/27 11:06:12 OK 1_commit_pending_closure.sql (8.74ms)7512026/08/27 11:06:12 OK 1_commit_pending_closure.sql (9.46ms)7522026/08/27 11:06:12 OK 2_object_stats_trigger.sql (3.57ms)7532026/08/27 11:06:12 goose: up to current file version: 27542026-08-27 11:06:12.195 UTC [996] ERROR: relation "goose_db_version" does not exist at character 367552026-08-27 11:06:12.195 UTC [996] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7562026-08-27 11:06:12.198 UTC [997] ERROR: relation "goose_db_version" does not exist at character 367572026-08-27 11:06:12.198 UTC [997] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7582026/08/27 11:06:12 OK 2_object_stats_trigger.sql (4.2ms)7592026/08/27 11:06:12 goose: up to current file version: 27602026/08/27 11:06:12 OK 2_object_stats_trigger.sql (5.91ms)7612026/08/27 11:06:12 goose: up to current file version: 27622026-08-27 11:06:12.202 UTC [998] ERROR: relation "goose_db_version" does not exist at character 367632026-08-27 11:06:12.202 UTC [998] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7642026/08/27 11:06:12 OK 20251218171726_add_pins.sql (8.02ms)7652026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (8.44ms)7662026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200007672026/08/27 11:06:12 OK 1_commit_pending_closure.sql (3.96ms)7682026-08-27 11:06:12.215 UTC [999] ERROR: relation "goose_db_version" does not exist at character 367692026-08-27 11:06:12.215 UTC [999] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7702026/08/27 11:06:12 OK 2_object_stats_trigger.sql (2.13ms)7712026/08/27 11:06:12 goose: up to current file version: 27722026-08-27 11:06:12.218 UTC [1000] ERROR: relation "goose_db_version" does not exist at character 367732026-08-27 11:06:12.218 UTC [1000] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7742026-08-27 11:06:12.219 UTC [1001] ERROR: relation "goose_db_version" does not exist at character 367752026-08-27 11:06:12.219 UTC [1001] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7762026-08-27 11:06:12.223 UTC [1002] ERROR: relation "goose_db_version" does not exist at character 367772026-08-27 11:06:12.223 UTC [1002] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7782026-08-27 11:06:12.224 UTC [1003] ERROR: relation "goose_db_version" does not exist at character 367792026-08-27 11:06:12.224 UTC [1003] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7802026/08/27 11:06:12 OK 20241026095416_initial_model.sql (12.72ms)7812026/08/27 11:06:12 WARN readiness check failed error="closed pool"782--- PASS: TestService_readinessHandler (0.39s)783=== CONT TestClientMultipleUploads7842026-08-27 11:06:12.227 UTC [1005] ERROR: relation "goose_db_version" does not exist at character 367852026-08-27 11:06:12.227 UTC [1005] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7862026/08/27 11:06:12 OK 20241026095416_initial_model.sql (23.55ms)7872026/08/27 11:06:12 OK 20241026095416_initial_model.sql (24.86ms)7882026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (14.17ms)7892026/08/27 11:06:12 OK 20241026095416_initial_model.sql (13.83ms)7902026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (3.46ms)7912026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (3.74ms)7922026/08/27 11:06:12 OK 20251218171726_add_pins.sql (4.62ms)7932026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (3.03ms)7942026/08/27 11:06:12 OK 20251218171726_add_pins.sql (4.25ms)7952026-08-27 11:06:12.248 UTC [1009] ERROR: relation "goose_db_version" does not exist at character 367962026-08-27 11:06:12.248 UTC [1009] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7972026/08/27 11:06:12 OK 20251218171726_add_pins.sql (5.43ms)7982026/08/27 11:06:12 OK 20251218171726_add_pins.sql (4.44ms)7992026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (5.53ms)8002026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200008012026-08-27 11:06:12.252 UTC [1025] ERROR: relation "goose_db_version" does not exist at character 368022026-08-27 11:06:12.252 UTC [1025] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8032026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.88ms)8042026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200008052026-08-27 11:06:12.253 UTC [1027] ERROR: relation "goose_db_version" does not exist at character 368062026-08-27 11:06:12.253 UTC [1027] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8072026-08-27 11:06:12.253 UTC [1028] ERROR: relation "goose_db_version" does not exist at character 368082026-08-27 11:06:12.253 UTC [1028] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8092026/08/27 11:06:12 OK 1_commit_pending_closure.sql (3.66ms)8102026-08-27 11:06:12.253 UTC [1026] ERROR: relation "goose_db_version" does not exist at character 368112026-08-27 11:06:12.253 UTC [1026] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8122026/08/27 11:06:12 OK 20241026095416_initial_model.sql (11.37ms)8132026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (5.05ms)8142026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200008152026-08-27 11:06:12.254 UTC [1031] ERROR: relation "goose_db_version" does not exist at character 368162026-08-27 11:06:12.254 UTC [1031] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8172026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (5.02ms)8182026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200008192026/08/27 11:06:12 OK 20241026095416_initial_model.sql (11.84ms)8202026/08/27 11:06:12 OK 20241026095416_initial_model.sql (11.88ms)8212026/08/27 11:06:12 OK 20241026095416_initial_model.sql (11.96ms)8222026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.84ms)8232026/08/27 11:06:12 goose: up to current file version: 28242026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.79ms)8252026-08-27 11:06:12.255 UTC [1030] ERROR: relation "goose_db_version" does not exist at character 368262026-08-27 11:06:12.255 UTC [1030] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8272026-08-27 11:06:12.255 UTC [1029] ERROR: relation "goose_db_version" does not exist at character 368282026-08-27 11:06:12.255 UTC [1029] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8292026/08/27 11:06:12 OK 20241026095416_initial_model.sql (13.43ms)8302026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.59ms)8312026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)8322026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.64ms)8332026/08/27 11:06:12 goose: up to current file version: 28342026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)8352026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)8362026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (1.6ms)8372026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.6ms)8382026/08/27 11:06:12 OK 1_commit_pending_closure.sql (3.04ms)8392026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.28ms)8402026/08/27 11:06:12 goose: up to current file version: 2841=== NAME TestNARDeduplicationMetadataUploadBug8422026/08/27 11:06:12 OK 2_object_stats_trigger.sql (3.26ms)843 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1861124756/001/store/h1zcrb6jdlznd9fpdfg8ahjnw3jjcjqn-file1.txt8442026/08/27 11:06:12 goose: up to current file version: 28452026/08/27 11:06:12 OK 20251218171726_add_pins.sql (4.59ms)8462026/08/27 11:06:12 OK 20251218171726_add_pins.sql (4.79ms)8472026/08/27 11:06:12 OK 20251218171726_add_pins.sql (5.06ms)8482026/08/27 11:06:12 OK 20251218171726_add_pins.sql (4.87ms)8492026/08/27 11:06:12 OK 20251218171726_add_pins.sql (4.97ms)8502026-08-27 11:06:12.266 UTC [1032] ERROR: relation "goose_db_version" does not exist at character 368512026-08-27 11:06:12.266 UTC [1032] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8522026/08/27 11:06:12 OK 20241026095416_initial_model.sql (10.86ms)8532026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (5.7ms)8542026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200008552026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)8562026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200008572026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.83ms)8582026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200008592026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.79ms)8602026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200008612026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.73ms)8622026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200008632026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (1.44ms)8642026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.49ms)8652026/08/27 11:06:12 OK 1_commit_pending_closure.sql (3.1ms)8662026/08/27 11:06:12 OK 20241026095416_initial_model.sql (10.58ms)8672026/08/27 11:06:12 OK 1_commit_pending_closure.sql (3.34ms)8682026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.94ms)8692026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.81ms)8702026/08/27 11:06:12 OK 2_object_stats_trigger.sql (2.14ms)8712026/08/27 11:06:12 goose: up to current file version: 28722026/08/27 11:06:12 OK 20251218171726_add_pins.sql (3.95ms)8732026/08/27 11:06:12 OK 20241026095416_initial_model.sql (13.08ms)8742026/08/27 11:06:12 OK 2_object_stats_trigger.sql (2.41ms)8752026/08/27 11:06:12 goose: up to current file version: 28762026/08/27 11:06:12 OK 2_object_stats_trigger.sql (2.04ms)8772026/08/27 11:06:12 goose: up to current file version: 28782026/08/27 11:06:12 OK 2_object_stats_trigger.sql (2.25ms)8792026/08/27 11:06:12 goose: up to current file version: 28802026/08/27 11:06:12 OK 20241026095416_initial_model.sql (11.77ms)8812026/08/27 11:06:12 OK 20241026095416_initial_model.sql (11.92ms)8822026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.47ms)8832026/08/27 11:06:12 OK 2_object_stats_trigger.sql (2.97ms)8842026/08/27 11:06:12 goose: up to current file version: 28852026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)8862026/08/27 11:06:12 OK 20241026095416_initial_model.sql (11.71ms)8872026/08/27 11:06:12 OK 20241026095416_initial_model.sql (12.52ms)8882026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (3.61ms)8892026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200008902026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)8912026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)8922026/08/27 11:06:12 OK 20241026095416_initial_model.sql (10.28ms)8932026/08/27 11:06:12 OK 20251218171726_add_pins.sql (2.67ms)8942026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)8952026/08/27 11:06:12 OK 20251218171726_add_pins.sql (2.83ms)8962026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)8972026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)8982026/08/27 11:06:12 OK 1_commit_pending_closure.sql (3.09ms)8992026/08/27 11:06:12 OK 20251218171726_add_pins.sql (3.96ms)9002026/08/27 11:06:12 OK 20251218171726_add_pins.sql (4.12ms)9012026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)9022026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200009032026/08/27 11:06:12 OK 20251218171726_add_pins.sql (3.47ms)9042026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.88ms)9052026/08/27 11:06:12 goose: up to current file version: 29062026/08/27 11:06:12 OK 20251218171726_add_pins.sql (3.81ms)9072026/08/27 11:06:12 OK 20251218171726_add_pins.sql (3.93ms)9082026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.99ms)9092026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200009102026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.65ms)9112026/08/27 11:06:12 OK 20241026095416_initial_model.sql (9.38ms)9122026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (3.75ms)9132026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200009142026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.37ms)9152026/08/27 11:06:12 goose: up to current file version: 29162026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)9172026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.42ms)9182026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200009192026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.14ms)9202026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)9212026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200009222026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)9232026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200009242026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (3.68ms)9252026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200009262026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.48ms)9272026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.76ms)9282026/08/27 11:06:12 goose: up to current file version: 29292026/08/27 11:06:12 OK 1_commit_pending_closure.sql (1.82ms)9302026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.15ms)9312026/08/27 11:06:12 OK 20251218171726_add_pins.sql (2.67ms)9322026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.4ms)9332026/08/27 11:06:12 OK 2_object_stats_trigger.sql (984.68µs)9342026/08/27 11:06:12 goose: up to current file version: 29352026/08/27 11:06:12 OK 1_commit_pending_closure.sql (1.57ms)9362026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.16ms)9372026/08/27 11:06:12 goose: up to current file version: 29382026/08/27 11:06:12 OK 2_object_stats_trigger.sql (826.71µs)9392026/08/27 11:06:12 goose: up to current file version: 29402026/08/27 11:06:12 OK 2_object_stats_trigger.sql (906.65µs)9412026/08/27 11:06:12 goose: up to current file version: 29422026/08/27 11:06:12 OK 2_object_stats_trigger.sql (802.2µs)9432026/08/27 11:06:12 goose: up to current file version: 29442026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (3.29ms)9452026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200009462026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.04ms)9472026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.39ms)9482026/08/27 11:06:12 goose: up to current file version: 29492026/08/27 11:06:12 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"950--- PASS: TestService_AuthMiddleware (0.46s)951=== CONT TestClientIntegration9522026/08/27 11:06:12 INFO Received cleanup request method=DELETE path=/api/pending_closures9532026/08/27 11:06:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9542026/08/27 11:06:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"955--- PASS: TestService_NativeMTLS (0.48s)956=== CONT TestReadProxyInvalidPath9572026/08/27 11:06:12 INFO Aborted multipart uploads count=1958--- PASS: TestMultipartCleanup (0.49s)959=== CONT TestReadProxyRangeRequest9602026-08-27 11:06:12.327 UTC [1055] ERROR: relation "goose_db_version" does not exist at character 369612026-08-27 11:06:12.327 UTC [1055] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9622026/08/27 11:06:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9632026/08/27 11:06:12 OK 20241026095416_initial_model.sql (7.89ms)9642026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.36ms)9652026/08/27 11:06:12 OK 20251218171726_add_pins.sql (2.73ms)9662026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (3.67ms)9672026/08/27 11:06:12 goose: successfully migrated database to version: 20260628120000968--- PASS: TestObjectStatsTrigger (0.51s)969=== CONT TestReadRedirectKeepsNarinfoProxied9702026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.18ms)9712026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.56ms)9722026/08/27 11:06:12 goose: up to current file version: 29732026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures974--- PASS: TestMetricsInventory (0.53s)975=== CONT TestReadRedirectNar976--- PASS: TestService_healthCheckHandler (0.52s)977=== CONT TestReadProxyDisabled9782026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures9792026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures9802026/08/27 11:06:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9812026/08/27 11:06:12 INFO Uploading h1zcrb6jdlznd9fpdfg8ahjnw3jjcjqn-file1.txt (160B)9822026/08/27 11:06:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9832026/08/27 11:06:12 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst984--- PASS: TestCompleteMultipartUnregistered (0.55s)985=== CONT TestReadProxyRootRedirectsToIndexHTML9862026/08/27 11:06:12 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9872026-08-27 11:06:12.397 UTC [1100] ERROR: relation "goose_db_version" does not exist at character 369882026-08-27 11:06:12.397 UTC [1100] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9892026/08/27 11:06:12 WARN Failed to register uploaded object key=h1zcrb6jdlznd9fpdfg8ahjnw3jjcjqn.ls error="server returned 404: 404 page not found\n"9902026/08/27 11:06:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9912026/08/27 11:06:12 INFO Signed narinfos id=1 count=19922026/08/27 11:06:12 INFO Uploading 1 narinfos9932026/08/27 11:06:12 WARN Failed to register uploaded object key=h1zcrb6jdlznd9fpdfg8ahjnw3jjcjqn.narinfo error="server returned 404: 404 page not found\n"9942026/08/27 11:06:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9952026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures9962026/08/27 11:06:12 INFO Completed upload id=19972026/08/27 11:06:12 INFO Upload complete. (109ms)9982026/08/27 11:06:12 OK 20241026095416_initial_model.sql (8.05ms)999=== NAME TestNARDeduplicationMetadataUploadBug1000 metadata_upload_test.go:54: Retrieved narinfo from S3:1001 StorePath: /build/TestNARDeduplicationMetadataUploadBug1861124756/001/store/h1zcrb6jdlznd9fpdfg8ahjnw3jjcjqn-file1.txt1002 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1003 Compression: zstd1004 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1005 NarSize: 1601006 References: 1007 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf10082026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2ms)1009 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1010 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1011 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}10122026/08/27 11:06:12 INFO Received cleanup request method=DELETE path=/api/pending_closures10132026/08/27 11:06:12 OK 20251218171726_add_pins.sql (3.13ms)10142026-08-27 11:06:12.419 UTC [1104] ERROR: relation "goose_db_version" does not exist at character 3610152026-08-27 11:06:12.419 UTC [1104] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10162026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures10172026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.27ms)10182026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000010192026-08-27 11:06:12.423 UTC [1105] ERROR: relation "goose_db_version" does not exist at character 3610202026-08-27 11:06:12.423 UTC [1105] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10212026/08/27 11:06:12 INFO Aborted multipart uploads count=010222026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures10232026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.88ms)10242026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.74ms)10252026/08/27 11:06:12 goose: up to current file version: 210262026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures10272026/08/27 11:06:12 OK 20241026095416_initial_model.sql (9.62ms)1028--- PASS: TestService_Rustfstest (0.60s)1029=== CONT TestReadProxyConditionalGet10302026/08/27 11:06:12 INFO Received cleanup request method=DELETE path=/api/pending_closures10312026/08/27 11:06:12 INFO Aborted multipart uploads count=11032=== NAME TestNARDeduplicationMetadataUploadBug1033 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1861124756/001/store/ka352k18m73x3rmqq6hbz51ybqifvxal-file2.txt10342026/08/27 11:06:12 OK 20241026095416_initial_model.sql (25.3ms)10352026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (21.01ms)10362026/08/27 11:06:12 OK 20251218171726_add_pins.sql (4.8ms)10372026/08/27 11:06:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10382026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (5.16ms)10392026-08-27 11:06:12.462 UTC [1002] ERROR: Closure does not exist: id=110402026-08-27 11:06:12.462 UTC [1002] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10412026-08-27 11:06:12.462 UTC [1002] STATEMENT: -- name: CommitPendingClosure :exec1042 SELECT commit_pending_closure($1::bigint)1043 1044--- PASS: TestService_cleanupPendingClosuresHandler (0.62s)1045=== CONT TestReadProxyHead10462026/08/27 11:06:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10472026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.86ms)10482026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000010492026/08/27 11:06:12 OK 20251218171726_add_pins.sql (4.4ms)10502026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.37ms)10512026/08/27 11:06:12 OK 2_object_stats_trigger.sql (2.01ms)10522026/08/27 11:06:12 goose: up to current file version: 210532026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)10542026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000010552026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.98ms)10562026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.32ms)10572026/08/27 11:06:12 goose: up to current file version: 210582026/08/27 11:06:12 INFO Aborted multipart uploads count=010592026-08-27 11:06:12.479 UTC [1132] ERROR: relation "goose_db_version" does not exist at character 3610602026-08-27 11:06:12.479 UTC [1132] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10612026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures10622026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures10632026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures10642026-08-27 11:06:12.480 UTC [1134] ERROR: relation "goose_db_version" does not exist at character 3610652026-08-27 11:06:12.480 UTC [1134] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10662026/08/27 11:06:12 WARN Force mode enabled - objects will be deleted immediately without grace period10672026-08-27 11:06:12.483 UTC [1151] ERROR: relation "goose_db_version" does not exist at character 3610682026-08-27 11:06:12.483 UTC [1151] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10692026/08/27 11:06:12 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=010702026/08/27 11:06:12 INFO Vacuumed table table=pending_closures10712026/08/27 11:06:12 INFO Vacuumed table table=pending_objects10722026/08/27 11:06:12 INFO Vacuumed table table=multipart_uploads10732026/08/27 11:06:12 INFO Vacuumed table table=closures10742026/08/27 11:06:12 INFO Vacuumed table table=objects10752026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures10762026/08/27 11:06:12 OK 20241026095416_initial_model.sql (9.39ms)1077--- PASS: TestGCMetrics (0.57s)1078=== CONT TestService_RequireScope_OIDC10792026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.97ms)10802026/08/27 11:06:12 INFO OIDC provider initialized name=test10812026/08/27 11:06:12 OK 20241026095416_initial_model.sql (9.79ms)10822026/08/27 11:06:12 OK 20251218171726_add_pins.sql (3.12ms)10832026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)10842026-08-27 11:06:12.502 UTC [1170] ERROR: relation "goose_db_version" does not exist at character 3610852026-08-27 11:06:12.502 UTC [1170] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10862026/08/27 11:06:12 OK 20241026095416_initial_model.sql (15.62ms)1087--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.66s)1088=== CONT TestClientCADerivations10892026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)10902026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000010912026/08/27 11:06:12 OK 20251218171726_add_pins.sql (3.5ms)10922026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (3.22ms)10932026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.69ms)10942026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.96ms)10952026/08/27 11:06:12 goose: up to current file version: 210962026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.64ms)10972026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000010982026/08/27 11:06:12 OK 20251218171726_add_pins.sql (4.66ms)10992026/08/27 11:06:12 OK 1_commit_pending_closure.sql (3.24ms)11002026/08/27 11:06:12 OK 2_object_stats_trigger.sql (2.51ms)11012026/08/27 11:06:12 goose: up to current file version: 211022026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (5.61ms)11032026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000011042026/08/27 11:06:12 OK 20241026095416_initial_model.sql (8.95ms)11052026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures11062026/08/27 11:06:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11072026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (3.1ms)11082026/08/27 11:06:12 OK 1_commit_pending_closure.sql (4.65ms)11092026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures11102026/08/27 11:06:12 OK 2_object_stats_trigger.sql (20.13ms)11112026/08/27 11:06:12 goose: up to current file version: 211122026/08/27 11:06:12 OK 20251218171726_add_pins.sql (21.87ms)1113=== NAME TestClientWithDependencies1114 client_integration_test.go:594: Built derivation: /build/TestClientWithDependencies3125297715/001/store/15fgybp6wrkiafql7ps1y169cw4cwdsp-test-script11152026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.85ms)11162026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000011172026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.42ms)11182026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures11192026/08/27 11:06:12 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11202026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures11212026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.94ms)11222026/08/27 11:06:12 goose: up to current file version: 211232026/08/27 11:06:12 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1124--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.71s)1125=== CONT TestCacheStatsHandler11262026-08-27 11:06:12.558 UTC [1231] ERROR: relation "goose_db_version" does not exist at character 3611272026-08-27 11:06:12.558 UTC [1231] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11282026/08/27 11:06:12 WARN Failed to register uploaded object key=ka352k18m73x3rmqq6hbz51ybqifvxal.ls error="server returned 404: 404 page not found\n"11292026/08/27 11:06:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11302026/08/27 11:06:12 INFO Signed narinfos id=2 count=111312026/08/27 11:06:12 INFO Uploading 1 narinfos1132=== NAME TestOrphanedObjectsGC1133 orphaned_objects_gc_test.go:290: GC Test Summary:1134 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1135 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1136 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1137 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1138 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1139--- PASS: TestOrphanedObjectsGC (0.73s)1140=== CONT TestCacheConfigHandler1141=== RUN TestCacheConfigHandler/full_config,_no_issuer11422026/08/27 11:06:12 WARN Failed to register uploaded object key=ka352k18m73x3rmqq6hbz51ybqifvxal.narinfo error="server returned 404: 404 page not found\n"1143=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1144=== RUN TestCacheConfigHandler/no_cache_url_configured1145=== PAUSE TestCacheConfigHandler/no_cache_url_configured11462026/08/27 11:06:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1147=== RUN TestCacheConfigHandler/no_signing_keys11482026/08/27 11:06:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1149=== PAUSE TestCacheConfigHandler/no_signing_keys1150=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1151=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1152=== CONT TestReadProxyNarinfo11532026/08/27 11:06:12 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmVmMDFlMTUtNGFiNi00ZWIzLTk0NTUtNGY3ZTkwODBhMDk3LmU1ZDE3ZTY0LWU2MDMtNDZhMi04MjVhLTBmNTEwMGY1MDQwOXgxNzg3ODI4NzcyNTQzNzgwMjYy11542026/08/27 11:06:12 INFO Completed upload id=211552026/08/27 11:06:12 INFO Upload complete. (83ms)1156=== NAME TestNARDeduplicationMetadataUploadBug1157 metadata_upload_test.go:76: Retrieved narinfo from S3:1158 StorePath: /build/TestNARDeduplicationMetadataUploadBug1861124756/001/store/ka352k18m73x3rmqq6hbz51ybqifvxal-file2.txt1159 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1160 Compression: zstd1161 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1162 NarSize: 1601163 References: 1164 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf11652026-08-27 11:06:12.570 UTC [1238] ERROR: relation "goose_db_version" does not exist at character 3611662026-08-27 11:06:12.570 UTC [1238] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1167 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1168 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1169 {"version":1,"root":{"type":"regular","size":44}}11702026/08/27 11:06:12 OK 20241026095416_initial_model.sql (9.36ms)11712026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (3.35ms)1172=== NAME TestClientWithDependencies1173 client_integration_test.go:596: Found 1 dependencies (including self)1174--- PASS: TestNARDeduplicationMetadataUploadBug (0.74s)1175=== CONT TestReadProxy40411762026/08/27 11:06:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmVmMDFlMTUtNGFiNi00ZWIzLTk0NTUtNGY3ZTkwODBhMDk3LmU1ZDE3ZTY0LWU2MDMtNDZhMi04MjVhLTBmNTEwMGY1MDQwOXgxNzg3ODI4NzcyNTQzNzgwMjYy parts=11177--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.65s)1178=== CONT TestReadProxyNarStreaming11792026/08/27 11:06:12 OK 20251218171726_add_pins.sql (3.04ms)1180--- PASS: TestReadProxyInvalidPath (0.26s)1181=== CONT TestReadProxyNarinfoAlreadyDecompressed11822026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.46ms)11832026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000011842026/08/27 11:06:12 OK 1_commit_pending_closure.sql (3.64ms)11852026/08/27 11:06:12 OK 20241026095416_initial_model.sql (10.34ms)11862026/08/27 11:06:12 OK 2_object_stats_trigger.sql (2.25ms)11872026/08/27 11:06:12 goose: up to current file version: 211882026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)11892026/08/27 11:06:12 OK 20251218171726_add_pins.sql (3.11ms)1190--- PASS: TestReadProxyRangeRequest (0.27s)1191=== CONT TestService_ReadAuthMiddleware11922026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.92ms)11932026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200001194=== NAME TestClientMultipleUploads1195 client_integration_test.go:339: Created store path 0: /build/TestClientMultipleUploads2548787417/001/store/jaj6ysdv086f78qz4dai0336cy5r09xh-test-file-0.txt11962026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.26ms)11972026-08-27 11:06:12.603 UTC [1315] ERROR: relation "goose_db_version" does not exist at character 3611982026-08-27 11:06:12.603 UTC [1315] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11992026/08/27 11:06:12 OK 2_object_stats_trigger.sql (2.02ms)12002026/08/27 11:06:12 goose: up to current file version: 21201=== NAME TestClientIntegration1202 client_integration_test.go:277: Created store path: /build/TestClientIntegration3703767755/002/store/li073dv9gzs1gmsl3sv3nkhh7hbjk1v6-test-file.txt1203--- PASS: TestReadRedirectKeepsNarinfoProxied (0.26s)1204=== CONT TestService_AuthMiddleware_OIDC12052026-08-27 11:06:12.610 UTC [1335] ERROR: relation "goose_db_version" does not exist at character 3612062026-08-27 11:06:12.610 UTC [1335] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12072026/08/27 11:06:12 INFO OIDC provider initialized name=test1208--- PASS: TestReadProxyDisabled (0.25s)1209=== CONT TestGCTaskStore_GetEmpty1210--- PASS: TestGCTaskStore_GetEmpty (0.00s)1211=== CONT TestParseSingleRange1212=== RUN TestParseSingleRange/none1213=== PAUSE TestParseSingleRange/none1214=== RUN TestParseSingleRange/unknown_unit1215=== PAUSE TestParseSingleRange/unknown_unit1216=== RUN TestParseSingleRange/multi-range_ignored1217=== PAUSE TestParseSingleRange/multi-range_ignored1218=== RUN TestParseSingleRange/malformed_no_dash1219=== PAUSE TestParseSingleRange/malformed_no_dash1220=== RUN TestParseSingleRange/malformed_both_empty1221=== PAUSE TestParseSingleRange/malformed_both_empty1222=== RUN TestParseSingleRange/malformed_end_before_start1223=== PAUSE TestParseSingleRange/malformed_end_before_start1224=== RUN TestParseSingleRange/closed1225=== PAUSE TestParseSingleRange/closed1226=== RUN TestParseSingleRange/open-ended1227=== PAUSE TestParseSingleRange/open-ended1228=== RUN TestParseSingleRange/end_clamped_to_size1229=== PAUSE TestParseSingleRange/end_clamped_to_size1230=== RUN TestParseSingleRange/suffix1231=== PAUSE TestParseSingleRange/suffix1232=== RUN TestParseSingleRange/suffix_exceeds_size1233=== PAUSE TestParseSingleRange/suffix_exceeds_size1234=== RUN TestParseSingleRange/single_byte1235=== PAUSE TestParseSingleRange/single_byte1236=== RUN TestParseSingleRange/start_past_EOF1237=== PAUSE TestParseSingleRange/start_past_EOF1238=== RUN TestParseSingleRange/start_far_past_EOF1239=== PAUSE TestParseSingleRange/start_far_past_EOF1240=== CONT TestIsValidCachePath1241=== RUN TestIsValidCachePath/narinfo1242=== PAUSE TestIsValidCachePath/narinfo1243=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1244=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1245=== RUN TestIsValidCachePath/nar_zst1246=== PAUSE TestIsValidCachePath/nar_zst1247=== RUN TestIsValidCachePath/nar_xz1248=== PAUSE TestIsValidCachePath/nar_xz1249=== RUN TestIsValidCachePath/nar_bz21250=== PAUSE TestIsValidCachePath/nar_bz21251=== RUN TestIsValidCachePath/nar_uncompressed1252=== PAUSE TestIsValidCachePath/nar_uncompressed1253=== RUN TestIsValidCachePath/ls1254=== PAUSE TestIsValidCachePath/ls1255=== RUN TestIsValidCachePath/log1256=== PAUSE TestIsValidCachePath/log1257=== RUN TestIsValidCachePath/realisation1258=== PAUSE TestIsValidCachePath/realisation1259=== RUN TestIsValidCachePath/nix-cache-info1260=== PAUSE TestIsValidCachePath/nix-cache-info1261=== RUN TestIsValidCachePath/index.html1262=== PAUSE TestIsValidCachePath/index.html1263=== RUN TestIsValidCachePath/traversal_parent1264=== PAUSE TestIsValidCachePath/traversal_parent1265=== RUN TestIsValidCachePath/traversal_in_middle1266=== PAUSE TestIsValidCachePath/traversal_in_middle1267=== RUN TestIsValidCachePath/invalid_char_e1268=== PAUSE TestIsValidCachePath/invalid_char_e1269=== RUN TestIsValidCachePath/invalid_char_u1270=== PAUSE TestIsValidCachePath/invalid_char_u1271=== RUN TestIsValidCachePath/random_path1272=== PAUSE TestIsValidCachePath/random_path1273=== RUN TestIsValidCachePath/empty1274=== PAUSE TestIsValidCachePath/empty1275=== RUN TestIsValidCachePath/leading_slash1276=== PAUSE TestIsValidCachePath/leading_slash1277=== RUN TestIsValidCachePath/wrong_extension1278=== PAUSE TestIsValidCachePath/wrong_extension1279=== RUN TestIsValidCachePath/short_hash1280=== PAUSE TestIsValidCachePath/short_hash1281=== CONT TestGCTaskStore_ConflictDifferentParams1282--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1283=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1284--- PASS: TestReadRedirectNar (0.26s)1285=== CONT TestService_AuthMiddleware_MTLSProxyHeader1286=== NAME TestPinProtectsFromGC1287 client_integration_test.go:647: Pinned store path: /build/TestPinProtectsFromGC1430552212/001/store/h56ckmg9z35gbp71c195489m1c2zg9sr-pinned-file.txt12882026/08/27 11:06:12 OK 20241026095416_initial_model.sql (13.59ms)1289 client_integration_test.go:648: Unpinned store path: /build/TestPinProtectsFromGC1430552212/001/store/grhr7c3jxl5pllavr075liaqfd79ixjy-unpinned-file.txt1290--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.24s)1291=== CONT TestResurrectedObjectNotDeleted12922026/08/27 11:06:12 OK 20241026095416_initial_model.sql (10.42ms)1293=== NAME TestClientMultipleUploads1294 client_integration_test.go:339: Created store path 1: /build/TestClientMultipleUploads2548787417/001/store/99xydrrd72wn2r30dfs6rgf1hm5ijmci-test-file-1.txt12952026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (3.44ms)12962026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (3.61ms)12972026/08/27 11:06:12 OK 20251218171726_add_pins.sql (4.32ms)12982026/08/27 11:06:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12992026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures13002026/08/27 11:06:12 OK 20251218171726_add_pins.sql (5.62ms)1301--- PASS: TestReadProxyConditionalGet (0.20s)1302=== CONT TestOrphanedObjectsGCStressTest13032026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (6.7ms)13042026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000013052026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (5.81ms)13062026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000013072026/08/27 11:06:12 OK 1_commit_pending_closure.sql (3.09ms)13082026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.77ms)13092026/08/27 11:06:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13102026/08/27 11:06:12 INFO Uploading 15fgybp6wrkiafql7ps1y169cw4cwdsp-test-script (136B)1311--- PASS: TestReadProxyHead (0.20s)1312=== CONT TestService_ReadScope_PublicByDefault13132026/08/27 11:06:12 WARN Failed to register uploaded object key=log/mw8a8j5sqgh4w13ajwc377f6m3w0da2r-test-script.drv error="server returned 404: 404 page not found\n"13142026/08/27 11:06:12 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13152026/08/27 11:06:12 WARN Failed to register uploaded object key=15fgybp6wrkiafql7ps1y169cw4cwdsp.ls error="server returned 404: 404 page not found\n"13162026/08/27 11:06:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13172026/08/27 11:06:12 OK 2_object_stats_trigger.sql (11.6ms)13182026/08/27 11:06:12 goose: up to current file version: 213192026/08/27 11:06:12 INFO Signed narinfos id=1 count=113202026/08/27 11:06:12 INFO Uploading 1 narinfos13212026/08/27 11:06:12 WARN Failed to register uploaded object key=15fgybp6wrkiafql7ps1y169cw4cwdsp.narinfo error="server returned 404: 404 page not found\n"13222026/08/27 11:06:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1323=== NAME TestClientMultipleUploads13242026/08/27 11:06:12 OK 2_object_stats_trigger.sql (15.36ms)1325 client_integration_test.go:339: Created store path 2: /build/TestClientMultipleUploads2548787417/001/store/kg27nvm9ik3snpfmy4ikb6s66bz8jdbi-test-file-2.txt13262026/08/27 11:06:12 goose: up to current file version: 213272026-08-27 11:06:12.678 UTC [1453] ERROR: relation "goose_db_version" does not exist at character 3613282026-08-27 11:06:12.678 UTC [1453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13292026/08/27 11:06:12 INFO Completed upload id=113302026/08/27 11:06:12 INFO Upload complete. (73ms)1331=== NAME TestClientWithDependencies1332 client_integration_test.go:598: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3125297715/001/store) requires matching store prefix1333=== RUN TestService_RequireScope_OIDC/builder_may_write1334=== PAUSE TestService_RequireScope_OIDC/builder_may_write1335=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1336=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1337=== RUN TestService_RequireScope_OIDC/ops_may_admin1338=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1339=== RUN TestService_RequireScope_OIDC/ops_may_not_write1340=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1341=== RUN TestService_RequireScope_OIDC/reader_may_not_write1342=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1343=== RUN TestService_RequireScope_OIDC/static_token_may_admin1344=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1345=== RUN TestService_RequireScope_OIDC/static_token_may_write1346=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1347--- PASS: TestClientWithDependencies (0.65s)1348=== CONT TestProxyWriteTimeout/narinfo1349=== RUN TestService_RequireScope_OIDC/reader_may_read1350=== CONT TestProxyWriteTimeout/10_GiB_nar1351=== CONT TestProxyWriteTimeout/1_GiB_nar1352=== PAUSE TestService_RequireScope_OIDC/reader_may_read1353=== CONT TestProxyWriteTimeout/unknown_size1354--- PASS: TestProxyWriteTimeout (0.00s)1355 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1356 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1357 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1358 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1359=== RUN TestService_RequireScope_OIDC/writer_implies_read1360=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info13612026-08-27 11:06:12.688 UTC [1472] ERROR: relation "goose_db_version" does not exist at character 3613622026-08-27 11:06:12.688 UTC [1472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1363=== PAUSE TestService_RequireScope_OIDC/writer_implies_read13642026/08/27 11:06:12 INFO Received uploads request method=POST path=/1365=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1366=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1367=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key13682026/08/27 11:06:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1369=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key13702026/08/27 11:06:12 INFO Received request for more parts method=POST path=/13712026/08/27 11:06:12 INFO Received complete multipart upload request method=POST path=/1372=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1373=== CONT TestServerTLSConfig/no_client_CA13742026/08/27 11:06:12 INFO Received uploads request method=POST path=/1375=== CONT TestServerTLSConfig/not_a_PEM_file1376--- PASS: TestUploadHandlersRejectInvalidKeys (0.09s)1377 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1378 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1379 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1380 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1381=== CONT TestServerTLSConfig/missing_CA_file1382=== CONT TestClientErrorHandling/InvalidStorePath1383--- PASS: TestServerTLSConfig (0.09s)1384 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1385 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1386 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1387=== CONT TestClientErrorHandling/ServerNotAvailable13882026/08/27 11:06:12 OK 20241026095416_initial_model.sql (11.07ms)13892026-08-27 11:06:12.698 UTC [1476] ERROR: relation "goose_db_version" does not exist at character 3613902026-08-27 11:06:12.698 UTC [1476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13912026-08-27 11:06:12.700 UTC [1478] ERROR: relation "goose_db_version" does not exist at character 3613922026-08-27 11:06:12.700 UTC [1478] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13932026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)13942026/08/27 11:06:12 OK 20251218171726_add_pins.sql (4.25ms)13952026/08/27 11:06:12 OK 20241026095416_initial_model.sql (11.4ms)13962026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)13972026-08-27 11:06:12.710 UTC [1497] ERROR: relation "goose_db_version" does not exist at character 3613982026-08-27 11:06:12.710 UTC [1497] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13992026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (5.8ms)14002026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000014012026/08/27 11:06:12 OK 1_commit_pending_closure.sql (12.34ms)14022026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures14032026/08/27 11:06:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14042026/08/27 11:06:12 OK 20251218171726_add_pins.sql (18.99ms)14052026/08/27 11:06:12 OK 20241026095416_initial_model.sql (20.03ms)14062026/08/27 11:06:12 OK 20241026095416_initial_model.sql (21.37ms)14072026/08/27 11:06:12 OK 2_object_stats_trigger.sql (7.01ms)14082026/08/27 11:06:12 goose: up to current file version: 214092026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (3.62ms)14102026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (3.86ms)14112026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (5.65ms)14122026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000014132026/08/27 11:06:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14142026/08/27 11:06:12 OK 20251218171726_add_pins.sql (6.38ms)14152026/08/27 11:06:12 OK 1_commit_pending_closure.sql (6.45ms)14162026/08/27 11:06:12 OK 20251218171726_add_pins.sql (8.38ms)14172026/08/27 11:06:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14182026/08/27 11:06:12 INFO Uploading li073dv9gzs1gmsl3sv3nkhh7hbjk1v6-test-file.txt (152B)14192026/08/27 11:06:12 OK 20241026095416_initial_model.sql (13.84ms)14202026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (5.6ms)14212026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000014222026/08/27 11:06:12 OK 2_object_stats_trigger.sql (3.6ms)14232026/08/27 11:06:12 goose: up to current file version: 214242026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (5.12ms)14252026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000014262026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (3.02ms)14272026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.37ms)14282026/08/27 11:06:12 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14292026/08/27 11:06:12 OK 1_commit_pending_closure.sql (3.36ms)14302026/08/27 11:06:12 OK 2_object_stats_trigger.sql (2.27ms)14312026/08/27 11:06:12 goose: up to current file version: 214322026/08/27 11:06:12 OK 20251218171726_add_pins.sql (4.54ms)14332026/08/27 11:06:12 WARN Failed to register uploaded object key=li073dv9gzs1gmsl3sv3nkhh7hbjk1v6.ls error="server returned 404: 404 page not found\n"14342026-08-27 11:06:12.752 UTC [1588] ERROR: relation "goose_db_version" does not exist at character 3614352026-08-27 11:06:12.752 UTC [1588] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14362026/08/27 11:06:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14372026/08/27 11:06:12 OK 2_object_stats_trigger.sql (2.37ms)14382026/08/27 11:06:12 goose: up to current file version: 214392026/08/27 11:06:12 INFO Signed narinfos id=1 count=114402026/08/27 11:06:12 INFO Uploading 1 narinfos14412026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.52ms)14422026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000014432026/08/27 11:06:12 WARN Failed to register uploaded object key=li073dv9gzs1gmsl3sv3nkhh7hbjk1v6.narinfo error="server returned 404: 404 page not found\n"1444--- PASS: TestCacheStatsHandler (0.20s)1445=== CONT TestClientErrorHandling/InvalidAuthToken14462026/08/27 11:06:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14472026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.59ms)14482026/08/27 11:06:12 OK 2_object_stats_trigger.sql (2.69ms)14492026/08/27 11:06:12 goose: up to current file version: 214502026-08-27 11:06:12.764 UTC [1606] ERROR: relation "goose_db_version" does not exist at character 3614512026-08-27 11:06:12.764 UTC [1606] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1452--- PASS: TestReadProxyNarinfo (0.20s)1453=== CONT TestIsValidUploadKey/narinfo1454=== CONT TestIsValidUploadKey/unknown_type1455=== CONT TestIsValidUploadKey/empty_key1456=== CONT TestIsValidUploadKey/absolute1457=== CONT TestIsValidUploadKey/traversal_nar1458=== CONT TestIsValidUploadKey/traversal1459=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1460=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1461=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1462=== CONT TestIsValidUploadKey/build_log_home-manager_file1463=== CONT TestIsValidUploadKey/build_log1464=== CONT TestIsValidUploadKey/listing1465=== CONT TestIsValidUploadKey/nar_plain1466=== CONT TestIsValidUploadKey/nar_xz1467=== CONT TestIsValidUploadKey/nar_zst1468=== CONT TestIsValidUploadKey/build_log_plus_in_name1469=== CONT TestIsValidUploadKey/realisation_plus_in_output1470=== CONT TestIsValidUploadKey/realisation1471=== CONT TestIsValidUploadKey/index.html1472=== CONT TestIsValidUploadKey/build_log_equals1473=== CONT TestIsValidUploadKey/build_log_question_mark1474=== CONT TestIsValidUploadKey/nix-cache-info1475--- PASS: TestIsValidUploadKey (0.09s)1476 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1477 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1478 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1479 --- PASS: TestIsValidUploadKey/absolute (0.00s)1480 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1481 --- PASS: TestIsValidUploadKey/traversal (0.00s)1482 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1483 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1484 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1485 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1486 --- PASS: TestIsValidUploadKey/build_log (0.00s)1487 --- PASS: TestIsValidUploadKey/listing (0.00s)1488 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1489 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1490 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1491 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1492 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1493 --- PASS: TestIsValidUploadKey/realisation (0.00s)1494 --- PASS: TestIsValidUploadKey/index.html (0.00s)1495 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1496 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1497 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1498=== CONT TestResolveDBConnectionString/flag_wins1499=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1500=== CONT TestResolveDBConnectionString/missing_file_is_an_error1501=== CONT TestResolveDBConnectionString/nothing_configured1502=== CONT TestResolveDBConnectionString/file_when_flag_empty1503=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15042026/08/27 11:06:12 INFO Received uploads request method=POST path=/1505--- PASS: TestGCBugBareHashReferences (0.84s)1506--- PASS: TestResolveDBConnectionString (0.00s)1507 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1508 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1509 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1510 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1511 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1512=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15132026/08/27 11:06:12 INFO Received request for more parts method=POST path=/15142026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures15152026-08-27 11:06:12.776 UTC [1644] ERROR: relation "goose_db_version" does not exist at character 3615162026-08-27 11:06:12.776 UTC [1644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1517--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.20s)1518=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15192026/08/27 11:06:12 INFO Received complete multipart upload request method=POST path=/15202026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures15212026/08/27 11:06:12 OK 20241026095416_initial_model.sql (24.23ms)15222026/08/27 11:06:12 INFO Completed upload id=115232026/08/27 11:06:12 INFO Upload complete. (146ms)1524=== NAME TestClientIntegration1525 client_integration_test.go:293: Retrieved narinfo from S3:1526 StorePath: /build/TestClientIntegration3703767755/002/store/li073dv9gzs1gmsl3sv3nkhh7hbjk1v6-test-file.txt1527 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1528 Compression: zstd1529 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11530 NarSize: 1521531 References: 1532 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk115332026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.58ms)15342026/08/27 11:06:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15352026/08/27 11:06:12 INFO Uploading h56ckmg9z35gbp71c195489m1c2zg9sr-pinned-file.txt (128B)1536 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1537 client_integration_test.go:294: Decompressed .ls content (64 bytes):1538 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1539 client_integration_test.go:297: Testing garbage collection...15402026/08/27 11:06:12 OK 20241026095416_initial_model.sql (10.45ms)15412026/08/27 11:06:12 OK 20251218171726_add_pins.sql (3.67ms)1542--- PASS: TestReadProxy404 (0.22s)1543=== CONT TestCacheConfigHandler/full_config,_no_issuer1544=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1545=== CONT TestCacheConfigHandler/no_cache_url_configured1546=== CONT TestCacheConfigHandler/no_signing_keys15472026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)1548--- PASS: TestCacheConfigHandler (0.00s)1549 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1550 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1551 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1552 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1553=== CONT TestParseSingleRange/none1554=== CONT TestParseSingleRange/open-ended1555=== CONT TestParseSingleRange/closed1556=== CONT TestParseSingleRange/malformed_end_before_start1557=== CONT TestParseSingleRange/malformed_both_empty15582026/08/27 11:06:12 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1559=== CONT TestParseSingleRange/malformed_no_dash1560=== CONT TestParseSingleRange/multi-range_ignored1561=== CONT TestParseSingleRange/unknown_unit1562=== CONT TestParseSingleRange/start_past_EOF1563=== CONT TestParseSingleRange/end_clamped_to_size1564=== CONT TestParseSingleRange/single_byte1565=== CONT TestParseSingleRange/suffix1566=== CONT TestParseSingleRange/start_far_past_EOF1567=== CONT TestParseSingleRange/suffix_exceeds_size15682026/08/27 11:06:12 OK 20241026095416_initial_model.sql (9.05ms)1569--- PASS: TestParseSingleRange (0.00s)1570 --- PASS: TestParseSingleRange/none (0.00s)1571 --- PASS: TestParseSingleRange/open-ended (0.00s)1572 --- PASS: TestParseSingleRange/closed (0.00s)1573 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1574 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1575 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1576 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1577 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1578 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1579 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1580 --- PASS: TestParseSingleRange/single_byte (0.00s)1581 --- PASS: TestParseSingleRange/suffix (0.00s)1582 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1583 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1584=== CONT TestIsValidCachePath/narinfo1585=== CONT TestIsValidCachePath/short_hash1586=== CONT TestIsValidCachePath/wrong_extension1587=== CONT TestIsValidCachePath/leading_slash1588=== CONT TestIsValidCachePath/empty1589=== CONT TestIsValidCachePath/random_path1590=== CONT TestIsValidCachePath/invalid_char_u1591=== CONT TestIsValidCachePath/invalid_char_e1592=== CONT TestIsValidCachePath/traversal_in_middle1593=== CONT TestIsValidCachePath/traversal_parent1594=== CONT TestIsValidCachePath/index.html1595=== CONT TestIsValidCachePath/nix-cache-info1596=== CONT TestIsValidCachePath/realisation1597=== CONT TestIsValidCachePath/log1598=== CONT TestIsValidCachePath/ls1599=== CONT TestIsValidCachePath/nar_uncompressed1600=== CONT TestIsValidCachePath/nar_bz21601=== CONT TestIsValidCachePath/nar_xz1602=== CONT TestIsValidCachePath/nar_zst1603=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1604--- PASS: TestIsValidCachePath (0.00s)1605 --- PASS: TestIsValidCachePath/narinfo (0.00s)1606 --- PASS: TestIsValidCachePath/short_hash (0.00s)1607 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1608 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1609 --- PASS: TestIsValidCachePath/empty (0.00s)1610 --- PASS: TestIsValidCachePath/random_path (0.00s)1611 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1612 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1613 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1614 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1615 --- PASS: TestIsValidCachePath/index.html (0.00s)1616 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1617 --- PASS: TestIsValidCachePath/realisation (0.00s)1618 --- PASS: TestIsValidCachePath/log (0.00s)1619 --- PASS: TestIsValidCachePath/ls (0.00s)1620 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1621 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1622 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1623 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1624 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)16252026-08-27 11:06:12.796 UTC [1664] ERROR: relation "goose_db_version" does not exist at character 3616262026-08-27 11:06:12.796 UTC [1664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1627=== CONT TestService_RequireScope_OIDC/builder_may_write16282026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures16292026-08-27 11:06:12.797 UTC [1666] ERROR: relation "goose_db_version" does not exist at character 3616302026-08-27 11:06:12.797 UTC [1666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16312026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (5.32ms)16322026-08-27 11:06:12.797 UTC [1665] ERROR: relation "goose_db_version" does not exist at character 3616332026-08-27 11:06:12.797 UTC [1665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16342026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000016352026/08/27 11:06:12 OK 20251218171726_add_pins.sql (3.48ms)16362026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2.65ms)16372026/08/27 11:06:12 INFO OIDC auth successful provider=test scopes=[write]1638=== CONT TestService_RequireScope_OIDC/reader_may_not_write16392026/08/27 11:06:12 WARN Failed to register uploaded object key=h56ckmg9z35gbp71c195489m1c2zg9sr.ls error="server returned 404: 404 page not found\n"16402026/08/27 11:06:12 INFO OIDC auth successful provider=test scopes=[read]1641=== CONT TestService_RequireScope_OIDC/static_token_may_admin16422026/08/27 11:06:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1643=== CONT TestService_RequireScope_OIDC/ops_may_admin16442026/08/27 11:06:12 INFO OIDC auth successful provider=test scopes=[admin]1645=== CONT TestService_RequireScope_OIDC/builder_may_not_admin16462026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.45ms)16472026/08/27 11:06:12 INFO OIDC auth successful provider=test scopes=[write]1648=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read16492026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures16502026-08-27 11:06:12.800 UTC [1685] ERROR: relation "goose_db_version" does not exist at character 3616512026-08-27 11:06:12.800 UTC [1685] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1652=== CONT TestService_RequireScope_OIDC/ops_may_not_write16532026/08/27 11:06:12 INFO Signed narinfos id=1 count=116542026/08/27 11:06:12 INFO OIDC auth successful provider=test scopes=[admin]16552026/08/27 11:06:12 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-config1656=== CONT TestService_RequireScope_OIDC/writer_implies_read16572026/08/27 11:06:12 INFO Uploading 1 narinfos16582026/08/27 11:06:12 OK 20251218171726_add_pins.sql (3.49ms)16592026/08/27 11:06:12 INFO OIDC auth successful provider=test scopes=[write]1660=== CONT TestService_RequireScope_OIDC/reader_may_read16612026/08/27 11:06:12 INFO OIDC auth successful provider=test scopes=[read]1662=== CONT TestService_RequireScope_OIDC/static_token_may_write16632026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.6ms)16642026/08/27 11:06:12 goose: up to current file version: 216652026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)16662026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000016672026/08/27 11:06:12 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)1668--- PASS: TestService_RequireScope_OIDC (0.19s)1669 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1670 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1671 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1672 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1673 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1674 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1675 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1676 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1677 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1678 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)16792026/08/27 11:06:12 INFO Uploading kg27nvm9ik3snpfmy4ikb6s66bz8jdbi-test-file-2.txt (160B)16802026/08/27 11:06:12 INFO Uploading jaj6ysdv086f78qz4dai0336cy5r09xh-test-file-0.txt (160B)16812026/08/27 11:06:12 INFO Uploading 99xydrrd72wn2r30dfs6rgf1hm5ijmci-test-file-1.txt (160B)16822026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.75ms)16832026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.59ms)16842026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000016852026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.43ms)16862026/08/27 11:06:12 goose: up to current file version: 216872026/08/27 11:06:12 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16882026/08/27 11:06:12 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16892026/08/27 11:06:12 WARN Failed to register uploaded object key=h56ckmg9z35gbp71c195489m1c2zg9sr.narinfo error="server returned 404: 404 page not found\n"16902026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.29ms)16912026/08/27 11:06:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1692=== NAME TestClientCADerivations1693 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3660487583/001/store/n1771bgf2ncpmkxg4ypyhxa6d4jcm44s-ca-test16942026/08/27 11:06:12 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16952026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.58ms)16962026/08/27 11:06:12 goose: up to current file version: 216972026/08/27 11:06:12 WARN Failed to register uploaded object key=jaj6ysdv086f78qz4dai0336cy5r09xh.ls error="server returned 404: 404 page not found\n"16982026/08/27 11:06:12 WARN Failed to register uploaded object key=kg27nvm9ik3snpfmy4ikb6s66bz8jdbi.ls error="server returned 404: 404 page not found\n"16992026/08/27 11:06:12 OK 20241026095416_initial_model.sql (8.77ms)17002026/08/27 11:06:12 OK 20241026095416_initial_model.sql (9.41ms)17012026/08/27 11:06:12 OK 20241026095416_initial_model.sql (9.36ms)17022026/08/27 11:06:12 WARN Failed to register uploaded object key=99xydrrd72wn2r30dfs6rgf1hm5ijmci.ls error="server returned 404: 404 page not found\n"17032026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (1.6ms)17042026/08/27 11:06:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign17052026/08/27 11:06:12 INFO Signed narinfos id=3 count=11706--- PASS: TestReadProxyNarStreaming (0.24s)17072026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (2ms)17082026/08/27 11:06:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17092026/08/27 11:06:12 INFO Signed narinfos id=1 count=117102026/08/27 11:06:12 OK 20241026095416_initial_model.sql (8.84ms)17112026/08/27 11:06:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17122026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)17132026/08/27 11:06:12 INFO Signed narinfos id=2 count=117142026/08/27 11:06:12 INFO Uploading 3 narinfos17152026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)17162026-08-27 11:06:12.817 UTC [1686] ERROR: relation "goose_db_version" does not exist at character 3617172026-08-27 11:06:12.817 UTC [1686] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17182026/08/27 11:06:12 OK 20251218171726_add_pins.sql (2.71ms)17192026/08/27 11:06:12 OK 20251218171726_add_pins.sql (3.64ms)17202026/08/27 11:06:12 OK 20251218171726_add_pins.sql (2.76ms)17212026/08/27 11:06:12 INFO Completed upload id=117222026/08/27 11:06:12 INFO Upload complete. (150ms)17232026/08/27 11:06:12 WARN Failed to register uploaded object key=kg27nvm9ik3snpfmy4ikb6s66bz8jdbi.narinfo error="server returned 404: 404 page not found\n"17242026/08/27 11:06:12 OK 20251218171726_add_pins.sql (2.84ms)17252026/08/27 11:06:12 WARN Failed to register uploaded object key=jaj6ysdv086f78qz4dai0336cy5r09xh.narinfo error="server returned 404: 404 page not found\n"1726--- PASS: TestService_ReadAuthMiddleware (0.22s)17272026/08/27 11:06:12 WARN Failed to register uploaded object key=99xydrrd72wn2r30dfs6rgf1hm5ijmci.narinfo error="server returned 404: 404 page not found\n"17282026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (3.36ms)17292026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000017302026/08/27 11:06:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17312026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.07ms)17322026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000017332026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)17342026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000017352026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.25ms)17362026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.28ms)17372026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)17382026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000017392026/08/27 11:06:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures17402026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.43ms)17412026/08/27 11:06:12 goose: up to current file version: 217422026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.48ms)17432026/08/27 11:06:12 INFO Garbage collection started17442026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.49ms)17452026/08/27 11:06:12 goose: up to current file version: 217462026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.14ms)17472026/08/27 11:06:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17482026/08/27 11:06:12 OK 2_object_stats_trigger.sql (2.19ms)17492026/08/27 11:06:12 goose: up to current file version: 217502026/08/27 11:06:12 OK 2_object_stats_trigger.sql (1.83ms)17512026/08/27 11:06:12 goose: up to current file version: 217522026/08/27 11:06:12 INFO Completed upload id=117532026/08/27 11:06:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17542026/08/27 11:06:12 OK 20241026095416_initial_model.sql (9.23ms)17552026/08/27 11:06:12 INFO Completed upload id=217562026/08/27 11:06:12 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete17572026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)17582026/08/27 11:06:12 INFO Completed upload id=31759=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token17602026/08/27 11:06:12 INFO Upload complete. (129ms)1761=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1762=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1763=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1764=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected17652026/08/27 11:06:12 INFO Aborted multipart uploads count=01766=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1767=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1768=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1769=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1770=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1771=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17722026/08/27 11:06:12 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]1773=== NAME TestClientMultipleUploads1774 client_integration_test.go:350: Uploaded 3 paths in 162.01364ms1775=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17762026/08/27 11:06:12 OK 20251218171726_add_pins.sql (2.53ms)17772026/08/27 11:06:12 INFO OIDC auth successful provider=test scopes=[write]17782026/08/27 11:06:12 WARN Force mode enabled - objects will be deleted immediately without grace period17792026/08/27 11:06:12 WARN Authentication failed token_preview=eyJhbGciOi...MusZN8yiQw 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--- PASS: TestService_AuthMiddleware_OIDC (0.23s)1781 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1782 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1783 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1784 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)17852026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (3.48ms)17862026/08/27 11:06:12 goose: successfully migrated database to version: 202606281200001787=== NAME TestClientCADerivations1788 client_ca_test.go:139: Found 1 dependencies (including self)17892026/08/27 11:06:12 OK 1_commit_pending_closure.sql (2.38ms)17902026/08/27 11:06:12 OK 2_object_stats_trigger.sql (975.87µs)17912026/08/27 11:06:12 goose: up to current file version: 21792--- PASS: TestClientMultipleUploads (0.62s)17932026/08/27 11:06:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17942026/08/27 11:06:12 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZmVmMDFlMTUtNGFiNi00ZWIzLTk0NTUtNGY3ZTkwODBhMDk3LmYwNWZhNmNkLTM4ZWQtNDA2Ny05ZWM5LTk3YTY1MGY3ZmRjMXgxNzg3ODI4NzcyNDU2MTI0MTIz parts=1017952026/08/27 11:06:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17962026/08/27 11:06:12 INFO Completed upload id=117972026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures17982026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures17992026/08/27 11:06:12 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18002026/08/27 11:06:12 WARN mTLS auth: bound subjects configured but subject DN unavailable18012026/08/27 11:06:12 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1802--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.24s)18032026/08/27 11:06:12 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo18042026/08/27 11:06:12 WARN Found objects in DB but missing from S3, will re-upload count=118052026/08/27 11:06:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1806--- PASS: TestService_verifyS3Integrity (1.02s)18072026/08/27 11:06:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18082026-08-27 11:06:12.862 UTC [1755] ERROR: relation "goose_db_version" does not exist at character 3618092026-08-27 11:06:12.862 UTC [1755] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1810--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.24s)18112026/08/27 11:06:12 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZmVmMDFlMTUtNGFiNi00ZWIzLTk0NTUtNGY3ZTkwODBhMDk3LjFiOTMyY2VkLTgzMjAtNDAxMC1iOGY1LTRlZDY0M2NhYTE4NHgxNzg3ODI4NzcyNDkxMTcxODUz parts=1018122026/08/27 11:06:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18132026/08/27 11:06:12 INFO Completed upload id=118142026/08/27 11:06:12 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000018152026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures18162026/08/27 11:06:12 OK 20241026095416_initial_model.sql (7.63ms)18172026/08/27 11:06:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures18182026/08/27 11:06:12 OK 20251210153512_drop_unused_gin_index.sql (1.17ms)1819--- PASS: TestResurrectedObjectNotDeleted (0.24s)18202026/08/27 11:06:12 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZmVmMDFlMTUtNGFiNi00ZWIzLTk0NTUtNGY3ZTkwODBhMDk3LmQ0MGQ0ZDRmLWFkMTEtNDNlNS1iMjUyLTVhMGM0Y2ViNzk1N3gxNzg3ODI4NzcyMzg5ODkzMjIz parts=1218212026/08/27 11:06:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZmVmMDFlMTUtNGFiNi00ZWIzLTk0NTUtNGY3ZTkwODBhMDk3LjhiMzk3MWQ4LWIzYzktNDMwOC1hMTYxLTBjOWViMmEwNDZmMXgxNzg3ODI4NzcyNDE2NjY1OTEz parts=1218222026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures1823--- PASS: TestRedundantMultipartUpload (1.04s)18242026/08/27 11:06:12 OK 20251218171726_add_pins.sql (2.27ms)1825--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.95s)18262026/08/27 11:06:12 OK 20260628120000_add_object_size_and_stats.sql (2.38ms)18272026/08/27 11:06:12 goose: successfully migrated database to version: 2026062812000018282026/08/27 11:06:12 OK 1_commit_pending_closure.sql (1.49ms)18292026/08/27 11:06:12 OK 2_object_stats_trigger.sql (695.58µs)18302026/08/27 11:06:12 goose: up to current file version: 21831--- PASS: TestService_ReadScope_PublicByDefault (0.23s)18322026/08/27 11:06:12 INFO Aborted multipart uploads count=018332026/08/27 11:06:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18342026/08/27 11:06:12 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=018352026/08/27 11:06:12 INFO Vacuumed table table=pending_closures18362026/08/27 11:06:12 INFO Vacuumed table table=pending_objects18372026/08/27 11:06:12 INFO Vacuumed table table=multipart_uploads18382026/08/27 11:06:12 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.589121ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18392026/08/27 11:06:12 INFO Vacuumed table table=closures18402026/08/27 11:06:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18412026/08/27 11:06:12 INFO Vacuumed table table=objects18422026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures18432026/08/27 11:06:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18442026/08/27 11:06:12 INFO Uploading grhr7c3jxl5pllavr075liaqfd79ixjy-unpinned-file.txt (128B)18452026/08/27 11:06:12 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001846--- PASS: TestService_createPendingClosureHandler (1.08s)18472026/08/27 11:06:12 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18482026/08/27 11:06:12 WARN Failed to register uploaded object key=grhr7c3jxl5pllavr075liaqfd79ixjy.ls error="server returned 404: 404 page not found\n"18492026/08/27 11:06:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18502026/08/27 11:06:12 INFO Signed narinfos id=2 count=118512026/08/27 11:06:12 INFO Uploading 1 narinfos18522026/08/27 11:06:12 INFO Received uploads request method=POST path=/api/pending_closures18532026/08/27 11:06:12 WARN Failed to register uploaded object key=grhr7c3jxl5pllavr075liaqfd79ixjy.narinfo error="server returned 404: 404 page not found\n"18542026/08/27 11:06:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18552026/08/27 11:06:12 INFO Completed upload id=218562026/08/27 11:06:12 INFO Upload complete. (81ms)18572026/08/27 11:06:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18582026/08/27 11:06:12 INFO Uploading n1771bgf2ncpmkxg4ypyhxa6d4jcm44s-ca-test (144B)18592026/08/27 11:06:12 WARN Failed to register uploaded object key=log/kn2ihy9l6w4wk0y35ml3h5pap2r5p3cc-ca-test.drv error="server returned 404: 404 page not found\n"18602026/08/27 11:06:12 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18612026/08/27 11:06:12 WARN Failed to register uploaded object key=n1771bgf2ncpmkxg4ypyhxa6d4jcm44s.ls error="server returned 404: 404 page not found\n"18622026/08/27 11:06:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18632026/08/27 11:06:12 INFO Signed narinfos id=1 count=118642026/08/27 11:06:12 INFO Uploading 1 narinfos18652026/08/27 11:06:12 WARN Failed to register uploaded object key=n1771bgf2ncpmkxg4ypyhxa6d4jcm44s.narinfo error="server returned 404: 404 page not found\n"18662026/08/27 11:06:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18672026/08/27 11:06:12 INFO Completed upload id=118682026/08/27 11:06:12 INFO Upload complete. (84ms)1869=== NAME TestClientCADerivations1870 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3660487583/001/store/n1771bgf2ncpmkxg4ypyhxa6d4jcm44s-ca-test1871 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1872 Compression: zstd1873 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1874 NarSize: 1441875 References: 1876 Deriver: /build/TestClientCADerivations3660487583/001/store/kn2ihy9l6w4wk0y35ml3h5pap2r5p3cc-ca-test.drv1877 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1878 client_ca_test.go:185: Checking for realisation files in S3...1879 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1880 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache18812026/08/27 11:06:12 INFO Received create pin request method=POST path=/api/pins/myapp18822026/08/27 11:06:12 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1430552212/001/store/h56ckmg9z35gbp71c195489m1c2zg9sr-pinned-file.txt narinfo_key=h56ckmg9z35gbp71c195489m1c2zg9sr.narinfo18832026/08/27 11:06:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures18842026/08/27 11:06:12 INFO Garbage collection started18852026/08/27 11:06:12 INFO Aborted multipart uploads count=018862026/08/27 11:06:12 WARN Force mode enabled - objects will be deleted immediately without grace period18872026/08/27 11:06:13 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18882026/08/27 11:06:13 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=018892026/08/27 11:06:13 INFO Vacuumed table table=pending_closures18902026/08/27 11:06:13 INFO Vacuumed table table=pending_objects18912026/08/27 11:06:13 INFO Vacuumed table table=multipart_uploads18922026/08/27 11:06:13 INFO Vacuumed table table=closures18932026/08/27 11:06:13 INFO Vacuumed table table=objects18942026/08/27 11:06:13 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18952026/08/27 11:06:13 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=418.380166ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1896 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1897 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1898 error: binary cache 's3://bucket37?endpoint=http://localhost:42031®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3660487583/001/store'1899 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11900--- PASS: TestClientCADerivations (0.62s)19012026/08/27 11:06:13 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=019022026/08/27 11:06:13 INFO Vacuumed table table=pending_closures19032026/08/27 11:06:13 INFO Vacuumed table table=pending_objects19042026/08/27 11:06:13 INFO Vacuumed table table=multipart_uploads19052026/08/27 11:06:13 INFO Vacuumed table table=closures19062026/08/27 11:06:13 INFO Vacuumed table table=objects1907--- PASS: TestUploadHandlersRejectOversizedBody (0.19s)1908 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)1909 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1910 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.69s)19112026/08/27 11:06:13 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=814.999843ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1912=== NAME TestOrphanedObjectsGCStressTest1913 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1914 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1915 orphaned_objects_gc_test.go:509: Stress test completed successfully:1916 orphaned_objects_gc_test.go:510: - Active objects preserved: 201917 orphaned_objects_gc_test.go:511: - Objects deleted: 2101918 orphaned_objects_gc_test.go:512: - Total GC'd: 2101919--- PASS: TestOrphanedObjectsGCStressTest (1.54s)19202026/08/27 11:06:14 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.626956417s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19212026/08/27 11:06:14 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01922=== NAME TestClientIntegration1923 client_integration_test.go:304: Objects in database after GC:1924 client_integration_test.go:304: Successfully deleted all objects with GC --force1925--- PASS: TestClientIntegration (2.54s)19262026/08/27 11:06:14 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01927=== NAME TestPinProtectsFromGC1928 client_integration_test.go:710: Pin successfully protected closure from garbage collection1929--- PASS: TestPinProtectsFromGC (3.00s)19302026/08/27 11:06:15 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"19312026/08/27 11:06:15 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_closures19322026/08/27 11:06:16 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=207.072897ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19332026/08/27 11:06:16 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=361.072947ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19342026/08/27 11:06:16 WARN Rate limiter enabled after throttle name=s3-test rate=519352026/08/27 11:06:16 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1936=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1937 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101938 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001939--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.61s)19402026/08/27 11:06:16 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=852.839976ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19412026/08/27 11:06:17 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.596762922s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1942--- PASS: TestClientErrorHandling (0.00s)1943 --- PASS: TestClientErrorHandling/InvalidStorePath (0.24s)1944 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.31s)1945 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.44s)1946PASS1947{"timestamp":"2026-08-27T11:06:19.13025671Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:56400","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(764)"}19482026-08-27 11:06:19.372 UTC [112] LOG: received smart shutdown request19492026-08-27 11:06:19.377 UTC [112] LOG: background worker "logical replication launcher" (PID 122) exited with exit code 119502026-08-27 11:06:19.384 UTC [117] LOG: shutting down19512026-08-27 11:06:19.385 UTC [117] LOG: checkpoint starting: shutdown immediate19522026-08-27 11:06:20.011 UTC [117] LOG: checkpoint complete: wrote 11175 buffers (68.2%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 14 recycled; write=0.278 s, sync=0.340 s, total=0.628 s; sync files=16812, longest=0.005 s, average=0.001 s; distance=231555 kB, estimate=231555 kB; lsn=0/F984CA0, redo lsn=0/F984CA019532026-08-27 11:06:20.091 UTC [112] LOG: database system is shut down1954Running OIDC tests...1955=== RUN TestGlobMatch1956=== PAUSE TestGlobMatch1957=== RUN TestAudienceForIssuer1958=== PAUSE TestAudienceForIssuer1959=== RUN TestValidateToken_ValidToken1960=== PAUSE TestValidateToken_ValidToken1961=== RUN TestValidateToken_WrongAudience1962=== PAUSE TestValidateToken_WrongAudience1963=== RUN TestValidateToken_Expired1964=== PAUSE TestValidateToken_Expired1965=== RUN TestValidateToken_BoundClaimsMismatch1966=== PAUSE TestValidateToken_BoundClaimsMismatch1967=== RUN TestValidateToken_BoundSubjectMismatch1968=== PAUSE TestValidateToken_BoundSubjectMismatch1969=== RUN TestValidateToken_MultipleProviders1970=== PAUSE TestValidateToken_MultipleProviders1971=== RUN TestValidateToken_NoMatchingProvider1972=== PAUSE TestValidateToken_NoMatchingProvider1973=== RUN TestValidateToken_KubernetesServiceAccount1974=== PAUSE TestValidateToken_KubernetesServiceAccount1975=== RUN TestNewValidator_KubernetesRequiresCA1976=== PAUSE TestNewValidator_KubernetesRequiresCA1977=== RUN TestScopes_LegacyProviderDefaultsToWrite1978=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1979=== RUN TestScopes_Rules1980=== PAUSE TestScopes_Rules1981=== RUN TestScopes_ConfigValidation1982=== PAUSE TestScopes_ConfigValidation1983=== CONT TestGlobMatch1984=== CONT TestValidateToken_MultipleProviders1985=== RUN TestGlobMatch/foo_foo1986=== CONT TestValidateToken_WrongAudience1987=== CONT TestValidateToken_ValidToken1988=== CONT TestAudienceForIssuer1989--- PASS: TestAudienceForIssuer (0.00s)1990=== CONT TestValidateToken_KubernetesServiceAccount1991=== CONT TestNewValidator_KubernetesRequiresCA1992=== CONT TestValidateToken_BoundSubjectMismatch1993=== CONT TestScopes_ConfigValidation1994=== CONT TestScopes_Rules1995=== CONT TestValidateToken_NoMatchingProvider1996=== CONT TestValidateToken_BoundClaimsMismatch1997=== CONT TestValidateToken_Expired1998=== CONT TestScopes_LegacyProviderDefaultsToWrite1999=== PAUSE TestGlobMatch/foo_foo2000--- PASS: TestScopes_ConfigValidation (0.00s)2001=== RUN TestGlobMatch/foo_bar2002=== PAUSE TestGlobMatch/foo_bar2003=== RUN TestGlobMatch/*_2004=== PAUSE TestGlobMatch/*_2005=== RUN TestGlobMatch/*_anything2006=== PAUSE TestGlobMatch/*_anything2007=== RUN TestGlobMatch/foo*_foo2008=== PAUSE TestGlobMatch/foo*_foo2009=== RUN TestGlobMatch/foo*_foobar2010=== PAUSE TestGlobMatch/foo*_foobar2011=== RUN TestGlobMatch/foo*_bar2012=== PAUSE TestGlobMatch/foo*_bar2013=== RUN TestGlobMatch/*bar_bar20142026/08/27 11:06:20 INFO OIDC provider initialized name=test20152026/08/27 11:06:20 INFO OIDC provider initialized name=provider120162026/08/27 11:06:20 INFO OIDC provider initialized name=test20172026/08/27 11:06:20 INFO OIDC provider initialized name=test2018=== PAUSE TestGlobMatch/*bar_bar2019=== RUN TestGlobMatch/*bar_foobar20202026/08/27 11:06:20 INFO OIDC provider initialized name=test2021=== PAUSE TestGlobMatch/*bar_foobar2022=== RUN TestGlobMatch/*bar_foo2023=== PAUSE TestGlobMatch/*bar_foo2024=== RUN TestGlobMatch/foo*bar_foobar2025=== PAUSE TestGlobMatch/foo*bar_foobar20262026/08/27 11:06:20 INFO OIDC provider initialized name=test2027=== RUN TestGlobMatch/foo*bar_foo123bar2028=== PAUSE TestGlobMatch/foo*bar_foo123bar2029=== RUN TestGlobMatch/foo*bar_foobarbaz2030=== PAUSE TestGlobMatch/foo*bar_foobarbaz2031=== RUN TestGlobMatch/*/*_foo/bar20322026/08/27 11:06:20 INFO OIDC provider initialized name=test2033=== PAUSE TestGlobMatch/*/*_foo/bar2034=== RUN TestGlobMatch/*/*_foo20352026/08/27 11:06:20 INFO OIDC provider initialized name=provider22036=== PAUSE TestGlobMatch/*/*_foo2037=== RUN TestGlobMatch/refs/heads/*_refs/heads/main20382026/08/27 11:06:20 INFO OIDC provider initialized name=test2039=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2040=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02041=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02042=== RUN TestGlobMatch/refs/*/main_refs/heads/main2043=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2044=== RUN TestGlobMatch/fo?_foo2045=== PAUSE TestGlobMatch/fo?_foo2046=== RUN TestGlobMatch/fo?_fo2047=== PAUSE TestGlobMatch/fo?_fo2048=== RUN TestGlobMatch/fo?_fooo2049=== PAUSE TestGlobMatch/fo?_fooo2050=== RUN TestGlobMatch/?oo_foo2051=== PAUSE TestGlobMatch/?oo_foo2052=== RUN TestGlobMatch/?oo_boo2053=== PAUSE TestGlobMatch/?oo_boo2054=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2055=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2056=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main20572026/08/27 11:06:20 INFO OIDC provider initialized name=provider12058=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2059=== CONT TestGlobMatch/fo?_fo2060=== CONT TestGlobMatch/fo?_foo2061=== CONT TestGlobMatch/foo*bar_foobar2062=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2063=== CONT TestGlobMatch/foo_foo2064=== CONT TestGlobMatch/*/*_foo/bar2065=== CONT TestGlobMatch/?oo_boo2066=== CONT TestGlobMatch/*bar_bar2067=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02068=== CONT TestGlobMatch/refs/*/main_refs/heads/main2069=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2070=== CONT TestGlobMatch/foo*bar_foobarbaz2071=== CONT TestGlobMatch/foo*_bar2072=== CONT TestGlobMatch/*bar_foo2073=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2074=== CONT TestGlobMatch/*/*_foo2075=== CONT TestGlobMatch/foo_bar2076=== CONT TestGlobMatch/*bar_foobar2077=== CONT TestGlobMatch/foo*bar_foo123bar2078=== CONT TestGlobMatch/*_2079=== CONT TestGlobMatch/?oo_foo2080=== CONT TestGlobMatch/fo?_fooo2081--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2082=== CONT TestGlobMatch/*_anything2083=== CONT TestGlobMatch/foo*_foobar2084=== CONT TestGlobMatch/foo*_foo2085--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2086--- PASS: TestGlobMatch (0.01s)2087 --- PASS: TestGlobMatch/fo?_fo (0.00s)2088 --- PASS: TestGlobMatch/fo?_foo (0.00s)2089 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2090 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2091 --- PASS: TestGlobMatch/foo_foo (0.00s)2092 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2093 --- PASS: TestGlobMatch/?oo_boo (0.00s)2094 --- PASS: TestGlobMatch/*bar_bar (0.00s)2095 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2096 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2097 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2098 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2099 --- PASS: TestGlobMatch/foo*_bar (0.00s)2100 --- PASS: TestGlobMatch/*bar_foo (0.00s)2101 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2102 --- PASS: TestGlobMatch/*/*_foo (0.00s)2103 --- PASS: TestGlobMatch/foo_bar (0.00s)2104 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2105 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2106 --- PASS: TestGlobMatch/*_ (0.00s)2107 --- PASS: TestGlobMatch/?oo_foo (0.00s)2108 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2109 --- PASS: TestGlobMatch/*_anything (0.00s)2110 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2111 --- PASS: TestGlobMatch/foo*_foo (0.00s)2112--- PASS: TestValidateToken_Expired (0.01s)2113--- PASS: TestValidateToken_WrongAudience (0.01s)2114--- PASS: TestValidateToken_ValidToken (0.02s)2115--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2116--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)21172026/08/27 11:06:20 INFO OIDC provider initialized name=kubernetes2118--- PASS: TestValidateToken_MultipleProviders (0.02s)2119--- PASS: TestScopes_Rules (0.02s)2120--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)21212026/08/27 11:06:20 http: TLS handshake error from 127.0.0.1:39148: remote error: tls: bad certificate2122--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2123PASS2124Running hook tests...2125=== RUN TestSendPathsEmpty2126=== PAUSE TestSendPathsEmpty2127=== RUN TestQueueEnqueueAndFetch2128=== PAUSE TestQueueEnqueueAndFetch2129=== RUN TestQueueDeduplication2130=== PAUSE TestQueueDeduplication2131=== RUN TestQueueRemove2132=== PAUSE TestQueueRemove2133=== RUN TestQueueFetchBatchLimit2134=== PAUSE TestQueueFetchBatchLimit2135=== RUN TestQueueRetryMovesToBack2136=== PAUSE TestQueueRetryMovesToBack2137=== RUN TestQueueFetchRemoveLifecycle2138=== PAUSE TestQueueFetchRemoveLifecycle2139=== RUN TestQueueConcurrentWriters2140=== PAUSE TestQueueConcurrentWriters2141=== RUN TestQueueRemoveLargeClosure2142=== PAUSE TestQueueRemoveLargeClosure2143=== RUN TestServerClientIntegration2144=== PAUSE TestServerClientIntegration2145=== RUN TestServerQueueError2146=== PAUSE TestServerQueueError2147=== RUN TestGetListenerSocketActivation2148 server_test.go:210: === RUN TestGetListenerSocketActivation2149 --- PASS: TestGetListenerSocketActivation (0.00s)2150 PASS2151 2152--- PASS: TestGetListenerSocketActivation (0.01s)2153=== RUN TestDrainIsolatesPoisonPath2154=== PAUSE TestDrainIsolatesPoisonPath2155=== RUN TestRunNotBlockedByPoisonHead2156=== PAUSE TestRunNotBlockedByPoisonHead2157=== RUN TestDrainGivesUpWhenServerDown2158=== PAUSE TestDrainGivesUpWhenServerDown2159=== RUN TestFailedPathPrunedByLaterClosure2160=== PAUSE TestFailedPathPrunedByLaterClosure2161=== RUN TestWorkerUploadsAndRemoves2162=== PAUSE TestWorkerUploadsAndRemoves2163=== RUN TestWorkerSkipsGCdPaths2164=== PAUSE TestWorkerSkipsGCdPaths2165=== RUN TestWorkerPrunesClosureDeps2166=== PAUSE TestWorkerPrunesClosureDeps2167=== RUN TestDrainTimeout2168=== PAUSE TestDrainTimeout2169=== CONT TestSendPathsEmpty2170=== CONT TestQueueEnqueueAndFetch2171=== CONT TestQueueRetryMovesToBack2172=== CONT TestServerQueueError2173=== CONT TestFailedPathPrunedByLaterClosure2174=== CONT TestWorkerUploadsAndRemoves2175=== CONT TestDrainGivesUpWhenServerDown2176=== CONT TestDrainTimeout2177=== CONT TestRunNotBlockedByPoisonHead2178=== CONT TestWorkerPrunesClosureDeps2179=== CONT TestDrainIsolatesPoisonPath2180=== CONT TestWorkerSkipsGCdPaths2181=== CONT TestQueueRemoveLargeClosure2182=== CONT TestQueueRemove21832026/08/27 11:06:20 ERROR Failed to queue paths error="permission denied" count=12184=== CONT TestServerClientIntegration2185=== CONT TestQueueFetchBatchLimit2186=== CONT TestQueueConcurrentWriters2187=== CONT TestQueueFetchRemoveLifecycle2188=== CONT TestQueueDeduplication2189--- PASS: TestSendPathsEmpty (0.00s)2190--- PASS: TestServerQueueError (0.00s)2191--- PASS: TestServerClientIntegration (0.00s)21922026/08/27 11:06:20 INFO Uploading batch count=121932026/08/27 11:06:20 ERROR Upload failed error="upload failed" count=121942026/08/27 11:06:20 INFO Upload queue status pending=221952026/08/27 11:06:20 INFO Uploading batch count=221962026/08/27 11:06:20 ERROR Upload failed error="upload failed" count=221972026/08/27 11:06:20 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3109671095/002/a21982026/08/27 11:06:20 INFO Uploading batch count=421992026/08/27 11:06:20 ERROR Upload failed error="upload failed" count=422002026/08/27 11:06:20 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3551785595/002/nonexistent22012026/08/27 11:06:20 INFO Uploading batch count=122022026/08/27 11:06:20 INFO Uploading batch count=222032026/08/27 11:06:20 INFO Upload queue status pending=222042026/08/27 11:06:20 INFO Upload queue status pending=322052026/08/27 11:06:20 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3109671095/002/b2206--- PASS: TestQueueEnqueueAndFetch (0.02s)22072026/08/27 11:06:20 INFO Uploading batch count=122082026/08/27 11:06:20 ERROR Upload failed error="upload failed" count=12209--- PASS: TestQueueFetchBatchLimit (0.02s)22102026/08/27 11:06:20 INFO Upload queue status pending=222112026/08/27 11:06:20 INFO Uploading batch count=222122026/08/27 11:06:20 INFO Uploading batch count=122132026/08/27 11:06:20 INFO Uploading batch count=222142026/08/27 11:06:20 ERROR Upload failed error="upload failed" count=222152026/08/27 11:06:20 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3109671095/002/c22162026/08/27 11:06:20 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2429451872/002/bbb2217--- PASS: TestQueueRetryMovesToBack (0.02s)22182026/08/27 11:06:20 INFO Uploading batch count=12219--- PASS: TestQueueDeduplication (0.02s)22202026/08/27 11:06:20 INFO Uploading batch count=12221--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2222--- PASS: TestQueueRemove (0.02s)22232026/08/27 11:06:20 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3109671095/002/d22242026/08/27 11:06:20 INFO Uploading batch count=222252026/08/27 11:06:20 ERROR Upload failed error="upload failed" count=222262026/08/27 11:06:20 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3109671095/002/e22272026/08/27 11:06:20 INFO Uploading batch count=122282026/08/27 11:06:20 ERROR Upload failed error="upload failed" count=122292026/08/27 11:06:20 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3109671095/002/f2230--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)22312026/08/27 11:06:20 INFO Uploading batch count=122322026/08/27 11:06:20 ERROR Upload failed error="upload failed" count=122332026/08/27 11:06:20 ERROR Drain finished with paths left in queue remaining=1022342026/08/27 11:06:20 INFO Uploading batch count=122352026/08/27 11:06:20 ERROR Upload failed error="upload failed" count=12236--- PASS: TestDrainGivesUpWhenServerDown (0.03s)22372026/08/27 11:06:21 ERROR Drain finished with paths left in queue remaining=12238--- PASS: TestDrainIsolatesPoisonPath (0.03s)2239--- PASS: TestWorkerSkipsGCdPaths (0.04s)2240--- PASS: TestWorkerUploadsAndRemoves (0.04s)2241--- PASS: TestWorkerPrunesClosureDeps (0.04s)2242--- PASS: TestQueueRemoveLargeClosure (0.14s)22432026/08/27 11:06:21 ERROR Upload failed error="context deadline exceeded" count=222442026/08/27 11:06:21 ERROR Drain finished with paths left in queue remaining=42245--- PASS: TestDrainTimeout (0.22s)2246--- PASS: TestQueueConcurrentWriters (0.37s)22472026/08/27 11:06:21 INFO Uploading batch count=122482026/08/27 11:06:21 INFO Uploading batch count=122492026/08/27 11:06:21 INFO Uploading batch count=122502026/08/27 11:06:21 ERROR Upload failed error="upload failed" count=122512026/08/27 11:06:22 INFO Uploading batch count=122522026/08/27 11:06:22 ERROR Upload failed error="upload failed" count=122532026/08/27 11:06:22 INFO Uploading batch count=122542026/08/27 11:06:22 ERROR Upload failed error="upload failed" count=122552026/08/27 11:06:22 INFO Uploading batch count=122562026/08/27 11:06:22 ERROR Upload failed error="upload failed" count=122572026/08/27 11:06:22 ERROR Drain finished with paths left in queue remaining=12258--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2259PASS