niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #144
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestCaseHackSuffix5=== PAUSE TestCaseHackSuffix6=== RUN TestFilterOversizedClosures7=== PAUSE TestFilterOversizedClosures8=== RUN TestPartSizeForNAR9=== PAUSE TestPartSizeForNAR10=== RUN TestUploadMultipart_SupersededByPeer11=== PAUSE TestUploadMultipart_SupersededByPeer12=== RUN TestDumpPathMatchesNix13=== PAUSE TestDumpPathMatchesNix14=== RUN TestDumpPathSingleFile15=== PAUSE TestDumpPathSingleFile16=== RUN TestDumpPathWriterError17=== PAUSE TestDumpPathWriterError18=== RUN TestEncodeNixBase3219=== PAUSE TestEncodeNixBase3220=== RUN TestEncodeNixBase32WithRealHash21=== PAUSE TestEncodeNixBase32WithRealHash22=== RUN TestConvertHashToNix3223=== PAUSE TestConvertHashToNix3224=== RUN TestGetStorePathHash25=== PAUSE TestGetStorePathHash26=== RUN TestPathInfoHashCompatibility27=== PAUSE TestPathInfoHashCompatibility28=== RUN TestParsePathInfoJSON29=== PAUSE TestParsePathInfoJSON30=== RUN TestParsePathInfoJSONMultiplePaths31=== PAUSE TestParsePathInfoJSONMultiplePaths32=== RUN TestPathInfoCACompatibility33=== PAUSE TestPathInfoCACompatibility34=== RUN TestRateLimiterFeedback35=== PAUSE TestRateLimiterFeedback36=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess37=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess38=== RUN TestResolveStorePath39=== PAUSE TestResolveStorePath40=== RUN TestDoWithRetry_BodyReplayedViaGetBody41=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody42=== RUN TestShellSplit43=== PAUSE TestShellSplit44=== RUN TestShellSplitErrors45=== PAUSE TestShellSplitErrors46=== RUN TestSetClientTLS47=== PAUSE TestSetClientTLS48=== RUN TestSetClientTLSDoesNotMutateDefaultTransport49=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport50=== RUN TestSetClientTLSErrors51=== PAUSE TestSetClientTLSErrors52=== RUN TestStaticToken53=== PAUSE TestStaticToken54=== RUN TestFileTokenReadsAndCaches55=== PAUSE TestFileTokenReadsAndCaches56=== RUN TestFileTokenMissing57=== PAUSE TestFileTokenMissing58=== RUN TestFileTokenEmpty59=== PAUSE TestFileTokenEmpty60=== RUN TestScriptTokenNoExpiryRerunsEveryCall61=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall62=== RUN TestScriptTokenCachesUntilRefresh63=== PAUSE TestScriptTokenCachesUntilRefresh64=== RUN TestScriptTokenEmptyToken65=== PAUSE TestScriptTokenEmptyToken66=== RUN TestScriptTokenBadJSON67=== PAUSE TestScriptTokenBadJSON68=== RUN TestScriptTokenScriptFails69=== PAUSE TestScriptTokenScriptFails70=== RUN TestScriptTokenEmptyCommand71=== PAUSE TestScriptTokenEmptyCommand72=== CONT TestDoServerRequestAttachesToken73=== CONT TestResolveStorePath74=== CONT TestFileTokenMissing75=== CONT TestEncodeNixBase32WithRealHash76--- PASS: TestEncodeNixBase32WithRealHash (0.00s)77=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess78=== CONT TestDumpPathMatchesNix79=== CONT TestSetClientTLSDoesNotMutateDefaultTransport80=== CONT TestShellSplitErrors81--- PASS: TestShellSplitErrors (0.00s)82=== CONT TestSetClientTLS832026/08/27 09:35:52 WARN Rate limiter enabled after throttle name=server-test rate=584=== CONT TestShellSplit85--- PASS: TestFileTokenMissing (0.00s)86=== CONT TestScriptTokenEmptyCommand87--- PASS: TestScriptTokenEmptyCommand (0.00s)88=== CONT TestScriptTokenScriptFails89=== CONT TestParsePathInfoJSON90=== RUN TestParsePathInfoJSON/Nix_format91=== PAUSE TestParsePathInfoJSON/Nix_format92=== RUN TestParsePathInfoJSON/Lix_format93=== PAUSE TestParsePathInfoJSON/Lix_format94=== RUN TestParsePathInfoJSON/empty_input95=== PAUSE TestParsePathInfoJSON/empty_input96=== RUN TestParsePathInfoJSON/whitespace_only97=== PAUSE TestParsePathInfoJSON/whitespace_only98=== RUN TestParsePathInfoJSON/invalid_JSON99=== PAUSE TestParsePathInfoJSON/invalid_JSON100=== CONT TestParsePathInfoJSON/Nix_format101=== CONT TestPathInfoCACompatibility102=== RUN TestPathInfoCACompatibility/null_ca_field103=== PAUSE TestPathInfoCACompatibility/null_ca_field104=== RUN TestPathInfoCACompatibility/old_string_format_-_text105=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text106=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive107=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive108=== RUN TestPathInfoCACompatibility/new_structured_format_-_text109=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text110=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method111=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method112--- PASS: TestShellSplit (0.00s)113=== CONT TestStaticToken114=== CONT TestFileTokenReadsAndCaches115--- PASS: TestStaticToken (0.00s)116=== CONT TestSetClientTLSErrors117=== CONT TestRateLimiterFeedback118=== RUN TestRateLimiterFeedback/429_enables_limiter119=== PAUSE TestRateLimiterFeedback/429_enables_limiter120=== RUN TestRateLimiterFeedback/503_enables_limiter121=== PAUSE TestRateLimiterFeedback/503_enables_limiter122=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter123=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter124=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter125=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter126=== CONT TestGetStorePathHash127=== RUN TestGetStorePathHash/valid_store_path128=== PAUSE TestGetStorePathHash/valid_store_path129=== RUN TestGetStorePathHash/basename_without_hyphen_should_error130=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error131=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error132=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error133=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error134=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error135=== CONT TestPathInfoHashCompatibility136=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)137=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)138=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon139=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon140=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI141=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI142=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512143=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512144=== CONT TestDoWithRetry_BodyReplayedViaGetBody145--- PASS: TestFileTokenReadsAndCaches (0.00s)146=== CONT TestFilterOversizedClosures147=== RUN TestFilterOversizedClosures/no_limit_keeps_everything148=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything149=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped150=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped151=== RUN TestFilterOversizedClosures/all_closures_skipped152--- PASS: TestResolveStorePath (0.00s)153=== PAUSE TestFilterOversizedClosures/all_closures_skipped154=== CONT TestPartSizeForNAR155=== RUN TestPartSizeForNAR/zero_stays_at_minimum156=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum157=== RUN TestPartSizeForNAR/small_stays_at_minimum158=== PAUSE TestPartSizeForNAR/small_stays_at_minimum159=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum160=== CONT TestUploadMultipart_SupersededByPeer161=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum162=== RUN TestUploadMultipart_SupersededByPeer/exists163=== PAUSE TestUploadMultipart_SupersededByPeer/exists164=== RUN TestUploadMultipart_SupersededByPeer/missing165=== PAUSE TestUploadMultipart_SupersededByPeer/missing166=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts167=== CONT TestScriptTokenCachesUntilRefresh168=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts169=== RUN TestPartSizeForNAR/1_TiB170=== PAUSE TestPartSizeForNAR/1_TiB171=== RUN TestPartSizeForNAR/5_TiB_S3_max_object172=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object173=== RUN TestPartSizeForNAR/capped_at_5_GiB174=== PAUSE TestPartSizeForNAR/capped_at_5_GiB175=== CONT TestScriptTokenBadJSON176--- PASS: TestDoServerRequestAttachesToken (0.01s)177=== CONT TestScriptTokenEmptyToken178=== RUN TestSetClientTLSErrors/missing_cert_file179=== PAUSE TestSetClientTLSErrors/missing_cert_file180=== RUN TestSetClientTLSErrors/missing_key_file181=== PAUSE TestSetClientTLSErrors/missing_key_file182=== RUN TestSetClientTLSErrors/missing_ca_file183=== PAUSE TestSetClientTLSErrors/missing_ca_file184=== RUN TestSetClientTLSErrors/invalid_ca_file185=== PAUSE TestSetClientTLSErrors/invalid_ca_file186=== CONT TestParsePathInfoJSON/whitespace_only1872026/08/27 09:35:52 WARN Rate limiter enabled after throttle name=server-test rate=5188=== CONT TestParsePathInfoJSONMultiplePaths1892026/08/27 09:35:52 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:51482190=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths191=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths192=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths193=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths194=== CONT TestParsePathInfoJSON/invalid_JSON195=== CONT TestDumpPathWriterError1962026/08/27 09:35:52 WARN Rate limiter backed off name=server-test rate=51972026/08/27 09:35:52 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:51482198--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)199=== CONT TestEncodeNixBase32200=== RUN TestEncodeNixBase32/test_string_hash201=== PAUSE TestEncodeNixBase32/test_string_hash202=== RUN TestEncodeNixBase32/empty_input203=== PAUSE TestEncodeNixBase32/empty_input204=== CONT TestParsePathInfoJSON/empty_input205=== CONT TestConvertHashToNix32206=== RUN TestConvertHashToNix32/SRI_format_to_Nix32207=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32208=== RUN TestConvertHashToNix32/already_Nix32_format209=== PAUSE TestConvertHashToNix32/already_Nix32_format210=== RUN TestConvertHashToNix32/invalid_format211=== PAUSE TestConvertHashToNix32/invalid_format212=== CONT TestParsePathInfoJSON/Lix_format213--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)214=== CONT TestDumpPathSingleFile215=== CONT TestCaseHackSuffix216--- PASS: TestParsePathInfoJSON (0.00s)217 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)218 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)219 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)220 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)221 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)222--- PASS: TestScriptTokenScriptFails (0.01s)223=== CONT TestPathInfoCACompatibility/null_ca_field224=== RUN TestSetClientTLS/rejects_connection_without_client_cert225=== CONT TestPathInfoCACompatibility/new_structured_format_-_text226=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert227=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA228=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA229=== RUN TestSetClientTLS/preserves_debug_logging_transport230=== PAUSE TestSetClientTLS/preserves_debug_logging_transport231=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method232=== CONT TestFileTokenEmpty233=== CONT TestScriptTokenNoExpiryRerunsEveryCall234--- PASS: TestFileTokenEmpty (0.00s)235=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive236=== CONT TestPathInfoCACompatibility/old_string_format_-_text237--- PASS: TestPathInfoCACompatibility (0.00s)238 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)239 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)240 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)241 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)242 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)243=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter244=== CONT TestRateLimiterFeedback/429_enables_limiter2452026/08/27 09:35:52 WARN Rate limiter enabled after throttle name=server-test rate=52462026/08/27 09:35:52 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:514872472026/08/27 09:35:52 WARN Rate limiter backed off name=server-test rate=5248=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter249=== CONT TestRateLimiterFeedback/503_enables_limiter2502026/08/27 09:35:52 WARN Rate limiter enabled after throttle name=server-test rate=52512026/08/27 09:35:52 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:514912522026/08/27 09:35:52 WARN Rate limiter backed off name=server-test rate=5253--- PASS: TestRateLimiterFeedback (0.00s)254 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)255 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)256 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)257 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)258=== CONT TestGetStorePathHash/valid_store_path259=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error260=== CONT TestGetStorePathHash/basename_without_hyphen_should_error261=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)262=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512263=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI264=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon265--- PASS: TestPathInfoHashCompatibility (0.00s)266 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)267 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)268 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)269 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)270=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error271--- PASS: TestGetStorePathHash (0.00s)272 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)273 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)274 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)275 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)276=== CONT TestFilterOversizedClosures/no_limit_keeps_everything277=== CONT TestFilterOversizedClosures/all_closures_skipped2782026/08/27 09:35:52 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50279=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2802026/08/27 09:35: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=2000281--- PASS: TestFilterOversizedClosures (0.00s)282 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)283 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)284 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)285=== CONT TestUploadMultipart_SupersededByPeer/exists286=== CONT TestUploadMultipart_SupersededByPeer/missing287--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)288 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)289 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)290=== CONT TestPartSizeForNAR/zero_stays_at_minimum291=== CONT TestPartSizeForNAR/1_TiB292=== CONT TestPartSizeForNAR/capped_at_5_GiB293=== CONT TestPartSizeForNAR/5_TiB_S3_max_object294=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum295=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts296=== CONT TestPartSizeForNAR/small_stays_at_minimum297--- PASS: TestPartSizeForNAR (0.00s)298 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)299 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)300 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)301 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)302 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)303 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)304 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)305=== CONT TestSetClientTLSErrors/missing_cert_file306=== CONT TestSetClientTLSErrors/invalid_ca_file307--- PASS: TestScriptTokenEmptyToken (0.02s)308=== CONT TestSetClientTLSErrors/missing_ca_file309--- PASS: TestScriptTokenBadJSON (0.02s)310=== CONT TestSetClientTLSErrors/missing_key_file311=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths312=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths313--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)314 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)315 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)316=== CONT TestEncodeNixBase32/test_string_hash317=== CONT TestEncodeNixBase32/empty_input318--- PASS: TestEncodeNixBase32 (0.00s)319 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)320 --- PASS: TestEncodeNixBase32/empty_input (0.00s)321=== CONT TestConvertHashToNix32/SRI_format_to_Nix32322=== CONT TestConvertHashToNix32/invalid_format323=== CONT TestConvertHashToNix32/already_Nix32_format324--- PASS: TestConvertHashToNix32 (0.00s)325 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)326 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)327 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)328=== CONT TestSetClientTLS/rejects_connection_without_client_cert329=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA330=== CONT TestSetClientTLS/preserves_debug_logging_transport331--- PASS: TestSetClientTLSErrors (0.01s)332 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)333 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)334 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)335 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)3362026/08/27 09:35:52 http: TLS handshake error from 127.0.0.1:51497: remote error: tls: bad certificate337--- PASS: TestSetClientTLS (0.01s)338 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)339 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)340 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)341--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)342--- PASS: TestDumpPathWriterError (0.04s)343--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)344--- PASS: TestDumpPathSingleFile (0.05s)345--- PASS: TestCaseHackSuffix (0.05s)346--- PASS: TestDumpPathMatchesNix (0.08s)347--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)348PASS349Running server tests...350The files belonging to this database system will be owned by user "_nixbld10".351This user must also own the server process.352353The database cluster will be initialized with locale "C".354The default database encoding has accordingly been set to "SQL_ASCII".355The default text search configuration will be set to "english".356357Data page checksums are enabled.358359creating directory /nix/var/nix/builds/nix-28356-531849286/postgres1688706964/data ... ok360creating subdirectories ... ok361selecting dynamic shared memory implementation ... posix362selecting default "max_connections" ... 100363selecting default "shared_buffers" ... 128MB364selecting default time zone ... UTC365creating configuration files ... ok366running bootstrap script ... ok367performing post-bootstrap initialization ... ok368syncing data to disk ... ok369370initdb: warning: enabling "trust" authentication for local connections371initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.372373Success. You can now start the database server using:374375 pg_ctl -D /nix/var/nix/builds/nix-28356-531849286/postgres1688706964/data -l logfile start376377/nix/var/nix/builds/nix-28356-531849286/postgres1688706964:5432 - no response3782026-08-27 09:35:54.088 UTC [28433] LOG: starting PostgreSQL 18.4 on aarch64-apple-darwin25.5.0, compiled by clang version 21.1.8, 64-bit3792026-08-27 09:35:54.088 UTC [28433] LOG: listening on Unix socket "/nix/var/nix/builds/nix-28356-531849286/postgres1688706964/.s.PGSQL.5432"3802026-08-27 09:35:54.090 UTC [28440] LOG: database system was shut down at 2026-08-27 09:35:54 UTC3812026-08-27 09:35:54.091 UTC [28433] LOG: database system is ready to accept connections382/nix/var/nix/builds/nix-28356-531849286/postgres1688706964:5432 - accepting connections383=== RUN TestService_AuthMiddleware384=== PAUSE TestService_AuthMiddleware385=== RUN TestService_AuthMiddleware_MTLSProxyHeader386=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader387=== RUN TestService_AuthMiddleware_MTLSBoundSubjects388=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects389=== RUN TestService_ReadAuthMiddleware390=== PAUSE TestService_ReadAuthMiddleware391=== RUN TestService_AuthMiddleware_OIDC392=== PAUSE TestService_AuthMiddleware_OIDC393=== RUN TestCacheConfigHandler394=== PAUSE TestCacheConfigHandler395=== RUN TestCacheStatsHandler396=== PAUSE TestCacheStatsHandler397=== RUN TestClientCADerivations398=== PAUSE TestClientCADerivations399=== RUN TestClientErrorHandling400=== PAUSE TestClientErrorHandling401=== RUN TestClientIntegration402=== PAUSE TestClientIntegration403=== RUN TestClientMultipleUploads404=== PAUSE TestClientMultipleUploads405=== RUN TestClientWithDependencies406=== PAUSE TestClientWithDependencies407=== RUN TestPinProtectsFromGC408=== PAUSE TestPinProtectsFromGC409=== RUN TestGCAdvisoryLockBlocksConcurrentRun4102026-08-27 09:35:54.424 UTC [28513] ERROR: relation "goose_db_version" does not exist at character 364112026-08-27 09:35:54.424 UTC [28513] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4122026/08/27 09:35:54 OK 20241026095416_initial_model.sql (3.07ms)4132026/08/27 09:35:54 OK 20251210153512_drop_unused_gin_index.sql (378.92µs)4142026/08/27 09:35:54 OK 20251218171726_add_pins.sql (805.83µs)4152026/08/27 09:35:54 OK 20260628120000_add_object_size_and_stats.sql (759.21µs)4162026/08/27 09:35:54 goose: successfully migrated database to version: 202606281200004172026/08/27 09:35:54 OK 1_commit_pending_closure.sql (881.54µs)4182026/08/27 09:35:54 OK 2_object_stats_trigger.sql (262.46µs)4192026/08/27 09:35:54 goose: up to current file version: 2420--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.17s)421=== RUN TestGCBugBareHashReferences422=== PAUSE TestGCBugBareHashReferences423=== RUN TestGCMetrics424=== PAUSE TestGCMetrics425=== RUN TestGCTaskStore_StartNew426=== PAUSE TestGCTaskStore_StartNew427=== RUN TestGCTaskStore_DeduplicateSameParams428=== PAUSE TestGCTaskStore_DeduplicateSameParams429=== RUN TestGCTaskStore_ConflictDifferentParams430=== PAUSE TestGCTaskStore_ConflictDifferentParams431=== RUN TestGCTaskStore_GetEmpty432=== PAUSE TestGCTaskStore_GetEmpty433=== RUN TestGCTaskStore_GetReturnsLatest434=== PAUSE TestGCTaskStore_GetReturnsLatest435=== RUN TestGCTaskStore_CompletedAllowsNewTask436=== PAUSE TestGCTaskStore_CompletedAllowsNewTask437=== RUN TestGCTaskStore_PhaseUpdates438=== PAUSE TestGCTaskStore_PhaseUpdates439=== RUN TestGCTaskStore_Fail440=== PAUSE TestGCTaskStore_Fail441=== RUN TestGracefulShutdownDrainsInflight442=== PAUSE TestGracefulShutdownDrainsInflight443=== RUN TestService_healthCheckHandler444=== PAUSE TestService_healthCheckHandler445=== RUN TestGenerateLandingPage446=== PAUSE TestGenerateLandingPage447=== RUN TestCacheConfigHandlerMaxNarSize448=== PAUSE TestCacheConfigHandlerMaxNarSize449=== RUN TestCreatePendingClosureRejectsOversizedNAR450=== PAUSE TestCreatePendingClosureRejectsOversizedNAR451=== RUN TestNARDeduplicationMetadataUploadBug452=== PAUSE TestNARDeduplicationMetadataUploadBug453=== RUN TestMetricsInventory454=== PAUSE TestMetricsInventory455=== RUN TestService_NativeMTLS456=== PAUSE TestService_NativeMTLS457=== RUN TestServerTLSConfig458=== PAUSE TestServerTLSConfig459=== RUN TestMultipartCleanup460=== PAUSE TestMultipartCleanup461=== RUN TestObjectStatsTrigger462=== PAUSE TestObjectStatsTrigger463=== RUN TestOrphanedObjectsGC464=== PAUSE TestOrphanedObjectsGC465=== RUN TestOrphanedObjectsGCStressTest466=== PAUSE TestOrphanedObjectsGCStressTest467=== RUN TestResurrectedObjectNotDeleted468=== PAUSE TestResurrectedObjectNotDeleted469=== RUN TestParseSingleRange470=== PAUSE TestParseSingleRange471=== RUN TestIsValidCachePath472=== PAUSE TestIsValidCachePath473=== RUN TestReadProxyNarinfo474=== PAUSE TestReadProxyNarinfo475=== RUN TestReadProxyNarinfoAlreadyDecompressed476=== PAUSE TestReadProxyNarinfoAlreadyDecompressed477=== RUN TestReadProxyNarStreaming478=== PAUSE TestReadProxyNarStreaming479=== RUN TestReadProxy404480=== PAUSE TestReadProxy404481=== RUN TestReadProxyInvalidPath482=== PAUSE TestReadProxyInvalidPath483=== RUN TestReadProxyHead484=== PAUSE TestReadProxyHead485=== RUN TestReadProxyConditionalGet486=== PAUSE TestReadProxyConditionalGet487=== RUN TestReadProxyRootRedirectsToIndexHTML488=== PAUSE TestReadProxyRootRedirectsToIndexHTML489=== RUN TestReadProxyDisabled490=== PAUSE TestReadProxyDisabled491=== RUN TestReadProxyRangeRequest492=== PAUSE TestReadProxyRangeRequest493=== RUN TestRedundantMultipartUpload494=== PAUSE TestRedundantMultipartUpload495=== RUN TestCompleteMultipartUpload_ErrorButObjectExists496=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists497=== RUN TestCompletedNarNotReofferedAcrossClosures498=== PAUSE TestCompletedNarNotReofferedAcrossClosures499=== RUN TestPresignedUploadRegisteredBeforeCommit500=== PAUSE TestPresignedUploadRegisteredBeforeCommit501=== RUN TestService_Rustfstest502=== PAUSE TestService_Rustfstest503=== RUN TestParseSize504=== PAUSE TestParseSize505=== RUN TestSkippedUploadsHandler506=== PAUSE TestSkippedUploadsHandler507=== RUN TestSystemdListenerNotActivated508--- PASS: TestSystemdListenerNotActivated (0.00s)509=== RUN TestWatchdogBeatsWhenHealthy510--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)511=== RUN TestWatchdogSkipsWhenUnhealthy5122026/08/27 09:35:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5132026/08/27 09:35:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5142026/08/27 09:35:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5152026/08/27 09:35:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5162026/08/27 09:35:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5172026/08/27 09:35:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5182026/08/27 09:35:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5192026/08/27 09:35:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5202026/08/27 09:35:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5212026/08/27 09:35:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"522--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)523=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle524=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle525=== RUN TestProxyWriteTimeout526=== PAUSE TestProxyWriteTimeout527=== RUN TestIsValidUploadKey528=== PAUSE TestIsValidUploadKey529=== RUN TestUploadHandlersRejectInvalidKeys530=== PAUSE TestUploadHandlersRejectInvalidKeys531=== RUN TestUploadHandlersRejectOversizedBody532=== PAUSE TestUploadHandlersRejectOversizedBody533=== RUN TestService_cleanupPendingClosuresHandler534=== PAUSE TestService_cleanupPendingClosuresHandler535=== RUN TestService_createPendingClosureHandler536=== PAUSE TestService_createPendingClosureHandler537=== RUN TestService_verifyS3Integrity538=== PAUSE TestService_verifyS3Integrity539=== RUN TestCompleteMultipartUnregistered540=== PAUSE TestCompleteMultipartUnregistered541=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT542=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT543=== CONT TestCompleteMultipartUnregistered544=== CONT TestService_AuthMiddleware545=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT546=== CONT TestMultipartCleanup547=== CONT TestServerTLSConfig548=== CONT TestReadProxyNarinfoAlreadyDecompressed549=== RUN TestServerTLSConfig/no_client_CA550=== CONT TestReadProxyNarinfo551=== CONT TestIsValidCachePath552=== RUN TestIsValidCachePath/narinfo553=== CONT TestResurrectedObjectNotDeleted554=== PAUSE TestServerTLSConfig/no_client_CA555=== PAUSE TestIsValidCachePath/narinfo556=== RUN TestServerTLSConfig/missing_CA_file557=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars558=== PAUSE TestServerTLSConfig/missing_CA_file559=== RUN TestServerTLSConfig/not_a_PEM_file560=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars561=== RUN TestIsValidCachePath/nar_zst562=== PAUSE TestIsValidCachePath/nar_zst563=== RUN TestIsValidCachePath/nar_xz564=== PAUSE TestServerTLSConfig/not_a_PEM_file565=== PAUSE TestIsValidCachePath/nar_xz566=== RUN TestIsValidCachePath/nar_bz2567=== PAUSE TestIsValidCachePath/nar_bz2568=== CONT TestParseSingleRange569=== RUN TestIsValidCachePath/nar_uncompressed570=== PAUSE TestIsValidCachePath/nar_uncompressed571=== RUN TestIsValidCachePath/ls572=== PAUSE TestIsValidCachePath/ls573=== RUN TestIsValidCachePath/log574=== PAUSE TestIsValidCachePath/log575=== RUN TestIsValidCachePath/realisation576=== PAUSE TestIsValidCachePath/realisation577=== RUN TestIsValidCachePath/nix-cache-info578=== PAUSE TestIsValidCachePath/nix-cache-info579=== RUN TestIsValidCachePath/index.html580=== PAUSE TestIsValidCachePath/index.html581=== CONT TestReadProxyRangeRequest582=== RUN TestIsValidCachePath/traversal_parent583=== PAUSE TestIsValidCachePath/traversal_parent584=== RUN TestIsValidCachePath/traversal_in_middle585=== PAUSE TestIsValidCachePath/traversal_in_middle586=== RUN TestIsValidCachePath/invalid_char_e587=== PAUSE TestIsValidCachePath/invalid_char_e588=== RUN TestIsValidCachePath/invalid_char_u589=== PAUSE TestIsValidCachePath/invalid_char_u590=== RUN TestIsValidCachePath/random_path591=== PAUSE TestIsValidCachePath/random_path592=== RUN TestIsValidCachePath/empty593=== RUN TestParseSingleRange/none594=== PAUSE TestParseSingleRange/none595=== RUN TestParseSingleRange/unknown_unit596=== PAUSE TestParseSingleRange/unknown_unit597=== PAUSE TestIsValidCachePath/empty598=== RUN TestIsValidCachePath/leading_slash599=== RUN TestParseSingleRange/multi-range_ignored600=== PAUSE TestIsValidCachePath/leading_slash601=== RUN TestIsValidCachePath/wrong_extension602=== PAUSE TestIsValidCachePath/wrong_extension603=== PAUSE TestParseSingleRange/multi-range_ignored604=== RUN TestParseSingleRange/malformed_no_dash605=== PAUSE TestParseSingleRange/malformed_no_dash606=== RUN TestParseSingleRange/malformed_both_empty607=== RUN TestIsValidCachePath/short_hash608=== PAUSE TestParseSingleRange/malformed_both_empty609=== PAUSE TestIsValidCachePath/short_hash610=== CONT TestGCTaskStore_DeduplicateSameParams611--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)612=== CONT TestService_NativeMTLS613=== RUN TestParseSingleRange/malformed_end_before_start614=== PAUSE TestParseSingleRange/malformed_end_before_start615=== RUN TestParseSingleRange/closed616=== PAUSE TestParseSingleRange/closed617=== RUN TestParseSingleRange/open-ended618=== PAUSE TestParseSingleRange/open-ended619=== RUN TestParseSingleRange/end_clamped_to_size620=== PAUSE TestParseSingleRange/end_clamped_to_size621=== RUN TestParseSingleRange/suffix622=== PAUSE TestParseSingleRange/suffix623=== RUN TestParseSingleRange/suffix_exceeds_size624=== PAUSE TestParseSingleRange/suffix_exceeds_size625=== RUN TestParseSingleRange/single_byte626=== PAUSE TestParseSingleRange/single_byte627=== RUN TestParseSingleRange/start_past_EOF628=== PAUSE TestParseSingleRange/start_past_EOF629=== RUN TestParseSingleRange/start_far_past_EOF630=== PAUSE TestParseSingleRange/start_far_past_EOF631=== CONT TestMetricsInventory6322026-08-27 09:35:55.005 UTC [28535] ERROR: relation "goose_db_version" does not exist at character 366332026-08-27 09:35:55.005 UTC [28535] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6342026-08-27 09:35:55.006 UTC [28537] ERROR: relation "goose_db_version" does not exist at character 366352026-08-27 09:35:55.006 UTC [28537] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6362026-08-27 09:35:55.006 UTC [28536] ERROR: relation "goose_db_version" does not exist at character 366372026-08-27 09:35:55.006 UTC [28536] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6382026-08-27 09:35:55.006 UTC [28539] ERROR: relation "goose_db_version" does not exist at character 366392026-08-27 09:35:55.006 UTC [28539] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6402026-08-27 09:35:55.006 UTC [28538] ERROR: relation "goose_db_version" does not exist at character 366412026-08-27 09:35:55.006 UTC [28538] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6422026-08-27 09:35:55.007 UTC [28541] ERROR: relation "goose_db_version" does not exist at character 366432026-08-27 09:35:55.007 UTC [28541] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6442026-08-27 09:35:55.008 UTC [28543] ERROR: relation "goose_db_version" does not exist at character 366452026-08-27 09:35:55.008 UTC [28543] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6462026-08-27 09:35:55.008 UTC [28542] ERROR: relation "goose_db_version" does not exist at character 366472026-08-27 09:35:55.008 UTC [28542] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6482026-08-27 09:35:55.008 UTC [28540] ERROR: relation "goose_db_version" does not exist at character 366492026-08-27 09:35:55.008 UTC [28540] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6502026-08-27 09:35:55.009 UTC [28544] ERROR: relation "goose_db_version" does not exist at character 366512026-08-27 09:35:55.009 UTC [28544] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6522026/08/27 09:35:55 OK 20241026095416_initial_model.sql (6.97ms)6532026/08/27 09:35:55 OK 20241026095416_initial_model.sql (8.33ms)6542026/08/27 09:35:55 OK 20251210153512_drop_unused_gin_index.sql (1ms)6552026/08/27 09:35:55 OK 20241026095416_initial_model.sql (7.92ms)6562026/08/27 09:35:55 OK 20251210153512_drop_unused_gin_index.sql (725.17µs)6572026/08/27 09:35:55 OK 20241026095416_initial_model.sql (7.88ms)6582026/08/27 09:35:55 OK 20251210153512_drop_unused_gin_index.sql (664.58µs)6592026/08/27 09:35:55 OK 20241026095416_initial_model.sql (8.44ms)6602026/08/27 09:35:55 OK 20251210153512_drop_unused_gin_index.sql (945.58µs)6612026/08/27 09:35:55 OK 20251218171726_add_pins.sql (1.84ms)6622026/08/27 09:35:55 OK 20251210153512_drop_unused_gin_index.sql (798.54µs)6632026/08/27 09:35:55 OK 20251218171726_add_pins.sql (1.93ms)6642026/08/27 09:35:55 OK 20241026095416_initial_model.sql (7.63ms)6652026/08/27 09:35:55 OK 20241026095416_initial_model.sql (8.24ms)6662026/08/27 09:35:55 OK 20241026095416_initial_model.sql (9.17ms)6672026/08/27 09:35:55 OK 20251218171726_add_pins.sql (1.91ms)6682026/08/27 09:35:55 OK 20251210153512_drop_unused_gin_index.sql (663.25µs)6692026/08/27 09:35:55 OK 20251218171726_add_pins.sql (1.25ms)6702026/08/27 09:35:55 OK 20251210153512_drop_unused_gin_index.sql (591.29µs)6712026/08/27 09:35:55 OK 20241026095416_initial_model.sql (8.42ms)6722026/08/27 09:35:55 OK 20251210153512_drop_unused_gin_index.sql (934.13µs)6732026/08/27 09:35:55 OK 20251218171726_add_pins.sql (1.9ms)6742026/08/27 09:35:55 OK 20260628120000_add_object_size_and_stats.sql (1.98ms)6752026/08/27 09:35:55 goose: successfully migrated database to version: 202606281200006762026/08/27 09:35:55 OK 20260628120000_add_object_size_and_stats.sql (1.74ms)6772026/08/27 09:35:55 goose: successfully migrated database to version: 202606281200006782026/08/27 09:35:55 OK 20251210153512_drop_unused_gin_index.sql (927.5µs)6792026/08/27 09:35:55 OK 20241026095416_initial_model.sql (8.68ms)6802026/08/27 09:35:55 OK 20251218171726_add_pins.sql (1.39ms)6812026/08/27 09:35:55 OK 20260628120000_add_object_size_and_stats.sql (2.12ms)6822026/08/27 09:35:55 goose: successfully migrated database to version: 202606281200006832026/08/27 09:35:55 OK 20251218171726_add_pins.sql (2.07ms)6842026/08/27 09:35:55 OK 20251218171726_add_pins.sql (1.76ms)6852026/08/27 09:35:55 OK 20260628120000_add_object_size_and_stats.sql (2.06ms)6862026/08/27 09:35:55 goose: successfully migrated database to version: 202606281200006872026/08/27 09:35:55 OK 20251210153512_drop_unused_gin_index.sql (634.58µs)6882026/08/27 09:35:55 OK 1_commit_pending_closure.sql (1.42ms)6892026/08/27 09:35:55 OK 20260628120000_add_object_size_and_stats.sql (1.76ms)6902026/08/27 09:35:55 goose: successfully migrated database to version: 202606281200006912026/08/27 09:35:55 OK 1_commit_pending_closure.sql (1.41ms)6922026/08/27 09:35:55 OK 2_object_stats_trigger.sql (514.96µs)6932026/08/27 09:35:55 goose: up to current file version: 26942026/08/27 09:35:55 OK 20251218171726_add_pins.sql (1.79ms)6952026/08/27 09:35:55 OK 20260628120000_add_object_size_and_stats.sql (1.4ms)6962026/08/27 09:35:55 goose: successfully migrated database to version: 202606281200006972026/08/27 09:35:55 OK 1_commit_pending_closure.sql (1.32ms)6982026/08/27 09:35:55 OK 2_object_stats_trigger.sql (735.08µs)6992026/08/27 09:35:55 goose: up to current file version: 27002026/08/27 09:35:55 OK 20251218171726_add_pins.sql (1.6ms)7012026/08/27 09:35:55 OK 1_commit_pending_closure.sql (1.67ms)7022026/08/27 09:35:55 OK 20260628120000_add_object_size_and_stats.sql (1.71ms)7032026/08/27 09:35:55 goose: successfully migrated database to version: 202606281200007042026/08/27 09:35:55 OK 1_commit_pending_closure.sql (1.67ms)7052026/08/27 09:35:55 OK 20260628120000_add_object_size_and_stats.sql (2.02ms)7062026/08/27 09:35:55 goose: successfully migrated database to version: 202606281200007072026/08/27 09:35:55 OK 2_object_stats_trigger.sql (346.17µs)7082026/08/27 09:35:55 goose: up to current file version: 27092026/08/27 09:35:55 OK 2_object_stats_trigger.sql (604.67µs)7102026/08/27 09:35:55 goose: up to current file version: 27112026/08/27 09:35:55 OK 2_object_stats_trigger.sql (434.58µs)7122026/08/27 09:35:55 goose: up to current file version: 27132026/08/27 09:35:55 OK 20260628120000_add_object_size_and_stats.sql (1.65ms)7142026/08/27 09:35:55 goose: successfully migrated database to version: 202606281200007152026/08/27 09:35:55 OK 1_commit_pending_closure.sql (991.96µs)7162026/08/27 09:35:55 OK 20260628120000_add_object_size_and_stats.sql (1.35ms)7172026/08/27 09:35:55 goose: successfully migrated database to version: 202606281200007182026/08/27 09:35:55 OK 1_commit_pending_closure.sql (1.1ms)7192026/08/27 09:35:55 OK 1_commit_pending_closure.sql (2.01ms)7202026/08/27 09:35:55 OK 2_object_stats_trigger.sql (338.46µs)7212026/08/27 09:35:55 goose: up to current file version: 27222026/08/27 09:35:55 OK 2_object_stats_trigger.sql (313.21µs)7232026/08/27 09:35:55 goose: up to current file version: 27242026/08/27 09:35:55 OK 2_object_stats_trigger.sql (365.04µs)7252026/08/27 09:35:55 goose: up to current file version: 27262026/08/27 09:35:55 OK 1_commit_pending_closure.sql (955.5µs)7272026/08/27 09:35:55 OK 2_object_stats_trigger.sql (206.25µs)7282026/08/27 09:35:55 goose: up to current file version: 27292026/08/27 09:35:55 OK 1_commit_pending_closure.sql (991.88µs)7302026/08/27 09:35:55 OK 2_object_stats_trigger.sql (187.5µs)7312026/08/27 09:35:55 goose: up to current file version: 2732{"timestamp":"2026-08-27T09:35:55.027578Z","level":"ERROR","duration":"81.625µs","resp":"Response { status: 503, version: HTTP/1.1, headers: {\"content-type\": \"application/xml\"}, body: Body { once: b\"<?xml version=\\\"1.0\\\" encoding=\\\"UTF-8\\\"?><Error><Code>SlowDown</Code><Message>bucket creation concurrency limit reached; retry later</Message></Error>\" } }","target":"s3s::service","filename":"/nix/var/nix/builds/nix-35807-2406330080/rustfs-1.0.0-beta.12-vendor/source-git-1/s3s-0.14.1/src/service.rs","line_number":640,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}733{"timestamp":"2026-08-27T09:35:55.02769Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"51dba114-3e18-4054-b1d5-f343f4d7c1c7","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket10/","status_code":503,"duration_ms":0,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}734{"timestamp":"2026-08-27T09:35:55.027858Z","level":"ERROR","duration":"49.125µs","resp":"Response { status: 503, version: HTTP/1.1, headers: {\"content-type\": \"application/xml\"}, body: Body { once: b\"<?xml version=\\\"1.0\\\" encoding=\\\"UTF-8\\\"?><Error><Code>SlowDown</Code><Message>bucket creation concurrency limit reached; retry later</Message></Error>\" } }","target":"s3s::service","filename":"/nix/var/nix/builds/nix-35807-2406330080/rustfs-1.0.0-beta.12-vendor/source-git-1/s3s-0.14.1/src/service.rs","line_number":640,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}735{"timestamp":"2026-08-27T09:35:55.027868Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"227ed47e-03ac-4d30-ba6c-af7c1c09cfe8","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket11/","status_code":503,"duration_ms":0,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}736{"timestamp":"2026-08-27T09:35:55.058027Z","level":"ERROR","duration":"18.709µs","resp":"Response { status: 503, version: HTTP/1.1, headers: {\"content-type\": \"application/xml\"}, body: Body { once: b\"<?xml version=\\\"1.0\\\" encoding=\\\"UTF-8\\\"?><Error><Code>SlowDown</Code><Message>bucket creation concurrency limit reached; retry later</Message></Error>\" } }","target":"s3s::service","filename":"/nix/var/nix/builds/nix-35807-2406330080/rustfs-1.0.0-beta.12-vendor/source-git-1/s3s-0.14.1/src/service.rs","line_number":640,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}737{"timestamp":"2026-08-27T09:35:55.058041Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"ede4a0ef-935b-4187-a8db-c96dfa3c55e1","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket10/","status_code":503,"duration_ms":0,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}738--- PASS: TestReadProxyNarinfo (0.45s)739=== CONT TestNARDeduplicationMetadataUploadBug7402026/08/27 09:35:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7412026/08/27 09:35:55 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst742--- PASS: TestCompleteMultipartUnregistered (0.57s)743=== CONT TestCreatePendingClosureRejectsOversizedNAR7442026/08/27 09:35:55 INFO Received uploads request method=POST path=/api/pending_closures745--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)746=== CONT TestCacheConfigHandlerMaxNarSize747--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)748=== CONT TestGenerateLandingPage749--- PASS: TestGenerateLandingPage (0.00s)750=== CONT TestService_healthCheckHandler7512026/08/27 09:35:55 INFO Received uploads request method=POST path=/api/pending_closures752--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.68s)753=== CONT TestGracefulShutdownDrainsInflight7542026/08/27 09:35:55 INFO Starting HTTP server address=127.0.0.1:515377552026/08/27 09:35:55 INFO Shutdown signal received, draining in-flight requests timeout=10s756--- PASS: TestGracefulShutdownDrainsInflight (0.07s)757=== CONT TestGCTaskStore_Fail758--- PASS: TestGCTaskStore_Fail (0.00s)759=== CONT TestGCTaskStore_PhaseUpdates760--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)761=== CONT TestGCTaskStore_CompletedAllowsNewTask762--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)763=== CONT TestGCTaskStore_GetReturnsLatest764--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)765=== CONT TestGCTaskStore_GetEmpty766--- PASS: TestGCTaskStore_GetEmpty (0.00s)767=== CONT TestGCTaskStore_ConflictDifferentParams768--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)769=== CONT TestClientErrorHandling770=== RUN TestClientErrorHandling/InvalidStorePath771=== PAUSE TestClientErrorHandling/InvalidStorePath772=== RUN TestClientErrorHandling/InvalidAuthToken773=== PAUSE TestClientErrorHandling/InvalidAuthToken774=== RUN TestClientErrorHandling/ServerNotAvailable775=== PAUSE TestClientErrorHandling/ServerNotAvailable776=== CONT TestGCTaskStore_StartNew777--- PASS: TestGCTaskStore_StartNew (0.00s)778=== CONT TestGCMetrics779--- PASS: TestReadProxyRangeRequest (0.76s)780=== CONT TestGCBugBareHashReferences7812026/08/27 09:35:55 WARN mTLS auth: subject not in bound subjects subject="CN=reader"7822026/08/27 09:35:55 WARN mTLS auth: subject not in bound subjects subject="CN=writer"783--- PASS: TestService_NativeMTLS (0.79s)784=== CONT TestPinProtectsFromGC785--- PASS: TestMetricsInventory (0.93s)786=== CONT TestClientWithDependencies787--- PASS: TestResurrectedObjectNotDeleted (0.99s)788=== CONT TestClientCADerivations789--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.00s)790=== CONT TestClientMultipleUploads7912026/08/27 09:35:55 INFO Received uploads request method=POST path=/api/pending_closures7922026/08/27 09:35:55 INFO Received cleanup request method=DELETE path=/api/pending_closures7932026/08/27 09:35:55 INFO Aborted multipart uploads count=1794--- PASS: TestMultipartCleanup (1.21s)795=== CONT TestCacheStatsHandler7962026/08/27 09:35:55 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"797--- PASS: TestService_AuthMiddleware (1.23s)798=== CONT TestClientIntegration7992026-08-27 09:35:56.010 UTC [28574] ERROR: relation "goose_db_version" does not exist at character 368002026-08-27 09:35:56.010 UTC [28574] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8012026/08/27 09:35:56 OK 20241026095416_initial_model.sql (56.84ms)8022026/08/27 09:35:56 OK 20251210153512_drop_unused_gin_index.sql (10.71ms)8032026/08/27 09:35:56 OK 20251218171726_add_pins.sql (9.41ms)8042026/08/27 09:35:56 OK 20260628120000_add_object_size_and_stats.sql (3.36ms)8052026/08/27 09:35:56 goose: successfully migrated database to version: 202606281200008062026/08/27 09:35:56 OK 1_commit_pending_closure.sql (1.56ms)8072026/08/27 09:35:56 OK 2_object_stats_trigger.sql (799.33µs)8082026/08/27 09:35:56 goose: up to current file version: 28092026-08-27 09:35:56.336 UTC [28590] ERROR: relation "goose_db_version" does not exist at character 368102026-08-27 09:35:56.336 UTC [28590] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC811=== NAME TestNARDeduplicationMetadataUploadBug812 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-28356-531849286/TestNARDeduplicationMetadataUploadBug2472757758/001/store/9k5kqi9iia5zwrz5qpr1f3wh7rklrw72-file1.txt8132026-08-27 09:35:56.431 UTC [28594] ERROR: relation "goose_db_version" does not exist at character 368142026-08-27 09:35:56.431 UTC [28594] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8152026-08-27 09:35:56.431 UTC [28595] ERROR: relation "goose_db_version" does not exist at character 368162026-08-27 09:35:56.431 UTC [28595] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8172026/08/27 09:35:56 OK 20241026095416_initial_model.sql (78.92ms)8182026/08/27 09:35:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8192026/08/27 09:35:56 OK 20251210153512_drop_unused_gin_index.sql (5.66ms)8202026/08/27 09:35:56 OK 20251218171726_add_pins.sql (25.47ms)8212026/08/27 09:35:56 OK 20260628120000_add_object_size_and_stats.sql (1.38ms)8222026/08/27 09:35:56 goose: successfully migrated database to version: 202606281200008232026/08/27 09:35:56 OK 1_commit_pending_closure.sql (869.42µs)8242026/08/27 09:35:56 OK 2_object_stats_trigger.sql (266.58µs)8252026/08/27 09:35:56 goose: up to current file version: 28262026/08/27 09:35:56 INFO Received uploads request method=POST path=/api/pending_closures8272026/08/27 09:35:56 OK 20241026095416_initial_model.sql (97.86ms)8282026/08/27 09:35:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8292026/08/27 09:35:56 INFO Uploading 9k5kqi9iia5zwrz5qpr1f3wh7rklrw72-file1.txt (160B)8302026/08/27 09:35:56 OK 20251210153512_drop_unused_gin_index.sql (7.44ms)8312026/08/27 09:35:56 OK 20251218171726_add_pins.sql (34.54ms)8322026/08/27 09:35:56 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"8332026/08/27 09:35:56 OK 20241026095416_initial_model.sql (153.9ms)8342026/08/27 09:35:56 OK 20251210153512_drop_unused_gin_index.sql (754.79µs)8352026/08/27 09:35:56 OK 20260628120000_add_object_size_and_stats.sql (43.37ms)8362026/08/27 09:35:56 goose: successfully migrated database to version: 202606281200008372026/08/27 09:35:56 WARN Failed to register uploaded object key=9k5kqi9iia5zwrz5qpr1f3wh7rklrw72.ls error="server returned 404: 404 page not found\n"8382026/08/27 09:35:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8392026/08/27 09:35:56 INFO Signed narinfos id=1 count=18402026/08/27 09:35:56 INFO Uploading 1 narinfos8412026/08/27 09:35:56 OK 1_commit_pending_closure.sql (6.82ms)8422026/08/27 09:35:56 OK 2_object_stats_trigger.sql (321.83µs)8432026/08/27 09:35:56 goose: up to current file version: 28442026-08-27 09:35:56.655 UTC [28602] ERROR: relation "goose_db_version" does not exist at character 368452026-08-27 09:35:56.655 UTC [28602] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8462026/08/27 09:35:56 OK 20251218171726_add_pins.sql (41.09ms)847--- PASS: TestService_healthCheckHandler (1.40s)848=== CONT TestCacheConfigHandler849=== RUN TestCacheConfigHandler/full_config,_no_issuer850=== PAUSE TestCacheConfigHandler/full_config,_no_issuer851=== RUN TestCacheConfigHandler/no_cache_url_configured852=== PAUSE TestCacheConfigHandler/no_cache_url_configured853=== RUN TestCacheConfigHandler/no_signing_keys854=== PAUSE TestCacheConfigHandler/no_signing_keys855=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator856=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator857=== CONT TestReadProxyHead8582026/08/27 09:35:56 WARN Failed to register uploaded object key=9k5kqi9iia5zwrz5qpr1f3wh7rklrw72.narinfo error="server returned 404: 404 page not found\n"8592026/08/27 09:35:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8602026/08/27 09:35:56 OK 20260628120000_add_object_size_and_stats.sql (46.49ms)8612026/08/27 09:35:56 goose: successfully migrated database to version: 202606281200008622026/08/27 09:35:56 INFO Completed upload id=18632026/08/27 09:35:56 INFO Upload complete. (291ms)8642026/08/27 09:35:56 OK 1_commit_pending_closure.sql (6.81ms)8652026/08/27 09:35:56 OK 2_object_stats_trigger.sql (388.42µs)8662026/08/27 09:35:56 goose: up to current file version: 2867=== NAME TestNARDeduplicationMetadataUploadBug868 metadata_upload_test.go:54: Retrieved narinfo from S3:869 StorePath: /nix/var/nix/builds/nix-28356-531849286/TestNARDeduplicationMetadataUploadBug2472757758/001/store/9k5kqi9iia5zwrz5qpr1f3wh7rklrw72-file1.txt870 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst871 Compression: zstd872 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf873 NarSize: 160874 References: 875 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf876 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)877 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):878 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}879 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-28356-531849286/TestNARDeduplicationMetadataUploadBug2472757758/001/store/yz30l6rwv1q08mdryqvvzcqhqpabiyrj-file2.txt8802026/08/27 09:35:56 OK 20241026095416_initial_model.sql (119.64ms)8812026/08/27 09:35:56 OK 20251210153512_drop_unused_gin_index.sql (14.69ms)8822026/08/27 09:35:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8832026-08-27 09:35:56.876 UTC [28612] ERROR: relation "goose_db_version" does not exist at character 368842026-08-27 09:35:56.876 UTC [28612] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8852026/08/27 09:35:56 OK 20251218171726_add_pins.sql (30.76ms)8862026/08/27 09:35:56 INFO Received uploads request method=POST path=/api/pending_closures8872026/08/27 09:35:56 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)8882026/08/27 09:35:56 OK 20260628120000_add_object_size_and_stats.sql (29.17ms)8892026/08/27 09:35:56 goose: successfully migrated database to version: 202606281200008902026/08/27 09:35:56 OK 1_commit_pending_closure.sql (10.5ms)8912026/08/27 09:35:56 OK 2_object_stats_trigger.sql (226.88µs)8922026/08/27 09:35:56 goose: up to current file version: 28932026/08/27 09:35:56 INFO Aborted multipart uploads count=08942026/08/27 09:35:56 WARN Force mode enabled - objects will be deleted immediately without grace period8952026/08/27 09:35: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=08962026/08/27 09:35:56 INFO Vacuumed table table=pending_closures8972026/08/27 09:35:56 INFO Vacuumed table table=pending_objects8982026/08/27 09:35:56 INFO Vacuumed table table=multipart_uploads8992026/08/27 09:35:56 INFO Vacuumed table table=closures9002026/08/27 09:35:56 INFO Vacuumed table table=objects901--- PASS: TestGCMetrics (1.49s)902=== CONT TestService_AuthMiddleware_OIDC9032026/08/27 09:35:56 WARN Failed to register uploaded object key=yz30l6rwv1q08mdryqvvzcqhqpabiyrj.ls error="server returned 404: 404 page not found\n"9042026/08/27 09:35:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9052026/08/27 09:35:56 INFO OIDC provider initialized name=test9062026/08/27 09:35:56 INFO Signed narinfos id=2 count=19072026/08/27 09:35:56 INFO Uploading 1 narinfos9082026/08/27 09:35:56 WARN Failed to register uploaded object key=yz30l6rwv1q08mdryqvvzcqhqpabiyrj.narinfo error="server returned 404: 404 page not found\n"9092026/08/27 09:35:56 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9102026/08/27 09:35:56 INFO Completed upload id=29112026/08/27 09:35:56 INFO Upload complete. (162ms)912=== NAME TestNARDeduplicationMetadataUploadBug913 metadata_upload_test.go:76: Retrieved narinfo from S3:914 StorePath: /nix/var/nix/builds/nix-28356-531849286/TestNARDeduplicationMetadataUploadBug2472757758/001/store/yz30l6rwv1q08mdryqvvzcqhqpabiyrj-file2.txt915 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst916 Compression: zstd917 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf918 NarSize: 160919 References: 920 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf921 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)922 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):923 {"version":1,"root":{"type":"regular","size":44}}9242026-08-27 09:35:57.011 UTC [28621] ERROR: relation "goose_db_version" does not exist at character 369252026-08-27 09:35:57.011 UTC [28621] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9262026-08-27 09:35:57.011 UTC [28620] ERROR: relation "goose_db_version" does not exist at character 369272026-08-27 09:35:57.011 UTC [28620] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC928--- PASS: TestNARDeduplicationMetadataUploadBug (1.89s)929=== CONT TestReadProxyDisabled9302026/08/27 09:35:57 OK 20241026095416_initial_model.sql (137.87ms)931--- PASS: TestGCBugBareHashReferences (1.61s)932=== CONT TestService_ReadAuthMiddleware9332026/08/27 09:35:57 OK 20251210153512_drop_unused_gin_index.sql (14.4ms)9342026/08/27 09:35:57 OK 20251218171726_add_pins.sql (27.21ms)9352026/08/27 09:35:57 OK 20260628120000_add_object_size_and_stats.sql (34.49ms)9362026/08/27 09:35:57 goose: successfully migrated database to version: 202606281200009372026/08/27 09:35:57 OK 1_commit_pending_closure.sql (920.67µs)9382026/08/27 09:35:57 OK 2_object_stats_trigger.sql (542.88µs)9392026/08/27 09:35:57 goose: up to current file version: 29402026/08/27 09:35:57 OK 20241026095416_initial_model.sql (96.25ms)9412026/08/27 09:35:57 OK 20251210153512_drop_unused_gin_index.sql (8.71ms)9422026/08/27 09:35:57 OK 20241026095416_initial_model.sql (109.46ms)9432026/08/27 09:35:57 OK 20251210153512_drop_unused_gin_index.sql (12.71ms)9442026/08/27 09:35:57 OK 20251218171726_add_pins.sql (32.47ms)9452026/08/27 09:35:57 OK 20251218171726_add_pins.sql (16.65ms)9462026/08/27 09:35:57 OK 20260628120000_add_object_size_and_stats.sql (11.61ms)9472026/08/27 09:35:57 goose: successfully migrated database to version: 202606281200009482026/08/27 09:35:57 OK 1_commit_pending_closure.sql (4.62ms)9492026/08/27 09:35:57 OK 2_object_stats_trigger.sql (194.92µs)9502026/08/27 09:35:57 goose: up to current file version: 29512026/08/27 09:35:57 OK 20260628120000_add_object_size_and_stats.sql (31.46ms)9522026/08/27 09:35:57 goose: successfully migrated database to version: 202606281200009532026/08/27 09:35:57 OK 1_commit_pending_closure.sql (6.86ms)9542026/08/27 09:35:57 OK 2_object_stats_trigger.sql (219µs)9552026/08/27 09:35:57 goose: up to current file version: 29562026-08-27 09:35:57.239 UTC [28631] ERROR: relation "goose_db_version" does not exist at character 369572026-08-27 09:35:57.239 UTC [28631] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9582026-08-27 09:35:57.268 UTC [28633] ERROR: relation "goose_db_version" does not exist at character 369592026-08-27 09:35:57.268 UTC [28633] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9602026/08/27 09:35:57 OK 20241026095416_initial_model.sql (141.27ms)9612026/08/27 09:35:57 OK 20251210153512_drop_unused_gin_index.sql (11.39ms)9622026/08/27 09:35:57 OK 20241026095416_initial_model.sql (120.73ms)9632026/08/27 09:35:57 OK 20251218171726_add_pins.sql (10ms)964=== NAME TestClientWithDependencies965 client_integration_test.go:593: Built derivation: /nix/var/nix/builds/nix-28356-531849286/TestClientWithDependencies3309023327/001/store/dz8gwf1j0f93sm2vsknizjiaxski2xlb-test-script9662026/08/27 09:35:57 OK 20251210153512_drop_unused_gin_index.sql (11.89ms)9672026/08/27 09:35:57 OK 20251218171726_add_pins.sql (19.66ms)9682026/08/27 09:35:57 OK 20260628120000_add_object_size_and_stats.sql (36.68ms)9692026/08/27 09:35:57 goose: successfully migrated database to version: 202606281200009702026/08/27 09:35:57 OK 1_commit_pending_closure.sql (1.75ms)971 client_integration_test.go:595: Found 1 dependencies (including self)9722026/08/27 09:35:57 OK 2_object_stats_trigger.sql (553.08µs)9732026/08/27 09:35:57 goose: up to current file version: 29742026/08/27 09:35:57 OK 20260628120000_add_object_size_and_stats.sql (29.05ms)9752026/08/27 09:35:57 goose: successfully migrated database to version: 202606281200009762026/08/27 09:35:57 OK 1_commit_pending_closure.sql (6.28ms)9772026/08/27 09:35:57 OK 2_object_stats_trigger.sql (339.75µs)9782026/08/27 09:35:57 goose: up to current file version: 2979=== NAME TestPinProtectsFromGC980 client_integration_test.go:646: Pinned store path: /nix/var/nix/builds/nix-28356-531849286/TestPinProtectsFromGC3808044799/001/store/warhaz5zwcizjihdrvvbsxvnhy71304b-pinned-file.txt981 client_integration_test.go:647: Unpinned store path: /nix/var/nix/builds/nix-28356-531849286/TestPinProtectsFromGC3808044799/001/store/jnbmpd5zylnm836barrh3rskrqvflxh8-unpinned-file.txt9822026/08/27 09:35:57 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9832026/08/27 09:35:57 INFO Received uploads request method=POST path=/api/pending_closures9842026/08/27 09:35:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9852026/08/27 09:35:57 INFO Uploading dz8gwf1j0f93sm2vsknizjiaxski2xlb-test-script (136B)9862026/08/27 09:35:57 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9872026/08/27 09:35:57 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"9882026/08/27 09:35:57 WARN Failed to register uploaded object key=log/lnw2qr2aa61ig0h7fmgqg39w86agvzfj-test-script.drv error="server returned 404: 404 page not found\n"989=== NAME TestClientMultipleUploads990 client_integration_test.go:338: Created store path 0: /nix/var/nix/builds/nix-28356-531849286/TestClientMultipleUploads697949007/001/store/s3pd27as4l281nvs55vmwszknhl1zxi7-test-file-0.txt9912026/08/27 09:35:57 WARN Failed to register uploaded object key=dz8gwf1j0f93sm2vsknizjiaxski2xlb.ls error="server returned 404: 404 page not found\n"9922026/08/27 09:35:57 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9932026/08/27 09:35:57 INFO Signed narinfos id=1 count=19942026/08/27 09:35:57 INFO Uploading 1 narinfos9952026/08/27 09:35:57 INFO Received uploads request method=POST path=/api/pending_closures9962026/08/27 09:35:57 WARN Failed to register uploaded object key=dz8gwf1j0f93sm2vsknizjiaxski2xlb.narinfo error="server returned 404: 404 page not found\n"9972026/08/27 09:35:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9982026/08/27 09:35:57 INFO Completed upload id=19992026/08/27 09:35:57 INFO Upload complete. (216ms)10002026/08/27 09:35:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10012026/08/27 09:35:57 INFO Uploading warhaz5zwcizjihdrvvbsxvnhy71304b-pinned-file.txt (128B)1002 client_integration_test.go:338: Created store path 1: /nix/var/nix/builds/nix-28356-531849286/TestClientMultipleUploads697949007/001/store/cpz2ljcvgsy3b1bz6hi8sglg7nr8ryyd-test-file-1.txt1003=== NAME TestClientWithDependencies1004 client_integration_test.go:597: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-28356-531849286/TestClientWithDependencies3309023327/001/store) requires matching store prefix1005=== NAME TestClientCADerivations1006 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-28356-531849286/TestClientCADerivations2996432280/001/store/waz40055w2mrvnmhd2jrsrkvalg7j48i-ca-test10072026/08/27 09:35:57 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1008--- PASS: TestCacheStatsHandler (1.85s)1009=== CONT TestReadProxyRootRedirectsToIndexHTML1010--- PASS: TestClientWithDependencies (2.13s)1011=== CONT TestReadProxyConditionalGet1012=== NAME TestClientMultipleUploads1013 client_integration_test.go:338: Created store path 2: /nix/var/nix/builds/nix-28356-531849286/TestClientMultipleUploads697949007/001/store/i6ip4cmzn5k262icxx543bwka6xsdl97-test-file-2.txt10142026/08/27 09:35:57 WARN Failed to register uploaded object key=warhaz5zwcizjihdrvvbsxvnhy71304b.ls error="server returned 404: 404 page not found\n"10152026/08/27 09:35:57 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10162026/08/27 09:35:57 INFO Signed narinfos id=1 count=110172026/08/27 09:35:57 INFO Uploading 1 narinfos1018=== NAME TestClientCADerivations1019 client_ca_test.go:139: Found 1 dependencies (including self)10202026/08/27 09:35:57 WARN Failed to register uploaded object key=warhaz5zwcizjihdrvvbsxvnhy71304b.narinfo error="server returned 404: 404 page not found\n"10212026/08/27 09:35:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1022=== NAME TestClientIntegration1023 client_integration_test.go:276: Created store path: /nix/var/nix/builds/nix-28356-531849286/TestClientIntegration3469711199/002/store/s0czjl1s8sacgwa8z6lkk8br9497q68d-test-file.txt10242026/08/27 09:35:57 INFO Completed upload id=110252026/08/27 09:35:57 INFO Upload complete. (274ms)10262026/08/27 09:35:57 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10272026/08/27 09:35:57 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10282026/08/27 09:35:57 INFO Received uploads request method=POST path=/api/pending_closures10292026/08/27 09:35:57 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10302026/08/27 09:35:57 INFO Received uploads request method=POST path=/api/pending_closures10312026/08/27 09:35:57 INFO Received uploads request method=POST path=/api/pending_closures10322026/08/27 09:35:57 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)10332026/08/27 09:35:57 INFO Uploading i6ip4cmzn5k262icxx543bwka6xsdl97-test-file-2.txt (160B)10342026/08/27 09:35:57 INFO Uploading s3pd27as4l281nvs55vmwszknhl1zxi7-test-file-0.txt (160B)10352026/08/27 09:35:57 INFO Uploading cpz2ljcvgsy3b1bz6hi8sglg7nr8ryyd-test-file-1.txt (160B)10362026/08/27 09:35:57 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10372026/08/27 09:35:57 INFO Received uploads request method=POST path=/api/pending_closures10382026/08/27 09:35:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10392026/08/27 09:35:57 INFO Uploading waz40055w2mrvnmhd2jrsrkvalg7j48i-ca-test (144B)10402026/08/27 09:35:57 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"10412026/08/27 09:35:57 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"10422026/08/27 09:35:57 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"10432026/08/27 09:35:57 INFO Received uploads request method=POST path=/api/pending_closures10442026/08/27 09:35:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10452026/08/27 09:35:57 INFO Uploading jnbmpd5zylnm836barrh3rskrqvflxh8-unpinned-file.txt (128B)10462026/08/27 09:35:57 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"10472026/08/27 09:35:58 WARN Failed to register uploaded object key=log/qvvcscqgnzpig1mww6j9ihd82nymnfgf-ca-test.drv error="server returned 404: 404 page not found\n"10482026/08/27 09:35:58 WARN Failed to register uploaded object key=s3pd27as4l281nvs55vmwszknhl1zxi7.ls error="server returned 404: 404 page not found\n"10492026/08/27 09:35:58 WARN Failed to register uploaded object key=i6ip4cmzn5k262icxx543bwka6xsdl97.ls error="server returned 404: 404 page not found\n"10502026/08/27 09:35:58 WARN Failed to register uploaded object key=cpz2ljcvgsy3b1bz6hi8sglg7nr8ryyd.ls error="server returned 404: 404 page not found\n"10512026/08/27 09:35:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10522026/08/27 09:35:58 INFO Signed narinfos id=1 count=110532026/08/27 09:35:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10542026/08/27 09:35:58 INFO Signed narinfos id=2 count=110552026/08/27 09:35:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign10562026/08/27 09:35:58 INFO Signed narinfos id=3 count=110572026/08/27 09:35:58 INFO Uploading 3 narinfos10582026/08/27 09:35:58 INFO Received uploads request method=POST path=/api/pending_closures10592026/08/27 09:35:58 WARN Failed to register uploaded object key=waz40055w2mrvnmhd2jrsrkvalg7j48i.ls error="server returned 404: 404 page not found\n"10602026/08/27 09:35:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10612026/08/27 09:35:58 INFO Signed narinfos id=1 count=110622026/08/27 09:35:58 INFO Uploading 1 narinfos10632026/08/27 09:35:58 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"10642026/08/27 09:35:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10652026/08/27 09:35:58 INFO Uploading s0czjl1s8sacgwa8z6lkk8br9497q68d-test-file.txt (152B)10662026/08/27 09:35:58 WARN Failed to register uploaded object key=s3pd27as4l281nvs55vmwszknhl1zxi7.narinfo error="server returned 404: 404 page not found\n"10672026/08/27 09:35:58 WARN Failed to register uploaded object key=cpz2ljcvgsy3b1bz6hi8sglg7nr8ryyd.narinfo error="server returned 404: 404 page not found\n"10682026/08/27 09:35:58 WARN Failed to register uploaded object key=i6ip4cmzn5k262icxx543bwka6xsdl97.narinfo error="server returned 404: 404 page not found\n"10692026/08/27 09:35:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10702026/08/27 09:35:58 WARN Failed to register uploaded object key=waz40055w2mrvnmhd2jrsrkvalg7j48i.narinfo error="server returned 404: 404 page not found\n"10712026/08/27 09:35:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10722026/08/27 09:35:58 INFO Completed upload id=110732026/08/27 09:35:58 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10742026/08/27 09:35:58 INFO Completed upload id=210752026/08/27 09:35:58 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete10762026/08/27 09:35:58 INFO Completed upload id=310772026/08/27 09:35:58 INFO Upload complete. (330ms)1078=== NAME TestClientMultipleUploads1079 client_integration_test.go:349: Uploaded 3 paths in 360.202959ms10802026/08/27 09:35:58 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"10812026/08/27 09:35:58 WARN Failed to register uploaded object key=jnbmpd5zylnm836barrh3rskrqvflxh8.ls error="server returned 404: 404 page not found\n"10822026/08/27 09:35:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10832026/08/27 09:35:58 INFO Signed narinfos id=2 count=110842026/08/27 09:35:58 INFO Uploading 1 narinfos10852026/08/27 09:35:58 INFO Completed upload id=110862026/08/27 09:35:58 INFO Upload complete. (308ms)1087=== NAME TestClientCADerivations1088 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-28356-531849286/TestClientCADerivations2996432280/001/store/waz40055w2mrvnmhd2jrsrkvalg7j48i-ca-test1089 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1090 Compression: zstd1091 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1092 NarSize: 1441093 References: 1094 Deriver: /nix/var/nix/builds/nix-28356-531849286/TestClientCADerivations2996432280/001/store/qvvcscqgnzpig1mww6j9ihd82nymnfgf-ca-test.drv1095 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1096 client_ca_test.go:185: Checking for realisation files in S3...1097 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1098 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache10992026/08/27 09:35:58 WARN Failed to register uploaded object key=s0czjl1s8sacgwa8z6lkk8br9497q68d.ls error="server returned 404: 404 page not found\n"11002026/08/27 09:35:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11012026/08/27 09:35:58 INFO Signed narinfos id=1 count=111022026/08/27 09:35:58 INFO Uploading 1 narinfos11032026/08/27 09:35:58 WARN Failed to register uploaded object key=jnbmpd5zylnm836barrh3rskrqvflxh8.narinfo error="server returned 404: 404 page not found\n"11042026/08/27 09:35:58 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11052026/08/27 09:35:58 INFO Completed upload id=211062026/08/27 09:35:58 INFO Upload complete. (304ms)11072026-08-27 09:35:58.184 UTC [28704] ERROR: relation "goose_db_version" does not exist at character 3611082026-08-27 09:35:58.184 UTC [28704] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11092026/08/27 09:35:58 WARN Failed to register uploaded object key=s0czjl1s8sacgwa8z6lkk8br9497q68d.narinfo error="server returned 404: 404 page not found\n"11102026/08/27 09:35:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1111--- PASS: TestClientMultipleUploads (2.50s)1112=== CONT TestOrphanedObjectsGC1113=== NAME TestClientCADerivations1114 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket19?endpoint=http://localhost:51504®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-28356-531849286/TestClientCADerivations2996432280/001/store'1115 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 111162026/08/27 09:35:58 INFO Received create pin request method=POST path=/api/pins/myapp11172026/08/27 09:35:58 INFO Completed upload id=111182026/08/27 09:35:58 INFO Upload complete. (362ms)1119=== NAME TestClientIntegration1120 client_integration_test.go:292: Retrieved narinfo from S3:1121 StorePath: /nix/var/nix/builds/nix-28356-531849286/TestClientIntegration3469711199/002/store/s0czjl1s8sacgwa8z6lkk8br9497q68d-test-file.txt1122 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1123 Compression: zstd1124 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11125 NarSize: 1521126 References: 1127 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11128 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1129 client_integration_test.go:293: Decompressed .ls content (64 bytes):1130 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1131 client_integration_test.go:296: Testing garbage collection...11322026/08/27 09:35:58 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-28356-531849286/TestPinProtectsFromGC3808044799/001/store/warhaz5zwcizjihdrvvbsxvnhy71304b-pinned-file.txt narinfo_key=warhaz5zwcizjihdrvvbsxvnhy71304b.narinfo11332026/08/27 09:35:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures11342026/08/27 09:35:58 INFO Garbage collection started11352026/08/27 09:35:58 INFO Aborted multipart uploads count=011362026/08/27 09:35:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures11372026/08/27 09:35:58 INFO Garbage collection started11382026/08/27 09:35:58 WARN Force mode enabled - objects will be deleted immediately without grace period11392026/08/27 09:35:58 INFO Aborted multipart uploads count=011402026/08/27 09:35:58 WARN Force mode enabled - objects will be deleted immediately without grace period1141--- PASS: TestClientCADerivations (2.57s)1142=== CONT TestOrphanedObjectsGCStressTest11432026-08-27 09:35:58.281 UTC [28717] ERROR: relation "goose_db_version" does not exist at character 3611442026-08-27 09:35:58.281 UTC [28717] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11452026/08/27 09:35:58 OK 20241026095416_initial_model.sql (78.1ms)11462026/08/27 09:35:58 OK 20251210153512_drop_unused_gin_index.sql (5.85ms)11472026/08/27 09:35:58 OK 20251218171726_add_pins.sql (2.58ms)11482026-08-27 09:35:58.313 UTC [28718] ERROR: relation "goose_db_version" does not exist at character 3611492026-08-27 09:35:58.313 UTC [28718] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11502026-08-27 09:35:58.323 UTC [28719] ERROR: relation "goose_db_version" does not exist at character 3611512026-08-27 09:35:58.323 UTC [28719] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11522026/08/27 09:35:58 OK 20260628120000_add_object_size_and_stats.sql (34.86ms)11532026/08/27 09:35:58 goose: successfully migrated database to version: 2026062812000011542026/08/27 09:35:58 OK 1_commit_pending_closure.sql (3.19ms)11552026/08/27 09:35:58 OK 2_object_stats_trigger.sql (644.42µs)11562026/08/27 09:35:58 goose: up to current file version: 211572026/08/27 09:35:58 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=011582026/08/27 09:35:58 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=011592026/08/27 09:35:58 OK 20241026095416_initial_model.sql (66.11ms)11602026/08/27 09:35:58 OK 20251210153512_drop_unused_gin_index.sql (7.38ms)11612026/08/27 09:35:58 INFO Vacuumed table table=pending_closures11622026/08/27 09:35:58 INFO Vacuumed table table=pending_closures11632026/08/27 09:35:58 INFO Vacuumed table table=pending_objects11642026/08/27 09:35:58 INFO Vacuumed table table=multipart_uploads11652026/08/27 09:35:58 OK 20251218171726_add_pins.sql (33.78ms)11662026/08/27 09:35:58 INFO Vacuumed table table=pending_objects11672026/08/27 09:35:58 INFO Vacuumed table table=multipart_uploads11682026/08/27 09:35:58 OK 20260628120000_add_object_size_and_stats.sql (19.68ms)11692026/08/27 09:35:58 goose: successfully migrated database to version: 2026062812000011702026/08/27 09:35:58 INFO Vacuumed table table=closures11712026/08/27 09:35:58 INFO Vacuumed table table=closures11722026/08/27 09:35:58 OK 1_commit_pending_closure.sql (4.62ms)11732026/08/27 09:35:58 OK 2_object_stats_trigger.sql (203.5µs)11742026/08/27 09:35:58 goose: up to current file version: 21175--- PASS: TestReadProxyHead (1.83s)1176=== CONT TestService_AuthMiddleware_MTLSProxyHeader11772026/08/27 09:35:58 OK 20241026095416_initial_model.sql (162.84ms)11782026/08/27 09:35:58 INFO Vacuumed table table=objects11792026/08/27 09:35:58 OK 20241026095416_initial_model.sql (163.24ms)11802026/08/27 09:35:58 INFO Vacuumed table table=objects11812026/08/27 09:35:58 OK 20251210153512_drop_unused_gin_index.sql (4.69ms)11822026/08/27 09:35:58 OK 20251210153512_drop_unused_gin_index.sql (4.38ms)11832026/08/27 09:35:58 OK 20251218171726_add_pins.sql (16.98ms)11842026/08/27 09:35:58 OK 20251218171726_add_pins.sql (29.66ms)11852026/08/27 09:35:58 OK 20260628120000_add_object_size_and_stats.sql (29.04ms)11862026/08/27 09:35:58 goose: successfully migrated database to version: 2026062812000011872026/08/27 09:35:58 OK 20260628120000_add_object_size_and_stats.sql (16.47ms)11882026/08/27 09:35:58 goose: successfully migrated database to version: 202606281200001189=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1190=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1191=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1192=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1193=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1194=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1195=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1196=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1197=== CONT TestService_AuthMiddleware_MTLSBoundSubjects11982026/08/27 09:35:58 OK 1_commit_pending_closure.sql (6.05ms)11992026/08/27 09:35:58 OK 1_commit_pending_closure.sql (7.17ms)12002026/08/27 09:35:58 OK 2_object_stats_trigger.sql (1.22ms)12012026/08/27 09:35:58 goose: up to current file version: 212022026/08/27 09:35:58 OK 2_object_stats_trigger.sql (1.2ms)12032026/08/27 09:35:58 goose: up to current file version: 212042026/08/27 09:35:58 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1205--- PASS: TestService_ReadAuthMiddleware (1.62s)1206=== CONT TestObjectStatsTrigger1207--- PASS: TestReadProxyDisabled (1.68s)1208=== CONT TestReadProxy40412092026-08-27 09:35:58.772 UTC [28732] ERROR: relation "goose_db_version" does not exist at character 3612102026-08-27 09:35:58.772 UTC [28732] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12112026/08/27 09:35:58 OK 20241026095416_initial_model.sql (7.05ms)12122026/08/27 09:35:58 OK 20251210153512_drop_unused_gin_index.sql (410.58µs)12132026/08/27 09:35:58 OK 20251218171726_add_pins.sql (730.29µs)12142026/08/27 09:35:58 OK 20260628120000_add_object_size_and_stats.sql (3.17ms)12152026/08/27 09:35:58 goose: successfully migrated database to version: 2026062812000012162026/08/27 09:35:58 OK 1_commit_pending_closure.sql (899.13µs)12172026/08/27 09:35:58 OK 2_object_stats_trigger.sql (210.29µs)12182026/08/27 09:35:58 goose: up to current file version: 212192026-08-27 09:35:58.925 UTC [28733] ERROR: relation "goose_db_version" does not exist at character 3612202026-08-27 09:35:58.925 UTC [28733] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1221--- PASS: TestReadProxyConditionalGet (1.17s)1222=== CONT TestReadProxyInvalidPath12232026/08/27 09:35:58 OK 20241026095416_initial_model.sql (8.38ms)12242026/08/27 09:35:58 OK 20251210153512_drop_unused_gin_index.sql (3.95ms)12252026/08/27 09:35:58 OK 20251218171726_add_pins.sql (803.25µs)12262026/08/27 09:35:58 OK 20260628120000_add_object_size_and_stats.sql (12.85ms)12272026/08/27 09:35:58 goose: successfully migrated database to version: 2026062812000012282026/08/27 09:35:58 OK 1_commit_pending_closure.sql (1.56ms)12292026/08/27 09:35:58 OK 2_object_stats_trigger.sql (559.25µs)12302026/08/27 09:35:58 goose: up to current file version: 21231--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.36s)1232=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle12332026-08-27 09:35:59.167 UTC [28738] ERROR: relation "goose_db_version" does not exist at character 3612342026-08-27 09:35:59.167 UTC [28738] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12352026-08-27 09:35:59.167 UTC [28739] ERROR: relation "goose_db_version" does not exist at character 3612362026-08-27 09:35:59.167 UTC [28739] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12372026/08/27 09:35:59 OK 20241026095416_initial_model.sql (24.63ms)12382026/08/27 09:35:59 OK 20241026095416_initial_model.sql (25.13ms)12392026/08/27 09:35:59 OK 20251210153512_drop_unused_gin_index.sql (1.13ms)12402026/08/27 09:35:59 OK 20251210153512_drop_unused_gin_index.sql (586.42µs)12412026/08/27 09:35:59 OK 20251218171726_add_pins.sql (3.91ms)12422026/08/27 09:35:59 OK 20251218171726_add_pins.sql (3.67ms)12432026/08/27 09:35:59 OK 20260628120000_add_object_size_and_stats.sql (22.03ms)12442026/08/27 09:35:59 goose: successfully migrated database to version: 2026062812000012452026/08/27 09:35:59 OK 20260628120000_add_object_size_and_stats.sql (22.09ms)12462026/08/27 09:35:59 goose: successfully migrated database to version: 2026062812000012472026/08/27 09:35:59 OK 1_commit_pending_closure.sql (1.2ms)12482026/08/27 09:35:59 OK 1_commit_pending_closure.sql (1.24ms)12492026/08/27 09:35:59 OK 2_object_stats_trigger.sql (223.25µs)12502026/08/27 09:35:59 goose: up to current file version: 212512026/08/27 09:35:59 OK 2_object_stats_trigger.sql (236.83µs)12522026/08/27 09:35:59 goose: up to current file version: 212532026-08-27 09:35:59.500 UTC [28740] ERROR: relation "goose_db_version" does not exist at character 3612542026-08-27 09:35:59.500 UTC [28740] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12552026/08/27 09:35:59 OK 20241026095416_initial_model.sql (100.7ms)12562026/08/27 09:35:59 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)12572026/08/27 09:35:59 OK 20251218171726_add_pins.sql (22.41ms)12582026-08-27 09:35:59.679 UTC [28741] ERROR: relation "goose_db_version" does not exist at character 3612592026-08-27 09:35:59.679 UTC [28741] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12602026/08/27 09:35:59 OK 20260628120000_add_object_size_and_stats.sql (26.57ms)12612026/08/27 09:35:59 goose: successfully migrated database to version: 2026062812000012622026/08/27 09:35:59 OK 1_commit_pending_closure.sql (1.55ms)12632026/08/27 09:35:59 OK 2_object_stats_trigger.sql (197.38µs)12642026/08/27 09:35:59 goose: up to current file version: 212652026-08-27 09:35:59.820 UTC [28742] ERROR: relation "goose_db_version" does not exist at character 3612662026-08-27 09:35:59.820 UTC [28742] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1267--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.36s)1268=== CONT TestReadProxyNarStreaming12692026/08/27 09:35:59 OK 20241026095416_initial_model.sql (189.32ms)12702026/08/27 09:35:59 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)12712026-08-27 09:35:59.924 UTC [28747] ERROR: relation "goose_db_version" does not exist at character 3612722026-08-27 09:35:59.924 UTC [28747] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12732026/08/27 09:35:59 OK 20251218171726_add_pins.sql (38.84ms)12742026/08/27 09:35:59 OK 20241026095416_initial_model.sql (114.12ms)12752026/08/27 09:35:59 OK 20260628120000_add_object_size_and_stats.sql (35.94ms)12762026/08/27 09:35:59 goose: successfully migrated database to version: 2026062812000012772026/08/27 09:36:00 OK 1_commit_pending_closure.sql (1.7ms)12782026/08/27 09:36:00 OK 2_object_stats_trigger.sql (292.46µs)12792026/08/27 09:36:00 goose: up to current file version: 212802026/08/27 09:36:00 OK 20251210153512_drop_unused_gin_index.sql (14.53ms)12812026/08/27 09:36:00 OK 20251218171726_add_pins.sql (34.88ms)12822026/08/27 09:36:00 OK 20260628120000_add_object_size_and_stats.sql (37.18ms)12832026/08/27 09:36:00 goose: successfully migrated database to version: 2026062812000012842026/08/27 09:36:00 OK 1_commit_pending_closure.sql (1.58ms)12852026/08/27 09:36:00 OK 2_object_stats_trigger.sql (242.46µs)12862026/08/27 09:36:00 goose: up to current file version: 212872026/08/27 09:36:00 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"12882026/08/27 09:36:00 WARN mTLS auth: bound subjects configured but subject DN unavailable12892026/08/27 09:36:00 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1290--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.60s)1291=== CONT TestUploadHandlersRejectOversizedBody12922026/08/27 09:36:00 OK 20241026095416_initial_model.sql (235.08ms)12932026/08/27 09:36:00 OK 20251210153512_drop_unused_gin_index.sql (15.91ms)1294=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1295=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1296=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1297=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1298=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1299=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1300=== CONT TestUploadHandlersRejectInvalidKeys1301=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1302=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1303=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1304=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1305=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1306=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1307=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1308=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1309=== CONT TestService_verifyS3Integrity13102026/08/27 09:36:00 OK 20251218171726_add_pins.sql (24.88ms)13112026/08/27 09:36:00 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01312=== NAME TestPinProtectsFromGC1313 client_integration_test.go:709: Pin successfully protected closure from garbage collection13142026/08/27 09:36:00 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01315=== NAME TestClientIntegration1316 client_integration_test.go:303: Objects in database after GC:1317 client_integration_test.go:303: Successfully deleted all objects with GC --force13182026/08/27 09:36:00 OK 20260628120000_add_object_size_and_stats.sql (39.19ms)13192026/08/27 09:36:00 goose: successfully migrated database to version: 2026062812000013202026/08/27 09:36:00 OK 1_commit_pending_closure.sql (8.15ms)13212026/08/27 09:36:00 OK 2_object_stats_trigger.sql (339µs)13222026/08/27 09:36:00 goose: up to current file version: 21323--- PASS: TestClientIntegration (4.43s)1324=== CONT TestIsValidUploadKey1325=== RUN TestIsValidUploadKey/narinfo1326=== PAUSE TestIsValidUploadKey/narinfo1327=== RUN TestIsValidUploadKey/nar_zst1328=== PAUSE TestIsValidUploadKey/nar_zst1329=== RUN TestIsValidUploadKey/nar_xz1330=== PAUSE TestIsValidUploadKey/nar_xz1331=== RUN TestIsValidUploadKey/nar_plain1332=== PAUSE TestIsValidUploadKey/nar_plain1333=== RUN TestIsValidUploadKey/listing1334=== PAUSE TestIsValidUploadKey/listing1335=== RUN TestIsValidUploadKey/build_log1336=== PAUSE TestIsValidUploadKey/build_log1337=== RUN TestIsValidUploadKey/build_log_home-manager_file1338=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1339=== RUN TestIsValidUploadKey/build_log_plus_in_name1340=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1341=== RUN TestIsValidUploadKey/build_log_question_mark1342=== PAUSE TestIsValidUploadKey/build_log_question_mark1343=== RUN TestIsValidUploadKey/build_log_equals1344=== PAUSE TestIsValidUploadKey/build_log_equals1345=== RUN TestIsValidUploadKey/realisation1346=== PAUSE TestIsValidUploadKey/realisation1347=== RUN TestIsValidUploadKey/realisation_plus_in_output1348=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1349=== RUN TestIsValidUploadKey/nix-cache-info1350=== PAUSE TestIsValidUploadKey/nix-cache-info1351=== RUN TestIsValidUploadKey/index.html1352=== PAUSE TestIsValidUploadKey/index.html1353=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1354=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1355=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1356=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1357=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1358=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1359=== RUN TestIsValidUploadKey/traversal1360=== PAUSE TestIsValidUploadKey/traversal1361=== RUN TestIsValidUploadKey/traversal_nar1362=== PAUSE TestIsValidUploadKey/traversal_nar1363=== RUN TestIsValidUploadKey/absolute1364=== PAUSE TestIsValidUploadKey/absolute1365=== RUN TestIsValidUploadKey/empty_key1366=== PAUSE TestIsValidUploadKey/empty_key1367=== RUN TestIsValidUploadKey/unknown_type1368=== PAUSE TestIsValidUploadKey/unknown_type1369=== CONT TestPresignedUploadRegisteredBeforeCommit1370--- PASS: TestPinProtectsFromGC (4.87s)1371=== CONT TestService_createPendingClosureHandler1372--- PASS: TestObjectStatsTrigger (1.68s)1373=== CONT TestProxyWriteTimeout1374=== RUN TestProxyWriteTimeout/narinfo1375=== PAUSE TestProxyWriteTimeout/narinfo1376=== RUN TestProxyWriteTimeout/1_GiB_nar1377=== PAUSE TestProxyWriteTimeout/1_GiB_nar1378=== RUN TestProxyWriteTimeout/10_GiB_nar1379=== PAUSE TestProxyWriteTimeout/10_GiB_nar1380=== RUN TestProxyWriteTimeout/unknown_size1381=== PAUSE TestProxyWriteTimeout/unknown_size1382=== CONT TestSkippedUploadsHandler13832026/08/27 09:36:00 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001384--- PASS: TestSkippedUploadsHandler (0.00s)1385=== CONT TestService_cleanupPendingClosuresHandler13862026-08-27 09:36:00.364 UTC [28753] ERROR: relation "goose_db_version" does not exist at character 3613872026-08-27 09:36:00.364 UTC [28753] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1388=== NAME TestOrphanedObjectsGC1389 orphaned_objects_gc_test.go:290: GC Test Summary:1390 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1391 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1392 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1393 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1394 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1395--- PASS: TestOrphanedObjectsGC (2.18s)1396=== CONT TestParseSize1397--- PASS: TestParseSize (0.00s)1398=== CONT TestService_Rustfstest1399--- PASS: TestReadProxy404 (1.75s)1400=== CONT TestCompleteMultipartUpload_ErrorButObjectExists14012026/08/27 09:36:00 OK 20241026095416_initial_model.sql (152.02ms)14022026/08/27 09:36:00 OK 20251210153512_drop_unused_gin_index.sql (6.61ms)14032026/08/27 09:36:00 OK 20251218171726_add_pins.sql (31.56ms)14042026/08/27 09:36:00 OK 20260628120000_add_object_size_and_stats.sql (45.31ms)14052026/08/27 09:36:00 goose: successfully migrated database to version: 2026062812000014062026/08/27 09:36:00 OK 1_commit_pending_closure.sql (13.73ms)14072026/08/27 09:36:00 OK 2_object_stats_trigger.sql (641.54µs)14082026/08/27 09:36:00 goose: up to current file version: 214092026-08-27 09:36:00.742 UTC [28764] ERROR: relation "goose_db_version" does not exist at character 3614102026-08-27 09:36:00.742 UTC [28764] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1411--- PASS: TestReadProxyInvalidPath (1.92s)1412=== CONT TestRedundantMultipartUpload14132026/08/27 09:36:00 OK 20241026095416_initial_model.sql (122.88ms)14142026/08/27 09:36:00 OK 20251210153512_drop_unused_gin_index.sql (8.57ms)14152026/08/27 09:36:00 OK 20251218171726_add_pins.sql (18.59ms)14162026/08/27 09:36:00 OK 20260628120000_add_object_size_and_stats.sql (26.39ms)14172026/08/27 09:36:00 goose: successfully migrated database to version: 2026062812000014182026/08/27 09:36:01 OK 1_commit_pending_closure.sql (14.82ms)14192026/08/27 09:36:01 OK 2_object_stats_trigger.sql (942.58µs)14202026/08/27 09:36:01 goose: up to current file version: 214212026/08/27 09:36:01 INFO Received uploads request method=POST path=/api/pending_closures14222026/08/27 09:36:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14232026-08-27 09:36:01.864 UTC [28769] ERROR: relation "goose_db_version" does not exist at character 3614242026-08-27 09:36:01.864 UTC [28769] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14252026/08/27 09:36:02 OK 20241026095416_initial_model.sql (129.98ms)14262026/08/27 09:36:02 OK 20251210153512_drop_unused_gin_index.sql (9.4ms)14272026/08/27 09:36:02 OK 20251218171726_add_pins.sql (18.14ms)14282026/08/27 09:36:02 OK 20260628120000_add_object_size_and_stats.sql (28.83ms)14292026/08/27 09:36:02 goose: successfully migrated database to version: 2026062812000014302026/08/27 09:36:02 OK 1_commit_pending_closure.sql (10.81ms)14312026/08/27 09:36:02 OK 2_object_stats_trigger.sql (2.67ms)14322026/08/27 09:36:02 goose: up to current file version: 214332026-08-27 09:36:02.118 UTC [28770] ERROR: relation "goose_db_version" does not exist at character 3614342026-08-27 09:36:02.118 UTC [28770] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1435--- PASS: TestReadProxyNarStreaming (2.50s)1436=== CONT TestCompletedNarNotReofferedAcrossClosures14372026-08-27 09:36:02.383 UTC [28771] ERROR: relation "goose_db_version" does not exist at character 3614382026-08-27 09:36:02.383 UTC [28771] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14392026-08-27 09:36:02.395 UTC [28772] ERROR: relation "goose_db_version" does not exist at character 3614402026-08-27 09:36:02.395 UTC [28772] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14412026/08/27 09:36:02 OK 20241026095416_initial_model.sql (209.28ms)14422026/08/27 09:36:02 OK 20251210153512_drop_unused_gin_index.sql (3.57ms)14432026/08/27 09:36:02 OK 20251218171726_add_pins.sql (14ms)14442026-08-27 09:36:02.422 UTC [28775] ERROR: relation "goose_db_version" does not exist at character 3614452026-08-27 09:36:02.422 UTC [28775] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14462026/08/27 09:36:02 OK 20260628120000_add_object_size_and_stats.sql (15.73ms)14472026/08/27 09:36:02 goose: successfully migrated database to version: 2026062812000014482026-08-27 09:36:02.430 UTC [28776] ERROR: relation "goose_db_version" does not exist at character 3614492026-08-27 09:36:02.430 UTC [28776] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14502026/08/27 09:36:02 OK 1_commit_pending_closure.sql (14.74ms)14512026/08/27 09:36:02 OK 2_object_stats_trigger.sql (526.54µs)14522026/08/27 09:36:02 goose: up to current file version: 214532026-08-27 09:36:02.450 UTC [28777] ERROR: relation "goose_db_version" does not exist at character 3614542026-08-27 09:36:02.450 UTC [28777] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14552026/08/27 09:36:02 OK 20241026095416_initial_model.sql (208.55ms)14562026/08/27 09:36:02 OK 20251210153512_drop_unused_gin_index.sql (9.98ms)14572026/08/27 09:36:02 INFO Received uploads request method=POST path=/api/pending_closures14582026/08/27 09:36:02 OK 20241026095416_initial_model.sql (235.6ms)14592026/08/27 09:36:02 OK 20251218171726_add_pins.sql (38.01ms)14602026/08/27 09:36:02 OK 20251210153512_drop_unused_gin_index.sql (13.02ms)14612026/08/27 09:36:02 OK 20260628120000_add_object_size_and_stats.sql (37.23ms)14622026/08/27 09:36:02 goose: successfully migrated database to version: 2026062812000014632026/08/27 09:36:02 OK 1_commit_pending_closure.sql (5.96ms)14642026/08/27 09:36:02 OK 2_object_stats_trigger.sql (2.92ms)14652026/08/27 09:36:02 goose: up to current file version: 214662026/08/27 09:36:02 OK 20251218171726_add_pins.sql (41.24ms)14672026/08/27 09:36:02 OK 20241026095416_initial_model.sql (235.44ms)14682026/08/27 09:36:02 OK 20251210153512_drop_unused_gin_index.sql (12.8ms)14692026/08/27 09:36:02 OK 20241026095416_initial_model.sql (237.52ms)14702026/08/27 09:36:02 OK 20251210153512_drop_unused_gin_index.sql (10.03ms)14712026/08/27 09:36:02 OK 20260628120000_add_object_size_and_stats.sql (38.13ms)14722026/08/27 09:36:02 goose: successfully migrated database to version: 2026062812000014732026/08/27 09:36:02 OK 20251218171726_add_pins.sql (25.61ms)14742026/08/27 09:36:02 OK 1_commit_pending_closure.sql (3.04ms)14752026/08/27 09:36:02 OK 2_object_stats_trigger.sql (559.46µs)14762026/08/27 09:36:02 goose: up to current file version: 214772026/08/27 09:36:02 OK 20241026095416_initial_model.sql (238.91ms)14782026/08/27 09:36:02 OK 20251210153512_drop_unused_gin_index.sql (13.39ms)14792026/08/27 09:36:02 OK 20260628120000_add_object_size_and_stats.sql (61.71ms)14802026/08/27 09:36:02 goose: successfully migrated database to version: 2026062812000014812026/08/27 09:36:02 OK 20251218171726_add_pins.sql (64.44ms)14822026/08/27 09:36:02 OK 1_commit_pending_closure.sql (17.59ms)14832026/08/27 09:36:02 OK 2_object_stats_trigger.sql (759.25µs)14842026/08/27 09:36:02 goose: up to current file version: 214852026/08/27 09:36:02 OK 20251218171726_add_pins.sql (75.49ms)14862026/08/27 09:36:02 OK 20260628120000_add_object_size_and_stats.sql (63.32ms)14872026/08/27 09:36:02 goose: successfully migrated database to version: 2026062812000014882026/08/27 09:36:02 OK 1_commit_pending_closure.sql (22.72ms)14892026/08/27 09:36:02 OK 2_object_stats_trigger.sql (1.15ms)14902026/08/27 09:36:02 goose: up to current file version: 214912026/08/27 09:36:02 OK 20260628120000_add_object_size_and_stats.sql (68.46ms)14922026/08/27 09:36:02 goose: successfully migrated database to version: 2026062812000014932026/08/27 09:36:02 OK 1_commit_pending_closure.sql (21.87ms)14942026/08/27 09:36:02 INFO Received uploads request method=POST path=/api/pending_closures14952026/08/27 09:36:02 OK 2_object_stats_trigger.sql (1.41ms)14962026/08/27 09:36:02 goose: up to current file version: 214972026/08/27 09:36:03 INFO Received uploads request method=POST path=/api/pending_closures14982026/08/27 09:36:03 INFO Received uploads request method=POST path=/api/pending_closures14992026/08/27 09:36:03 INFO Received uploads request method=POST path=/api/pending_closures15002026/08/27 09:36:03 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst15012026/08/27 09:36:03 INFO Received uploads request method=POST path=/api/pending_closures1502--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.69s)1503=== CONT TestServerTLSConfig/no_client_CA1504=== CONT TestServerTLSConfig/not_a_PEM_file1505=== CONT TestServerTLSConfig/missing_CA_file1506=== CONT TestIsValidCachePath/narinfo1507--- PASS: TestServerTLSConfig (0.00s)1508 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1509 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.03s)1510 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1511=== CONT TestIsValidCachePath/index.html1512=== CONT TestIsValidCachePath/short_hash1513=== CONT TestIsValidCachePath/wrong_extension1514=== CONT TestIsValidCachePath/leading_slash1515=== CONT TestIsValidCachePath/empty1516=== CONT TestIsValidCachePath/random_path1517=== CONT TestIsValidCachePath/invalid_char_u1518=== CONT TestIsValidCachePath/invalid_char_e1519=== CONT TestIsValidCachePath/traversal_in_middle1520=== CONT TestIsValidCachePath/traversal_parent1521=== CONT TestIsValidCachePath/nar_uncompressed1522=== CONT TestIsValidCachePath/nix-cache-info1523=== CONT TestIsValidCachePath/realisation1524=== CONT TestIsValidCachePath/log1525=== CONT TestIsValidCachePath/ls1526=== CONT TestIsValidCachePath/nar_xz1527=== CONT TestIsValidCachePath/nar_bz21528=== CONT TestIsValidCachePath/nar_zst1529=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1530--- PASS: TestIsValidCachePath (0.00s)1531 --- PASS: TestIsValidCachePath/narinfo (0.00s)1532 --- PASS: TestIsValidCachePath/index.html (0.00s)1533 --- PASS: TestIsValidCachePath/short_hash (0.00s)1534 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1535 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1536 --- PASS: TestIsValidCachePath/empty (0.00s)1537 --- PASS: TestIsValidCachePath/random_path (0.00s)1538 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1539 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1540 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1541 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1542 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1543 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1544 --- PASS: TestIsValidCachePath/realisation (0.00s)1545 --- PASS: TestIsValidCachePath/log (0.00s)1546 --- PASS: TestIsValidCachePath/ls (0.00s)1547 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1548 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1549 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1550 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1551=== CONT TestParseSingleRange/none1552=== CONT TestParseSingleRange/open-ended1553=== CONT TestParseSingleRange/start_far_past_EOF1554=== CONT TestParseSingleRange/start_past_EOF1555=== CONT TestParseSingleRange/single_byte1556=== CONT TestParseSingleRange/suffix_exceeds_size1557=== CONT TestParseSingleRange/suffix1558=== CONT TestParseSingleRange/end_clamped_to_size1559=== CONT TestParseSingleRange/malformed_both_empty1560=== CONT TestParseSingleRange/closed1561=== CONT TestParseSingleRange/malformed_end_before_start1562=== CONT TestParseSingleRange/multi-range_ignored1563=== CONT TestParseSingleRange/malformed_no_dash1564=== CONT TestParseSingleRange/unknown_unit1565--- PASS: TestParseSingleRange (0.00s)1566 --- PASS: TestParseSingleRange/none (0.00s)1567 --- PASS: TestParseSingleRange/open-ended (0.00s)1568 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1569 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1570 --- PASS: TestParseSingleRange/single_byte (0.00s)1571 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1572 --- PASS: TestParseSingleRange/suffix (0.00s)1573 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1574 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1575 --- PASS: TestParseSingleRange/closed (0.00s)1576 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1577 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1578 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1579 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1580=== CONT TestClientErrorHandling/InvalidStorePath1581--- PASS: TestService_Rustfstest (2.81s)1582=== CONT TestClientErrorHandling/ServerNotAvailable15832026/08/27 09:36:03 INFO Received cleanup request method=DELETE path=/api/pending_closures15842026/08/27 09:36:03 INFO Aborted multipart uploads count=015852026/08/27 09:36:03 INFO Received uploads request method=POST path=/api/pending_closures15862026/08/27 09:36:03 INFO Received cleanup request method=DELETE path=/api/pending_closures15872026/08/27 09:36:03 INFO Aborted multipart uploads count=115882026/08/27 09:36:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15892026-08-27 09:36:03.418 UTC [28776] ERROR: Closure does not exist: id=115902026-08-27 09:36:03.418 UTC [28776] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE15912026-08-27 09:36:03.418 UTC [28776] STATEMENT: -- name: CommitPendingClosure :exec1592 SELECT commit_pending_closure($1::bigint)1593 1594--- PASS: TestService_cleanupPendingClosuresHandler (3.06s)1595=== CONT TestClientErrorHandling/InvalidAuthToken15962026/08/27 09:36:03 INFO Received uploads request method=POST path=/api/pending_closures15972026-08-27 09:36:03.424 UTC [28781] ERROR: relation "goose_db_version" does not exist at character 3615982026-08-27 09:36:03.424 UTC [28781] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15992026/08/27 09:36:03 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-config16002026/08/27 09:36:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16012026/08/27 09:36:03 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjliYmZhNzMtMTI1My00OWIzLTlmMjQtOGZjYzc1MzY3MzA2LjY2ZDc0ZjA4LTUxZWItNDcwMy1hMzI4LTFmZDhmMmYzZWRkYngxNzg3ODIzMzYzNDUwMzkwMDAw16022026/08/27 09:36:03 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjliYmZhNzMtMTI1My00OWIzLTlmMjQtOGZjYzc1MzY3MzA2LjY2ZDc0ZjA4LTUxZWItNDcwMy1hMzI4LTFmZDhmMmYzZWRkYngxNzg3ODIzMzYzNDUwMzkwMDAw parts=11603--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.28s)1604=== CONT TestCacheConfigHandler/full_config,_no_issuer1605=== CONT TestCacheConfigHandler/no_signing_keys1606=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1607=== CONT TestCacheConfigHandler/no_cache_url_configured1608--- PASS: TestCacheConfigHandler (0.00s)1609 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1610 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1611 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1612 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1613=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token16142026/08/27 09:36:03 INFO OIDC auth successful provider=test1615=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected16162026/08/27 09:36:03 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]1617=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1618=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16192026/08/27 09:36:03 WARN Authentication failed token_preview=eyJhbGciOi...lijanJXZNQ 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]1620=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16212026/08/27 09:36:03 INFO Received uploads request method=POST path=/1622--- PASS: TestService_AuthMiddleware_OIDC (1.65s)1623 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1624 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1625 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1626 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)16272026/08/27 09:36:03 OK 20241026095416_initial_model.sql (242.11ms)16282026/08/27 09:36:03 OK 20251210153512_drop_unused_gin_index.sql (9.69ms)16292026/08/27 09:36:03 OK 20251218171726_add_pins.sql (40ms)16302026/08/27 09:36:03 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.007717ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config16312026/08/27 09:36:03 OK 20260628120000_add_object_size_and_stats.sql (25.95ms)16322026/08/27 09:36:03 goose: successfully migrated database to version: 2026062812000016332026/08/27 09:36:03 OK 1_commit_pending_closure.sql (1.33ms)16342026/08/27 09:36:03 OK 2_object_stats_trigger.sql (402.04µs)16352026/08/27 09:36:03 goose: up to current file version: 216362026/08/27 09:36:04 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=427.919176ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1637=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16382026/08/27 09:36:04 INFO Received request for more parts method=POST path=/1639=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16402026/08/27 09:36:04 INFO Received complete multipart upload request method=POST path=/1641--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)1642 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.27s)1643 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1644 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1645=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16462026/08/27 09:36:04 INFO Received uploads request method=POST path=/1647=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16482026/08/27 09:36:04 INFO Received complete multipart upload request method=POST path=/1649=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16502026/08/27 09:36:04 INFO Received uploads request method=POST path=/1651=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16522026/08/27 09:36:04 INFO Received request for more parts method=POST path=/1653--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1654 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1655 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1656 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1657 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1658=== CONT TestIsValidUploadKey/narinfo1659=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1660=== CONT TestIsValidUploadKey/index.html1661=== CONT TestIsValidUploadKey/nix-cache-info1662=== CONT TestIsValidUploadKey/realisation_plus_in_output1663=== CONT TestIsValidUploadKey/realisation1664=== CONT TestIsValidUploadKey/build_log_equals1665=== CONT TestIsValidUploadKey/build_log_question_mark1666=== CONT TestIsValidUploadKey/build_log_plus_in_name1667=== CONT TestIsValidUploadKey/build_log_home-manager_file1668=== CONT TestIsValidUploadKey/build_log1669=== CONT TestIsValidUploadKey/listing1670=== CONT TestIsValidUploadKey/nar_plain1671=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1672=== CONT TestIsValidUploadKey/nar_xz1673=== CONT TestIsValidUploadKey/nar_zst1674=== CONT TestIsValidUploadKey/absolute1675=== CONT TestIsValidUploadKey/unknown_type1676=== CONT TestIsValidUploadKey/empty_key1677=== CONT TestIsValidUploadKey/traversal1678=== CONT TestIsValidUploadKey/traversal_nar1679=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1680--- PASS: TestIsValidUploadKey (0.00s)1681 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1682 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1683 --- PASS: TestIsValidUploadKey/index.html (0.00s)1684 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1685 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1686 --- PASS: TestIsValidUploadKey/realisation (0.00s)1687 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1688 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1689 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1690 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1691 --- PASS: TestIsValidUploadKey/build_log (0.00s)1692 --- PASS: TestIsValidUploadKey/listing (0.00s)1693 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1694 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1695 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1696 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1697 --- PASS: TestIsValidUploadKey/absolute (0.00s)1698 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1699 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1700 --- PASS: TestIsValidUploadKey/traversal (0.00s)1701 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1702 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1703=== CONT TestProxyWriteTimeout/narinfo1704=== CONT TestProxyWriteTimeout/10_GiB_nar1705=== CONT TestProxyWriteTimeout/unknown_size1706=== CONT TestProxyWriteTimeout/1_GiB_nar1707--- PASS: TestProxyWriteTimeout (0.00s)1708 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1709 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1710 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1711 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)17122026/08/27 09:36:04 INFO Received uploads request method=POST path=/api/pending_closures17132026/08/27 09:36:04 INFO Received uploads request method=POST path=/api/pending_closures17142026/08/27 09:36:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17152026/08/27 09:36:04 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=759.050266ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17162026/08/27 09:36:04 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZjliYmZhNzMtMTI1My00OWIzLTlmMjQtOGZjYzc1MzY3MzA2LjlhYzBlMDQ1LWUyNmItNDIxOC1hYzZkLTUwMWI2MjhhOTEyZngxNzg3ODIzMzYyNjY2ODI3MDAw parts=1017172026/08/27 09:36:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17182026/08/27 09:36:04 INFO Completed upload id=117192026/08/27 09:36:04 INFO Received uploads request method=POST path=/api/pending_closures17202026/08/27 09:36:04 INFO Received uploads request method=POST path=/api/pending_closures17212026/08/27 09:36:04 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo17222026/08/27 09:36:04 WARN Found objects in DB but missing from S3, will re-upload count=11723--- PASS: TestService_verifyS3Integrity (4.28s)1724=== NAME TestService_createPendingClosureHandler1725 uploads_test.go:307: unexpected error: Put "http://localhost:51504/bucket39/nar/0000000000000000000000000000000000000000000000000000.nar.zst?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=rustfsadmin%2F20260827%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20260827T093603Z&X-Amz-Expires=18000&X-Amz-SignedHeaders=host&partNumber=10&uploadId=ZjliYmZhNzMtMTI1My00OWIzLTlmMjQtOGZjYzc1MzY3MzA2LjU0MDkwNGNhLWNjMmMtNDFiYy1hNzY2LWM0YzAwZjk3MzJmZHgxNzg3ODIzMzYzMDYxMzU5MDAw&X-Amz-Signature=aaa5fa047982fe00009fd2db9ad0ba4827b23908404566374a0a5cb119639f4d": context deadline exceeded1726 1727--- FAIL: TestService_createPendingClosureHandler (4.34s)17282026-08-27 09:36:05.051 UTC [28789] ERROR: relation "goose_db_version" does not exist at character 3617292026-08-27 09:36:05.051 UTC [28789] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17302026/08/27 09:36:05 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.73061215s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17312026/08/27 09:36:05 OK 20241026095416_initial_model.sql (184.46ms)17322026/08/27 09:36:05 OK 20251210153512_drop_unused_gin_index.sql (13.38ms)17332026/08/27 09:36:05 OK 20251218171726_add_pins.sql (40.29ms)17342026/08/27 09:36:05 OK 20260628120000_add_object_size_and_stats.sql (33.75ms)17352026/08/27 09:36:05 goose: successfully migrated database to version: 2026062812000017362026/08/27 09:36:05 OK 1_commit_pending_closure.sql (13.21ms)17372026/08/27 09:36:05 OK 2_object_stats_trigger.sql (1.56ms)17382026/08/27 09:36:05 goose: up to current file version: 217392026-08-27 09:36:05.550 UTC [28790] ERROR: relation "goose_db_version" does not exist at character 3617402026-08-27 09:36:05.550 UTC [28790] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17412026/08/27 09:36:05 INFO Received uploads request method=POST path=/api/pending_closures17422026/08/27 09:36:05 OK 20241026095416_initial_model.sql (194.4ms)17432026/08/27 09:36:05 OK 20251210153512_drop_unused_gin_index.sql (4.21ms)17442026/08/27 09:36:05 OK 20251218171726_add_pins.sql (22.37ms)17452026-08-27 09:36:05.851 UTC [28791] ERROR: relation "goose_db_version" does not exist at character 3617462026-08-27 09:36:05.851 UTC [28791] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17472026/08/27 09:36:05 OK 20260628120000_add_object_size_and_stats.sql (30.83ms)17482026/08/27 09:36:05 goose: successfully migrated database to version: 2026062812000017492026/08/27 09:36:05 OK 1_commit_pending_closure.sql (8.29ms)17502026/08/27 09:36:05 OK 2_object_stats_trigger.sql (630.13µs)17512026/08/27 09:36:05 goose: up to current file version: 217522026/08/27 09:36:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17532026/08/27 09:36:06 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZjliYmZhNzMtMTI1My00OWIzLTlmMjQtOGZjYzc1MzY3MzA2LjgyZGMyMGY1LTY5ODEtNGEwNC1iNDdkLTM0ZTIwMTc4MjljMHgxNzg3ODIzMzY0MDg4MDIyMDAw parts=121754--- PASS: TestRedundantMultipartUpload (5.22s)17552026/08/27 09:36:06 OK 20241026095416_initial_model.sql (209.97ms)17562026/08/27 09:36:06 OK 20251210153512_drop_unused_gin_index.sql (3.74ms)17572026/08/27 09:36:06 OK 20251218171726_add_pins.sql (11.31ms)17582026/08/27 09:36:06 OK 20260628120000_add_object_size_and_stats.sql (24.11ms)17592026/08/27 09:36:06 goose: successfully migrated database to version: 2026062812000017602026/08/27 09:36:06 OK 1_commit_pending_closure.sql (10.1ms)17612026/08/27 09:36:06 OK 2_object_stats_trigger.sql (297.38µs)17622026/08/27 09:36:06 goose: up to current file version: 217632026/08/27 09:36:06 WARN Rate limiter enabled after throttle name=s3-test rate=517642026/08/27 09:36:06 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1765=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1766 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101767 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001768--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (7.42s)17692026/08/27 09:36:06 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17702026/08/27 09:36:06 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"17712026/08/27 09:36:06 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"17722026/08/27 09:36:07 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_closures17732026/08/27 09:36:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17742026/08/27 09:36:07 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZjliYmZhNzMtMTI1My00OWIzLTlmMjQtOGZjYzc1MzY3MzA2LmIxMTU2Njk5LWExNmYtNDAwYi04MDkwLTA1Y2QxZDExZTk1ZngxNzg3ODIzMzY1NTgwMTQ5MDAw parts=1217752026/08/27 09:36:07 INFO Received uploads request method=POST path=/api/pending_closures1776--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.72s)17772026/08/27 09:36:07 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.986202ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17782026/08/27 09:36:07 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=430.845862ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17792026/08/27 09:36:07 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=834.756923ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1780=== NAME TestOrphanedObjectsGCStressTest1781 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1782 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1783 orphaned_objects_gc_test.go:509: Stress test completed successfully:1784 orphaned_objects_gc_test.go:510: - Active objects preserved: 201785 orphaned_objects_gc_test.go:511: - Objects deleted: 2101786 orphaned_objects_gc_test.go:512: - Total GC'd: 2101787--- PASS: TestOrphanedObjectsGCStressTest (9.70s)17882026/08/27 09:36:08 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.446937533s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1789--- PASS: TestClientErrorHandling (0.00s)1790 --- PASS: TestClientErrorHandling/InvalidStorePath (3.08s)1791 --- PASS: TestClientErrorHandling/InvalidAuthToken (3.31s)1792 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.86s)1793FAIL1794{"timestamp":"2026-08-27T09:36:10.049597Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:51692","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(4)"}17952026-08-27 09:36:10.157 UTC [28433] LOG: received smart shutdown request17962026-08-27 09:36:10.157 UTC [28433] LOG: background worker "logical replication launcher" (PID 28443) exited with exit code 117972026-08-27 09:36:10.169 UTC [28438] LOG: shutting down17982026-08-27 09:36:10.169 UTC [28438] LOG: checkpoint starting: shutdown immediate17992026-08-27 09:36:11.231 UTC [28438] LOG: checkpoint complete: wrote 13669 buffers (83.4%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 13 recycled; write=0.777 s, sync=0.284 s, total=1.063 s; sync files=15157, longest=0.029 s, average=0.001 s; distance=212371 kB, estimate=212371 kB; lsn=0/E6EFE38, redo lsn=0/E6EFE3818002026-08-27 09:36:11.236 UTC [28433] LOG: database system is shut down