niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #155
· 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 TestResolveStorePath75=== CONT TestEncodeNixBase32WithRealHash76=== CONT TestDumpPathMatchesNix77--- PASS: TestEncodeNixBase32WithRealHash (0.00s)78=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess79=== CONT TestRateLimiterFeedback802026/08/27 10:00:52 WARN Rate limiter enabled after throttle name=server-test rate=581--- PASS: TestResolveStorePath (0.00s)82=== CONT TestCaseHackSuffix83=== RUN TestRateLimiterFeedback/429_enables_limiter84=== PAUSE TestRateLimiterFeedback/429_enables_limiter85=== RUN TestRateLimiterFeedback/503_enables_limiter86=== PAUSE TestRateLimiterFeedback/503_enables_limiter87=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter88=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter89=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter90=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter91=== CONT TestPathInfoCACompatibility92=== RUN TestPathInfoCACompatibility/null_ca_field93=== PAUSE TestPathInfoCACompatibility/null_ca_field94=== RUN TestPathInfoCACompatibility/old_string_format_-_text95=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text96=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive97=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive98=== RUN TestPathInfoCACompatibility/new_structured_format_-_text99=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text100=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method101=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method102=== CONT TestSetClientTLSDoesNotMutateDefaultTransport103=== CONT TestFileTokenReadsAndCaches104--- PASS: TestFileTokenReadsAndCaches (0.00s)105=== CONT TestStaticToken106--- PASS: TestStaticToken (0.00s)107=== CONT TestSetClientTLSErrors108=== CONT TestParsePathInfoJSONMultiplePaths109=== CONT TestParsePathInfoJSON110=== CONT TestPathInfoHashCompatibility111=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)112=== CONT TestGetStorePathHash113=== CONT TestConvertHashToNix32114=== CONT TestPartSizeForNAR115=== CONT TestUploadMultipart_SupersededByPeer116=== CONT TestDumpPathWriterError117=== RUN TestGetStorePathHash/valid_store_path118=== CONT TestFilterOversizedClosures119=== CONT TestFileTokenMissing120=== PAUSE TestGetStorePathHash/valid_store_path121=== CONT TestScriptTokenEmptyCommand122=== CONT TestScriptTokenScriptFails123=== CONT TestScriptTokenBadJSON124=== CONT TestScriptTokenEmptyToken125=== CONT TestScriptTokenCachesUntilRefresh126=== CONT TestScriptTokenNoExpiryRerunsEveryCall127=== CONT TestFileTokenEmpty128=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths129=== RUN TestParsePathInfoJSON/Nix_format130=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)131=== CONT TestEncodeNixBase32132=== RUN TestConvertHashToNix32/SRI_format_to_Nix32133=== RUN TestPartSizeForNAR/zero_stays_at_minimum134=== RUN TestSetClientTLSErrors/missing_cert_file135--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)136=== CONT TestShellSplitErrors137=== RUN TestUploadMultipart_SupersededByPeer/exists138=== PAUSE TestUploadMultipart_SupersededByPeer/exists139=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32140=== RUN TestConvertHashToNix32/already_Nix32_format141=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum142=== PAUSE TestSetClientTLSErrors/missing_cert_file143=== RUN TestSetClientTLSErrors/missing_key_file144=== RUN TestPartSizeForNAR/small_stays_at_minimum145=== PAUSE TestPartSizeForNAR/small_stays_at_minimum146=== RUN TestUploadMultipart_SupersededByPeer/missing147=== CONT TestDumpPathSingleFile148=== PAUSE TestSetClientTLSErrors/missing_key_file149=== CONT TestSetClientTLS150=== PAUSE TestUploadMultipart_SupersededByPeer/missing151=== PAUSE TestParsePathInfoJSON/Nix_format152=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths153=== RUN TestParsePathInfoJSON/Lix_format154=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths155=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon156=== RUN TestFilterOversizedClosures/no_limit_keeps_everything157--- PASS: TestScriptTokenEmptyCommand (0.00s)158=== PAUSE TestConvertHashToNix32/already_Nix32_format159=== RUN TestEncodeNixBase32/test_string_hash160=== CONT TestShellSplit161=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum162=== CONT TestDoWithRetry_BodyReplayedViaGetBody163=== RUN TestGetStorePathHash/basename_without_hyphen_should_error164=== CONT TestRateLimiterFeedback/429_enables_limiter165=== CONT TestPathInfoCACompatibility/new_structured_format_-_text166=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum167=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts168=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method169=== RUN TestSetClientTLSErrors/missing_ca_file170=== PAUSE TestParsePathInfoJSON/Lix_format171=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths172=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon173=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter174=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI175=== PAUSE TestEncodeNixBase32/test_string_hash176=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything177--- PASS: TestDoServerRequestAttachesToken (0.01s)178=== RUN TestConvertHashToNix32/invalid_format179=== CONT TestPathInfoCACompatibility/null_ca_field180=== PAUSE TestSetClientTLSErrors/missing_ca_file181=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error182=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts183=== RUN TestParsePathInfoJSON/empty_input184=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter185=== CONT TestPathInfoCACompatibility/old_string_format_-_text186=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI187=== CONT TestRateLimiterFeedback/503_enables_limiter188=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error189=== PAUSE TestParsePathInfoJSON/empty_input1902026/08/27 10:00:52 WARN Rate limiter enabled after throttle name=server-test rate=5191=== RUN TestParsePathInfoJSON/whitespace_only192=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error193=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error194=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive195=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped196=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error197=== PAUSE TestConvertHashToNix32/invalid_format198--- PASS: TestShellSplitErrors (0.00s)1992026/08/27 10:00:52 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:35945200=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths201=== RUN TestSetClientTLSErrors/invalid_ca_file202=== RUN TestSetClientTLS/rejects_connection_without_client_cert203=== RUN TestPartSizeForNAR/1_TiB204=== PAUSE TestSetClientTLSErrors/invalid_ca_file2052026/08/27 10:00:52 WARN Rate limiter enabled after throttle name=server-test rate=5206=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha5122072026/08/27 10:00:52 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:45319208=== CONT TestGetStorePathHash/valid_store_path2092026/08/27 10:00:52 WARN Rate limiter enabled after throttle name=server-test rate=5210=== CONT TestGetStorePathHash/basename_without_hyphen_should_error2112026/08/27 10:00:52 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33443212=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error213=== CONT TestConvertHashToNix32/SRI_format_to_Nix32214=== CONT TestUploadMultipart_SupersededByPeer/missing2152026/08/27 10:00:52 WARN Rate limiter backed off name=server-test rate=52162026/08/27 10:00:52 WARN Rate limiter backed off name=server-test rate=5217=== PAUSE TestParsePathInfoJSON/whitespace_only2182026/08/27 10:00:52 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33443219=== RUN TestParsePathInfoJSON/invalid_JSON220=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2212026/08/27 10:00:52 WARN Rate limiter backed off name=server-test rate=5222=== CONT TestSetClientTLSErrors/missing_ca_file223--- PASS: TestScriptTokenScriptFails (0.00s)224=== CONT TestUploadMultipart_SupersededByPeer/exists225=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert226=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error227=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths228=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512229=== RUN TestEncodeNixBase32/empty_input230=== PAUSE TestPartSizeForNAR/1_TiB231=== CONT TestConvertHashToNix32/invalid_format232=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)233=== CONT TestConvertHashToNix32/already_Nix32_format234=== CONT TestSetClientTLSErrors/missing_cert_file235=== PAUSE TestParsePathInfoJSON/invalid_JSON236=== CONT TestParsePathInfoJSON/Nix_format237=== CONT TestParsePathInfoJSON/Lix_format238=== CONT TestParsePathInfoJSON/whitespace_only239=== RUN TestFilterOversizedClosures/all_closures_skipped240=== PAUSE TestFilterOversizedClosures/all_closures_skipped241--- PASS: TestFileTokenMissing (0.00s)242--- PASS: TestShellSplit (0.00s)243=== CONT TestSetClientTLSErrors/missing_key_file244=== PAUSE TestEncodeNixBase32/empty_input245=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon246=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI247=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512248=== RUN TestPartSizeForNAR/5_TiB_S3_max_object249=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA250=== CONT TestSetClientTLSErrors/invalid_ca_file251=== CONT TestParsePathInfoJSON/invalid_JSON252=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA253=== CONT TestFilterOversizedClosures/no_limit_keeps_everything254=== RUN TestSetClientTLS/preserves_debug_logging_transport255=== PAUSE TestSetClientTLS/preserves_debug_logging_transport256=== CONT TestSetClientTLS/rejects_connection_without_client_cert257=== CONT TestFilterOversizedClosures/all_closures_skipped2582026/08/27 10:00:52 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=50259=== CONT TestSetClientTLS/preserves_debug_logging_transport260=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2612026/08/27 10:00:52 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=2000262--- PASS: TestFileTokenEmpty (0.00s)263=== CONT TestEncodeNixBase32/test_string_hash264=== CONT TestEncodeNixBase32/empty_input265=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object266=== RUN TestPartSizeForNAR/capped_at_5_GiB267=== CONT TestParsePathInfoJSON/empty_input268=== PAUSE TestPartSizeForNAR/capped_at_5_GiB269=== CONT TestPartSizeForNAR/zero_stays_at_minimum270=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts271=== CONT TestPartSizeForNAR/1_TiB272=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA273--- PASS: TestScriptTokenEmptyToken (0.01s)274--- PASS: TestScriptTokenBadJSON (0.01s)275=== CONT TestPartSizeForNAR/capped_at_5_GiB276=== CONT TestPartSizeForNAR/5_TiB_S3_max_object277=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum278=== CONT TestPartSizeForNAR/small_stays_at_minimum279--- PASS: TestPathInfoCACompatibility (0.00s)280 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)281 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)282 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)283 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)284 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)285--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)286--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)287 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)288 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)289--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)290--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)291--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)292 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)293 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)294--- PASS: TestFilterOversizedClosures (0.01s)295 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)296 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)297 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)298--- PASS: TestEncodeNixBase32 (0.01s)299 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)300 --- PASS: TestEncodeNixBase32/empty_input (0.00s)301--- PASS: TestParsePathInfoJSON (0.01s)302 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)303 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)304 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)305 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)306 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)307--- PASS: TestPartSizeForNAR (0.02s)308 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)309 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)310 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)311 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)312 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)313 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)314 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)315--- PASS: TestRateLimiterFeedback (0.00s)316 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)317 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)318 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)319 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)320--- PASS: TestGetStorePathHash (0.01s)321 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)322 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)323 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)324 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)325--- PASS: TestConvertHashToNix32 (0.01s)326 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)327 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)328 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)329--- PASS: TestPathInfoHashCompatibility (0.01s)330 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)331 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)332 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)333 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)334--- PASS: TestSetClientTLSErrors (0.01s)335 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)336 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)337 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)338 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)3392026/08/27 10:00:52 http: TLS handshake error from 127.0.0.1:34876: remote error: tls: bad certificate340--- PASS: TestSetClientTLS (0.01s)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: TestCaseHackSuffix (0.03s)345--- PASS: TestDumpPathSingleFile (0.03s)346--- PASS: TestDumpPathWriterError (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/postgres1515387203/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/postgres1515387203/data -l logfile start377378/build/postgres1515387203:5432 - no response3792026-08-27 10:00:54.559 UTC [112] LOG: starting PostgreSQL 18.4 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit3802026-08-27 10:00:54.559 UTC [112] LOG: listening on Unix socket "/build/postgres1515387203/.s.PGSQL.5432"3812026-08-27 10:00:54.564 UTC [119] LOG: database system was shut down at 2026-08-27 10:00:54 UTC3822026-08-27 10:00:54.568 UTC [112] LOG: database system is ready to accept connections383/build/postgres1515387203: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 TestCacheConfigHandler395=== PAUSE TestCacheConfigHandler396=== RUN TestCacheStatsHandler397=== PAUSE TestCacheStatsHandler398=== RUN TestClientCADerivations399=== PAUSE TestClientCADerivations400=== RUN TestClientErrorHandling401=== PAUSE TestClientErrorHandling402=== RUN TestClientIntegration403=== PAUSE TestClientIntegration404=== RUN TestClientMultipleUploads405=== PAUSE TestClientMultipleUploads406=== RUN TestClientWithDependencies407=== PAUSE TestClientWithDependencies408=== RUN TestPinProtectsFromGC409=== PAUSE TestPinProtectsFromGC410=== RUN TestGCAdvisoryLockBlocksConcurrentRun4112026-08-27 10:00:55.055 UTC [908] ERROR: relation "goose_db_version" does not exist at character 364122026-08-27 10:00:55.055 UTC [908] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4132026/08/27 10:00:55 OK 20241026095416_initial_model.sql (7.2ms)4142026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (1.27ms)4152026/08/27 10:00:55 OK 20251218171726_add_pins.sql (1.86ms)4162026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (1.79ms)4172026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200004182026/08/27 10:00:55 OK 1_commit_pending_closure.sql (1.27ms)4192026/08/27 10:00:55 OK 2_object_stats_trigger.sql (713.21µs)4202026/08/27 10:00:55 goose: up to current file version: 2421--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.13s)422=== RUN TestGCBugBareHashReferences423=== PAUSE TestGCBugBareHashReferences424=== RUN TestGCMetrics425=== PAUSE TestGCMetrics426=== RUN TestGCTaskStore_StartNew427=== PAUSE TestGCTaskStore_StartNew428=== RUN TestGCTaskStore_DeduplicateSameParams429=== PAUSE TestGCTaskStore_DeduplicateSameParams430=== RUN TestGCTaskStore_ConflictDifferentParams431=== PAUSE TestGCTaskStore_ConflictDifferentParams432=== RUN TestGCTaskStore_GetEmpty433=== PAUSE TestGCTaskStore_GetEmpty434=== RUN TestGCTaskStore_GetReturnsLatest435=== PAUSE TestGCTaskStore_GetReturnsLatest436=== RUN TestGCTaskStore_CompletedAllowsNewTask437=== PAUSE TestGCTaskStore_CompletedAllowsNewTask438=== RUN TestGCTaskStore_PhaseUpdates439=== PAUSE TestGCTaskStore_PhaseUpdates440=== RUN TestGCTaskStore_Fail441=== PAUSE TestGCTaskStore_Fail442=== RUN TestGracefulShutdownDrainsInflight443=== PAUSE TestGracefulShutdownDrainsInflight444=== RUN TestService_healthCheckHandler445=== PAUSE TestService_healthCheckHandler446=== RUN TestGenerateLandingPage447=== PAUSE TestGenerateLandingPage448=== RUN TestCacheConfigHandlerMaxNarSize449=== PAUSE TestCacheConfigHandlerMaxNarSize450=== RUN TestCreatePendingClosureRejectsOversizedNAR451=== PAUSE TestCreatePendingClosureRejectsOversizedNAR452=== RUN TestNARDeduplicationMetadataUploadBug453=== PAUSE TestNARDeduplicationMetadataUploadBug454=== RUN TestMetricsInventory455=== PAUSE TestMetricsInventory456=== RUN TestService_NativeMTLS457=== PAUSE TestService_NativeMTLS458=== RUN TestServerTLSConfig459=== PAUSE TestServerTLSConfig460=== RUN TestMultipartCleanup461=== PAUSE TestMultipartCleanup462=== RUN TestObjectStatsTrigger463=== PAUSE TestObjectStatsTrigger464=== RUN TestOrphanedObjectsGC465=== PAUSE TestOrphanedObjectsGC466=== RUN TestOrphanedObjectsGCStressTest467=== PAUSE TestOrphanedObjectsGCStressTest468=== RUN TestResurrectedObjectNotDeleted469=== PAUSE TestResurrectedObjectNotDeleted470=== RUN TestParseSingleRange471=== PAUSE TestParseSingleRange472=== RUN TestIsValidCachePath473=== PAUSE TestIsValidCachePath474=== RUN TestReadProxyNarinfo475=== PAUSE TestReadProxyNarinfo476=== RUN TestReadProxyNarinfoAlreadyDecompressed477=== PAUSE TestReadProxyNarinfoAlreadyDecompressed478=== RUN TestReadProxyNarStreaming479=== PAUSE TestReadProxyNarStreaming480=== RUN TestReadProxy404481=== PAUSE TestReadProxy404482=== RUN TestReadProxyInvalidPath483=== PAUSE TestReadProxyInvalidPath484=== RUN TestReadProxyHead485=== PAUSE TestReadProxyHead486=== RUN TestReadProxyConditionalGet487=== PAUSE TestReadProxyConditionalGet488=== RUN TestReadProxyRootRedirectsToIndexHTML489=== PAUSE TestReadProxyRootRedirectsToIndexHTML490=== RUN TestReadProxyDisabled491=== PAUSE TestReadProxyDisabled492=== RUN TestReadRedirectNar493=== PAUSE TestReadRedirectNar494=== RUN TestReadRedirectKeepsNarinfoProxied495=== PAUSE TestReadRedirectKeepsNarinfoProxied496=== RUN TestReadProxyRangeRequest497=== PAUSE TestReadProxyRangeRequest498=== RUN TestRedundantMultipartUpload499=== PAUSE TestRedundantMultipartUpload500=== RUN TestCompleteMultipartUpload_ErrorButObjectExists501=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists502=== RUN TestCompletedNarNotReofferedAcrossClosures503=== PAUSE TestCompletedNarNotReofferedAcrossClosures504=== RUN TestPresignedUploadRegisteredBeforeCommit505=== PAUSE TestPresignedUploadRegisteredBeforeCommit506=== RUN TestService_Rustfstest507=== PAUSE TestService_Rustfstest508=== RUN TestParseSize509=== PAUSE TestParseSize510=== RUN TestSkippedUploadsHandler511=== PAUSE TestSkippedUploadsHandler512=== RUN TestSystemdListenerNotActivated513--- PASS: TestSystemdListenerNotActivated (0.00s)514=== RUN TestWatchdogBeatsWhenHealthy515--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)516=== RUN TestWatchdogSkipsWhenUnhealthy5172026/08/27 10:00:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5182026/08/27 10:00:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5192026/08/27 10:00:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5202026/08/27 10:00:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5212026/08/27 10:00:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5222026/08/27 10:00:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5232026/08/27 10:00:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5242026/08/27 10:00:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5252026/08/27 10:00:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5262026/08/27 10:00:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"527--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)528=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle529=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle530=== RUN TestProxyWriteTimeout531=== PAUSE TestProxyWriteTimeout532=== RUN TestIsValidUploadKey533=== PAUSE TestIsValidUploadKey534=== RUN TestUploadHandlersRejectInvalidKeys535=== PAUSE TestUploadHandlersRejectInvalidKeys536=== RUN TestUploadHandlersRejectOversizedBody537=== PAUSE TestUploadHandlersRejectOversizedBody538=== RUN TestService_cleanupPendingClosuresHandler539=== PAUSE TestService_cleanupPendingClosuresHandler540=== RUN TestService_createPendingClosureHandler541=== PAUSE TestService_createPendingClosureHandler542=== RUN TestService_verifyS3Integrity543=== PAUSE TestService_verifyS3Integrity544=== RUN TestCompleteMultipartUnregistered545=== PAUSE TestCompleteMultipartUnregistered546=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT547=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT548=== CONT TestService_AuthMiddleware549=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT550=== CONT TestService_cleanupPendingClosuresHandler551=== CONT TestMultipartCleanup552=== CONT TestUploadHandlersRejectOversizedBody553=== CONT TestUploadHandlersRejectInvalidKeys554=== CONT TestIsValidUploadKey555=== RUN TestIsValidUploadKey/narinfo556=== CONT TestProxyWriteTimeout557=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle558=== CONT TestSkippedUploadsHandler559=== CONT TestParseSize560=== CONT TestService_Rustfstest561=== CONT TestPresignedUploadRegisteredBeforeCommit562=== CONT TestCompletedNarNotReofferedAcrossClosures563=== CONT TestCompleteMultipartUpload_ErrorButObjectExists564=== CONT TestRedundantMultipartUpload565=== CONT TestReadProxyRangeRequest566=== CONT TestReadRedirectKeepsNarinfoProxied567=== CONT TestReadRedirectNar568=== CONT TestReadProxyDisabled569=== CONT TestReadProxyRootRedirectsToIndexHTML570=== CONT TestReadProxyConditionalGet571=== CONT TestReadProxyHead572=== CONT TestReadProxyInvalidPath573=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info574=== RUN TestProxyWriteTimeout/narinfo575=== PAUSE TestProxyWriteTimeout/narinfo576=== RUN TestProxyWriteTimeout/1_GiB_nar577=== PAUSE TestProxyWriteTimeout/1_GiB_nar578=== RUN TestProxyWriteTimeout/10_GiB_nar579=== PAUSE TestProxyWriteTimeout/10_GiB_nar580=== RUN TestProxyWriteTimeout/unknown_size581=== PAUSE TestProxyWriteTimeout/unknown_size582=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info583=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal584=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal585=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key586--- PASS: TestParseSize (0.00s)587=== CONT TestReadProxy4045882026/08/27 10:00:55 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000589=== PAUSE TestIsValidUploadKey/narinfo590=== RUN TestIsValidUploadKey/nar_zst591=== CONT TestReadProxyNarStreaming592=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key593=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key594=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key595=== CONT TestReadProxyNarinfoAlreadyDecompressed596=== PAUSE TestIsValidUploadKey/nar_zst597=== RUN TestIsValidUploadKey/nar_xz598=== PAUSE TestIsValidUploadKey/nar_xz599=== RUN TestIsValidUploadKey/nar_plain600=== PAUSE TestIsValidUploadKey/nar_plain601=== RUN TestIsValidUploadKey/listing602=== PAUSE TestIsValidUploadKey/listing603=== RUN TestIsValidUploadKey/build_log604=== PAUSE TestIsValidUploadKey/build_log605=== RUN TestIsValidUploadKey/build_log_home-manager_file606=== PAUSE TestIsValidUploadKey/build_log_home-manager_file607=== RUN TestIsValidUploadKey/build_log_plus_in_name608=== PAUSE TestIsValidUploadKey/build_log_plus_in_name609=== RUN TestIsValidUploadKey/build_log_question_mark610=== PAUSE TestIsValidUploadKey/build_log_question_mark611=== RUN TestIsValidUploadKey/build_log_equals612=== PAUSE TestIsValidUploadKey/build_log_equals613=== RUN TestIsValidUploadKey/realisation614=== PAUSE TestIsValidUploadKey/realisation615=== RUN TestIsValidUploadKey/realisation_plus_in_output616=== PAUSE TestIsValidUploadKey/realisation_plus_in_output617=== RUN TestIsValidUploadKey/nix-cache-info618=== PAUSE TestIsValidUploadKey/nix-cache-info619=== RUN TestIsValidUploadKey/index.html620=== PAUSE TestIsValidUploadKey/index.html621=== RUN TestIsValidUploadKey/narinfo_key,_nar_type622=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type623=== RUN TestIsValidUploadKey/nar_key,_narinfo_type624=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type625=== RUN TestIsValidUploadKey/listing_key,_narinfo_type626=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type627=== RUN TestIsValidUploadKey/traversal628=== PAUSE TestIsValidUploadKey/traversal629=== RUN TestIsValidUploadKey/traversal_nar630=== PAUSE TestIsValidUploadKey/traversal_nar631=== RUN TestIsValidUploadKey/absolute632=== PAUSE TestIsValidUploadKey/absolute633=== RUN TestIsValidUploadKey/empty_key634=== PAUSE TestIsValidUploadKey/empty_key635=== RUN TestIsValidUploadKey/unknown_type636=== PAUSE TestIsValidUploadKey/unknown_type637=== CONT TestReadProxyNarinfo638--- PASS: TestSkippedUploadsHandler (0.08s)639=== CONT TestIsValidCachePath640=== RUN TestIsValidCachePath/narinfo641=== PAUSE TestIsValidCachePath/narinfo642=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars643=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars644=== RUN TestIsValidCachePath/nar_zst645=== PAUSE TestIsValidCachePath/nar_zst646=== RUN TestIsValidCachePath/nar_xz647=== PAUSE TestIsValidCachePath/nar_xz648=== RUN TestIsValidCachePath/nar_bz2649=== PAUSE TestIsValidCachePath/nar_bz2650=== RUN TestIsValidCachePath/nar_uncompressed651=== PAUSE TestIsValidCachePath/nar_uncompressed652=== RUN TestIsValidCachePath/ls653=== PAUSE TestIsValidCachePath/ls654=== RUN TestIsValidCachePath/log655=== PAUSE TestIsValidCachePath/log656=== RUN TestIsValidCachePath/realisation657=== PAUSE TestIsValidCachePath/realisation658=== RUN TestIsValidCachePath/nix-cache-info659=== PAUSE TestIsValidCachePath/nix-cache-info660=== RUN TestIsValidCachePath/index.html661=== PAUSE TestIsValidCachePath/index.html662=== RUN TestIsValidCachePath/traversal_parent663=== PAUSE TestIsValidCachePath/traversal_parent664=== RUN TestIsValidCachePath/traversal_in_middle665=== PAUSE TestIsValidCachePath/traversal_in_middle666=== RUN TestIsValidCachePath/invalid_char_e667=== PAUSE TestIsValidCachePath/invalid_char_e668=== RUN TestIsValidCachePath/invalid_char_u669=== PAUSE TestIsValidCachePath/invalid_char_u670=== RUN TestIsValidCachePath/random_path671=== PAUSE TestIsValidCachePath/random_path672=== RUN TestIsValidCachePath/empty673=== PAUSE TestIsValidCachePath/empty674=== RUN TestIsValidCachePath/leading_slash675=== PAUSE TestIsValidCachePath/leading_slash676=== RUN TestIsValidCachePath/wrong_extension677=== PAUSE TestIsValidCachePath/wrong_extension678=== RUN TestIsValidCachePath/short_hash679=== PAUSE TestIsValidCachePath/short_hash680=== CONT TestParseSingleRange681=== RUN TestParseSingleRange/none682=== PAUSE TestParseSingleRange/none683=== RUN TestParseSingleRange/unknown_unit684=== PAUSE TestParseSingleRange/unknown_unit685=== RUN TestParseSingleRange/multi-range_ignored686=== PAUSE TestParseSingleRange/multi-range_ignored687=== RUN TestParseSingleRange/malformed_no_dash688=== PAUSE TestParseSingleRange/malformed_no_dash689=== RUN TestParseSingleRange/malformed_both_empty690=== PAUSE TestParseSingleRange/malformed_both_empty691=== RUN TestParseSingleRange/malformed_end_before_start692=== PAUSE TestParseSingleRange/malformed_end_before_start693=== RUN TestParseSingleRange/closed694=== PAUSE TestParseSingleRange/closed695=== RUN TestParseSingleRange/open-ended696=== PAUSE TestParseSingleRange/open-ended697=== RUN TestParseSingleRange/end_clamped_to_size698=== PAUSE TestParseSingleRange/end_clamped_to_size699=== RUN TestParseSingleRange/suffix700=== PAUSE TestParseSingleRange/suffix701=== RUN TestParseSingleRange/suffix_exceeds_size702=== PAUSE TestParseSingleRange/suffix_exceeds_size703=== RUN TestParseSingleRange/single_byte704=== PAUSE TestParseSingleRange/single_byte705=== RUN TestParseSingleRange/start_past_EOF706=== PAUSE TestParseSingleRange/start_past_EOF707=== RUN TestParseSingleRange/start_far_past_EOF708=== PAUSE TestParseSingleRange/start_far_past_EOF709=== CONT TestResurrectedObjectNotDeleted7102026-08-27 10:00:55.503 UTC [981] ERROR: relation "goose_db_version" does not exist at character 367112026-08-27 10:00:55.503 UTC [981] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7122026-08-27 10:00:55.503 UTC [980] ERROR: relation "goose_db_version" does not exist at character 367132026-08-27 10:00:55.503 UTC [980] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7142026-08-27 10:00:55.503 UTC [979] ERROR: relation "goose_db_version" does not exist at character 367152026-08-27 10:00:55.503 UTC [979] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC716=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts717=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts718=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure719=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure720=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart721=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart722=== CONT TestOrphanedObjectsGCStressTest7232026-08-27 10:00:55.505 UTC [982] ERROR: relation "goose_db_version" does not exist at character 367242026-08-27 10:00:55.505 UTC [982] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7252026/08/27 10:00:55 OK 20241026095416_initial_model.sql (64.06ms)7262026/08/27 10:00:55 OK 20241026095416_initial_model.sql (76.75ms)7272026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (15.94ms)7282026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (4.24ms)7292026/08/27 10:00:55 OK 20251218171726_add_pins.sql (5.26ms)7302026/08/27 10:00:55 OK 20241026095416_initial_model.sql (94.58ms)7312026/08/27 10:00:55 OK 20241026095416_initial_model.sql (92.76ms)7322026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (3.4ms)7332026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (5.67ms)7342026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200007352026/08/27 10:00:55 OK 20251218171726_add_pins.sql (7.3ms)7362026-08-27 10:00:55.653 UTC [987] ERROR: relation "goose_db_version" does not exist at character 367372026-08-27 10:00:55.653 UTC [987] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7382026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (4.43ms)7392026/08/27 10:00:55 OK 1_commit_pending_closure.sql (4.44ms)7402026/08/27 10:00:55 OK 20251218171726_add_pins.sql (8.55ms)7412026-08-27 10:00:55.659 UTC [989] ERROR: relation "goose_db_version" does not exist at character 367422026-08-27 10:00:55.659 UTC [989] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7432026/08/27 10:00:55 OK 2_object_stats_trigger.sql (4.18ms)7442026/08/27 10:00:55 goose: up to current file version: 27452026-08-27 10:00:55.660 UTC [988] ERROR: relation "goose_db_version" does not exist at character 367462026-08-27 10:00:55.660 UTC [988] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7472026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (10.75ms)7482026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200007492026-08-27 10:00:55.662 UTC [990] ERROR: relation "goose_db_version" does not exist at character 367502026-08-27 10:00:55.662 UTC [990] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7512026/08/27 10:00:55 OK 20251218171726_add_pins.sql (10.11ms)7522026-08-27 10:00:55.666 UTC [991] ERROR: relation "goose_db_version" does not exist at character 367532026-08-27 10:00:55.666 UTC [991] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7542026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (7.98ms)7552026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200007562026/08/27 10:00:55 OK 1_commit_pending_closure.sql (5.34ms)7572026/08/27 10:00:55 OK 2_object_stats_trigger.sql (3.42ms)7582026/08/27 10:00:55 goose: up to current file version: 27592026/08/27 10:00:55 OK 1_commit_pending_closure.sql (4.83ms)7602026/08/27 10:00:55 OK 20241026095416_initial_model.sql (9.85ms)7612026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (8.58ms)7622026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200007632026-08-27 10:00:55.673 UTC [992] ERROR: relation "goose_db_version" does not exist at character 367642026-08-27 10:00:55.673 UTC [992] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7652026/08/27 10:00:55 OK 2_object_stats_trigger.sql (2.91ms)7662026/08/27 10:00:55 goose: up to current file version: 27672026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (1.5ms)7682026-08-27 10:00:55.679 UTC [993] ERROR: relation "goose_db_version" does not exist at character 367692026-08-27 10:00:55.679 UTC [993] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7702026/08/27 10:00:55 OK 1_commit_pending_closure.sql (6.32ms)7712026/08/27 10:00:55 OK 20251218171726_add_pins.sql (5.74ms)7722026/08/27 10:00:55 OK 2_object_stats_trigger.sql (2.77ms)7732026/08/27 10:00:55 goose: up to current file version: 27742026/08/27 10:00:55 OK 20241026095416_initial_model.sql (16.26ms)7752026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)7762026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (7.51ms)7772026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200007782026/08/27 10:00:55 OK 20241026095416_initial_model.sql (19.62ms)7792026/08/27 10:00:55 INFO Received uploads request method=POST path=/api/pending_closures7802026/08/27 10:00:55 OK 20241026095416_initial_model.sql (25.16ms)7812026-08-27 10:00:55.700 UTC [994] ERROR: relation "goose_db_version" does not exist at character 367822026-08-27 10:00:55.700 UTC [994] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7832026/08/27 10:00:55 OK 1_commit_pending_closure.sql (16.03ms)7842026/08/27 10:00:55 OK 20251218171726_add_pins.sql (17.25ms)7852026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (14.83ms)7862026/08/27 10:00:55 OK 20241026095416_initial_model.sql (33ms)7872026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (5.25ms)7882026/08/27 10:00:55 OK 2_object_stats_trigger.sql (2.68ms)7892026/08/27 10:00:55 goose: up to current file version: 27902026/08/27 10:00:55 OK 20241026095416_initial_model.sql (27.48ms)7912026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (5.11ms)7922026/08/27 10:00:55 OK 20251218171726_add_pins.sql (6.89ms)7932026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (7.87ms)7942026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200007952026/08/27 10:00:55 OK 20251218171726_add_pins.sql (7.69ms)7962026/08/27 10:00:55 INFO Received uploads request method=POST path=/api/pending_closures7972026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (4.87ms)7982026/08/27 10:00:55 OK 1_commit_pending_closure.sql (3.98ms)7992026/08/27 10:00:55 OK 20241026095416_initial_model.sql (26.47ms)8002026-08-27 10:00:55.718 UTC [995] ERROR: relation "goose_db_version" does not exist at character 368012026-08-27 10:00:55.718 UTC [995] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8022026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (6.02ms)8032026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200008042026/08/27 10:00:55 OK 20251218171726_add_pins.sql (8.85ms)8052026/08/27 10:00:55 OK 2_object_stats_trigger.sql (3.06ms)8062026/08/27 10:00:55 goose: up to current file version: 28072026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (7.48ms)8082026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200008092026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (3.31ms)8102026/08/27 10:00:55 OK 20251218171726_add_pins.sql (5.15ms)8112026/08/27 10:00:55 OK 1_commit_pending_closure.sql (3.51ms)8122026/08/27 10:00:55 OK 1_commit_pending_closure.sql (3.85ms)813--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.40s)814=== CONT TestOrphanedObjectsGC8152026/08/27 10:00:55 OK 2_object_stats_trigger.sql (3.03ms)8162026/08/27 10:00:55 goose: up to current file version: 28172026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (5.33ms)8182026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200008192026/08/27 10:00:55 OK 20241026095416_initial_model.sql (13.02ms)8202026/08/27 10:00:55 OK 20251218171726_add_pins.sql (5.52ms)8212026/08/27 10:00:55 OK 2_object_stats_trigger.sql (2.52ms)8222026/08/27 10:00:55 goose: up to current file version: 28232026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (7.71ms)8242026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200008252026/08/27 10:00:55 OK 1_commit_pending_closure.sql (3.31ms)8262026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (3.3ms)8272026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (4.21ms)8282026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200008292026/08/27 10:00:55 OK 2_object_stats_trigger.sql (2.35ms)8302026/08/27 10:00:55 goose: up to current file version: 28312026/08/27 10:00:55 OK 1_commit_pending_closure.sql (4.71ms)8322026/08/27 10:00:55 INFO Received cleanup request method=DELETE path=/api/pending_closures8332026/08/27 10:00:55 OK 20251218171726_add_pins.sql (4.58ms)8342026/08/27 10:00:55 OK 2_object_stats_trigger.sql (3.78ms)8352026/08/27 10:00:55 goose: up to current file version: 28362026/08/27 10:00:55 OK 1_commit_pending_closure.sql (5.03ms)8372026/08/27 10:00:55 INFO Aborted multipart uploads count=08382026/08/27 10:00:55 INFO Received uploads request method=POST path=/api/pending_closures8392026/08/27 10:00:55 OK 2_object_stats_trigger.sql (14.81ms)8402026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (16.41ms)8412026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200008422026/08/27 10:00:55 goose: up to current file version: 28432026/08/27 10:00:55 OK 20241026095416_initial_model.sql (20.85ms)8442026-08-27 10:00:55.754 UTC [998] ERROR: relation "goose_db_version" does not exist at character 368452026-08-27 10:00:55.754 UTC [998] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8462026-08-27 10:00:55.754 UTC [1000] ERROR: relation "goose_db_version" does not exist at character 368472026-08-27 10:00:55.754 UTC [1000] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8482026-08-27 10:00:55.755 UTC [999] ERROR: relation "goose_db_version" does not exist at character 368492026-08-27 10:00:55.755 UTC [999] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8502026/08/27 10:00:55 OK 1_commit_pending_closure.sql (3.77ms)8512026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (3.41ms)8522026/08/27 10:00:55 OK 2_object_stats_trigger.sql (1.09ms)8532026/08/27 10:00:55 goose: up to current file version: 28542026/08/27 10:00:55 INFO Received cleanup request method=DELETE path=/api/pending_closures8552026/08/27 10:00:55 OK 20251218171726_add_pins.sql (3.61ms)8562026/08/27 10:00:55 INFO Aborted multipart uploads count=18572026/08/27 10:00:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8582026-08-27 10:00:55.763 UTC [1001] ERROR: relation "goose_db_version" does not exist at character 368592026-08-27 10:00:55.763 UTC [1001] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8602026-08-27 10:00:55.763 UTC [979] ERROR: Closure does not exist: id=18612026-08-27 10:00:55.763 UTC [979] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE8622026-08-27 10:00:55.763 UTC [979] STATEMENT: -- name: CommitPendingClosure :exec863 SELECT commit_pending_closure($1::bigint)864 8652026-08-27 10:00:55.763 UTC [1002] ERROR: relation "goose_db_version" does not exist at character 368662026-08-27 10:00:55.763 UTC [1002] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC867--- PASS: TestService_cleanupPendingClosuresHandler (0.44s)868--- PASS: TestReadProxyDisabled (0.43s)869=== CONT TestObjectStatsTrigger870=== CONT TestService_verifyS3Integrity8712026-08-27 10:00:55.764 UTC [1003] ERROR: relation "goose_db_version" does not exist at character 368722026-08-27 10:00:55.764 UTC [1003] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8732026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (4.73ms)8742026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200008752026-08-27 10:00:55.766 UTC [1005] ERROR: relation "goose_db_version" does not exist at character 368762026-08-27 10:00:55.766 UTC [1005] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8772026-08-27 10:00:55.766 UTC [1004] ERROR: relation "goose_db_version" does not exist at character 368782026-08-27 10:00:55.766 UTC [1004] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8792026-08-27 10:00:55.766 UTC [1006] ERROR: relation "goose_db_version" does not exist at character 368802026-08-27 10:00:55.766 UTC [1006] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8812026-08-27 10:00:55.767 UTC [1007] ERROR: relation "goose_db_version" does not exist at character 368822026-08-27 10:00:55.767 UTC [1007] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8832026-08-27 10:00:55.768 UTC [1008] ERROR: relation "goose_db_version" does not exist at character 368842026-08-27 10:00:55.768 UTC [1008] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8852026/08/27 10:00:55 OK 1_commit_pending_closure.sql (3.66ms)8862026/08/27 10:00:55 OK 2_object_stats_trigger.sql (2.61ms)8872026/08/27 10:00:55 goose: up to current file version: 28882026/08/27 10:00:55 OK 20241026095416_initial_model.sql (10.54ms)8892026/08/27 10:00:55 OK 20241026095416_initial_model.sql (12.33ms)8902026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (3.62ms)8912026/08/27 10:00:55 OK 20241026095416_initial_model.sql (14.54ms)892--- PASS: TestService_Rustfstest (0.45s)893=== CONT TestCompleteMultipartUnregistered894--- PASS: TestReadProxyRangeRequest (0.45s)895=== CONT TestService_createPendingClosureHandler8962026/08/27 10:00:55 OK 20241026095416_initial_model.sql (12.14ms)8972026/08/27 10:00:55 OK 20241026095416_initial_model.sql (12.67ms)8982026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (3.76ms)8992026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (3.58ms)9002026/08/27 10:00:55 OK 20251218171726_add_pins.sql (4.75ms)9012026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (2.8ms)9022026/08/27 10:00:55 OK 20241026095416_initial_model.sql (13.37ms)9032026/08/27 10:00:55 OK 20241026095416_initial_model.sql (14.16ms)9042026/08/27 10:00:55 OK 20241026095416_initial_model.sql (13.5ms)9052026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)9062026/08/27 10:00:55 OK 20241026095416_initial_model.sql (13.47ms)9072026/08/27 10:00:55 OK 20241026095416_initial_model.sql (12.98ms)9082026/08/27 10:00:55 OK 20241026095416_initial_model.sql (14.22ms)9092026/08/27 10:00:55 OK 20251218171726_add_pins.sql (4.49ms)9102026/08/27 10:00:55 OK 20251218171726_add_pins.sql (4.49ms)9112026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (3.35ms)9122026/08/27 10:00:55 OK 20251218171726_add_pins.sql (4.34ms)9132026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (4.62ms)9142026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (6.32ms)9152026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200009162026/08/27 10:00:55 OK 20251218171726_add_pins.sql (6.15ms)9172026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (4.42ms)9182026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (4.75ms)9192026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)9202026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (3.12ms)9212026/08/27 10:00:55 OK 20251218171726_add_pins.sql (3.95ms)9222026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (5.64ms)9232026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200009242026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (5.56ms)9252026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200009262026/08/27 10:00:55 OK 20251218171726_add_pins.sql (3.25ms)9272026/08/27 10:00:55 OK 20251218171726_add_pins.sql (4.01ms)9282026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (4.17ms)9292026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200009302026/08/27 10:00:55 OK 1_commit_pending_closure.sql (3.75ms)9312026/08/27 10:00:55 OK 20251218171726_add_pins.sql (4.02ms)9322026/08/27 10:00:55 OK 20251218171726_add_pins.sql (3.69ms)9332026/08/27 10:00:55 OK 20251218171726_add_pins.sql (3.84ms)9342026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (4.33ms)9352026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200009362026/08/27 10:00:55 OK 1_commit_pending_closure.sql (2.92ms)9372026/08/27 10:00:55 OK 1_commit_pending_closure.sql (3.89ms)9382026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)9392026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200009402026/08/27 10:00:55 OK 1_commit_pending_closure.sql (2.72ms)9412026/08/27 10:00:55 OK 2_object_stats_trigger.sql (2.66ms)9422026/08/27 10:00:55 goose: up to current file version: 29432026/08/27 10:00:55 INFO Received uploads request method=POST path=/api/pending_closures9442026/08/27 10:00:55 OK 1_commit_pending_closure.sql (3.07ms)9452026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)9462026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200009472026/08/27 10:00:55 OK 2_object_stats_trigger.sql (1.98ms)9482026/08/27 10:00:55 goose: up to current file version: 29492026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (4.09ms)9502026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200009512026/08/27 10:00:55 OK 2_object_stats_trigger.sql (2.42ms)9522026/08/27 10:00:55 goose: up to current file version: 29532026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (5.13ms)9542026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200009552026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (5.29ms)9562026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200009572026/08/27 10:00:55 OK 2_object_stats_trigger.sql (3ms)9582026/08/27 10:00:55 goose: up to current file version: 29592026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (5.22ms)9602026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200009612026/08/27 10:00:55 OK 1_commit_pending_closure.sql (3.84ms)9622026/08/27 10:00:55 OK 2_object_stats_trigger.sql (2.78ms)9632026/08/27 10:00:55 goose: up to current file version: 29642026/08/27 10:00:55 OK 1_commit_pending_closure.sql (2.57ms)9652026/08/27 10:00:55 OK 1_commit_pending_closure.sql (3.16ms)9662026/08/27 10:00:55 OK 1_commit_pending_closure.sql (2.31ms)9672026/08/27 10:00:55 OK 2_object_stats_trigger.sql (1.55ms)9682026/08/27 10:00:55 goose: up to current file version: 29692026/08/27 10:00:55 OK 2_object_stats_trigger.sql (1.81ms)9702026/08/27 10:00:55 goose: up to current file version: 29712026/08/27 10:00:55 OK 1_commit_pending_closure.sql (2.81ms)9722026/08/27 10:00:55 OK 1_commit_pending_closure.sql (2.6ms)9732026/08/27 10:00:55 OK 2_object_stats_trigger.sql (1.67ms)9742026/08/27 10:00:55 goose: up to current file version: 29752026/08/27 10:00:55 OK 2_object_stats_trigger.sql (1.84ms)9762026/08/27 10:00:55 goose: up to current file version: 29772026/08/27 10:00:55 OK 2_object_stats_trigger.sql (2.7ms)9782026/08/27 10:00:55 goose: up to current file version: 29792026/08/27 10:00:55 OK 2_object_stats_trigger.sql (2.78ms)9802026/08/27 10:00:55 goose: up to current file version: 29812026/08/27 10:00:55 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"982--- PASS: TestService_AuthMiddleware (0.49s)983=== CONT TestGCTaskStore_DeduplicateSameParams984--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)985=== CONT TestServerTLSConfig986=== RUN TestServerTLSConfig/no_client_CA987=== PAUSE TestServerTLSConfig/no_client_CA988=== RUN TestServerTLSConfig/missing_CA_file989=== PAUSE TestServerTLSConfig/missing_CA_file990=== RUN TestServerTLSConfig/not_a_PEM_file991=== PAUSE TestServerTLSConfig/not_a_PEM_file992=== CONT TestService_NativeMTLS9932026/08/27 10:00:55 INFO Received uploads request method=POST path=/api/pending_closures9942026/08/27 10:00:55 INFO Received cleanup request method=DELETE path=/api/pending_closures9952026/08/27 10:00:55 INFO Aborted multipart uploads count=1996--- PASS: TestReadRedirectNar (0.51s)997=== CONT TestMetricsInventory998--- PASS: TestReadProxy404 (0.52s)999=== CONT TestNARDeduplicationMetadataUploadBug1000--- PASS: TestMultipartCleanup (0.53s)1001=== CONT TestCreatePendingClosureRejectsOversizedNAR10022026/08/27 10:00:55 INFO Received uploads request method=POST path=/api/pending_closures1003--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1004=== CONT TestCacheConfigHandlerMaxNarSize1005--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1006=== CONT TestGenerateLandingPage10072026/08/27 10:00:55 INFO Received uploads request method=POST path=/api/pending_closures1008--- PASS: TestGenerateLandingPage (0.01s)1009=== CONT TestService_healthCheckHandler10102026-08-27 10:00:55.870 UTC [1023] ERROR: relation "goose_db_version" does not exist at character 3610112026-08-27 10:00:55.870 UTC [1023] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10122026/08/27 10:00:55 INFO Received uploads request method=POST path=/api/pending_closures1013--- PASS: TestReadProxyNarStreaming (0.55s)1014=== CONT TestGracefulShutdownDrainsInflight10152026/08/27 10:00:55 INFO Starting HTTP server address=127.0.0.1:3448710162026/08/27 10:00:55 OK 20241026095416_initial_model.sql (12.01ms)10172026/08/27 10:00:55 INFO Shutdown signal received, draining in-flight requests timeout=10s10182026-08-27 10:00:55.898 UTC [1027] ERROR: relation "goose_db_version" does not exist at character 3610192026-08-27 10:00:55.898 UTC [1027] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10202026-08-27 10:00:55.899 UTC [1028] ERROR: relation "goose_db_version" does not exist at character 3610212026-08-27 10:00:55.899 UTC [1028] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10222026/08/27 10:00:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10232026/08/27 10:00:55 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10242026/08/27 10:00:55 INFO Received uploads request method=POST path=/api/pending_closures1025--- PASS: TestReadRedirectKeepsNarinfoProxied (0.50s)1026=== CONT TestGCTaskStore_Fail1027--- PASS: TestGCTaskStore_Fail (0.00s)1028=== CONT TestGCTaskStore_PhaseUpdates1029--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)10302026/08/27 10:00:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1031=== CONT TestGCTaskStore_CompletedAllowsNewTask1032--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1033=== CONT TestGCTaskStore_GetReturnsLatest1034--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1035=== CONT TestGCTaskStore_GetEmpty1036--- PASS: TestGCTaskStore_GetEmpty (0.00s)1037=== CONT TestGCTaskStore_ConflictDifferentParams1038--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)10392026/08/27 10:00:55 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzEzMDBmNjMtZDUzNi00ZDc5LThjMmEtNzk0OTZjZTdiNzg4LjI5ZDg4OTg3LTAyMjctNDE5My1iMTU5LWNhNjEzZTdjNmI3M3gxNzg3ODI0ODU1ODc5MDAwMzE21040=== CONT TestService_AuthMiddleware_OIDC10412026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (14.33ms)10422026/08/27 10:00:55 INFO OIDC provider initialized name=test1043--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.58s)1044=== CONT TestClientCADerivations10452026/08/27 10:00:55 OK 20251218171726_add_pins.sql (4.95ms)10462026/08/27 10:00:55 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzEzMDBmNjMtZDUzNi00ZDc5LThjMmEtNzk0OTZjZTdiNzg4LjI5ZDg4OTg3LTAyMjctNDE5My1iMTU5LWNhNjEzZTdjNmI3M3gxNzg3ODI0ODU1ODc5MDAwMzE2 parts=11047--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.51s)1048=== CONT TestCacheStatsHandler1049--- PASS: TestReadProxyNarinfo (0.51s)1050=== CONT TestCacheConfigHandler1051=== RUN TestCacheConfigHandler/full_config,_no_issuer1052=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1053=== RUN TestCacheConfigHandler/no_cache_url_configured1054=== PAUSE TestCacheConfigHandler/no_cache_url_configured1055=== RUN TestCacheConfigHandler/no_signing_keys1056=== PAUSE TestCacheConfigHandler/no_signing_keys1057=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1058=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1059=== CONT TestClientErrorHandling1060=== RUN TestClientErrorHandling/InvalidStorePath1061=== PAUSE TestClientErrorHandling/InvalidStorePath1062=== RUN TestClientErrorHandling/InvalidAuthToken1063=== PAUSE TestClientErrorHandling/InvalidAuthToken1064=== RUN TestClientErrorHandling/ServerNotAvailable1065=== PAUSE TestClientErrorHandling/ServerNotAvailable1066=== CONT TestService_AuthMiddleware_MTLSBoundSubjects10672026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (4.91ms)10682026/08/27 10:00:55 goose: successfully migrated database to version: 2026062812000010692026-08-27 10:00:55.921 UTC [1032] ERROR: relation "goose_db_version" does not exist at character 3610702026-08-27 10:00:55.921 UTC [1032] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10712026-08-27 10:00:55.921 UTC [1031] ERROR: relation "goose_db_version" does not exist at character 3610722026-08-27 10:00:55.921 UTC [1031] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10732026/08/27 10:00:55 OK 20241026095416_initial_model.sql (10.85ms)10742026/08/27 10:00:55 OK 20241026095416_initial_model.sql (11.77ms)10752026/08/27 10:00:55 OK 1_commit_pending_closure.sql (2.81ms)10762026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)10772026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (3.09ms)10782026/08/27 10:00:55 OK 2_object_stats_trigger.sql (2.33ms)10792026/08/27 10:00:55 goose: up to current file version: 210802026/08/27 10:00:55 OK 20251218171726_add_pins.sql (3.65ms)10812026/08/27 10:00:55 OK 20251218171726_add_pins.sql (5.01ms)1082--- PASS: TestReadProxyHead (0.52s)1083=== CONT TestService_ReadAuthMiddleware10842026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (4.85ms)10852026/08/27 10:00:55 goose: successfully migrated database to version: 2026062812000010862026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (5.1ms)10872026/08/27 10:00:55 goose: successfully migrated database to version: 2026062812000010882026/08/27 10:00:55 OK 1_commit_pending_closure.sql (2.61ms)10892026/08/27 10:00:55 OK 20241026095416_initial_model.sql (10.5ms)10902026/08/27 10:00:55 OK 2_object_stats_trigger.sql (3.12ms)10912026/08/27 10:00:55 goose: up to current file version: 210922026/08/27 10:00:55 OK 20241026095416_initial_model.sql (11.95ms)10932026/08/27 10:00:55 OK 1_commit_pending_closure.sql (4.41ms)10942026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (2.8ms)10952026/08/27 10:00:55 OK 2_object_stats_trigger.sql (2.68ms)10962026/08/27 10:00:55 goose: up to current file version: 210972026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (2.95ms)1098--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.53s)1099=== CONT TestGCTaskStore_StartNew1100--- PASS: TestGCTaskStore_StartNew (0.00s)1101=== CONT TestService_AuthMiddleware_MTLSProxyHeader11022026/08/27 10:00:55 OK 20251218171726_add_pins.sql (3.75ms)11032026/08/27 10:00:55 OK 20251218171726_add_pins.sql (3.45ms)11042026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (5.59ms)11052026/08/27 10:00:55 goose: successfully migrated database to version: 2026062812000011062026-08-27 10:00:55.954 UTC [1042] ERROR: relation "goose_db_version" does not exist at character 3611072026-08-27 10:00:55.954 UTC [1042] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11082026-08-27 10:00:55.956 UTC [1044] ERROR: relation "goose_db_version" does not exist at character 3611092026-08-27 10:00:55.956 UTC [1044] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1110--- PASS: TestReadProxyConditionalGet (0.55s)1111=== CONT TestGCMetrics11122026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (15.72ms)11132026/08/27 10:00:55 goose: successfully migrated database to version: 202606281200001114--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1115=== CONT TestGCBugBareHashReferences11162026/08/27 10:00:55 OK 1_commit_pending_closure.sql (15.91ms)1117--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.56s)1118=== CONT TestClientWithDependencies11192026/08/27 10:00:55 OK 1_commit_pending_closure.sql (6.45ms)11202026/08/27 10:00:55 OK 2_object_stats_trigger.sql (3.22ms)11212026/08/27 10:00:55 goose: up to current file version: 211222026/08/27 10:00:55 OK 2_object_stats_trigger.sql (2.73ms)11232026/08/27 10:00:55 goose: up to current file version: 211242026/08/27 10:00:55 INFO Received uploads request method=POST path=/api/pending_closures11252026/08/27 10:00:55 OK 20241026095416_initial_model.sql (9.71ms)11262026/08/27 10:00:55 OK 20241026095416_initial_model.sql (11.3ms)11272026-08-27 10:00:55.981 UTC [1050] ERROR: relation "goose_db_version" does not exist at character 3611282026-08-27 10:00:55.981 UTC [1050] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11292026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (2.88ms)11302026-08-27 10:00:55.982 UTC [1051] ERROR: relation "goose_db_version" does not exist at character 3611312026-08-27 10:00:55.982 UTC [1051] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11322026/08/27 10:00:55 OK 20251210153512_drop_unused_gin_index.sql (2.84ms)11332026/08/27 10:00:55 OK 20251218171726_add_pins.sql (3.55ms)11342026/08/27 10:00:55 OK 20251218171726_add_pins.sql (3.73ms)11352026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (6.74ms)11362026/08/27 10:00:55 goose: successfully migrated database to version: 2026062812000011372026/08/27 10:00:55 OK 20260628120000_add_object_size_and_stats.sql (7.04ms)11382026/08/27 10:00:55 goose: successfully migrated database to version: 2026062812000011392026/08/27 10:00:55 OK 1_commit_pending_closure.sql (3.19ms)11402026/08/27 10:00:55 OK 1_commit_pending_closure.sql (2.92ms)11412026/08/27 10:00:55 INFO Received uploads request method=POST path=/api/pending_closures11422026/08/27 10:00:55 OK 2_object_stats_trigger.sql (3.26ms)11432026/08/27 10:00:55 goose: up to current file version: 211442026/08/27 10:00:56 OK 2_object_stats_trigger.sql (5.82ms)11452026/08/27 10:00:56 goose: up to current file version: 21146--- PASS: TestReadProxyInvalidPath (0.60s)1147=== CONT TestClientMultipleUploads11482026/08/27 10:00:56 OK 20241026095416_initial_model.sql (25.11ms)11492026/08/27 10:00:56 OK 20241026095416_initial_model.sql (25.96ms)11502026/08/27 10:00:56 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)11512026/08/27 10:00:56 OK 20251210153512_drop_unused_gin_index.sql (5.53ms)11522026/08/27 10:00:56 OK 20251218171726_add_pins.sql (4.96ms)11532026/08/27 10:00:56 OK 20251218171726_add_pins.sql (4.87ms)11542026/08/27 10:00:56 OK 20260628120000_add_object_size_and_stats.sql (4.55ms)11552026/08/27 10:00:56 goose: successfully migrated database to version: 2026062812000011562026/08/27 10:00:56 OK 20260628120000_add_object_size_and_stats.sql (5ms)11572026/08/27 10:00:56 goose: successfully migrated database to version: 2026062812000011582026/08/27 10:00:56 OK 1_commit_pending_closure.sql (3.16ms)11592026/08/27 10:00:56 OK 1_commit_pending_closure.sql (4.92ms)11602026/08/27 10:00:56 OK 2_object_stats_trigger.sql (3ms)11612026/08/27 10:00:56 goose: up to current file version: 211622026/08/27 10:00:56 OK 2_object_stats_trigger.sql (3.21ms)11632026/08/27 10:00:56 goose: up to current file version: 21164--- PASS: TestResurrectedObjectNotDeleted (0.63s)1165=== CONT TestClientIntegration11662026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures11672026-08-27 10:00:56.053 UTC [1056] ERROR: relation "goose_db_version" does not exist at character 3611682026-08-27 10:00:56.053 UTC [1056] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11692026-08-27 10:00:56.053 UTC [1055] ERROR: relation "goose_db_version" does not exist at character 3611702026-08-27 10:00:56.053 UTC [1055] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11712026-08-27 10:00:56.054 UTC [1057] ERROR: relation "goose_db_version" does not exist at character 3611722026-08-27 10:00:56.054 UTC [1057] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11732026-08-27 10:00:56.056 UTC [1058] ERROR: relation "goose_db_version" does not exist at character 3611742026-08-27 10:00:56.056 UTC [1058] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11752026-08-27 10:00:56.060 UTC [1061] ERROR: relation "goose_db_version" does not exist at character 3611762026-08-27 10:00:56.060 UTC [1061] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11772026/08/27 10:00:56 OK 20241026095416_initial_model.sql (9.09ms)11782026/08/27 10:00:56 OK 20241026095416_initial_model.sql (10.49ms)11792026/08/27 10:00:56 OK 20241026095416_initial_model.sql (10.67ms)11802026/08/27 10:00:56 OK 20241026095416_initial_model.sql (10.84ms)11812026/08/27 10:00:56 OK 20241026095416_initial_model.sql (10.66ms)11822026/08/27 10:00:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11832026/08/27 10:00:56 OK 20251210153512_drop_unused_gin_index.sql (2.55ms)11842026/08/27 10:00:56 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)11852026/08/27 10:00:56 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)11862026/08/27 10:00:56 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)11872026/08/27 10:00:56 OK 20251210153512_drop_unused_gin_index.sql (2.75ms)11882026/08/27 10:00:56 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1189--- PASS: TestCompleteMultipartUnregistered (0.30s)1190=== CONT TestPinProtectsFromGC11912026/08/27 10:00:56 OK 20251218171726_add_pins.sql (3.3ms)11922026-08-27 10:00:56.085 UTC [1062] ERROR: relation "goose_db_version" does not exist at character 3611932026-08-27 10:00:56.085 UTC [1062] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11942026/08/27 10:00:56 OK 20251218171726_add_pins.sql (3.19ms)11952026/08/27 10:00:56 OK 20251218171726_add_pins.sql (3.2ms)11962026/08/27 10:00:56 OK 20251218171726_add_pins.sql (3.27ms)11972026/08/27 10:00:56 OK 20251218171726_add_pins.sql (3.67ms)11982026/08/27 10:00:56 OK 20260628120000_add_object_size_and_stats.sql (4.13ms)11992026/08/27 10:00:56 goose: successfully migrated database to version: 2026062812000012002026/08/27 10:00:56 OK 20260628120000_add_object_size_and_stats.sql (3.87ms)12012026/08/27 10:00:56 goose: successfully migrated database to version: 2026062812000012022026/08/27 10:00:56 OK 20260628120000_add_object_size_and_stats.sql (4.36ms)12032026/08/27 10:00:56 goose: successfully migrated database to version: 2026062812000012042026/08/27 10:00:56 OK 20260628120000_add_object_size_and_stats.sql (5.25ms)12052026/08/27 10:00:56 goose: successfully migrated database to version: 2026062812000012062026/08/27 10:00:56 OK 20260628120000_add_object_size_and_stats.sql (4.99ms)12072026/08/27 10:00:56 goose: successfully migrated database to version: 2026062812000012082026-08-27 10:00:56.092 UTC [1063] ERROR: relation "goose_db_version" does not exist at character 3612092026-08-27 10:00:56.092 UTC [1063] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12102026/08/27 10:00:56 OK 1_commit_pending_closure.sql (3.27ms)12112026/08/27 10:00:56 OK 1_commit_pending_closure.sql (3.18ms)12122026-08-27 10:00:56.094 UTC [1065] ERROR: relation "goose_db_version" does not exist at character 3612132026-08-27 10:00:56.094 UTC [1065] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12142026/08/27 10:00:56 OK 1_commit_pending_closure.sql (3.02ms)12152026/08/27 10:00:56 OK 1_commit_pending_closure.sql (2.97ms)12162026/08/27 10:00:56 OK 1_commit_pending_closure.sql (3.03ms)12172026/08/27 10:00:56 OK 2_object_stats_trigger.sql (2.09ms)12182026/08/27 10:00:56 goose: up to current file version: 212192026/08/27 10:00:56 OK 2_object_stats_trigger.sql (1.98ms)12202026/08/27 10:00:56 goose: up to current file version: 212212026/08/27 10:00:56 OK 2_object_stats_trigger.sql (1.74ms)12222026/08/27 10:00:56 goose: up to current file version: 212232026/08/27 10:00:56 OK 2_object_stats_trigger.sql (2.12ms)12242026/08/27 10:00:56 goose: up to current file version: 212252026/08/27 10:00:56 OK 2_object_stats_trigger.sql (1.88ms)1226--- PASS: TestObjectStatsTrigger (0.33s)12272026/08/27 10:00:56 goose: up to current file version: 21228=== CONT TestProxyWriteTimeout/narinfo1229=== CONT TestProxyWriteTimeout/unknown_size1230=== CONT TestProxyWriteTimeout/10_GiB_nar1231=== CONT TestProxyWriteTimeout/1_GiB_nar1232--- PASS: TestProxyWriteTimeout (0.00s)1233 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1234 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1235 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1236 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1237=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info12382026/08/27 10:00:56 INFO Received uploads request method=POST path=/1239=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key12402026/08/27 10:00:56 INFO Received complete multipart upload request method=POST path=/1241=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key12422026/08/27 10:00:56 INFO Received request for more parts method=POST path=/1243=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal12442026/08/27 10:00:56 INFO Received uploads request method=POST path=/1245--- PASS: TestUploadHandlersRejectInvalidKeys (0.08s)1246 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1247 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1248 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1249 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1250=== CONT TestIsValidUploadKey/narinfo1251=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1252=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1253=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1254=== CONT TestIsValidUploadKey/index.html1255=== CONT TestIsValidUploadKey/nix-cache-info12562026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures1257=== CONT TestIsValidUploadKey/realisation_plus_in_output1258=== CONT TestIsValidUploadKey/realisation1259=== CONT TestIsValidUploadKey/build_log_equals12602026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures1261=== CONT TestIsValidUploadKey/build_log_question_mark12622026-08-27 10:00:56.099 UTC [1067] ERROR: relation "goose_db_version" does not exist at character 3612632026-08-27 10:00:56.099 UTC [1067] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1264=== CONT TestIsValidUploadKey/build_log_plus_in_name12652026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures1266=== CONT TestIsValidUploadKey/build_log_home-manager_file1267=== CONT TestIsValidUploadKey/build_log1268=== CONT TestIsValidUploadKey/listing1269=== CONT TestIsValidUploadKey/nar_plain1270=== CONT TestIsValidUploadKey/nar_xz1271=== CONT TestIsValidUploadKey/nar_zst1272=== CONT TestIsValidUploadKey/empty_key1273=== CONT TestIsValidUploadKey/traversal1274=== CONT TestIsValidUploadKey/traversal_nar1275=== CONT TestIsValidUploadKey/unknown_type1276=== CONT TestIsValidUploadKey/absolute1277--- PASS: TestIsValidUploadKey (0.08s)1278 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1279 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1280 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1281 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1282 --- PASS: TestIsValidUploadKey/index.html (0.00s)1283 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1284 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1285 --- PASS: TestIsValidUploadKey/realisation (0.00s)1286 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1287 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1288 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1289 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1290 --- PASS: TestIsValidUploadKey/build_log (0.00s)1291 --- PASS: TestIsValidUploadKey/listing (0.00s)1292 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1293 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1294 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1295 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1296 --- PASS: TestIsValidUploadKey/traversal (0.00s)1297 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1298 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1299 --- PASS: TestIsValidUploadKey/absolute (0.00s)1300=== CONT TestIsValidCachePath/narinfo1301=== CONT TestIsValidCachePath/index.html1302=== CONT TestIsValidCachePath/nix-cache-info1303=== CONT TestIsValidCachePath/realisation1304=== CONT TestIsValidCachePath/log1305=== CONT TestIsValidCachePath/ls1306=== CONT TestIsValidCachePath/nar_uncompressed1307=== CONT TestIsValidCachePath/nar_bz21308=== CONT TestIsValidCachePath/nar_xz1309=== CONT TestIsValidCachePath/nar_zst1310=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1311=== CONT TestIsValidCachePath/empty1312=== CONT TestIsValidCachePath/traversal_parent1313=== CONT TestIsValidCachePath/random_path1314=== CONT TestIsValidCachePath/invalid_char_u1315=== CONT TestIsValidCachePath/invalid_char_e1316=== CONT TestIsValidCachePath/traversal_in_middle1317=== CONT TestIsValidCachePath/short_hash1318=== CONT TestIsValidCachePath/leading_slash1319=== CONT TestIsValidCachePath/wrong_extension1320--- PASS: TestIsValidCachePath (0.00s)1321 --- PASS: TestIsValidCachePath/narinfo (0.00s)1322 --- PASS: TestIsValidCachePath/index.html (0.00s)1323 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1324 --- PASS: TestIsValidCachePath/realisation (0.00s)1325 --- PASS: TestIsValidCachePath/log (0.00s)1326 --- PASS: TestIsValidCachePath/ls (0.00s)1327 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1328 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1329 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1330 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1331 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1332 --- PASS: TestIsValidCachePath/empty (0.00s)1333 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1334 --- PASS: TestIsValidCachePath/random_path (0.00s)1335 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1336 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1337 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1338 --- PASS: TestIsValidCachePath/short_hash (0.00s)1339 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1340 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1341=== CONT TestParseSingleRange/none1342=== CONT TestParseSingleRange/open-ended1343=== CONT TestParseSingleRange/start_far_past_EOF1344=== CONT TestParseSingleRange/start_past_EOF1345=== CONT TestParseSingleRange/single_byte1346=== CONT TestParseSingleRange/suffix_exceeds_size1347=== CONT TestParseSingleRange/end_clamped_to_size1348=== CONT TestParseSingleRange/malformed_both_empty1349=== CONT TestParseSingleRange/closed1350=== CONT TestParseSingleRange/suffix1351=== CONT TestParseSingleRange/malformed_end_before_start1352=== CONT TestParseSingleRange/multi-range_ignored1353=== CONT TestParseSingleRange/malformed_no_dash1354=== CONT TestParseSingleRange/unknown_unit1355=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts13562026/08/27 10:00:56 INFO Received request for more parts method=POST path=/1357--- PASS: TestParseSingleRange (0.00s)1358 --- PASS: TestParseSingleRange/none (0.00s)1359 --- PASS: TestParseSingleRange/open-ended (0.00s)1360 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1361 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1362 --- PASS: TestParseSingleRange/single_byte (0.00s)1363 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1364 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1365 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1366 --- PASS: TestParseSingleRange/closed (0.00s)1367 --- PASS: TestParseSingleRange/suffix (0.00s)1368 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1369 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1370 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1371 --- PASS: TestParseSingleRange/unknown_unit (0.00s)13722026/08/27 10:00:56 OK 20241026095416_initial_model.sql (9.32ms)13732026/08/27 10:00:56 OK 20251210153512_drop_unused_gin_index.sql (3.01ms)13742026/08/27 10:00:56 OK 20241026095416_initial_model.sql (9.25ms)13752026/08/27 10:00:56 OK 20241026095416_initial_model.sql (9.38ms)13762026/08/27 10:00:56 OK 20251218171726_add_pins.sql (4.69ms)13772026/08/27 10:00:56 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)13782026/08/27 10:00:56 OK 20251210153512_drop_unused_gin_index.sql (2.6ms)13792026/08/27 10:00:56 OK 20251218171726_add_pins.sql (3.4ms)13802026/08/27 10:00:56 OK 20241026095416_initial_model.sql (9.24ms)13812026/08/27 10:00:56 OK 20260628120000_add_object_size_and_stats.sql (4.14ms)13822026/08/27 10:00:56 goose: successfully migrated database to version: 2026062812000013832026/08/27 10:00:56 OK 20251218171726_add_pins.sql (2.87ms)13842026/08/27 10:00:56 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)13852026/08/27 10:00:56 OK 1_commit_pending_closure.sql (3.17ms)13862026/08/27 10:00:56 OK 20260628120000_add_object_size_and_stats.sql (4.09ms)13872026/08/27 10:00:56 goose: successfully migrated database to version: 2026062812000013882026/08/27 10:00:56 OK 20260628120000_add_object_size_and_stats.sql (4.15ms)13892026/08/27 10:00:56 goose: successfully migrated database to version: 2026062812000013902026/08/27 10:00:56 OK 2_object_stats_trigger.sql (2.14ms)13912026/08/27 10:00:56 goose: up to current file version: 213922026/08/27 10:00:56 OK 20251218171726_add_pins.sql (4.23ms)13932026/08/27 10:00:56 OK 1_commit_pending_closure.sql (3.11ms)13942026/08/27 10:00:56 OK 1_commit_pending_closure.sql (2.19ms)13952026-08-27 10:00:56.124 UTC [1068] ERROR: relation "goose_db_version" does not exist at character 3613962026-08-27 10:00:56.124 UTC [1068] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13972026/08/27 10:00:56 OK 2_object_stats_trigger.sql (2.75ms)13982026/08/27 10:00:56 goose: up to current file version: 213992026/08/27 10:00:56 OK 2_object_stats_trigger.sql (2.81ms)14002026/08/27 10:00:56 goose: up to current file version: 214012026/08/27 10:00:56 OK 20260628120000_add_object_size_and_stats.sql (4.72ms)14022026/08/27 10:00:56 goose: successfully migrated database to version: 2026062812000014032026/08/27 10:00:56 OK 1_commit_pending_closure.sql (2.11ms)14042026/08/27 10:00:56 OK 2_object_stats_trigger.sql (1.8ms)14052026/08/27 10:00:56 goose: up to current file version: 214062026/08/27 10:00:56 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14072026/08/27 10:00:56 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1408--- PASS: TestService_NativeMTLS (0.32s)1409=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14102026/08/27 10:00:56 INFO Received complete multipart upload request method=POST path=/1411--- PASS: TestMetricsInventory (0.29s)1412=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14132026/08/27 10:00:56 INFO Received uploads request method=POST path=/14142026/08/27 10:00:56 OK 20241026095416_initial_model.sql (9.57ms)14152026/08/27 10:00:56 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)14162026/08/27 10:00:56 OK 20251218171726_add_pins.sql (3.28ms)1417--- PASS: TestService_healthCheckHandler (0.28s)1418=== CONT TestServerTLSConfig/no_client_CA1419=== CONT TestServerTLSConfig/not_a_PEM_file1420=== CONT TestServerTLSConfig/missing_CA_file1421--- PASS: TestServerTLSConfig (0.00s)1422 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1423 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1424 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1425=== CONT TestCacheConfigHandler/full_config,_no_issuer1426=== CONT TestCacheConfigHandler/no_signing_keys1427=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1428=== CONT TestCacheConfigHandler/no_cache_url_configured1429--- PASS: TestCacheConfigHandler (0.00s)1430 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1431 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1432 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1433 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1434=== CONT TestClientErrorHandling/InvalidStorePath14352026/08/27 10:00:56 OK 20260628120000_add_object_size_and_stats.sql (13.93ms)14362026/08/27 10:00:56 goose: successfully migrated database to version: 2026062812000014372026/08/27 10:00:56 OK 1_commit_pending_closure.sql (2.41ms)14382026/08/27 10:00:56 OK 2_object_stats_trigger.sql (1.76ms)14392026/08/27 10:00:56 goose: up to current file version: 21440=== CONT TestClientErrorHandling/ServerNotAvailable14412026-08-27 10:00:56.173 UTC [1071] ERROR: relation "goose_db_version" does not exist at character 3614422026-08-27 10:00:56.173 UTC [1071] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14432026/08/27 10:00:56 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1444--- PASS: TestService_ReadAuthMiddleware (0.25s)1445=== CONT TestClientErrorHandling/InvalidAuthToken14462026/08/27 10:00:56 OK 20241026095416_initial_model.sql (9.27ms)14472026/08/27 10:00:56 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)14482026-08-27 10:00:56.194 UTC [1076] ERROR: relation "goose_db_version" does not exist at character 3614492026-08-27 10:00:56.194 UTC [1076] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14502026/08/27 10:00:56 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14512026/08/27 10:00:56 WARN mTLS auth: bound subjects configured but subject DN unavailable14522026/08/27 10:00:56 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1453--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.27s)14542026/08/27 10:00:56 OK 20251218171726_add_pins.sql (4.55ms)14552026/08/27 10:00:56 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)14562026/08/27 10:00:56 goose: successfully migrated database to version: 2026062812000014572026/08/27 10:00:56 OK 1_commit_pending_closure.sql (2.43ms)14582026/08/27 10:00:56 OK 2_object_stats_trigger.sql (1.66ms)14592026/08/27 10:00:56 goose: up to current file version: 214602026/08/27 10:00:56 OK 20241026095416_initial_model.sql (8.22ms)1461=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1462=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1463=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1464=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected14652026/08/27 10:00:56 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)1466=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1467=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1468=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1469=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1470=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1471=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1472=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured14732026/08/27 10:00:56 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1474=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected14752026/08/27 10:00:56 OK 20251218171726_add_pins.sql (2.72ms)1476=== NAME TestNARDeduplicationMetadataUploadBug1477 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3568504857/001/store/kpqkjykwi1s018r9zfb765p22r16qyy5-file1.txt14782026/08/27 10:00:56 INFO OIDC auth successful provider=test14792026/08/27 10:00:56 WARN Authentication failed token_preview=eyJhbGciOi...WOeTMzAaIg token_length=702 oidc_error="bound claims validation failed: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1480--- PASS: TestService_AuthMiddleware_OIDC (0.30s)1481 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1482 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1483 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1484 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)14852026/08/27 10:00:56 OK 20260628120000_add_object_size_and_stats.sql (3.93ms)14862026/08/27 10:00:56 goose: successfully migrated database to version: 2026062812000014872026/08/27 10:00:56 OK 1_commit_pending_closure.sql (2.6ms)14882026/08/27 10:00:56 OK 2_object_stats_trigger.sql (1.39ms)14892026/08/27 10:00:56 goose: up to current file version: 21490--- PASS: TestCacheStatsHandler (0.32s)1491--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.30s)14922026-08-27 10:00:56.255 UTC [1146] ERROR: relation "goose_db_version" does not exist at character 3614932026-08-27 10:00:56.255 UTC [1146] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14942026/08/27 10:00:56 OK 20241026095416_initial_model.sql (7.76ms)14952026/08/27 10:00:56 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)14962026/08/27 10:00:56 OK 20251218171726_add_pins.sql (1.87ms)14972026/08/27 10:00:56 OK 20260628120000_add_object_size_and_stats.sql (2.99ms)14982026/08/27 10:00:56 goose: successfully migrated database to version: 2026062812000014992026/08/27 10:00:56 OK 1_commit_pending_closure.sql (2.42ms)15002026/08/27 10:00:56 OK 2_object_stats_trigger.sql (631.48µs)15012026/08/27 10:00:56 goose: up to current file version: 215022026/08/27 10:00:56 INFO Aborted multipart uploads count=015032026/08/27 10:00:56 WARN Force mode enabled - objects will be deleted immediately without grace period15042026-08-27 10:00:56.286 UTC [1168] ERROR: relation "goose_db_version" does not exist at character 3615052026-08-27 10:00:56.286 UTC [1168] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15062026/08/27 10:00:56 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=015072026/08/27 10:00:56 INFO Vacuumed table table=pending_closures15082026/08/27 10:00:56 INFO Vacuumed table table=pending_objects15092026/08/27 10:00:56 INFO Vacuumed table table=multipart_uploads15102026/08/27 10:00:56 INFO Vacuumed table table=closures15112026/08/27 10:00:56 INFO Vacuumed table table=objects15122026/08/27 10:00:56 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-config15132026/08/27 10:00:56 OK 20241026095416_initial_model.sql (7.72ms)1514--- PASS: TestGCMetrics (0.34s)15152026/08/27 10:00:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15162026/08/27 10:00:56 OK 20251210153512_drop_unused_gin_index.sql (1.51ms)15172026/08/27 10:00:56 OK 20251218171726_add_pins.sql (2.3ms)15182026/08/27 10:00:56 OK 20260628120000_add_object_size_and_stats.sql (2.49ms)15192026/08/27 10:00:56 goose: successfully migrated database to version: 2026062812000015202026/08/27 10:00:56 OK 1_commit_pending_closure.sql (1.35ms)15212026/08/27 10:00:56 OK 2_object_stats_trigger.sql (666.49µs)15222026/08/27 10:00:56 goose: up to current file version: 21523=== NAME TestClientCADerivations1524 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4283904179/001/store/2x63hailf3g7y3kl6fk3181jk85fnsw8-ca-test1525=== NAME TestClientMultipleUploads1526 client_integration_test.go:338: Created store path 0: /build/TestClientMultipleUploads1118248051/001/store/vqk8060661ik9d98zw0f5gakcnalj4wi-test-file-0.txt15272026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures1528=== NAME TestOrphanedObjectsGC1529 orphaned_objects_gc_test.go:290: GC Test Summary:1530 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1531 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1532 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1533 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1534 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1535--- PASS: TestOrphanedObjectsGC (0.62s)15362026/08/27 10:00:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15372026/08/27 10:00:56 INFO Uploading kpqkjykwi1s018r9zfb765p22r16qyy5-file1.txt (160B)1538=== NAME TestClientIntegration1539 client_integration_test.go:276: Created store path: /build/TestClientIntegration568463770/002/store/934aqxslqd26xrzpq3yvrxqm12hhrww1-test-file.txt15402026/08/27 10:00:56 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15412026/08/27 10:00:56 WARN Failed to register uploaded object key=kpqkjykwi1s018r9zfb765p22r16qyy5.ls error="server returned 404: 404 page not found\n"15422026/08/27 10:00:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15432026/08/27 10:00:56 INFO Signed narinfos id=1 count=115442026/08/27 10:00:56 INFO Uploading 1 narinfos15452026/08/27 10:00:56 WARN Failed to register uploaded object key=kpqkjykwi1s018r9zfb765p22r16qyy5.narinfo error="server returned 404: 404 page not found\n"1546=== NAME TestClientCADerivations1547 client_ca_test.go:139: Found 1 dependencies (including self)15482026/08/27 10:00:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15492026/08/27 10:00:56 INFO Completed upload id=115502026/08/27 10:00:56 INFO Upload complete. (112ms)1551=== NAME TestNARDeduplicationMetadataUploadBug1552 metadata_upload_test.go:54: Retrieved narinfo from S3:1553 StorePath: /build/TestNARDeduplicationMetadataUploadBug3568504857/001/store/kpqkjykwi1s018r9zfb765p22r16qyy5-file1.txt1554 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1555 Compression: zstd1556 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1557 NarSize: 1601558 References: 1559 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1560 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1561 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1562 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1563=== NAME TestClientWithDependencies1564 client_integration_test.go:593: Built derivation: /build/TestClientWithDependencies3873704416/001/store/26n23bgcz0m87v7zha15vpiwz5si3c71-test-script15652026/08/27 10:00:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1566=== NAME TestPinProtectsFromGC1567 client_integration_test.go:646: Pinned store path: /build/TestPinProtectsFromGC923307288/001/store/p18ps30m1pjn647s19mc29f8xy2l5li2-pinned-file.txt1568 client_integration_test.go:647: Unpinned store path: /build/TestPinProtectsFromGC923307288/001/store/vwjwx45876rsxavdnq7vlx9ry3vy10yh-unpinned-file.txt15692026/08/27 10:00:56 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YzEzMDBmNjMtZDUzNi00ZDc5LThjMmEtNzk0OTZjZTdiNzg4LjZhMzBmZDQ4LTI2YjMtNGYyMi04Yjc5LTgxOGI4MDQ2YWMyNngxNzg3ODI0ODU1ODUxMTExMzA4 parts=121570=== NAME TestClientMultipleUploads1571 client_integration_test.go:338: Created store path 1: /build/TestClientMultipleUploads1118248051/001/store/pn2rsw8pxdjybi0jbgkfda3cf3k92bhk-test-file-1.txt15722026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures15732026/08/27 10:00:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=199.813165ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1574--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.06s)1575=== NAME TestNARDeduplicationMetadataUploadBug1576 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3568504857/001/store/hawzv45960jhc48fq0j4aw7fz5cmv193-file2.txt1577=== NAME TestClientWithDependencies1578 client_integration_test.go:595: Found 1 dependencies (including self)15792026/08/27 10:00:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15802026/08/27 10:00:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1581=== NAME TestClientMultipleUploads1582 client_integration_test.go:338: Created store path 2: /build/TestClientMultipleUploads1118248051/001/store/805xz8rnzjssngrsdkhqh348parkap2z-test-file-2.txt15832026/08/27 10:00:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15842026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures15852026/08/27 10:00:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15862026/08/27 10:00:56 INFO Uploading 934aqxslqd26xrzpq3yvrxqm12hhrww1-test-file.txt (152B)15872026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures15882026/08/27 10:00:56 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15892026/08/27 10:00:56 WARN Failed to register uploaded object key=934aqxslqd26xrzpq3yvrxqm12hhrww1.ls error="server returned 404: 404 page not found\n"15902026/08/27 10:00:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15912026/08/27 10:00:56 INFO Signed narinfos id=1 count=115922026/08/27 10:00:56 INFO Uploading 1 narinfos15932026/08/27 10:00:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15942026/08/27 10:00:56 INFO Uploading 2x63hailf3g7y3kl6fk3181jk85fnsw8-ca-test (144B)15952026/08/27 10:00:56 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15962026/08/27 10:00:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15972026/08/27 10:00:56 WARN Failed to register uploaded object key=log/qqfkz04blm8msiqj7pm3j5vyc1mgrmas-ca-test.drv error="server returned 404: 404 page not found\n"15982026/08/27 10:00:56 WARN Failed to register uploaded object key=934aqxslqd26xrzpq3yvrxqm12hhrww1.narinfo error="server returned 404: 404 page not found\n"15992026/08/27 10:00:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16002026/08/27 10:00:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16012026/08/27 10:00:56 WARN Failed to register uploaded object key=2x63hailf3g7y3kl6fk3181jk85fnsw8.ls error="server returned 404: 404 page not found\n"16022026/08/27 10:00:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16032026/08/27 10:00:56 INFO Signed narinfos id=1 count=116042026/08/27 10:00:56 INFO Uploading 1 narinfos16052026/08/27 10:00:56 INFO Completed upload id=116062026/08/27 10:00:56 INFO Upload complete. (87ms)1607=== NAME TestClientIntegration1608 client_integration_test.go:292: Retrieved narinfo from S3:1609 StorePath: /build/TestClientIntegration568463770/002/store/934aqxslqd26xrzpq3yvrxqm12hhrww1-test-file.txt1610 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1611 Compression: zstd1612 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11613 NarSize: 1521614 References: 1615 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk116162026/08/27 10:00:56 WARN Failed to register uploaded object key=2x63hailf3g7y3kl6fk3181jk85fnsw8.narinfo error="server returned 404: 404 page not found\n"16172026/08/27 10:00:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1618 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1619 client_integration_test.go:293: Decompressed .ls content (64 bytes):1620 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1621 client_integration_test.go:296: Testing garbage collection...16222026/08/27 10:00:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16232026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures16242026/08/27 10:00:56 INFO Completed upload id=116252026/08/27 10:00:56 INFO Upload complete. (84ms)16262026/08/27 10:00:56 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1627=== NAME TestClientCADerivations1628 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4283904179/001/store/2x63hailf3g7y3kl6fk3181jk85fnsw8-ca-test1629 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1630 Compression: zstd1631 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n16322026/08/27 10:00:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1633 NarSize: 14416342026/08/27 10:00:56 INFO Uploading 26n23bgcz0m87v7zha15vpiwz5si3c71-test-script (136B)1635 References: 1636 Deriver: /build/TestClientCADerivations4283904179/001/store/qqfkz04blm8msiqj7pm3j5vyc1mgrmas-ca-test.drv1637 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1638 client_ca_test.go:185: Checking for realisation files in S3...1639 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1640 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16412026/08/27 10:00:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1642--- PASS: TestGCBugBareHashReferences (0.52s)16432026/08/27 10:00:56 WARN Failed to register uploaded object key=log/hm7b29dr0zni6sbagspkgmjq8ss4ficq-test-script.drv error="server returned 404: 404 page not found\n"16442026/08/27 10:00:56 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16452026/08/27 10:00:56 WARN Failed to register uploaded object key=26n23bgcz0m87v7zha15vpiwz5si3c71.ls error="server returned 404: 404 page not found\n"16462026/08/27 10:00:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16472026/08/27 10:00:56 INFO Signed narinfos id=1 count=116482026/08/27 10:00:56 INFO Uploading 1 narinfos16492026/08/27 10:00:56 WARN Failed to register uploaded object key=26n23bgcz0m87v7zha15vpiwz5si3c71.narinfo error="server returned 404: 404 page not found\n"16502026/08/27 10:00:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16512026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures16522026/08/27 10:00:56 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YzEzMDBmNjMtZDUzNi00ZDc5LThjMmEtNzk0OTZjZTdiNzg4LmFlZGY2ZjE0LWMwNDYtNGZlNy05NmEzLWFjOGQyMzBjZGMzM3gxNzg3ODI0ODU2MDcwMTg4MDgw parts=1016532026/08/27 10:00:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16542026/08/27 10:00:56 INFO Completed upload id=116552026/08/27 10:00:56 INFO Upload complete. (56ms)16562026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures16572026/08/27 10:00:56 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1658=== NAME TestClientWithDependencies1659 client_integration_test.go:597: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3873704416/001/store) requires matching store prefix16602026/08/27 10:00:56 INFO Completed upload id=116612026/08/27 10:00:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16622026/08/27 10:00:56 WARN Failed to register uploaded object key=hawzv45960jhc48fq0j4aw7fz5cmv193.ls error="server returned 404: 404 page not found\n"16632026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures16642026/08/27 10:00:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16652026/08/27 10:00:56 INFO Signed narinfos id=2 count=116662026/08/27 10:00:56 INFO Uploading 1 narinfos16672026/08/27 10:00:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures16682026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures16692026/08/27 10:00:56 INFO Garbage collection started16702026/08/27 10:00:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16712026/08/27 10:00:56 INFO Uploading p18ps30m1pjn647s19mc29f8xy2l5li2-pinned-file.txt (128B)1672--- PASS: TestClientWithDependencies (0.53s)16732026/08/27 10:00:56 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16742026/08/27 10:00:56 WARN Found objects in DB but missing from S3, will re-upload count=11675--- PASS: TestService_verifyS3Integrity (0.74s)16762026/08/27 10:00:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16772026/08/27 10:00:56 WARN Failed to register uploaded object key=hawzv45960jhc48fq0j4aw7fz5cmv193.narinfo error="server returned 404: 404 page not found\n"16782026/08/27 10:00:56 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16792026/08/27 10:00:56 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16802026/08/27 10:00:56 INFO Aborted multipart uploads count=016812026/08/27 10:00:56 INFO Completed upload id=216822026/08/27 10:00:56 INFO Upload complete. (76ms)1683=== NAME TestNARDeduplicationMetadataUploadBug1684 metadata_upload_test.go:76: Retrieved narinfo from S3:1685 StorePath: /build/TestNARDeduplicationMetadataUploadBug3568504857/001/store/hawzv45960jhc48fq0j4aw7fz5cmv193-file2.txt1686 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst16872026/08/27 10:00:56 WARN Failed to register uploaded object key=p18ps30m1pjn647s19mc29f8xy2l5li2.ls error="server returned 404: 404 page not found\n"1688 Compression: zstd1689 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1690 NarSize: 16016912026/08/27 10:00:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1692 References: 1693 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf16942026/08/27 10:00:56 WARN Force mode enabled - objects will be deleted immediately without grace period16952026/08/27 10:00:56 INFO Signed narinfos id=1 count=116962026/08/27 10:00:56 INFO Uploading 1 narinfos1697 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1698 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1699 {"version":1,"root":{"type":"regular","size":44}}17002026/08/27 10:00:56 WARN Failed to register uploaded object key=p18ps30m1pjn647s19mc29f8xy2l5li2.narinfo error="server returned 404: 404 page not found\n"17012026/08/27 10:00:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1702--- PASS: TestNARDeduplicationMetadataUploadBug (0.67s)17032026/08/27 10:00:56 INFO Completed upload id=117042026/08/27 10:00:56 INFO Upload complete. (96ms)17052026/08/27 10:00:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17062026/08/27 10:00:56 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YzEzMDBmNjMtZDUzNi00ZDc5LThjMmEtNzk0OTZjZTdiNzg4LjVkNGY4MDQxLTdhN2QtNDFkZi05YjMxLTYwZDUxZTNjNWI0YngxNzg3ODI0ODU1OTkxMjgzMzk2 parts=121707--- PASS: TestRedundantMultipartUpload (1.12s)17082026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures17092026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures17102026/08/27 10:00:56 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YzEzMDBmNjMtZDUzNi00ZDc5LThjMmEtNzk0OTZjZTdiNzg4Ljk0ZjZhOTcyLWYzYjQtNDA0YS1iNDVjLTNjYjZmZWIzYzUxYXgxNzg3ODI0ODU2MTEyMTMwOTU2 parts=1017112026/08/27 10:00:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17122026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures17132026/08/27 10:00:56 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17142026/08/27 10:00:56 INFO Uploading pn2rsw8pxdjybi0jbgkfda3cf3k92bhk-test-file-1.txt (160B)17152026/08/27 10:00:56 INFO Uploading 805xz8rnzjssngrsdkhqh348parkap2z-test-file-2.txt (160B)17162026/08/27 10:00:56 INFO Uploading vqk8060661ik9d98zw0f5gakcnalj4wi-test-file-0.txt (160B)17172026/08/27 10:00:56 INFO Completed upload id=117182026/08/27 10:00:56 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000017192026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures17202026/08/27 10:00:56 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17212026/08/27 10:00:56 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17222026/08/27 10:00:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures17232026/08/27 10:00:56 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17242026/08/27 10:00:56 WARN Failed to register uploaded object key=pn2rsw8pxdjybi0jbgkfda3cf3k92bhk.ls error="server returned 404: 404 page not found\n"17252026/08/27 10:00:56 WARN Failed to register uploaded object key=vqk8060661ik9d98zw0f5gakcnalj4wi.ls error="server returned 404: 404 page not found\n"17262026/08/27 10:00:56 WARN Failed to register uploaded object key=805xz8rnzjssngrsdkhqh348parkap2z.ls error="server returned 404: 404 page not found\n"17272026/08/27 10:00:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign17282026/08/27 10:00:56 INFO Signed narinfos id=3 count=117292026/08/27 10:00:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17302026/08/27 10:00:56 INFO Signed narinfos id=1 count=117312026/08/27 10:00:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17322026/08/27 10:00:56 INFO Signed narinfos id=2 count=117332026/08/27 10:00:56 INFO Uploading 3 narinfos17342026/08/27 10:00:56 WARN Failed to register uploaded object key=pn2rsw8pxdjybi0jbgkfda3cf3k92bhk.narinfo error="server returned 404: 404 page not found\n"17352026/08/27 10:00:56 WARN Failed to register uploaded object key=vqk8060661ik9d98zw0f5gakcnalj4wi.narinfo error="server returned 404: 404 page not found\n"17362026/08/27 10:00:56 WARN Failed to register uploaded object key=805xz8rnzjssngrsdkhqh348parkap2z.narinfo error="server returned 404: 404 page not found\n"17372026/08/27 10:00:56 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete17382026/08/27 10:00:56 INFO Aborted multipart uploads count=017392026/08/27 10:00:56 INFO Completed upload id=317402026/08/27 10:00:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17412026/08/27 10:00:56 INFO Completed upload id=117422026/08/27 10:00:56 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17432026/08/27 10:00:56 INFO Completed upload id=217442026/08/27 10:00:56 INFO Upload complete. (93ms)1745=== NAME TestClientMultipleUploads1746 client_integration_test.go:349: Uploaded 3 paths in 123.965359ms17472026/08/27 10:00:56 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=017482026/08/27 10:00:56 INFO Vacuumed table table=pending_closures17492026/08/27 10:00:56 INFO Vacuumed table table=pending_objects17502026/08/27 10:00:56 INFO Vacuumed table table=multipart_uploads1751--- PASS: TestClientMultipleUploads (0.56s)17522026/08/27 10:00:56 INFO Vacuumed table table=closures17532026/08/27 10:00:56 INFO Vacuumed table table=objects17542026/08/27 10:00:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17552026/08/27 10:00:56 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=361.409093ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17562026/08/27 10:00:56 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001757--- PASS: TestService_createPendingClosureHandler (0.82s)17582026/08/27 10:00:56 INFO Received uploads request method=POST path=/api/pending_closures17592026/08/27 10:00:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17602026/08/27 10:00:56 INFO Uploading vwjwx45876rsxavdnq7vlx9ry3vy10yh-unpinned-file.txt (128B)17612026/08/27 10:00:56 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"1762=== NAME TestClientCADerivations1763 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1764 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1765 error: binary cache 's3://bucket39?endpoint=http://localhost:33981®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4283904179/001/store'1766 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117672026/08/27 10:00:56 WARN Failed to register uploaded object key=vwjwx45876rsxavdnq7vlx9ry3vy10yh.ls error="server returned 404: 404 page not found\n"17682026/08/27 10:00:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17692026/08/27 10:00:56 INFO Signed narinfos id=2 count=117702026/08/27 10:00:56 INFO Uploading 1 narinfos17712026/08/27 10:00:56 WARN Failed to register uploaded object key=vwjwx45876rsxavdnq7vlx9ry3vy10yh.narinfo error="server returned 404: 404 page not found\n"1772--- PASS: TestClientCADerivations (0.72s)17732026/08/27 10:00:56 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17742026/08/27 10:00:56 INFO Completed upload id=217752026/08/27 10:00:56 INFO Upload complete. (76ms)17762026/08/27 10:00:56 INFO Received create pin request method=POST path=/api/pins/myapp17772026/08/27 10:00:56 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC923307288/001/store/p18ps30m1pjn647s19mc29f8xy2l5li2-pinned-file.txt narinfo_key=p18ps30m1pjn647s19mc29f8xy2l5li2.narinfo17782026/08/27 10:00:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures17792026/08/27 10:00:56 INFO Garbage collection started17802026/08/27 10:00:56 INFO Aborted multipart uploads count=017812026/08/27 10:00:56 WARN Force mode enabled - objects will be deleted immediately without grace period1782--- PASS: TestUploadHandlersRejectOversizedBody (0.18s)1783 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)1784 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1785 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.70s)17862026/08/27 10:00:56 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=017872026/08/27 10:00:56 INFO Vacuumed table table=pending_closures17882026/08/27 10:00:56 INFO Vacuumed table table=pending_objects17892026/08/27 10:00:56 INFO Vacuumed table table=multipart_uploads17902026/08/27 10:00:56 INFO Vacuumed table table=closures17912026/08/27 10:00:56 INFO Vacuumed table table=objects17922026/08/27 10:00:56 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=807.048395ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17932026/08/27 10:00:57 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=017942026/08/27 10:00:57 INFO Vacuumed table table=pending_closures17952026/08/27 10:00:57 INFO Vacuumed table table=pending_objects17962026/08/27 10:00:57 INFO Vacuumed table table=multipart_uploads17972026/08/27 10:00:57 INFO Vacuumed table table=closures17982026/08/27 10:00:57 INFO Vacuumed table table=objects1799=== NAME TestOrphanedObjectsGCStressTest1800 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1801 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1802 orphaned_objects_gc_test.go:509: Stress test completed successfully:1803 orphaned_objects_gc_test.go:510: - Active objects preserved: 201804 orphaned_objects_gc_test.go:511: - Objects deleted: 2101805 orphaned_objects_gc_test.go:512: - Total GC'd: 2101806--- PASS: TestOrphanedObjectsGCStressTest (1.95s)18072026/08/27 10:00:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.710197846s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18082026/08/27 10:00:58 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01809=== NAME TestClientIntegration1810 client_integration_test.go:303: Objects in database after GC:1811 client_integration_test.go:303: Successfully deleted all objects with GC --force1812--- PASS: TestClientIntegration (2.46s)18132026/08/27 10:00:58 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01814=== NAME TestPinProtectsFromGC1815 client_integration_test.go:709: Pin successfully protected closure from garbage collection1816--- PASS: TestPinProtectsFromGC (2.60s)18172026/08/27 10:00:59 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"18182026/08/27 10:00:59 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_closures18192026/08/27 10:00:59 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.645511ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18202026/08/27 10:00:59 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=400.846345ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18212026/08/27 10:01:00 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=798.488076ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18222026/08/27 10:01:00 WARN Rate limiter enabled after throttle name=s3-test rate=518232026/08/27 10:01:00 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1824=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1825 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101826 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001827--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.18s)18282026/08/27 10:01:01 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.726876913s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1829--- PASS: TestClientErrorHandling (0.00s)1830 --- PASS: TestClientErrorHandling/InvalidStorePath (0.21s)1831 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.30s)1832 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.57s)1833PASS1834{"timestamp":"2026-08-27T10:01:02.742450295Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:41788","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(583)"}18352026-08-27 10:01:02.946 UTC [112] LOG: received smart shutdown request18362026-08-27 10:01:02.950 UTC [112] LOG: background worker "logical replication launcher" (PID 122) exited with exit code 118372026-08-27 10:01:02.956 UTC [117] LOG: shutting down18382026-08-27 10:01:02.957 UTC [117] LOG: checkpoint starting: shutdown immediate18392026-08-27 10:01:04.108 UTC [117] LOG: checkpoint complete: wrote 11321 buffers (69.1%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 13 recycled; write=0.267 s, sync=0.872 s, total=1.152 s; sync files=15825, longest=0.002 s, average=0.001 s; distance=217983 kB, estimate=217983 kB; lsn=0/EC43AA8, redo lsn=0/EC43AA818402026-08-27 10:01:04.193 UTC [112] LOG: database system is shut down1841Running OIDC tests...1842=== RUN TestGlobMatch1843=== PAUSE TestGlobMatch1844=== RUN TestAudienceForIssuer1845=== PAUSE TestAudienceForIssuer1846=== RUN TestValidateToken_ValidToken1847=== PAUSE TestValidateToken_ValidToken1848=== RUN TestValidateToken_WrongAudience1849=== PAUSE TestValidateToken_WrongAudience1850=== RUN TestValidateToken_Expired1851=== PAUSE TestValidateToken_Expired1852=== RUN TestValidateToken_BoundClaimsMismatch1853=== PAUSE TestValidateToken_BoundClaimsMismatch1854=== RUN TestValidateToken_BoundSubjectMismatch1855=== PAUSE TestValidateToken_BoundSubjectMismatch1856=== RUN TestValidateToken_MultipleProviders1857=== PAUSE TestValidateToken_MultipleProviders1858=== RUN TestValidateToken_NoMatchingProvider1859=== PAUSE TestValidateToken_NoMatchingProvider1860=== CONT TestGlobMatch1861=== CONT TestValidateToken_BoundClaimsMismatch1862=== CONT TestValidateToken_Expired1863=== RUN TestGlobMatch/foo_foo1864=== PAUSE TestGlobMatch/foo_foo1865=== CONT TestValidateToken_ValidToken1866=== CONT TestAudienceForIssuer1867--- PASS: TestAudienceForIssuer (0.00s)1868=== CONT TestValidateToken_MultipleProviders1869=== CONT TestValidateToken_NoMatchingProvider1870=== CONT TestValidateToken_BoundSubjectMismatch1871=== CONT TestValidateToken_WrongAudience1872=== RUN TestGlobMatch/foo_bar1873=== PAUSE TestGlobMatch/foo_bar1874=== RUN TestGlobMatch/*_1875=== PAUSE TestGlobMatch/*_1876=== RUN TestGlobMatch/*_anything1877=== PAUSE TestGlobMatch/*_anything1878=== RUN TestGlobMatch/foo*_foo1879=== PAUSE TestGlobMatch/foo*_foo1880=== RUN TestGlobMatch/foo*_foobar1881=== PAUSE TestGlobMatch/foo*_foobar1882=== RUN TestGlobMatch/foo*_bar1883=== PAUSE TestGlobMatch/foo*_bar1884=== RUN TestGlobMatch/*bar_bar1885=== PAUSE TestGlobMatch/*bar_bar1886=== RUN TestGlobMatch/*bar_foobar1887=== PAUSE TestGlobMatch/*bar_foobar1888=== RUN TestGlobMatch/*bar_foo1889=== PAUSE TestGlobMatch/*bar_foo1890=== RUN TestGlobMatch/foo*bar_foobar1891=== PAUSE TestGlobMatch/foo*bar_foobar1892=== RUN TestGlobMatch/foo*bar_foo123bar1893=== PAUSE TestGlobMatch/foo*bar_foo123bar1894=== RUN TestGlobMatch/foo*bar_foobarbaz1895=== PAUSE TestGlobMatch/foo*bar_foobarbaz1896=== RUN TestGlobMatch/*/*_foo/bar1897=== PAUSE TestGlobMatch/*/*_foo/bar1898=== RUN TestGlobMatch/*/*_foo1899=== PAUSE TestGlobMatch/*/*_foo1900=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1901=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1902=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01903=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01904=== RUN TestGlobMatch/refs/*/main_refs/heads/main1905=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1906=== RUN TestGlobMatch/fo?_foo1907=== PAUSE TestGlobMatch/fo?_foo1908=== RUN TestGlobMatch/fo?_fo1909=== PAUSE TestGlobMatch/fo?_fo1910=== RUN TestGlobMatch/fo?_fooo1911=== PAUSE TestGlobMatch/fo?_fooo1912=== RUN TestGlobMatch/?oo_foo1913=== PAUSE TestGlobMatch/?oo_foo1914=== RUN TestGlobMatch/?oo_boo1915=== PAUSE TestGlobMatch/?oo_boo1916=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1917=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1918=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1919=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1920=== CONT TestGlobMatch/foo_foo1921=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1922=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1923=== CONT TestGlobMatch/foo*bar_foobarbaz1924=== CONT TestGlobMatch/?oo_foo1925=== CONT TestGlobMatch/*/*_foo/bar1926=== CONT TestGlobMatch/foo*bar_foo123bar19272026/08/27 10:01:05 INFO OIDC provider initialized name=test1928=== CONT TestGlobMatch/foo*bar_foobar19292026/08/27 10:01:05 INFO OIDC provider initialized name=test1930=== CONT TestGlobMatch/*/*_foo1931=== CONT TestGlobMatch/*bar_foo1932=== CONT TestGlobMatch/foo*_foo1933=== CONT TestGlobMatch/*_anything1934=== CONT TestGlobMatch/foo*_foobar19352026/08/27 10:01:05 INFO OIDC provider initialized name=test1936=== CONT TestGlobMatch/*_1937=== CONT TestGlobMatch/*bar_foobar1938=== CONT TestGlobMatch/*bar_bar1939=== CONT TestGlobMatch/foo_bar1940=== CONT TestGlobMatch/foo*_bar19412026/08/27 10:01:05 INFO OIDC provider initialized name=provider11942=== CONT TestGlobMatch/fo?_foo1943=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1944=== CONT TestGlobMatch/?oo_boo1945=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01946=== CONT TestGlobMatch/refs/*/main_refs/heads/main19472026/08/27 10:01:05 INFO OIDC provider initialized name=test1948=== CONT TestGlobMatch/fo?_fooo1949=== CONT TestGlobMatch/fo?_fo19502026/08/27 10:01:05 INFO OIDC provider initialized name=provider11951--- PASS: TestGlobMatch (0.01s)1952 --- PASS: TestGlobMatch/foo_foo (0.00s)1953 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1954 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1955 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1956 --- PASS: TestGlobMatch/?oo_foo (0.00s)1957 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1958 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1959 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1960 --- PASS: TestGlobMatch/*/*_foo (0.00s)1961 --- PASS: TestGlobMatch/*bar_foo (0.00s)1962 --- PASS: TestGlobMatch/foo*_foo (0.00s)1963 --- PASS: TestGlobMatch/*_anything (0.00s)1964 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1965 --- PASS: TestGlobMatch/*_ (0.00s)1966 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1967 --- PASS: TestGlobMatch/*bar_bar (0.00s)1968 --- PASS: TestGlobMatch/foo_bar (0.00s)1969 --- PASS: TestGlobMatch/foo*_bar (0.00s)1970 --- PASS: TestGlobMatch/fo?_foo (0.00s)1971 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1972 --- PASS: TestGlobMatch/?oo_boo (0.00s)1973 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1974 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1975 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1976 --- PASS: TestGlobMatch/fo?_fo (0.00s)19772026/08/27 10:01:05 INFO OIDC provider initialized name=provider219782026/08/27 10:01:05 INFO OIDC provider initialized name=test1979--- PASS: TestValidateToken_Expired (0.01s)1980--- PASS: TestValidateToken_ValidToken (0.01s)1981--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1982--- PASS: TestValidateToken_WrongAudience (0.01s)1983--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1984--- PASS: TestValidateToken_MultipleProviders (0.01s)1985--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1986PASS1987Running hook tests...1988=== RUN TestSendPathsEmpty1989=== PAUSE TestSendPathsEmpty1990=== RUN TestQueueEnqueueAndFetch1991=== PAUSE TestQueueEnqueueAndFetch1992=== RUN TestQueueDeduplication1993=== PAUSE TestQueueDeduplication1994=== RUN TestQueueRemove1995=== PAUSE TestQueueRemove1996=== RUN TestQueueFetchBatchLimit1997=== PAUSE TestQueueFetchBatchLimit1998=== RUN TestQueueRetryMovesToBack1999=== PAUSE TestQueueRetryMovesToBack2000=== RUN TestQueueFetchRemoveLifecycle2001=== PAUSE TestQueueFetchRemoveLifecycle2002=== RUN TestQueueConcurrentWriters2003=== PAUSE TestQueueConcurrentWriters2004=== RUN TestQueueRemoveLargeClosure2005=== PAUSE TestQueueRemoveLargeClosure2006=== RUN TestServerClientIntegration2007=== PAUSE TestServerClientIntegration2008=== RUN TestServerQueueError2009=== PAUSE TestServerQueueError2010=== RUN TestGetListenerSocketActivation2011 server_test.go:210: === RUN TestGetListenerSocketActivation2012 --- PASS: TestGetListenerSocketActivation (0.00s)2013 PASS2014 2015--- PASS: TestGetListenerSocketActivation (0.01s)2016=== RUN TestDrainIsolatesPoisonPath2017=== PAUSE TestDrainIsolatesPoisonPath2018=== RUN TestRunNotBlockedByPoisonHead2019=== PAUSE TestRunNotBlockedByPoisonHead2020=== RUN TestDrainGivesUpWhenServerDown2021=== PAUSE TestDrainGivesUpWhenServerDown2022=== RUN TestFailedPathPrunedByLaterClosure2023=== PAUSE TestFailedPathPrunedByLaterClosure2024=== RUN TestWorkerUploadsAndRemoves2025=== PAUSE TestWorkerUploadsAndRemoves2026=== RUN TestWorkerSkipsGCdPaths2027=== PAUSE TestWorkerSkipsGCdPaths2028=== RUN TestWorkerPrunesClosureDeps2029=== PAUSE TestWorkerPrunesClosureDeps2030=== RUN TestDrainTimeoutStopsSlowDrain2031=== PAUSE TestDrainTimeoutStopsSlowDrain2032=== RUN TestDrainWithoutTimeoutRunsToCompletion2033=== PAUSE TestDrainWithoutTimeoutRunsToCompletion2034=== RUN TestDrainTimeoutNotWaitedOutOnSuccess2035=== PAUSE TestDrainTimeoutNotWaitedOutOnSuccess2036=== CONT TestSendPathsEmpty2037=== CONT TestDrainIsolatesPoisonPath2038=== CONT TestQueueRemoveLargeClosure2039--- PASS: TestSendPathsEmpty (0.00s)2040=== CONT TestQueueRetryMovesToBack2041=== CONT TestQueueFetchBatchLimit2042=== CONT TestQueueRemove2043=== CONT TestQueueFetchRemoveLifecycle2044=== CONT TestQueueDeduplication2045=== CONT TestServerQueueError2046=== CONT TestServerClientIntegration2047=== CONT TestQueueEnqueueAndFetch2048=== CONT TestWorkerSkipsGCdPaths2049=== CONT TestDrainTimeoutNotWaitedOutOnSuccess2050=== CONT TestDrainWithoutTimeoutRunsToCompletion2051=== CONT TestDrainTimeoutStopsSlowDrain2052=== CONT TestQueueConcurrentWriters2053=== CONT TestFailedPathPrunedByLaterClosure2054=== CONT TestWorkerPrunesClosureDeps2055=== CONT TestWorkerUploadsAndRemoves2056=== CONT TestDrainGivesUpWhenServerDown20572026/08/27 10:01:05 ERROR Failed to queue paths error="permission denied" count=12058=== CONT TestRunNotBlockedByPoisonHead2059--- PASS: TestServerClientIntegration (0.00s)2060--- PASS: TestServerQueueError (0.00s)2061--- PASS: TestQueueFetchBatchLimit (0.02s)20622026/08/27 10:01:05 INFO Uploading batch count=120632026/08/27 10:01:05 ERROR Upload failed error="upload failed" count=120642026/08/27 10:01:05 INFO Uploading batch count=120652026/08/27 10:01:05 INFO Uploading batch count=220662026/08/27 10:01:05 INFO Uploading batch count=420672026/08/27 10:01:05 ERROR Upload failed error="upload failed" count=42068--- PASS: TestQueueRemove (0.02s)20692026/08/27 10:01:05 INFO Uploading batch count=22070--- PASS: TestQueueEnqueueAndFetch (0.02s)20712026/08/27 10:01:05 INFO Upload queue status pending=22072--- PASS: TestQueueDeduplication (0.02s)2073--- PASS: TestQueueRetryMovesToBack (0.02s)20742026/08/27 10:01:05 INFO Uploading batch count=22075--- PASS: TestQueueFetchRemoveLifecycle (0.02s)20762026/08/27 10:01:05 ERROR Upload failed error="upload failed" count=220772026/08/27 10:01:05 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2943808409/002/nonexistent20782026/08/27 10:01:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1971157065/002/a20792026/08/27 10:01:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath365271151/002/bbb20802026/08/27 10:01:05 INFO Upload queue status pending=220812026/08/27 10:01:05 INFO Uploading batch count=220822026/08/27 10:01:05 INFO Uploading batch count=120832026/08/27 10:01:05 INFO Upload queue status pending=320842026/08/27 10:01:05 INFO Uploading batch count=220852026/08/27 10:01:05 INFO Uploading batch count=120862026/08/27 10:01:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1971157065/002/b20872026/08/27 10:01:05 ERROR Upload failed error="upload failed" count=120882026/08/27 10:01:05 INFO Uploading batch count=120892026/08/27 10:01:05 INFO Upload queue status pending=220902026/08/27 10:01:05 INFO Uploading batch count=120912026/08/27 10:01:05 INFO Uploading batch count=120922026/08/27 10:01:05 INFO Uploading batch count=220932026/08/27 10:01:05 ERROR Upload failed error="upload failed" count=220942026/08/27 10:01:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1971157065/002/c20952026/08/27 10:01:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1971157065/002/d20962026/08/27 10:01:05 INFO Uploading batch count=120972026/08/27 10:01:05 ERROR Upload failed error="upload failed" count=120982026/08/27 10:01:05 INFO Uploading batch count=220992026/08/27 10:01:05 ERROR Upload failed error="upload failed" count=22100--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)21012026/08/27 10:01:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1971157065/002/e2102--- PASS: TestDrainTimeoutNotWaitedOutOnSuccess (0.03s)21032026/08/27 10:01:05 INFO Uploading batch count=121042026/08/27 10:01:05 ERROR Upload failed error="upload failed" count=121052026/08/27 10:01:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1971157065/002/f21062026/08/27 10:01:05 INFO Uploading batch count=121072026/08/27 10:01:05 ERROR Upload failed error="upload failed" count=121082026/08/27 10:01:05 ERROR Drain finished with paths left in queue remaining=1021092026/08/27 10:01:05 ERROR Drain finished with paths left in queue remaining=121102026/08/27 10:01:05 INFO Uploading batch count=12111--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2112--- PASS: TestDrainIsolatesPoisonPath (0.03s)2113--- PASS: TestWorkerUploadsAndRemoves (0.04s)2114--- PASS: TestWorkerSkipsGCdPaths (0.04s)21152026/08/27 10:01:05 INFO Uploading batch count=12116--- PASS: TestWorkerPrunesClosureDeps (0.04s)21172026/08/27 10:01:05 INFO Uploading batch count=12118--- PASS: TestDrainWithoutTimeoutRunsToCompletion (0.07s)2119--- PASS: TestQueueRemoveLargeClosure (0.17s)21202026/08/27 10:01:05 ERROR Upload failed error="context deadline exceeded" count=221212026/08/27 10:01:05 ERROR Upload failed, will retry later error="context deadline exceeded" path=/build/TestDrainTimeoutStopsSlowDrain1627220451/002/a21222026/08/27 10:01:05 ERROR Upload failed, will retry later error="context deadline exceeded" path=/build/TestDrainTimeoutStopsSlowDrain1627220451/002/b21232026/08/27 10:01:05 WARN Drain timed out timeout=200ms21242026/08/27 10:01:05 ERROR Drain finished with paths left in queue remaining=42125--- PASS: TestDrainTimeoutStopsSlowDrain (0.22s)2126--- PASS: TestQueueConcurrentWriters (0.38s)21272026/08/27 10:01:06 INFO Uploading batch count=121282026/08/27 10:01:06 INFO Uploading batch count=121292026/08/27 10:01:06 INFO Uploading batch count=121302026/08/27 10:01:06 ERROR Upload failed error="upload failed" count=121312026/08/27 10:01:06 INFO Uploading batch count=121322026/08/27 10:01:06 ERROR Upload failed error="upload failed" count=121332026/08/27 10:01:06 INFO Uploading batch count=121342026/08/27 10:01:06 ERROR Upload failed error="upload failed" count=121352026/08/27 10:01:06 INFO Uploading batch count=121362026/08/27 10:01:06 ERROR Upload failed error="upload failed" count=121372026/08/27 10:01:06 ERROR Drain finished with paths left in queue remaining=12138--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2139PASS