nixbot

builds

succeeded niks3-go-unit-tests checks.aarch64-linux.go-unit-tests · build #139 · raw

1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestCaseHackSuffix6=== PAUSE TestCaseHackSuffix7=== RUN TestFilterOversizedClosures8=== PAUSE TestFilterOversizedClosures9=== RUN TestPartSizeForNAR10=== PAUSE TestPartSizeForNAR11=== RUN TestUploadMultipart_SupersededByPeer12=== PAUSE TestUploadMultipart_SupersededByPeer13=== RUN TestDumpPathMatchesNix14=== PAUSE TestDumpPathMatchesNix15=== RUN TestDumpPathSingleFile16=== PAUSE TestDumpPathSingleFile17=== RUN TestDumpPathWriterError18=== PAUSE TestDumpPathWriterError19=== RUN TestEncodeNixBase3220=== PAUSE TestEncodeNixBase3221=== RUN TestEncodeNixBase32WithRealHash22=== PAUSE TestEncodeNixBase32WithRealHash23=== RUN TestConvertHashToNix3224=== PAUSE TestConvertHashToNix3225=== RUN TestGetStorePathHash26=== PAUSE TestGetStorePathHash27=== RUN TestPathInfoHashCompatibility28=== PAUSE TestPathInfoHashCompatibility29=== RUN TestParsePathInfoJSON30=== PAUSE TestParsePathInfoJSON31=== RUN TestParsePathInfoJSONMultiplePaths32=== PAUSE TestParsePathInfoJSONMultiplePaths33=== RUN TestPathInfoCACompatibility34=== PAUSE TestPathInfoCACompatibility35=== RUN TestRateLimiterFeedback36=== PAUSE TestRateLimiterFeedback37=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess38=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess39=== RUN TestResolveStorePath40=== PAUSE TestResolveStorePath41=== RUN TestDoWithRetry_BodyReplayedViaGetBody42=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody43=== RUN TestShellSplit44=== PAUSE TestShellSplit45=== RUN TestShellSplitErrors46=== PAUSE TestShellSplitErrors47=== RUN TestSetClientTLS48=== PAUSE TestSetClientTLS49=== RUN TestSetClientTLSDoesNotMutateDefaultTransport50=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport51=== RUN TestSetClientTLSErrors52=== PAUSE TestSetClientTLSErrors53=== RUN TestStaticToken54=== PAUSE TestStaticToken55=== RUN TestFileTokenReadsAndCaches56=== PAUSE TestFileTokenReadsAndCaches57=== RUN TestFileTokenMissing58=== PAUSE TestFileTokenMissing59=== RUN TestFileTokenEmpty60=== PAUSE TestFileTokenEmpty61=== RUN TestScriptTokenNoExpiryRerunsEveryCall62=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall63=== RUN TestScriptTokenCachesUntilRefresh64=== PAUSE TestScriptTokenCachesUntilRefresh65=== RUN TestScriptTokenEmptyToken66=== PAUSE TestScriptTokenEmptyToken67=== RUN TestScriptTokenBadJSON68=== PAUSE TestScriptTokenBadJSON69=== RUN TestScriptTokenScriptFails70=== PAUSE TestScriptTokenScriptFails71=== RUN TestScriptTokenEmptyCommand72=== PAUSE TestScriptTokenEmptyCommand73=== CONT TestDoServerRequestAttachesToken74=== CONT TestResolveStorePath75=== CONT TestEncodeNixBase32WithRealHash76=== CONT TestFileTokenMissing77--- PASS: TestEncodeNixBase32WithRealHash (0.00s)78=== CONT TestParsePathInfoJSON79=== RUN TestParsePathInfoJSON/Nix_format80=== PAUSE TestParsePathInfoJSON/Nix_format81=== RUN TestParsePathInfoJSON/Lix_format82=== CONT TestParsePathInfoJSONMultiplePaths83=== CONT TestEncodeNixBase3284=== CONT TestDumpPathSingleFile85=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths86=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths87=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths88=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths89=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths90--- PASS: TestFileTokenMissing (0.00s)91=== CONT TestRateLimiterFeedback92=== RUN TestRateLimiterFeedback/429_enables_limiter93=== CONT TestDumpPathMatchesNix94=== PAUSE TestRateLimiterFeedback/429_enables_limiter95=== RUN TestRateLimiterFeedback/503_enables_limiter96=== PAUSE TestRateLimiterFeedback/503_enables_limiter97=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter98=== CONT TestPathInfoHashCompatibility99--- PASS: TestResolveStorePath (0.00s)100=== CONT TestSetClientTLSErrors101=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)102=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)103=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon104=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon105=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI106=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI107=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512108=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512109=== CONT TestPartSizeForNAR110=== CONT TestGetStorePathHash111=== RUN TestGetStorePathHash/valid_store_path112=== CONT TestConvertHashToNix32113=== RUN TestConvertHashToNix32/SRI_format_to_Nix32114=== CONT TestDumpPathWriterError115=== CONT TestPathInfoCACompatibility116=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32117=== RUN TestConvertHashToNix32/already_Nix32_format118=== PAUSE TestConvertHashToNix32/already_Nix32_format119=== RUN TestConvertHashToNix32/invalid_format120=== PAUSE TestConvertHashToNix32/invalid_format121=== CONT TestShellSplitErrors122--- PASS: TestShellSplitErrors (0.00s)123=== CONT TestSetClientTLS124=== CONT TestScriptTokenEmptyCommand125--- PASS: TestScriptTokenEmptyCommand (0.00s)126=== CONT TestShellSplit127--- PASS: TestShellSplit (0.00s)128=== CONT TestScriptTokenScriptFails129=== CONT TestScriptTokenBadJSON130=== CONT TestScriptTokenEmptyToken131=== CONT TestScriptTokenCachesUntilRefresh132=== CONT TestScriptTokenNoExpiryRerunsEveryCall133=== CONT TestFileTokenEmpty134=== RUN TestEncodeNixBase32/test_string_hash135=== PAUSE TestParsePathInfoJSON/Lix_format136=== CONT TestSetClientTLSDoesNotMutateDefaultTransport137=== CONT TestFileTokenReadsAndCaches138=== CONT TestStaticToken139=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter140=== RUN TestPartSizeForNAR/zero_stays_at_minimum141=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum142=== RUN TestPartSizeForNAR/small_stays_at_minimum143=== PAUSE TestPartSizeForNAR/small_stays_at_minimum144=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum145=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum146=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts147=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts148=== RUN TestPartSizeForNAR/1_TiB149=== PAUSE TestPartSizeForNAR/1_TiB150=== RUN TestPartSizeForNAR/5_TiB_S3_max_object151=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object152=== PAUSE TestGetStorePathHash/valid_store_path153=== CONT TestUploadMultipart_SupersededByPeer154=== RUN TestPathInfoCACompatibility/null_ca_field155=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess156=== CONT TestFilterOversizedClosures157--- PASS: TestStaticToken (0.00s)158=== PAUSE TestPathInfoCACompatibility/null_ca_field159=== CONT TestDoWithRetry_BodyReplayedViaGetBody160=== PAUSE TestEncodeNixBase32/test_string_hash161=== RUN TestParsePathInfoJSON/empty_input162=== PAUSE TestParsePathInfoJSON/empty_input163=== RUN TestParsePathInfoJSON/whitespace_only164=== PAUSE TestParsePathInfoJSON/whitespace_only165=== RUN TestParsePathInfoJSON/invalid_JSON166=== PAUSE TestParsePathInfoJSON/invalid_JSON167=== RUN TestPartSizeForNAR/capped_at_5_GiB168=== PAUSE TestPartSizeForNAR/capped_at_5_GiB169=== CONT TestCaseHackSuffix170=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter1712026/08/27 09:24:19 WARN Rate limiter enabled after throttle name=server-test rate=5172=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter173=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths174--- PASS: TestScriptTokenScriptFails (0.01s)175=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512176--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)177 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)178 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)179=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon180--- PASS: TestFileTokenEmpty (0.00s)181=== CONT TestConvertHashToNix32/SRI_format_to_Nix32182=== CONT TestConvertHashToNix32/invalid_format183=== CONT TestConvertHashToNix32/already_Nix32_format184=== CONT TestParsePathInfoJSON/Nix_format185=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)186=== CONT TestPartSizeForNAR/zero_stays_at_minimum187=== RUN TestEncodeNixBase32/empty_input188=== RUN TestGetStorePathHash/basename_without_hyphen_should_error189=== RUN TestUploadMultipart_SupersededByPeer/exists190=== CONT TestParsePathInfoJSON/invalid_JSON191=== CONT TestParsePathInfoJSON/Lix_format192--- PASS: TestScriptTokenBadJSON (0.01s)193=== CONT TestParsePathInfoJSON/empty_input194=== CONT TestPartSizeForNAR/capped_at_5_GiB195=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error196=== CONT TestPartSizeForNAR/1_TiB197=== PAUSE TestUploadMultipart_SupersededByPeer/exists198=== CONT TestPartSizeForNAR/5_TiB_S3_max_object199--- PASS: TestFileTokenReadsAndCaches (0.01s)200=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum201=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts202=== CONT TestPartSizeForNAR/small_stays_at_minimum203--- PASS: TestScriptTokenEmptyToken (0.01s)204=== CONT TestRateLimiterFeedback/429_enables_limiter205--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)206=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2072026/08/27 09:24:19 WARN Rate limiter enabled after throttle name=server-test rate=52082026/08/27 09:24:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:46723209=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2102026/08/27 09:24:19 WARN Rate limiter backed off name=server-test rate=5211=== CONT TestRateLimiterFeedback/503_enables_limiter2122026/08/27 09:24:19 WARN Rate limiter enabled after throttle name=server-test rate=52132026/08/27 09:24:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:466752142026/08/27 09:24:19 WARN Rate limiter backed off name=server-test rate=5215--- PASS: TestRateLimiterFeedback (0.01s)216 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)217 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)218 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)219 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)220=== CONT TestParsePathInfoJSON/whitespace_only2212026/08/27 09:24:19 WARN Rate limiter enabled after throttle name=server-test rate=5222=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error2232026/08/27 09:24:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:44077224--- PASS: TestParsePathInfoJSON (0.01s)225 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)226 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)227 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)228 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)229 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)230=== RUN TestUploadMultipart_SupersededByPeer/missing231=== RUN TestSetClientTLSErrors/missing_cert_file232=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI233--- PASS: TestConvertHashToNix32 (0.00s)234 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)235 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)236 --- PASS: TestConvertHashToNix32/invalid_format (0.01s)2372026/08/27 09:24:19 WARN Rate limiter backed off name=server-test rate=5238=== RUN TestFilterOversizedClosures/no_limit_keeps_everything2392026/08/27 09:24:19 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:44077240=== RUN TestPathInfoCACompatibility/old_string_format_-_text241=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text242=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive243=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive244=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error245=== PAUSE TestEncodeNixBase32/empty_input246=== PAUSE TestSetClientTLSErrors/missing_cert_file247=== PAUSE TestUploadMultipart_SupersededByPeer/missing248=== CONT TestUploadMultipart_SupersededByPeer/exists249--- PASS: TestPartSizeForNAR (0.00s)250 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)251 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)252 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)253 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)254 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)255 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)256 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)257--- PASS: TestPathInfoHashCompatibility (0.00s)258 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)259 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)260 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)261 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)262--- PASS: TestDoServerRequestAttachesToken (0.02s)263=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything264=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped265=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped266--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)267=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error268=== CONT TestEncodeNixBase32/test_string_hash269=== CONT TestEncodeNixBase32/empty_input270=== RUN TestSetClientTLSErrors/missing_key_file271=== CONT TestUploadMultipart_SupersededByPeer/missing272=== RUN TestPathInfoCACompatibility/new_structured_format_-_text273=== RUN TestFilterOversizedClosures/all_closures_skipped274=== PAUSE TestFilterOversizedClosures/all_closures_skipped275=== CONT TestFilterOversizedClosures/no_limit_keeps_everything276--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)277=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error278=== CONT TestGetStorePathHash/valid_store_path279=== CONT TestFilterOversizedClosures/all_closures_skipped280=== PAUSE TestSetClientTLSErrors/missing_key_file2812026/08/27 09:24:19 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=50282=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error283=== RUN TestSetClientTLSErrors/missing_ca_file284--- PASS: TestEncodeNixBase32 (0.02s)285 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)286 --- PASS: TestEncodeNixBase32/empty_input (0.00s)287=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text288=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped289=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error290=== CONT TestGetStorePathHash/basename_without_hyphen_should_error291--- PASS: TestGetStorePathHash (0.02s)292 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)293 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)294 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)295 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)296=== RUN TestSetClientTLS/rejects_connection_without_client_cert297=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method2982026/08/27 09:24:19 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000299=== PAUSE TestSetClientTLSErrors/missing_ca_file300=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method301--- PASS: TestFilterOversizedClosures (0.01s)302 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)303 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)304 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)305=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert306=== RUN TestSetClientTLSErrors/invalid_ca_file307=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA308=== PAUSE TestSetClientTLSErrors/invalid_ca_file309=== CONT TestSetClientTLSErrors/missing_cert_file310=== CONT TestSetClientTLSErrors/invalid_ca_file311=== CONT TestSetClientTLSErrors/missing_ca_file312=== CONT TestSetClientTLSErrors/missing_key_file313=== CONT TestPathInfoCACompatibility/old_string_format_-_text314=== CONT TestPathInfoCACompatibility/null_ca_field315=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA316=== CONT TestPathInfoCACompatibility/new_structured_format_-_text317--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)318 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)319 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)320=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive321=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method322--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)323--- PASS: TestPathInfoCACompatibility (0.02s)324 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)325 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)326 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)327 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)328 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)329=== RUN TestSetClientTLS/preserves_debug_logging_transport330=== PAUSE TestSetClientTLS/preserves_debug_logging_transport331=== CONT TestSetClientTLS/rejects_connection_without_client_cert332=== CONT TestSetClientTLS/preserves_debug_logging_transport333=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA334--- PASS: TestSetClientTLSErrors (0.02s)335 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)336 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)337 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)338 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)339--- PASS: TestDumpPathSingleFile (0.03s)3402026/08/27 09:24:19 http: TLS handshake error from 127.0.0.1:52580: remote error: tls: bad certificate341--- PASS: TestSetClientTLS (0.02s)342 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)343 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)344 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)345--- PASS: TestDumpPathWriterError (0.04s)346--- PASS: TestCaseHackSuffix (0.04s)347--- PASS: TestDumpPathMatchesNix (0.07s)348--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)349PASS350Running server tests...351The files belonging to this database system will be owned by user "nixbld".352This user must also own the server process.353354The database cluster will be initialized with locale "C".355The default database encoding has accordingly been set to "SQL_ASCII".356The default text search configuration will be set to "english".357358Data page checksums are enabled.359360creating directory /build/postgres65062374/data ... ok361creating subdirectories ... ok362selecting dynamic shared memory implementation ... posix363selecting default "max_connections" ... 100364selecting default "shared_buffers" ... 128MB365selecting default time zone ... UTC366creating configuration files ... ok367running bootstrap script ... ok368performing post-bootstrap initialization ... ok369syncing data to disk ... ok370371initdb: warning: enabling "trust" authentication for local connections372initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.373374Success. You can now start the database server using:375376 pg_ctl -D /build/postgres65062374/data -l logfile start377378/build/postgres65062374:5432 - no response3792026-08-27 09:24:21.529 UTC [112] LOG: starting PostgreSQL 18.4 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit3802026-08-27 09:24:21.529 UTC [112] LOG: listening on Unix socket "/build/postgres65062374/.s.PGSQL.5432"3812026-08-27 09:24:21.533 UTC [119] LOG: database system was shut down at 2026-08-27 09:24:21 UTC3822026-08-27 09:24:21.537 UTC [112] LOG: database system is ready to accept connections383/build/postgres65062374:5432 - accepting connections384=== RUN TestService_AuthMiddleware385=== PAUSE TestService_AuthMiddleware386=== RUN TestService_AuthMiddleware_MTLSProxyHeader387=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader388=== RUN TestService_AuthMiddleware_MTLSBoundSubjects389=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects390=== RUN TestService_ReadAuthMiddleware391=== PAUSE TestService_ReadAuthMiddleware392=== RUN TestService_AuthMiddleware_OIDC393=== PAUSE TestService_AuthMiddleware_OIDC394=== RUN TestCacheConfigHandler395=== PAUSE TestCacheConfigHandler396=== RUN TestCacheStatsHandler397=== PAUSE TestCacheStatsHandler398=== RUN TestClientCADerivations399=== PAUSE TestClientCADerivations400=== RUN TestClientErrorHandling401=== PAUSE TestClientErrorHandling402=== RUN TestClientIntegration403=== PAUSE TestClientIntegration404=== RUN TestClientMultipleUploads405=== PAUSE TestClientMultipleUploads406=== RUN TestClientWithDependencies407=== PAUSE TestClientWithDependencies408=== RUN TestPinProtectsFromGC409=== PAUSE TestPinProtectsFromGC410=== RUN TestGCAdvisoryLockBlocksConcurrentRun4112026-08-27 09:24:26.720 UTC [521] ERROR: relation "goose_db_version" does not exist at character 364122026-08-27 09:24:26.720 UTC [521] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4132026/08/27 09:24:26 OK 20241026095416_initial_model.sql (17.82ms)4142026/08/27 09:24:26 OK 20251210153512_drop_unused_gin_index.sql (2.6ms)4152026/08/27 09:24:26 OK 20251218171726_add_pins.sql (4.47ms)4162026/08/27 09:24:26 OK 20260628120000_add_object_size_and_stats.sql (3.96ms)4172026/08/27 09:24:26 goose: successfully migrated database to version: 202606281200004182026/08/27 09:24:26 OK 1_commit_pending_closure.sql (2.1ms)4192026/08/27 09:24:26 OK 2_object_stats_trigger.sql (924.09µs)4202026/08/27 09:24:26 goose: up to current file version: 2421--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.06s)422=== RUN TestGCBugBareHashReferences423=== PAUSE TestGCBugBareHashReferences424=== RUN TestGCMetrics425=== PAUSE TestGCMetrics426=== RUN TestGCTaskStore_StartNew427=== PAUSE TestGCTaskStore_StartNew428=== RUN TestGCTaskStore_DeduplicateSameParams429=== PAUSE TestGCTaskStore_DeduplicateSameParams430=== RUN TestGCTaskStore_ConflictDifferentParams431=== PAUSE TestGCTaskStore_ConflictDifferentParams432=== RUN TestGCTaskStore_GetEmpty433=== PAUSE TestGCTaskStore_GetEmpty434=== RUN TestGCTaskStore_GetReturnsLatest435=== PAUSE TestGCTaskStore_GetReturnsLatest436=== RUN TestGCTaskStore_CompletedAllowsNewTask437=== PAUSE TestGCTaskStore_CompletedAllowsNewTask438=== RUN TestGCTaskStore_PhaseUpdates439=== PAUSE TestGCTaskStore_PhaseUpdates440=== RUN TestGCTaskStore_Fail441=== PAUSE TestGCTaskStore_Fail442=== RUN TestGracefulShutdownDrainsInflight443=== PAUSE TestGracefulShutdownDrainsInflight444=== RUN TestService_healthCheckHandler445=== PAUSE TestService_healthCheckHandler446=== RUN TestGenerateLandingPage447=== PAUSE TestGenerateLandingPage448=== RUN TestCacheConfigHandlerMaxNarSize449=== PAUSE TestCacheConfigHandlerMaxNarSize450=== RUN TestCreatePendingClosureRejectsOversizedNAR451=== PAUSE TestCreatePendingClosureRejectsOversizedNAR452=== RUN TestNARDeduplicationMetadataUploadBug453=== PAUSE TestNARDeduplicationMetadataUploadBug454=== RUN TestMetricsInventory455=== PAUSE TestMetricsInventory456=== RUN TestService_NativeMTLS457=== PAUSE TestService_NativeMTLS458=== RUN TestServerTLSConfig459=== PAUSE TestServerTLSConfig460=== RUN TestMultipartCleanup461=== PAUSE TestMultipartCleanup462=== RUN TestObjectStatsTrigger463=== PAUSE TestObjectStatsTrigger464=== RUN TestOrphanedObjectsGC465=== PAUSE TestOrphanedObjectsGC466=== RUN TestOrphanedObjectsGCStressTest467=== PAUSE TestOrphanedObjectsGCStressTest468=== RUN TestResurrectedObjectNotDeleted469=== PAUSE TestResurrectedObjectNotDeleted470=== RUN TestParseSingleRange471=== PAUSE TestParseSingleRange472=== RUN TestIsValidCachePath473=== PAUSE TestIsValidCachePath474=== RUN TestReadProxyNarinfo475=== PAUSE TestReadProxyNarinfo476=== RUN TestReadProxyNarinfoAlreadyDecompressed477=== PAUSE TestReadProxyNarinfoAlreadyDecompressed478=== RUN TestReadProxyNarStreaming479=== PAUSE TestReadProxyNarStreaming480=== RUN TestReadProxy404481=== PAUSE TestReadProxy404482=== RUN TestReadProxyInvalidPath483=== PAUSE TestReadProxyInvalidPath484=== RUN TestReadProxyHead485=== PAUSE TestReadProxyHead486=== RUN TestReadProxyConditionalGet487=== PAUSE TestReadProxyConditionalGet488=== RUN TestReadProxyRootRedirectsToIndexHTML489=== PAUSE TestReadProxyRootRedirectsToIndexHTML490=== RUN TestReadProxyDisabled491=== PAUSE TestReadProxyDisabled492=== RUN TestReadProxyRangeRequest493=== PAUSE TestReadProxyRangeRequest494=== RUN TestRedundantMultipartUpload495=== PAUSE TestRedundantMultipartUpload496=== RUN TestCompleteMultipartUpload_ErrorButObjectExists497=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists498=== RUN TestCompletedNarNotReofferedAcrossClosures499=== PAUSE TestCompletedNarNotReofferedAcrossClosures500=== RUN TestPresignedUploadRegisteredBeforeCommit501=== PAUSE TestPresignedUploadRegisteredBeforeCommit502=== RUN TestService_Rustfstest503=== PAUSE TestService_Rustfstest504=== RUN TestParseSize505=== PAUSE TestParseSize506=== RUN TestSkippedUploadsHandler507=== PAUSE TestSkippedUploadsHandler508=== RUN TestSystemdListenerNotActivated509--- PASS: TestSystemdListenerNotActivated (0.00s)510=== RUN TestWatchdogBeatsWhenHealthy511--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)512=== RUN TestWatchdogSkipsWhenUnhealthy5132026/08/27 09:24:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5142026/08/27 09:24:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5152026/08/27 09:24:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5162026/08/27 09:24:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5172026/08/27 09:24:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5182026/08/27 09:24:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5192026/08/27 09:24:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5202026/08/27 09:24:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5212026/08/27 09:24:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5222026/08/27 09:24:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"523--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)524=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle525=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle526=== RUN TestProxyWriteTimeout527=== PAUSE TestProxyWriteTimeout528=== RUN TestIsValidUploadKey529=== PAUSE TestIsValidUploadKey530=== RUN TestUploadHandlersRejectInvalidKeys531=== PAUSE TestUploadHandlersRejectInvalidKeys532=== RUN TestUploadHandlersRejectOversizedBody533=== PAUSE TestUploadHandlersRejectOversizedBody534=== RUN TestService_cleanupPendingClosuresHandler535=== PAUSE TestService_cleanupPendingClosuresHandler536=== RUN TestService_createPendingClosureHandler537=== PAUSE TestService_createPendingClosureHandler538=== RUN TestService_verifyS3Integrity539=== PAUSE TestService_verifyS3Integrity540=== RUN TestCompleteMultipartUnregistered541=== PAUSE TestCompleteMultipartUnregistered542=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT543=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT544=== CONT TestService_AuthMiddleware545=== CONT TestObjectStatsTrigger546=== CONT TestGracefulShutdownDrainsInflight547=== CONT TestGCTaskStore_ConflictDifferentParams548--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)549=== CONT TestProxyWriteTimeout550=== CONT TestService_healthCheckHandler5512026/08/27 09:24:27 INFO Starting HTTP server address=127.0.0.1:42103552=== CONT TestGenerateLandingPage553=== CONT TestMultipartCleanup554=== CONT TestServerTLSConfig555=== RUN TestServerTLSConfig/no_client_CA556=== CONT TestService_NativeMTLS557=== CONT TestMetricsInventory558=== CONT TestNARDeduplicationMetadataUploadBug559=== CONT TestCreatePendingClosureRejectsOversizedNAR560=== CONT TestCacheConfigHandlerMaxNarSize561=== CONT TestCompleteMultipartUpload_ErrorButObjectExists562=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT563=== CONT TestCompleteMultipartUnregistered564=== CONT TestService_verifyS3Integrity565=== CONT TestService_createPendingClosureHandler566=== CONT TestService_cleanupPendingClosuresHandler567=== CONT TestUploadHandlersRejectOversizedBody568=== CONT TestUploadHandlersRejectInvalidKeys569=== CONT TestGCTaskStore_CompletedAllowsNewTask570=== CONT TestIsValidUploadKey571=== CONT TestGCTaskStore_Fail572=== RUN TestProxyWriteTimeout/narinfo573=== PAUSE TestServerTLSConfig/no_client_CA574=== RUN TestServerTLSConfig/missing_CA_file575=== PAUSE TestServerTLSConfig/missing_CA_file576=== RUN TestServerTLSConfig/not_a_PEM_file577=== PAUSE TestServerTLSConfig/not_a_PEM_file5782026/08/27 09:24:27 INFO Shutdown signal received, draining in-flight requests timeout=10s579--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)580=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle5812026/08/27 09:24:27 INFO Received uploads request method=POST path=/api/pending_closures582--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)583=== CONT TestPresignedUploadRegisteredBeforeCommit584--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)585=== CONT TestService_Rustfstest586=== PAUSE TestProxyWriteTimeout/narinfo587=== RUN TestProxyWriteTimeout/1_GiB_nar588=== PAUSE TestProxyWriteTimeout/1_GiB_nar589=== RUN TestProxyWriteTimeout/10_GiB_nar590=== PAUSE TestProxyWriteTimeout/10_GiB_nar591=== RUN TestProxyWriteTimeout/unknown_size592=== PAUSE TestProxyWriteTimeout/unknown_size593--- PASS: TestGCTaskStore_Fail (0.00s)594=== CONT TestSkippedUploadsHandler595=== RUN TestIsValidUploadKey/narinfo596=== PAUSE TestIsValidUploadKey/narinfo597=== RUN TestIsValidUploadKey/nar_zst598=== PAUSE TestIsValidUploadKey/nar_zst599=== RUN TestIsValidUploadKey/nar_xz600=== PAUSE TestIsValidUploadKey/nar_xz601=== RUN TestIsValidUploadKey/nar_plain602=== PAUSE TestIsValidUploadKey/nar_plain603=== CONT TestCompletedNarNotReofferedAcrossClosures6042026/08/27 09:24:27 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000605=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info606=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info607=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal608=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal609=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key610=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key611=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key612=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key613=== RUN TestIsValidUploadKey/listing614=== PAUSE TestIsValidUploadKey/listing615=== RUN TestIsValidUploadKey/build_log616=== PAUSE TestIsValidUploadKey/build_log617=== RUN TestIsValidUploadKey/build_log_home-manager_file618=== PAUSE TestIsValidUploadKey/build_log_home-manager_file619=== RUN TestIsValidUploadKey/build_log_plus_in_name620=== PAUSE TestIsValidUploadKey/build_log_plus_in_name621=== CONT TestGCTaskStore_PhaseUpdates622--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)623=== CONT TestGCTaskStore_GetReturnsLatest624--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)625=== CONT TestReadProxy404626=== CONT TestParseSize627--- PASS: TestParseSize (0.00s)628=== CONT TestGCTaskStore_GetEmpty629=== RUN TestIsValidUploadKey/build_log_question_mark630--- PASS: TestGCTaskStore_GetEmpty (0.00s)631=== CONT TestRedundantMultipartUpload632=== PAUSE TestIsValidUploadKey/build_log_question_mark633=== RUN TestIsValidUploadKey/build_log_equals634=== PAUSE TestIsValidUploadKey/build_log_equals635=== RUN TestIsValidUploadKey/realisation636=== PAUSE TestIsValidUploadKey/realisation637=== RUN TestIsValidUploadKey/realisation_plus_in_output638=== PAUSE TestIsValidUploadKey/realisation_plus_in_output639=== RUN TestIsValidUploadKey/nix-cache-info640=== PAUSE TestIsValidUploadKey/nix-cache-info641=== RUN TestIsValidUploadKey/index.html642=== PAUSE TestIsValidUploadKey/index.html643=== RUN TestIsValidUploadKey/narinfo_key,_nar_type644=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type645=== RUN TestIsValidUploadKey/nar_key,_narinfo_type646=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type647=== RUN TestIsValidUploadKey/listing_key,_narinfo_type648--- PASS: TestGenerateLandingPage (0.01s)649--- PASS: TestSkippedUploadsHandler (0.01s)650=== CONT TestReadProxyRangeRequest651=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type652=== RUN TestIsValidUploadKey/traversal653=== PAUSE TestIsValidUploadKey/traversal654=== RUN TestIsValidUploadKey/traversal_nar655=== CONT TestReadProxyNarinfoAlreadyDecompressed656=== PAUSE TestIsValidUploadKey/traversal_nar657=== RUN TestIsValidUploadKey/absolute658=== PAUSE TestIsValidUploadKey/absolute659=== RUN TestIsValidUploadKey/empty_key660=== PAUSE TestIsValidUploadKey/empty_key661=== RUN TestIsValidUploadKey/unknown_type662=== PAUSE TestIsValidUploadKey/unknown_type663=== CONT TestReadProxyNarStreaming664--- PASS: TestGracefulShutdownDrainsInflight (0.07s)665=== CONT TestReadProxyDisabled6662026-08-27 09:24:27.974 UTC [601] ERROR: relation "goose_db_version" does not exist at character 366672026-08-27 09:24:27.974 UTC [601] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6682026-08-27 09:24:27.975 UTC [602] ERROR: relation "goose_db_version" does not exist at character 366692026-08-27 09:24:27.975 UTC [602] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC670=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure671=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure672=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart673=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart674=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts675=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts676=== CONT TestReadProxyNarinfo6772026-08-27 09:24:28.106 UTC [606] ERROR: relation "goose_db_version" does not exist at character 366782026-08-27 09:24:28.106 UTC [606] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6792026-08-27 09:24:28.107 UTC [607] ERROR: relation "goose_db_version" does not exist at character 366802026-08-27 09:24:28.107 UTC [607] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6812026/08/27 09:24:28 OK 20241026095416_initial_model.sql (109.61ms)6822026/08/27 09:24:28 OK 20241026095416_initial_model.sql (110.52ms)6832026-08-27 09:24:28.113 UTC [608] ERROR: relation "goose_db_version" does not exist at character 366842026-08-27 09:24:28.113 UTC [608] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6852026-08-27 09:24:28.122 UTC [609] ERROR: relation "goose_db_version" does not exist at character 366862026-08-27 09:24:28.122 UTC [609] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6872026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (9.19ms)6882026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (14.68ms)6892026-08-27 09:24:28.134 UTC [610] ERROR: relation "goose_db_version" does not exist at character 366902026-08-27 09:24:28.134 UTC [610] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6912026/08/27 09:24:28 OK 20251218171726_add_pins.sql (12.72ms)6922026/08/27 09:24:28 OK 20251218171726_add_pins.sql (9.41ms)6932026-08-27 09:24:28.150 UTC [611] ERROR: relation "goose_db_version" does not exist at character 366942026-08-27 09:24:28.150 UTC [611] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6952026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (13.98ms)6962026/08/27 09:24:28 OK 20241026095416_initial_model.sql (33.36ms)6972026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200006982026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (15.01ms)6992026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200007002026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (3.92ms)7012026/08/27 09:24:28 OK 1_commit_pending_closure.sql (4.95ms)7022026/08/27 09:24:28 OK 20241026095416_initial_model.sql (34.95ms)7032026/08/27 09:24:28 OK 1_commit_pending_closure.sql (6.5ms)7042026/08/27 09:24:28 OK 20241026095416_initial_model.sql (30.78ms)7052026/08/27 09:24:28 OK 2_object_stats_trigger.sql (3.86ms)7062026/08/27 09:24:28 goose: up to current file version: 27072026/08/27 09:24:28 OK 2_object_stats_trigger.sql (3.92ms)7082026/08/27 09:24:28 goose: up to current file version: 27092026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (4.42ms)7102026-08-27 09:24:28.167 UTC [612] ERROR: relation "goose_db_version" does not exist at character 367112026-08-27 09:24:28.167 UTC [612] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7122026/08/27 09:24:28 OK 20251218171726_add_pins.sql (8.94ms)7132026-08-27 09:24:28.168 UTC [613] ERROR: relation "goose_db_version" does not exist at character 367142026-08-27 09:24:28.168 UTC [613] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7152026/08/27 09:24:28 OK 20241026095416_initial_model.sql (32.18ms)7162026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (5.4ms)7172026-08-27 09:24:28.170 UTC [614] ERROR: relation "goose_db_version" does not exist at character 367182026-08-27 09:24:28.170 UTC [614] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7192026/08/27 09:24:28 OK 20241026095416_initial_model.sql (17.12ms)7202026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (5.93ms)7212026-08-27 09:24:28.176 UTC [615] ERROR: relation "goose_db_version" does not exist at character 367222026-08-27 09:24:28.176 UTC [615] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7232026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (9.61ms)7242026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200007252026/08/27 09:24:28 OK 20251218171726_add_pins.sql (11.35ms)7262026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (6.94ms)7272026/08/27 09:24:28 OK 20251218171726_add_pins.sql (9.2ms)7282026/08/27 09:24:28 OK 20241026095416_initial_model.sql (17.91ms)7292026/08/27 09:24:28 OK 1_commit_pending_closure.sql (12.15ms)7302026/08/27 09:24:28 OK 20251218171726_add_pins.sql (15.35ms)7312026/08/27 09:24:28 OK 20251218171726_add_pins.sql (14.73ms)7322026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (14.82ms)7332026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200007342026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (11.94ms)7352026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (14.85ms)7362026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200007372026/08/27 09:24:28 OK 2_object_stats_trigger.sql (4.83ms)7382026/08/27 09:24:28 goose: up to current file version: 27392026/08/27 09:24:28 OK 20241026095416_initial_model.sql (12.41ms)7402026/08/27 09:24:28 OK 20241026095416_initial_model.sql (13.96ms)7412026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (10.44ms)7422026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200007432026/08/27 09:24:28 OK 1_commit_pending_closure.sql (8.81ms)7442026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (9.1ms)7452026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200007462026/08/27 09:24:28 OK 20251218171726_add_pins.sql (8.79ms)7472026/08/27 09:24:28 OK 1_commit_pending_closure.sql (8.77ms)7482026/08/27 09:24:28 OK 20241026095416_initial_model.sql (10.92ms)7492026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (5.49ms)7502026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (7.24ms)7512026/08/27 09:24:28 OK 1_commit_pending_closure.sql (6.28ms)7522026/08/27 09:24:28 OK 1_commit_pending_closure.sql (4.96ms)7532026/08/27 09:24:28 OK 2_object_stats_trigger.sql (4.87ms)7542026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (4.51ms)7552026-08-27 09:24:28.207 UTC [616] ERROR: relation "goose_db_version" does not exist at character 367562026-08-27 09:24:28.207 UTC [616] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7572026/08/27 09:24:28 OK 2_object_stats_trigger.sql (5.05ms)7582026/08/27 09:24:28 goose: up to current file version: 27592026/08/27 09:24:28 goose: up to current file version: 27602026/08/27 09:24:28 OK 20241026095416_initial_model.sql (13.15ms)7612026-08-27 09:24:28.208 UTC [617] ERROR: relation "goose_db_version" does not exist at character 367622026-08-27 09:24:28.208 UTC [617] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7632026/08/27 09:24:28 OK 20251218171726_add_pins.sql (7.64ms)7642026/08/27 09:24:28 OK 20251218171726_add_pins.sql (7.61ms)7652026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (8ms)7662026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200007672026-08-27 09:24:28.210 UTC [619] ERROR: relation "goose_db_version" does not exist at character 367682026-08-27 09:24:28.210 UTC [619] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7692026-08-27 09:24:28.210 UTC [618] ERROR: relation "goose_db_version" does not exist at character 367702026-08-27 09:24:28.210 UTC [618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7712026/08/27 09:24:28 OK 2_object_stats_trigger.sql (4.35ms)7722026/08/27 09:24:28 goose: up to current file version: 27732026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (4.13ms)7742026-08-27 09:24:28.212 UTC [621] ERROR: relation "goose_db_version" does not exist at character 367752026-08-27 09:24:28.212 UTC [621] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7762026-08-27 09:24:28.212 UTC [620] ERROR: relation "goose_db_version" does not exist at character 367772026-08-27 09:24:28.212 UTC [620] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7782026-08-27 09:24:28.213 UTC [622] ERROR: relation "goose_db_version" does not exist at character 367792026-08-27 09:24:28.213 UTC [622] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7802026/08/27 09:24:28 OK 2_object_stats_trigger.sql (6.44ms)7812026/08/27 09:24:28 goose: up to current file version: 27822026-08-27 09:24:28.215 UTC [625] ERROR: relation "goose_db_version" does not exist at character 367832026-08-27 09:24:28.215 UTC [625] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7842026-08-27 09:24:28.215 UTC [623] ERROR: relation "goose_db_version" does not exist at character 367852026-08-27 09:24:28.215 UTC [623] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7862026/08/27 09:24:28 OK 1_commit_pending_closure.sql (5.49ms)7872026/08/27 09:24:28 OK 20251218171726_add_pins.sql (8.36ms)7882026-08-27 09:24:28.216 UTC [624] ERROR: relation "goose_db_version" does not exist at character 367892026-08-27 09:24:28.216 UTC [624] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7902026-08-27 09:24:28.216 UTC [626] ERROR: relation "goose_db_version" does not exist at character 367912026-08-27 09:24:28.216 UTC [626] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7922026-08-27 09:24:28.217 UTC [629] ERROR: relation "goose_db_version" does not exist at character 367932026-08-27 09:24:28.217 UTC [629] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7942026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (7.18ms)7952026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200007962026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (7.21ms)7972026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200007982026/08/27 09:24:28 OK 20251218171726_add_pins.sql (8.44ms)7992026/08/27 09:24:28 OK 2_object_stats_trigger.sql (4.58ms)8002026/08/27 09:24:28 goose: up to current file version: 28012026/08/27 09:24:28 OK 1_commit_pending_closure.sql (5.19ms)8022026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (6.92ms)8032026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200008042026/08/27 09:24:28 OK 1_commit_pending_closure.sql (5.21ms)8052026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (7.06ms)8062026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200008072026/08/27 09:24:28 OK 2_object_stats_trigger.sql (4.51ms)8082026/08/27 09:24:28 goose: up to current file version: 28092026/08/27 09:24:28 OK 2_object_stats_trigger.sql (4.74ms)8102026/08/27 09:24:28 goose: up to current file version: 28112026/08/27 09:24:28 OK 1_commit_pending_closure.sql (6.26ms)812{"timestamp":"2026-08-27T09:24:28.230038305Z","level":"ERROR","duration":"568.005µ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":"/build/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(335)"}813{"timestamp":"2026-08-27T09:24:28.230184346Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b0a51e94-73f5-4f14-a16c-bde9bbda14cf","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(335)"}8142026/08/27 09:24:28 OK 2_object_stats_trigger.sql (3.52ms)8152026/08/27 09:24:28 goose: up to current file version: 28162026/08/27 09:24:28 OK 20241026095416_initial_model.sql (15.33ms)8172026/08/27 09:24:28 OK 1_commit_pending_closure.sql (5.32ms)8182026/08/27 09:24:28 OK 20241026095416_initial_model.sql (16.92ms)819{"timestamp":"2026-08-27T09:24:28.234754768Z","level":"ERROR","duration":"498.165µ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":"/build/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(335)"}820{"timestamp":"2026-08-27T09:24:28.234822528Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"91ddf225-765a-48cd-b0bb-12d12a356d93","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket12/","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(335)"}821--- PASS: TestObjectStatsTrigger (0.35s)822=== CONT TestIsValidCachePath823=== RUN TestIsValidCachePath/narinfo824=== PAUSE TestIsValidCachePath/narinfo825=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars826=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars827=== RUN TestIsValidCachePath/nar_zst828=== PAUSE TestIsValidCachePath/nar_zst829=== RUN TestIsValidCachePath/nar_xz830=== PAUSE TestIsValidCachePath/nar_xz831=== RUN TestIsValidCachePath/nar_bz2832=== PAUSE TestIsValidCachePath/nar_bz2833=== RUN TestIsValidCachePath/nar_uncompressed834=== PAUSE TestIsValidCachePath/nar_uncompressed835=== RUN TestIsValidCachePath/ls836=== PAUSE TestIsValidCachePath/ls837=== RUN TestIsValidCachePath/log838=== PAUSE TestIsValidCachePath/log839=== RUN TestIsValidCachePath/realisation840=== PAUSE TestIsValidCachePath/realisation841=== RUN TestIsValidCachePath/nix-cache-info842=== PAUSE TestIsValidCachePath/nix-cache-info843=== RUN TestIsValidCachePath/index.html844=== PAUSE TestIsValidCachePath/index.html845=== RUN TestIsValidCachePath/traversal_parent846=== PAUSE TestIsValidCachePath/traversal_parent847=== RUN TestIsValidCachePath/traversal_in_middle848=== PAUSE TestIsValidCachePath/traversal_in_middle849=== RUN TestIsValidCachePath/invalid_char_e850=== PAUSE TestIsValidCachePath/invalid_char_e851=== RUN TestIsValidCachePath/invalid_char_u852=== PAUSE TestIsValidCachePath/invalid_char_u853=== RUN TestIsValidCachePath/random_path854=== PAUSE TestIsValidCachePath/random_path855=== RUN TestIsValidCachePath/empty856=== PAUSE TestIsValidCachePath/empty857=== RUN TestIsValidCachePath/leading_slash858=== PAUSE TestIsValidCachePath/leading_slash859=== RUN TestIsValidCachePath/wrong_extension860=== PAUSE TestIsValidCachePath/wrong_extension861=== RUN TestIsValidCachePath/short_hash862=== PAUSE TestIsValidCachePath/short_hash863=== CONT TestReadProxyHead8642026/08/27 09:24:28 OK 2_object_stats_trigger.sql (4.71ms)8652026/08/27 09:24:28 goose: up to current file version: 28662026/08/27 09:24:28 OK 20241026095416_initial_model.sql (16.14ms)8672026/08/27 09:24:28 OK 20241026095416_initial_model.sql (15ms)8682026/08/27 09:24:28 OK 20241026095416_initial_model.sql (17.06ms)869{"timestamp":"2026-08-27T09:24:28.239766514Z","level":"ERROR","duration":"272.183µ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":"/build/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(335)"}870{"timestamp":"2026-08-27T09:24:28.239801874Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"27bc86bd-f743-40e9-b675-a09a1acd0039","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket13/","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(335)"}8712026/08/27 09:24:28 OK 20241026095416_initial_model.sql (14.05ms)8722026/08/27 09:24:28 OK 20241026095416_initial_model.sql (16.33ms)8732026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (6.5ms)8742026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (6.35ms)8752026/08/27 09:24:28 OK 20241026095416_initial_model.sql (12.71ms)8762026/08/27 09:24:28 OK 20241026095416_initial_model.sql (18.45ms)8772026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (3.31ms)8782026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (3.35ms)8792026/08/27 09:24:28 OK 20241026095416_initial_model.sql (16.08ms)8802026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (3.17ms)8812026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (4.82ms)8822026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (3.27ms)8832026/08/27 09:24:28 OK 20241026095416_initial_model.sql (18.07ms)8842026/08/27 09:24:28 OK 20241026095416_initial_model.sql (14.6ms)8852026/08/27 09:24:28 OK 20251218171726_add_pins.sql (6.3ms)8862026/08/27 09:24:28 OK 20251218171726_add_pins.sql (6.41ms)8872026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (5.22ms)8882026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (3.77ms)8892026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (5.16ms)8902026/08/27 09:24:28 OK 20251218171726_add_pins.sql (5.5ms)8912026/08/27 09:24:28 OK 20251218171726_add_pins.sql (4.17ms)8922026/08/27 09:24:28 OK 20251218171726_add_pins.sql (5.57ms)8932026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)8942026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)8952026/08/27 09:24:28 OK 20251218171726_add_pins.sql (4.48ms)8962026/08/27 09:24:28 OK 20251218171726_add_pins.sql (4.41ms)8972026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (4.76ms)8982026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200008992026/08/27 09:24:28 OK 20251218171726_add_pins.sql (5.81ms)9002026/08/27 09:24:28 OK 20251218171726_add_pins.sql (5.12ms)9012026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (4.99ms)9022026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200009032026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (5.36ms)9042026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200009052026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (6.12ms)9062026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200009072026/08/27 09:24:28 OK 20251218171726_add_pins.sql (5.94ms)9082026/08/27 09:24:28 OK 20251218171726_add_pins.sql (5.04ms)9092026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (6.34ms)9102026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200009112026/08/27 09:24:28 OK 20251218171726_add_pins.sql (6.92ms)9122026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (6.11ms)9132026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200009142026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (6.45ms)9152026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200009162026/08/27 09:24:28 OK 1_commit_pending_closure.sql (3.98ms)917--- PASS: TestService_healthCheckHandler (0.37s)918=== CONT TestReadProxyConditionalGet9192026/08/27 09:24:28 OK 1_commit_pending_closure.sql (3.82ms)9202026/08/27 09:24:28 OK 1_commit_pending_closure.sql (3.5ms)9212026/08/27 09:24:28 OK 1_commit_pending_closure.sql (4.69ms)9222026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (5ms)9232026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200009242026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (4.52ms)9252026/08/27 09:24:28 OK 1_commit_pending_closure.sql (3.65ms)9262026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (4.73ms)9272026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200009282026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (4.89ms)9292026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200009302026/08/27 09:24:28 OK 1_commit_pending_closure.sql (4.56ms)9312026/08/27 09:24:28 OK 2_object_stats_trigger.sql (2.41ms)9322026/08/27 09:24:28 goose: up to current file version: 29332026/08/27 09:24:28 OK 2_object_stats_trigger.sql (1.19ms)9342026/08/27 09:24:28 goose: up to current file version: 29352026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200009362026/08/27 09:24:28 OK 1_commit_pending_closure.sql (3.3ms)9372026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (3.72ms)9382026/08/27 09:24:28 goose: successfully migrated database to version: 20260628120000939{"timestamp":"2026-08-27T09:24:28.260313682Z","level":"ERROR","duration":"503.325µ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":"/build/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(383)"}940{"timestamp":"2026-08-27T09:24:28.260398683Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"da159641-2dd0-41a2-bf26-bea43294c264","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket14/","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(383)"}9412026/08/27 09:24:28 OK 2_object_stats_trigger.sql (2.31ms)9422026/08/27 09:24:28 goose: up to current file version: 2943{"timestamp":"2026-08-27T09:24:28.26224744Z","level":"ERROR","duration":"371.384µ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":"/build/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(376)"}944{"timestamp":"2026-08-27T09:24:28.26230258Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"18dc450b-f19b-4a51-acfb-3b5b9557339f","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket16/","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(376)"}9452026/08/27 09:24:28 OK 2_object_stats_trigger.sql (3.7ms)9462026/08/27 09:24:28 goose: up to current file version: 29472026/08/27 09:24:28 OK 2_object_stats_trigger.sql (4.16ms)9482026/08/27 09:24:28 goose: up to current file version: 29492026/08/27 09:24:28 OK 1_commit_pending_closure.sql (3.82ms)9502026/08/27 09:24:28 OK 2_object_stats_trigger.sql (3.25ms)9512026/08/27 09:24:28 goose: up to current file version: 29522026/08/27 09:24:28 OK 2_object_stats_trigger.sql (3.9ms)9532026/08/27 09:24:28 goose: up to current file version: 29542026/08/27 09:24:28 OK 1_commit_pending_closure.sql (3.78ms)9552026/08/27 09:24:28 OK 1_commit_pending_closure.sql (4.08ms)9562026/08/27 09:24:28 OK 1_commit_pending_closure.sql (4.05ms)9572026/08/27 09:24:28 OK 1_commit_pending_closure.sql (3.99ms)958{"timestamp":"2026-08-27T09:24:28.263797894Z","level":"ERROR","duration":"478.945µ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":"/build/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(375)"}959{"timestamp":"2026-08-27T09:24:28.263873755Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"2d401452-0e1f-408d-ab41-717b5fc4e4ad","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket17/","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(375)"}9602026/08/27 09:24:28 OK 2_object_stats_trigger.sql (1.17ms)9612026/08/27 09:24:28 goose: up to current file version: 2962{"timestamp":"2026-08-27T09:24:28.264000756Z","level":"ERROR","duration":"341.883µ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":"/build/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(376)"}963{"timestamp":"2026-08-27T09:24:28.264060116Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"e10d99dc-f020-4ed7-856b-bbc61370fc07","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket19/","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(376)"}964{"timestamp":"2026-08-27T09:24:28.264156737Z","level":"ERROR","duration":"427.264µ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":"/build/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(383)"}965{"timestamp":"2026-08-27T09:24:28.264265998Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"124c437e-82a9-4087-82bb-5e4c9e849a7f","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket18/","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(383)"}9662026/08/27 09:24:28 OK 2_object_stats_trigger.sql (1.24ms)9672026/08/27 09:24:28 goose: up to current file version: 29682026/08/27 09:24:28 OK 2_object_stats_trigger.sql (1.48ms)9692026/08/27 09:24:28 goose: up to current file version: 2970{"timestamp":"2026-08-27T09:24:28.265177907Z","level":"ERROR","duration":"445.464µ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":"/build/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(335)"}971{"timestamp":"2026-08-27T09:24:28.265249927Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"7a42782f-cdf4-4e0c-ac4f-7773699bc033","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket20/","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(335)"}972{"timestamp":"2026-08-27T09:24:28.265308248Z","level":"ERROR","duration":"474.425µ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":"/build/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(244)"}973{"timestamp":"2026-08-27T09:24:28.265336088Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"4eade207-1c32-4425-a917-f59f6ddd088c","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket21/","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(244)"}974{"timestamp":"2026-08-27T09:24:28.265770052Z","level":"ERROR","duration":"319.383µ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":"/build/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(376)"}975{"timestamp":"2026-08-27T09:24:28.265823513Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"aef71195-9be9-4331-a32c-faaa8385c408","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket23/","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(376)"}9762026/08/27 09:24:28 OK 2_object_stats_trigger.sql (2.62ms)9772026/08/27 09:24:28 goose: up to current file version: 29782026/08/27 09:24:28 OK 2_object_stats_trigger.sql (2.99ms)9792026/08/27 09:24:28 goose: up to current file version: 2980{"timestamp":"2026-08-27T09:24:28.267787471Z","level":"ERROR","duration":"357.924µ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":"/build/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(375)"}981{"timestamp":"2026-08-27T09:24:28.267839511Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"f7add756-d752-4851-aae3-72e85f2608f8","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket24/","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(375)"}9822026-08-27 09:24:28.323 UTC [634] ERROR: relation "goose_db_version" does not exist at character 369832026-08-27 09:24:28.323 UTC [634] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9842026-08-27 09:24:28.340 UTC [635] ERROR: relation "goose_db_version" does not exist at character 369852026-08-27 09:24:28.340 UTC [635] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9862026/08/27 09:24:28 OK 20241026095416_initial_model.sql (10.08ms)9872026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (1.65ms)9882026/08/27 09:24:28 OK 20251218171726_add_pins.sql (3.08ms)9892026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (3.76ms)9902026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200009912026/08/27 09:24:28 OK 1_commit_pending_closure.sql (3.11ms)9922026/08/27 09:24:28 OK 2_object_stats_trigger.sql (1.71ms)9932026/08/27 09:24:28 goose: up to current file version: 29942026/08/27 09:24:28 OK 20241026095416_initial_model.sql (10.53ms)9952026/08/27 09:24:28 OK 20251210153512_drop_unused_gin_index.sql (1.29ms)9962026/08/27 09:24:28 OK 20251218171726_add_pins.sql (2.87ms)9972026/08/27 09:24:28 OK 20260628120000_add_object_size_and_stats.sql (3.47ms)9982026/08/27 09:24:28 goose: successfully migrated database to version: 202606281200009992026/08/27 09:24:28 OK 1_commit_pending_closure.sql (1.89ms)10002026/08/27 09:24:28 OK 2_object_stats_trigger.sql (821.51µs)10012026/08/27 09:24:28 goose: up to current file version: 21002{"timestamp":"2026-08-27T09:24:28.733865238Z","level":"ERROR","duration":"1.420633ms","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":"/build/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(376)"}1003{"timestamp":"2026-08-27T09:24:28.733933938Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"d5ed2889-6cb2-4b59-873e-39a340840a34","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket16/","status_code":503,"duration_ms":1,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(376)"}1004{"timestamp":"2026-08-27T09:24:28.733907018Z","level":"ERROR","duration":"1.13287ms","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":"/build/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(385)"}1005{"timestamp":"2026-08-27T09:24:28.733974779Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"e02054fd-dc63-4a6a-a114-f29a21d1a01a","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket14/","status_code":503,"duration_ms":1,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(385)"}1006{"timestamp":"2026-08-27T09:24:28.734162661Z","level":"ERROR","duration":"1.287351ms","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":"/build/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(375)"}1007{"timestamp":"2026-08-27T09:24:28.734227941Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"ae552ee7-888f-432c-8f9e-c9e7a3ec2776","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket27/","status_code":503,"duration_ms":1,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(375)"}1008{"timestamp":"2026-08-27T09:24:28.734333582Z","level":"ERROR","duration":"1.765236ms","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":"/build/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(384)"}1009{"timestamp":"2026-08-27T09:24:28.734393803Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"086cfb35-2ca6-4989-81f1-938f592eecf2","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket19/","status_code":503,"duration_ms":1,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(384)"}1010{"timestamp":"2026-08-27T09:24:28.734662225Z","level":"ERROR","duration":"2.2327ms","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":"/build/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(244)"}1011{"timestamp":"2026-08-27T09:24:28.734696725Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"320c1451-c18b-4f7a-90ba-00ec0d4ff5d5","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket18/","status_code":503,"duration_ms":2,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(244)"}1012{"timestamp":"2026-08-27T09:24:28.73514621Z","level":"ERROR","duration":"467.277239ms","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":"/build/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(384)"}1013{"timestamp":"2026-08-27T09:24:28.73519387Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"c2e5112f-1de4-4a6f-be33-963bbe9e2227","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket25/","status_code":503,"duration_ms":467,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(384)"}1014{"timestamp":"2026-08-27T09:24:29.074286215Z","level":"ERROR","duration":"100.701µ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":"/build/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(383)"}1015{"timestamp":"2026-08-27T09:24:29.074332175Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"0c43418d-3ac1-4ec7-aae9-1d4931414aa4","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket16/","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(383)"}1016{"timestamp":"2026-08-27T09:24:29.074407056Z","level":"ERROR","duration":"130.781µ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":"/build/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(385)"}1017{"timestamp":"2026-08-27T09:24:29.074453376Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"d5245faa-0e71-420d-a454-66d4823e5a88","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket18/","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(385)"}1018{"timestamp":"2026-08-27T09:24:29.074457616Z","level":"ERROR","duration":"145.241µ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":"/build/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(376)"}1019{"timestamp":"2026-08-27T09:24:29.074522197Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"c80e3c45-7da9-4262-8de1-5914427be8d2","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket14/","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(376)"}1020{"timestamp":"2026-08-27T09:24:29.074287795Z","level":"ERROR","duration":"458.244µ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":"/build/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(288)"}1021{"timestamp":"2026-08-27T09:24:29.074666598Z","level":"ERROR","duration":"537.325µ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":"/build/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(378)"}1022{"timestamp":"2026-08-27T09:24:29.074708019Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"8f7ae174-bc29-4fae-b59e-16fce7a19324","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(378)"}1023{"timestamp":"2026-08-27T09:24:29.074736359Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"d3ae64b0-1445-4f24-a9ec-479c9f3bf931","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket20/","status_code":503,"duration_ms":340,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(288)"}1024{"timestamp":"2026-08-27T09:24:29.074589618Z","level":"ERROR","duration":"1.422293ms","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":"/build/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(312)"}1025{"timestamp":"2026-08-27T09:24:29.07482996Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"1a72e3ad-5d3a-460a-905c-70bd08148028","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket17/","status_code":503,"duration_ms":340,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(312)"}1026{"timestamp":"2026-08-27T09:24:29.074977041Z","level":"ERROR","duration":"787.187µ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":"/build/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(374)"}1027{"timestamp":"2026-08-27T09:24:29.074983101Z","level":"ERROR","duration":"342.262334ms","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":"/build/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(380)"}1028{"timestamp":"2026-08-27T09:24:29.075019582Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"f4fdcb75-1224-4550-8310-2ad2a9a665d6","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket23/","status_code":503,"duration_ms":342,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(380)"}1029{"timestamp":"2026-08-27T09:24:29.075012402Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"015515b6-5abb-4e9a-903c-9cefce8cb8aa","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket19/","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(374)"}1030{"timestamp":"2026-08-27T09:24:29.075361205Z","level":"ERROR","duration":"340.226216ms","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":"/build/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(292)"}1031{"timestamp":"2026-08-27T09:24:29.075364145Z","level":"ERROR","duration":"644.506µ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":"/build/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(290)"}1032{"timestamp":"2026-08-27T09:24:29.075605687Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"23383c88-6f18-4e2d-8d57-1d3191ff0100","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket12/","status_code":503,"duration_ms":342,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(292)"}1033{"timestamp":"2026-08-27T09:24:29.076414934Z","level":"ERROR","duration":"425.684µ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":"/build/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(359)"}1034{"timestamp":"2026-08-27T09:24:29.076453475Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"0457e668-70ce-4954-8aef-83b04e1baa1b","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket22/","status_code":503,"duration_ms":341,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(359)"}1035{"timestamp":"2026-08-27T09:24:29.077228042Z","level":"ERROR","duration":"266.783µ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":"/build/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(381)"}1036{"timestamp":"2026-08-27T09:24:29.077276182Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"c8823d4c-6222-4fbf-b2ea-032c2ede3dc2","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket24/","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(381)"}1037{"timestamp":"2026-08-27T09:24:29.080096608Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"dd0d915e-0901-455f-a359-7efad49d5da5","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket25/","status_code":503,"duration_ms":5,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(290)"}1038{"timestamp":"2026-08-27T09:24:29.081870024Z","level":"ERROR","duration":"152.121µ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":"/build/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(335)"}1039{"timestamp":"2026-08-27T09:24:29.081924225Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"42a2fbc9-3f78-47aa-877a-83803611af2e","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket19/","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(335)"}1040{"timestamp":"2026-08-27T09:24:29.082117027Z","level":"ERROR","duration":"52.481µ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":"/build/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(335)"}1041{"timestamp":"2026-08-27T09:24:29.082138087Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"f046e735-4233-4347-afe1-2defce734745","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket24/","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(335)"}1042{"timestamp":"2026-08-27T09:24:29.118777902Z","level":"ERROR","duration":"145.981µ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":"/build/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(335)"}1043{"timestamp":"2026-08-27T09:24:29.118836363Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"398cb032-3402-4616-8e6a-8ba95ff1d1a7","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket24/","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(335)"}1044{"timestamp":"2026-08-27T09:24:29.19278694Z","level":"ERROR","duration":"118.321µ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":"/build/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(381)"}1045{"timestamp":"2026-08-27T09:24:29.19283758Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3203fecd-0389-48bb-b868-1f85e445ab1b","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket22/","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(381)"}1046{"timestamp":"2026-08-27T09:24:29.219455004Z","level":"ERROR","duration":"102.221µ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":"/build/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(381)"}1047{"timestamp":"2026-08-27T09:24:29.219501344Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"d83e0aa4-4802-4577-ac11-0506879d7b14","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket12/","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(381)"}1048{"timestamp":"2026-08-27T09:24:29.225341198Z","level":"ERROR","duration":"170.862µ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":"/build/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(381)"}1049{"timestamp":"2026-08-27T09:24:29.225410819Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"928fd1a7-37fa-4fd6-aa7b-2c1a040ec6f2","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket19/","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(381)"}1050--- PASS: TestService_Rustfstest (1.34s)1051=== CONT TestReadProxyRootRedirectsToIndexHTML1052{"timestamp":"2026-08-27T09:24:29.266611416Z","level":"ERROR","duration":"191.10425ms","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":"/build/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(246)"}1053{"timestamp":"2026-08-27T09:24:29.266693457Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"7fa5de50-fdbe-43a9-b6f7-10fd77cc6fc0","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket13/","status_code":503,"duration_ms":531,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(246)"}1054{"timestamp":"2026-08-27T09:24:29.267428263Z","level":"ERROR","duration":"41.229697ms","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":"/build/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(382)"}1055{"timestamp":"2026-08-27T09:24:29.267491444Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"79759896-8de0-48d0-a5e5-1b82bedfaea0","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket27/","status_code":503,"duration_ms":76,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(382)"}1056{"timestamp":"2026-08-27T09:24:29.267574485Z","level":"ERROR","duration":"76.580001ms","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":"/build/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(291)"}1057{"timestamp":"2026-08-27T09:24:29.267652925Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"a1c37444-66a5-4336-8b3e-c64a61e38802","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket26/","status_code":503,"duration_ms":192,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(291)"}10582026/08/27 09:24:29 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1059--- PASS: TestService_AuthMiddleware (1.40s)1060=== CONT TestClientIntegration10612026/08/27 09:24:29 INFO Received uploads request method=POST path=/api/pending_closures10622026-08-27 09:24:29.306 UTC [640] ERROR: relation "goose_db_version" does not exist at character 3610632026-08-27 09:24:29.306 UTC [640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1064--- PASS: TestReadProxyHead (1.07s)1065=== CONT TestReadProxyInvalidPath10662026/08/27 09:24:29 INFO Received uploads request method=POST path=/api/pending_closures1067--- PASS: TestMetricsInventory (1.42s)1068=== CONT TestGCTaskStore_DeduplicateSameParams1069--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1070=== CONT TestParseSingleRange1071=== RUN TestParseSingleRange/none1072=== PAUSE TestParseSingleRange/none1073=== RUN TestParseSingleRange/unknown_unit1074=== PAUSE TestParseSingleRange/unknown_unit1075=== RUN TestParseSingleRange/multi-range_ignored1076=== PAUSE TestParseSingleRange/multi-range_ignored1077=== RUN TestParseSingleRange/malformed_no_dash1078=== PAUSE TestParseSingleRange/malformed_no_dash1079=== RUN TestParseSingleRange/malformed_both_empty1080=== PAUSE TestParseSingleRange/malformed_both_empty1081=== RUN TestParseSingleRange/malformed_end_before_start1082=== PAUSE TestParseSingleRange/malformed_end_before_start1083=== RUN TestParseSingleRange/closed1084=== PAUSE TestParseSingleRange/closed1085=== RUN TestParseSingleRange/open-ended1086=== PAUSE TestParseSingleRange/open-ended1087=== RUN TestParseSingleRange/end_clamped_to_size1088=== PAUSE TestParseSingleRange/end_clamped_to_size1089=== RUN TestParseSingleRange/suffix1090=== PAUSE TestParseSingleRange/suffix1091=== RUN TestParseSingleRange/suffix_exceeds_size1092=== PAUSE TestParseSingleRange/suffix_exceeds_size1093=== RUN TestParseSingleRange/single_byte1094=== PAUSE TestParseSingleRange/single_byte1095=== RUN TestParseSingleRange/start_past_EOF1096=== PAUSE TestParseSingleRange/start_past_EOF1097=== RUN TestParseSingleRange/start_far_past_EOF1098=== PAUSE TestParseSingleRange/start_far_past_EOF1099=== CONT TestGCTaskStore_StartNew1100--- PASS: TestGCTaskStore_StartNew (0.00s)1101=== CONT TestResurrectedObjectNotDeleted11022026/08/27 09:24:29 OK 20241026095416_initial_model.sql (9.08ms)11032026/08/27 09:24:29 OK 20251210153512_drop_unused_gin_index.sql (1.2ms)11042026/08/27 09:24:29 OK 20251218171726_add_pins.sql (4.2ms)11052026/08/27 09:24:29 OK 20260628120000_add_object_size_and_stats.sql (4.78ms)11062026/08/27 09:24:29 goose: successfully migrated database to version: 2026062812000011072026/08/27 09:24:29 OK 1_commit_pending_closure.sql (3.03ms)11082026/08/27 09:24:29 OK 2_object_stats_trigger.sql (2.43ms)11092026/08/27 09:24:29 goose: up to current file version: 211102026-08-27 09:24:29.359 UTC [645] ERROR: relation "goose_db_version" does not exist at character 3611112026-08-27 09:24:29.359 UTC [645] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11122026/08/27 09:24:29 OK 20241026095416_initial_model.sql (10.41ms)11132026/08/27 09:24:29 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)11142026/08/27 09:24:29 OK 20251218171726_add_pins.sql (8.01ms)11152026-08-27 09:24:29.388 UTC [646] ERROR: relation "goose_db_version" does not exist at character 3611162026-08-27 09:24:29.388 UTC [646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11172026-08-27 09:24:29.389 UTC [647] ERROR: relation "goose_db_version" does not exist at character 3611182026-08-27 09:24:29.389 UTC [647] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11192026/08/27 09:24:29 OK 20260628120000_add_object_size_and_stats.sql (3.53ms)11202026/08/27 09:24:29 goose: successfully migrated database to version: 2026062812000011212026/08/27 09:24:29 OK 1_commit_pending_closure.sql (3.21ms)11222026/08/27 09:24:29 OK 2_object_stats_trigger.sql (862.97µs)11232026/08/27 09:24:29 goose: up to current file version: 211242026/08/27 09:24:29 OK 20241026095416_initial_model.sql (11.97ms)11252026/08/27 09:24:29 OK 20241026095416_initial_model.sql (12.94ms)11262026/08/27 09:24:29 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)11272026/08/27 09:24:29 OK 20251210153512_drop_unused_gin_index.sql (1.37ms)11282026/08/27 09:24:29 OK 20251218171726_add_pins.sql (3.03ms)11292026/08/27 09:24:29 OK 20251218171726_add_pins.sql (3.25ms)11302026/08/27 09:24:29 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)11312026/08/27 09:24:29 goose: successfully migrated database to version: 2026062812000011322026/08/27 09:24:29 OK 20260628120000_add_object_size_and_stats.sql (3.43ms)11332026/08/27 09:24:29 goose: successfully migrated database to version: 2026062812000011342026/08/27 09:24:29 OK 1_commit_pending_closure.sql (1.95ms)11352026/08/27 09:24:29 OK 1_commit_pending_closure.sql (2.08ms)11362026/08/27 09:24:29 OK 2_object_stats_trigger.sql (870.39µs)11372026/08/27 09:24:29 goose: up to current file version: 211382026/08/27 09:24:29 OK 2_object_stats_trigger.sql (1.1ms)11392026/08/27 09:24:29 goose: up to current file version: 21140{"timestamp":"2026-08-27T09:24:29.621018961Z","level":"ERROR","duration":"84.841µ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":"/build/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(359)"}1141{"timestamp":"2026-08-27T09:24:29.620993001Z","level":"ERROR","duration":"141.042µ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":"/build/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(335)"}1142{"timestamp":"2026-08-27T09:24:29.621054041Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b5c7bbb5-87f9-4334-aef6-54e86206120d","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(359)"}1143{"timestamp":"2026-08-27T09:24:29.621053861Z","level":"ERROR","duration":"312.983µ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":"/build/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(360)"}1144{"timestamp":"2026-08-27T09:24:29.621058381Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"c29fe427-634d-4e9a-957e-81fd69c3d8bc","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket17/","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(335)"}1145{"timestamp":"2026-08-27T09:24:29.621082082Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"06f73df9-464f-43f5-9836-ac30f3100b79","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket14/","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(360)"}1146{"timestamp":"2026-08-27T09:24:29.621073301Z","level":"ERROR","duration":"58.9µ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":"/build/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(291)"}1147{"timestamp":"2026-08-27T09:24:29.621106462Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"e25cd108-e95d-4aab-861b-a597d26e666b","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket22/","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(291)"}1148{"timestamp":"2026-08-27T09:24:29.621164702Z","level":"ERROR","duration":"159.321µ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":"/build/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(380)"}1149{"timestamp":"2026-08-27T09:24:29.621206583Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"196371ef-6ee9-4954-8395-ee1faa1a0728","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket16/","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(380)"}1150{"timestamp":"2026-08-27T09:24:29.621220723Z","level":"ERROR","duration":"141.722µ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":"/build/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(292)"}1151{"timestamp":"2026-08-27T09:24:29.621226483Z","level":"ERROR","duration":"136.361µ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":"/build/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(374)"}1152{"timestamp":"2026-08-27T09:24:29.621246123Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"9d694890-7c02-4a3b-86f1-86db4c3f7525","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket19/","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(292)"}1153{"timestamp":"2026-08-27T09:24:29.621250783Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"c46e3490-80ba-4195-bffe-2a43b34aaf59","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket24/","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(374)"}1154{"timestamp":"2026-08-27T09:24:29.621394364Z","level":"ERROR","duration":"175.581µ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":"/build/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(378)"}1155{"timestamp":"2026-08-27T09:24:29.621424265Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"d8799fe9-ea55-4331-81ea-c46b71d06ae9","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket20/","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(378)"}1156{"timestamp":"2026-08-27T09:24:29.621597366Z","level":"ERROR","duration":"800.547µ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":"/build/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(281)"}1157{"timestamp":"2026-08-27T09:24:29.621621626Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"f99666a4-3fa1-41bd-ac88-003a27633c3c","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket13/","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(281)"}1158{"timestamp":"2026-08-27T09:24:29.621796748Z","level":"ERROR","duration":"240.642µ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":"/build/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(359)"}1159{"timestamp":"2026-08-27T09:24:29.621813748Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"c2d97a0c-0d20-4e08-aca1-c945bd09db8b","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket30/","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(359)"}1160{"timestamp":"2026-08-27T09:24:29.622176512Z","level":"ERROR","duration":"281.983µ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":"/build/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(287)"}1161{"timestamp":"2026-08-27T09:24:29.622206492Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"8d75f7d5-74f8-4098-8050-6807440203bf","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket31/","status_code":503,"duration_ms":1,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(287)"}1162{"timestamp":"2026-08-27T09:24:29.622477254Z","level":"ERROR","duration":"501.284µ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":"/build/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(288)"}1163{"timestamp":"2026-08-27T09:24:29.622509755Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"09385df3-e862-427b-a881-b6ff66386460","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket28/","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(288)"}1164{"timestamp":"2026-08-27T09:24:29.622617036Z","level":"ERROR","duration":"663.006µ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":"/build/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(312)"}1165{"timestamp":"2026-08-27T09:24:29.622652196Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"e56e3208-a65a-45aa-818f-19b2af2205c8","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket29/","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(312)"}1166{"timestamp":"2026-08-27T09:24:29.634560305Z","level":"ERROR","duration":"169.122µ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":"/build/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(381)"}1167{"timestamp":"2026-08-27T09:24:29.634591345Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b2c7effd-6041-4ce1-8547-53244abe064a","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket29/","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(381)"}1168{"timestamp":"2026-08-27T09:24:29.668132712Z","level":"ERROR","duration":"198.181µ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":"/build/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(359)"}1169{"timestamp":"2026-08-27T09:24:29.668210413Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"360e2909-420f-4ed6-8ae4-e26bc8f1c030","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket31/","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(359)"}1170{"timestamp":"2026-08-27T09:24:29.729667676Z","level":"ERROR","duration":"185.202µ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":"/build/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(359)"}1171{"timestamp":"2026-08-27T09:24:29.729740157Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"399dba9a-2924-4e3e-a74c-f92e3360bf54","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket12/","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(359)"}1172{"timestamp":"2026-08-27T09:24:29.757517131Z","level":"ERROR","duration":"159.541µ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":"/build/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(359)"}1173{"timestamp":"2026-08-27T09:24:29.757573692Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"1f2b9ea5-a45e-43c1-9b6f-eb0a86eb2a57","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket20/","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(359)"}1174{"timestamp":"2026-08-27T09:24:29.760461718Z","level":"ERROR","duration":"198.342µ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":"/build/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(335)"}1175{"timestamp":"2026-08-27T09:24:29.760532498Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3fb1fe56-6e1e-4ab0-8f96-230b4cf5ea62","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket28/","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(335)"}1176{"timestamp":"2026-08-27T09:24:29.784154295Z","level":"ERROR","duration":"177.982µ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":"/build/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(335)"}1177{"timestamp":"2026-08-27T09:24:29.784221595Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"73b7c2b3-b47f-4d87-94ac-1bdaeab0d49a","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket30/","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(335)"}1178--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.91s)1179=== CONT TestGCMetrics11802026/08/27 09:24:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11812026/08/27 09:24:29 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1182--- PASS: TestCompleteMultipartUnregistered (1.98s)1183=== CONT TestCacheConfigHandler1184=== RUN TestCacheConfigHandler/full_config,_no_issuer1185=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1186=== RUN TestCacheConfigHandler/no_cache_url_configured1187=== PAUSE TestCacheConfigHandler/no_cache_url_configured1188=== RUN TestCacheConfigHandler/no_signing_keys1189=== PAUSE TestCacheConfigHandler/no_signing_keys1190=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1191=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1192=== CONT TestGCBugBareHashReferences11932026/08/27 09:24:29 INFO Created nix-cache-info in bucket bucket=bucket711942026-08-27 09:24:29.924 UTC [655] ERROR: relation "goose_db_version" does not exist at character 3611952026-08-27 09:24:29.924 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1196--- PASS: TestReadProxy404 (2.03s)1197=== CONT TestService_ReadAuthMiddleware11982026/08/27 09:24:29 INFO Received uploads request method=POST path=/api/pending_closures11992026/08/27 09:24:29 INFO Received uploads request method=POST path=/api/pending_closures12002026/08/27 09:24:29 INFO Received uploads request method=POST path=/api/pending_closures1201--- PASS: TestReadProxyConditionalGet (1.67s)1202=== CONT TestClientErrorHandling1203=== RUN TestClientErrorHandling/InvalidStorePath1204=== PAUSE TestClientErrorHandling/InvalidStorePath1205=== RUN TestClientErrorHandling/InvalidAuthToken1206=== PAUSE TestClientErrorHandling/InvalidAuthToken1207=== RUN TestClientErrorHandling/ServerNotAvailable1208=== PAUSE TestClientErrorHandling/ServerNotAvailable1209=== CONT TestPinProtectsFromGC1210--- PASS: TestResurrectedObjectNotDeleted (0.63s)1211=== CONT TestClientCADerivations12122026/08/27 09:24:29 OK 20241026095416_initial_model.sql (14.24ms)12132026/08/27 09:24:29 OK 20251210153512_drop_unused_gin_index.sql (2.34ms)12142026/08/27 09:24:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1215=== NAME TestNARDeduplicationMetadataUploadBug1216 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug972158752/001/store/mr3kx7p7ah7ml4zs2ayv63anlx00i37b-file1.txt1217--- PASS: TestReadProxyInvalidPath (0.64s)1218=== CONT TestClientWithDependencies12192026/08/27 09:24:29 OK 20251218171726_add_pins.sql (5.94ms)12202026-08-27 09:24:29.958 UTC [679] ERROR: relation "goose_db_version" does not exist at character 3612212026-08-27 09:24:29.958 UTC [679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12222026/08/27 09:24:29 OK 20260628120000_add_object_size_and_stats.sql (5.03ms)12232026/08/27 09:24:29 goose: successfully migrated database to version: 2026062812000012242026/08/27 09:24:29 OK 1_commit_pending_closure.sql (3.74ms)12252026/08/27 09:24:29 OK 2_object_stats_trigger.sql (2.62ms)12262026/08/27 09:24:29 goose: up to current file version: 212272026/08/27 09:24:29 OK 20241026095416_initial_model.sql (24.49ms)12282026/08/27 09:24:29 OK 20251210153512_drop_unused_gin_index.sql (4.62ms)12292026/08/27 09:24:30 OK 20251218171726_add_pins.sql (7.6ms)12302026/08/27 09:24:30 OK 20260628120000_add_object_size_and_stats.sql (6.12ms)12312026/08/27 09:24:30 goose: successfully migrated database to version: 2026062812000012322026-08-27 09:24:30.010 UTC [700] ERROR: relation "goose_db_version" does not exist at character 3612332026-08-27 09:24:30.010 UTC [700] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12342026/08/27 09:24:30 OK 1_commit_pending_closure.sql (4ms)12352026/08/27 09:24:30 OK 2_object_stats_trigger.sql (2.28ms)12362026/08/27 09:24:30 goose: up to current file version: 212372026-08-27 09:24:30.024 UTC [701] ERROR: relation "goose_db_version" does not exist at character 3612382026-08-27 09:24:30.024 UTC [701] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12392026/08/27 09:24:30 OK 20241026095416_initial_model.sql (13.69ms)12402026/08/27 09:24:30 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)12412026/08/27 09:24:30 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12422026/08/27 09:24:30 OK 20251218171726_add_pins.sql (5.07ms)12432026/08/27 09:24:30 OK 20260628120000_add_object_size_and_stats.sql (5.26ms)12442026/08/27 09:24:30 goose: successfully migrated database to version: 2026062812000012452026/08/27 09:24:30 OK 20241026095416_initial_model.sql (12.22ms)12462026/08/27 09:24:30 OK 1_commit_pending_closure.sql (3.1ms)12472026/08/27 09:24:30 OK 20251210153512_drop_unused_gin_index.sql (2.91ms)12482026-08-27 09:24:30.049 UTC [720] ERROR: relation "goose_db_version" does not exist at character 3612492026-08-27 09:24:30.049 UTC [720] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12502026/08/27 09:24:30 OK 2_object_stats_trigger.sql (1.16ms)12512026/08/27 09:24:30 goose: up to current file version: 212522026/08/27 09:24:30 OK 20251218171726_add_pins.sql (4.88ms)12532026/08/27 09:24:30 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)12542026/08/27 09:24:30 goose: successfully migrated database to version: 2026062812000012552026/08/27 09:24:30 OK 1_commit_pending_closure.sql (4.72ms)12562026/08/27 09:24:30 OK 2_object_stats_trigger.sql (2.25ms)12572026/08/27 09:24:30 goose: up to current file version: 212582026/08/27 09:24:30 OK 20241026095416_initial_model.sql (10.71ms)12592026/08/27 09:24:30 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)12602026-08-27 09:24:30.068 UTC [721] ERROR: relation "goose_db_version" does not exist at character 3612612026-08-27 09:24:30.068 UTC [721] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12622026/08/27 09:24:30 OK 20251218171726_add_pins.sql (3.92ms)12632026/08/27 09:24:30 OK 20260628120000_add_object_size_and_stats.sql (3.24ms)12642026/08/27 09:24:30 goose: successfully migrated database to version: 2026062812000012652026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures12662026/08/27 09:24:30 OK 1_commit_pending_closure.sql (3.65ms)12672026/08/27 09:24:30 OK 2_object_stats_trigger.sql (1.36ms)12682026/08/27 09:24:30 goose: up to current file version: 212692026/08/27 09:24:30 OK 20241026095416_initial_model.sql (10.4ms)12702026/08/27 09:24:30 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)12712026/08/27 09:24:30 OK 20251218171726_add_pins.sql (3.48ms)12722026/08/27 09:24:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12732026/08/27 09:24:30 INFO Uploading mr3kx7p7ah7ml4zs2ayv63anlx00i37b-file1.txt (160B)12742026/08/27 09:24:30 OK 20260628120000_add_object_size_and_stats.sql (4.18ms)12752026/08/27 09:24:30 goose: successfully migrated database to version: 2026062812000012762026/08/27 09:24:30 OK 1_commit_pending_closure.sql (1.92ms)12772026/08/27 09:24:30 OK 2_object_stats_trigger.sql (827.15µs)12782026/08/27 09:24:30 goose: up to current file version: 21279{"timestamp":"2026-08-27T09:24:30.119067381Z","level":"ERROR","duration":"906.588µ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":"/build/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(288)"}1280{"timestamp":"2026-08-27T09:24:30.119124242Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"293735c9-0dd6-4f9b-92e2-e37d4390ade6","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket36/","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(288)"}1281{"timestamp":"2026-08-27T09:24:30.119300803Z","level":"ERROR","duration":"1.208211ms","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":"/build/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(374)"}1282{"timestamp":"2026-08-27T09:24:30.119345284Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"63d4e3a7-a35e-4528-b54f-170a670d31b0","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket33/","status_code":503,"duration_ms":1,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(374)"}1283{"timestamp":"2026-08-27T09:24:30.119500525Z","level":"ERROR","duration":"743.707µ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":"/build/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(281)"}1284{"timestamp":"2026-08-27T09:24:30.119550746Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"1007c40c-b4ab-4d0f-9a19-6d240fd6519d","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket34/","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(281)"}12852026/08/27 09:24:30 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12862026/08/27 09:24:30 WARN Failed to register uploaded object key=mr3kx7p7ah7ml4zs2ayv63anlx00i37b.ls error="server returned 404: 404 page not found\n"12872026/08/27 09:24:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12882026/08/27 09:24:30 INFO Signed narinfos id=1 count=112892026/08/27 09:24:30 INFO Uploading 1 narinfos12902026/08/27 09:24:30 WARN Failed to register uploaded object key=mr3kx7p7ah7ml4zs2ayv63anlx00i37b.narinfo error="server returned 404: 404 page not found\n"12912026/08/27 09:24:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1292{"timestamp":"2026-08-27T09:24:30.135807755Z","level":"ERROR","duration":"242.943µ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":"/build/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(244)"}1293{"timestamp":"2026-08-27T09:24:30.135888595Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"037d483c-9b23-4844-8eff-beea4c0232ba","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(244)"}12942026/08/27 09:24:30 INFO Completed upload id=112952026/08/27 09:24:30 INFO Upload complete. (137ms)1296=== NAME TestNARDeduplicationMetadataUploadBug1297 metadata_upload_test.go:54: Retrieved narinfo from S3:1298 StorePath: /build/TestNARDeduplicationMetadataUploadBug972158752/001/store/mr3kx7p7ah7ml4zs2ayv63anlx00i37b-file1.txt1299 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1300 Compression: zstd1301 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1302 NarSize: 1601303 References: 1304 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1305{"timestamp":"2026-08-27T09:24:30.141226604Z","level":"ERROR","duration":"172.304058ms","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":"/build/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(359)"}1306{"timestamp":"2026-08-27T09:24:30.141290445Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"46855b3a-6233-4879-ac23-aba2ee459ed8","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket32/","status_code":503,"duration_ms":172,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(359)"}1307 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1308 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1309 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1310{"timestamp":"2026-08-27T09:24:30.145222441Z","level":"ERROR","duration":"138.882µ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":"/build/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(359)"}1311{"timestamp":"2026-08-27T09:24:30.145268401Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b4f29295-937b-4b4a-89f1-21cd4f963d95","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket33/","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(359)"}13122026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures13132026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures13142026/08/27 09:24:30 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13152026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures1316--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.28s)1317=== CONT TestService_AuthMiddleware_OIDC13182026/08/27 09:24:30 INFO OIDC provider initialized name=test1319--- PASS: TestReadProxyRangeRequest (2.28s)1320=== CONT TestCacheStatsHandler1321--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.94s)1322=== CONT TestClientMultipleUploads1323=== NAME TestNARDeduplicationMetadataUploadBug1324 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug972158752/001/store/pjba79adxazjdpln6zrgg6bgpw4snv6p-file2.txt13252026/08/27 09:24:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13262026/08/27 09:24:30 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzU2NGUxZjYtZDQxMC00NzYzLWFjMzUtNDY1ZmMyNDliYzg2LjBjOThiYjQyLTI3NGYtNGFiMi04YWZmLTllMGMyYmFkMDQ4MHgxNzg3ODIyNjcwMTU4Mzg1NDQx13272026/08/27 09:24:30 INFO Created nix-cache-info in bucket bucket=bucket2913282026/08/27 09:24:30 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzU2NGUxZjYtZDQxMC00NzYzLWFjMzUtNDY1ZmMyNDliYzg2LjBjOThiYjQyLTI3NGYtNGFiMi04YWZmLTllMGMyYmFkMDQ4MHgxNzg3ODIyNjcwMTU4Mzg1NDQx parts=11329--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.31s)1330=== CONT TestOrphanedObjectsGCStressTest13312026/08/27 09:24:30 INFO Created nix-cache-info in bucket bucket=bucket3513322026/08/27 09:24:30 INFO Created nix-cache-info in bucket bucket=bucket371333--- PASS: TestReadProxyNarStreaming (2.27s)1334=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1335=== NAME TestClientIntegration1336 client_integration_test.go:276: Created store path: /build/TestClientIntegration2587778531/002/store/xx8h1cg1jpf2msksh1kg40b3q6cbril2-test-file.txt13372026/08/27 09:24:30 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13382026/08/27 09:24:30 INFO Created nix-cache-info in bucket bucket=bucket3613392026-08-27 09:24:30.268 UTC [875] ERROR: relation "goose_db_version" does not exist at character 3613402026-08-27 09:24:30.268 UTC [875] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13412026-08-27 09:24:30.268 UTC [876] ERROR: relation "goose_db_version" does not exist at character 3613422026-08-27 09:24:30.268 UTC [876] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13432026-08-27 09:24:30.281 UTC [878] ERROR: relation "goose_db_version" does not exist at character 3613442026-08-27 09:24:30.281 UTC [878] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1345=== NAME TestPinProtectsFromGC1346 client_integration_test.go:646: Pinned store path: /build/TestPinProtectsFromGC2242413990/001/store/bsr470v3a221r9kjmxa6wcn5sp77rfdf-pinned-file.txt1347 client_integration_test.go:647: Unpinned store path: /build/TestPinProtectsFromGC2242413990/001/store/hwq3j936m8wjb8n70xp39374rlsng4nf-unpinned-file.txt13482026/08/27 09:24:30 INFO Aborted multipart uploads count=013492026/08/27 09:24:30 WARN Force mode enabled - objects will be deleted immediately without grace period13502026/08/27 09:24:30 OK 20241026095416_initial_model.sql (17.56ms)13512026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures13522026/08/27 09:24:30 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=013532026/08/27 09:24:30 INFO Vacuumed table table=pending_closures13542026/08/27 09:24:30 INFO Vacuumed table table=pending_objects13552026/08/27 09:24:30 INFO Vacuumed table table=multipart_uploads1356=== NAME TestClientCADerivations1357 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3076933210/001/store/sv395hdwhsz5gr3n9a1hkqkjidsc0b63-ca-test13582026/08/27 09:24:30 INFO Vacuumed table table=closures13592026/08/27 09:24:30 INFO Vacuumed table table=objects13602026/08/27 09:24:30 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13612026/08/27 09:24:30 OK 20251210153512_drop_unused_gin_index.sql (8.94ms)13622026/08/27 09:24:30 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13632026/08/27 09:24:30 OK 20241026095416_initial_model.sql (13.2ms)13642026/08/27 09:24:30 OK 20241026095416_initial_model.sql (22.13ms)1365--- PASS: TestGCMetrics (0.45s)1366=== CONT TestService_AuthMiddleware_MTLSProxyHeader13672026/08/27 09:24:30 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)13682026/08/27 09:24:30 OK 20251210153512_drop_unused_gin_index.sql (2.63ms)13692026/08/27 09:24:30 OK 20251218171726_add_pins.sql (4.65ms)13702026/08/27 09:24:30 OK 20251218171726_add_pins.sql (5.27ms)13712026-08-27 09:24:30.313 UTC [966] ERROR: relation "goose_db_version" does not exist at character 3613722026-08-27 09:24:30.313 UTC [966] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13732026/08/27 09:24:30 OK 20251218171726_add_pins.sql (6.82ms)13742026/08/27 09:24:30 OK 20260628120000_add_object_size_and_stats.sql (6.19ms)13752026/08/27 09:24:30 goose: successfully migrated database to version: 2026062812000013762026/08/27 09:24:30 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1377--- PASS: TestService_ReadAuthMiddleware (0.39s)1378=== CONT TestOrphanedObjectsGC13792026/08/27 09:24:30 OK 20260628120000_add_object_size_and_stats.sql (4.81ms)13802026/08/27 09:24:30 goose: successfully migrated database to version: 2026062812000013812026-08-27 09:24:30.317 UTC [968] ERROR: relation "goose_db_version" does not exist at character 3613822026-08-27 09:24:30.317 UTC [968] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13832026/08/27 09:24:30 OK 1_commit_pending_closure.sql (3.26ms)13842026/08/27 09:24:30 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)13852026/08/27 09:24:30 goose: successfully migrated database to version: 202606281200001386--- PASS: TestReadProxyNarinfo (2.29s)1387=== CONT TestServerTLSConfig/no_client_CA1388=== CONT TestProxyWriteTimeout/narinfo1389=== CONT TestServerTLSConfig/not_a_PEM_file13902026/08/27 09:24:30 OK 1_commit_pending_closure.sql (2.65ms)13912026/08/27 09:24:30 OK 2_object_stats_trigger.sql (1.47ms)13922026/08/27 09:24:30 goose: up to current file version: 21393=== CONT TestServerTLSConfig/missing_CA_file1394=== CONT TestProxyWriteTimeout/unknown_size1395=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1396--- PASS: TestServerTLSConfig (0.00s)1397 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1398 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1399 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)14002026/08/27 09:24:30 INFO Received uploads request method=POST path=/14012026/08/27 09:24:30 WARN Failed to register uploaded object key=pjba79adxazjdpln6zrgg6bgpw4snv6p.ls error="server returned 404: 404 page not found\n"1402=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14032026/08/27 09:24:30 INFO Received request for more parts method=POST path=/1404=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14052026/08/27 09:24:30 INFO Received complete multipart upload request method=POST path=/1406=== CONT TestProxyWriteTimeout/1_GiB_nar1407=== CONT TestProxyWriteTimeout/10_GiB_nar1408--- PASS: TestProxyWriteTimeout (0.00s)1409 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1410 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1411 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1412 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1413=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14142026/08/27 09:24:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14152026/08/27 09:24:30 INFO Received uploads request method=POST path=/1416--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1417 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1418 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1419 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1420 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1421=== CONT TestIsValidUploadKey/narinfo1422=== CONT TestIsValidUploadKey/realisation_plus_in_output1423=== CONT TestIsValidUploadKey/unknown_type1424=== CONT TestIsValidUploadKey/empty_key1425=== CONT TestIsValidUploadKey/absolute1426=== CONT TestIsValidUploadKey/traversal_nar1427=== CONT TestIsValidUploadKey/traversal1428=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1429=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1430=== CONT TestIsValidUploadKey/build_log_home-manager_file1431=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1432=== CONT TestIsValidUploadKey/realisation1433=== CONT TestIsValidUploadKey/index.html1434=== CONT TestIsValidUploadKey/build_log_equals14352026/08/27 09:24:30 OK 2_object_stats_trigger.sql (2.17ms)1436=== CONT TestIsValidUploadKey/nix-cache-info14372026/08/27 09:24:30 goose: up to current file version: 21438=== CONT TestIsValidUploadKey/build_log_question_mark14392026/08/27 09:24:30 INFO Signed narinfos id=2 count=11440=== CONT TestIsValidUploadKey/build_log_plus_in_name1441=== CONT TestIsValidUploadKey/nar_plain1442=== CONT TestIsValidUploadKey/build_log1443=== CONT TestIsValidUploadKey/nar_xz1444=== CONT TestIsValidUploadKey/listing1445=== CONT TestIsValidUploadKey/nar_zst1446--- PASS: TestIsValidUploadKey (0.06s)1447 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1448 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1449 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1450 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1451 --- PASS: TestIsValidUploadKey/absolute (0.00s)1452 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1453 --- PASS: TestIsValidUploadKey/traversal (0.00s)1454 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1455 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1456 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1457 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1458 --- PASS: TestIsValidUploadKey/realisation (0.00s)1459 --- PASS: TestIsValidUploadKey/index.html (0.00s)1460 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1461 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1462 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1463 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1464 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1465 --- PASS: TestIsValidUploadKey/build_log (0.00s)1466 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1467 --- PASS: TestIsValidUploadKey/listing (0.00s)1468 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1469=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14702026/08/27 09:24:30 INFO Uploading 1 narinfos14712026/08/27 09:24:30 INFO Received uploads request method=POST path=/14722026/08/27 09:24:30 OK 1_commit_pending_closure.sql (4.99ms)14732026/08/27 09:24:30 OK 2_object_stats_trigger.sql (2.78ms)14742026/08/27 09:24:30 goose: up to current file version: 214752026/08/27 09:24:30 WARN Failed to register uploaded object key=pjba79adxazjdpln6zrgg6bgpw4snv6p.narinfo error="server returned 404: 404 page not found\n"14762026/08/27 09:24:30 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1477=== NAME TestClientCADerivations1478 client_ca_test.go:139: Found 1 dependencies (including self)14792026/08/27 09:24:30 INFO Completed upload id=214802026/08/27 09:24:30 INFO Upload complete. (117ms)14812026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures14822026/08/27 09:24:30 OK 20241026095416_initial_model.sql (10.36ms)1483=== NAME TestNARDeduplicationMetadataUploadBug1484 metadata_upload_test.go:76: Retrieved narinfo from S3:1485 StorePath: /build/TestNARDeduplicationMetadataUploadBug972158752/001/store/pjba79adxazjdpln6zrgg6bgpw4snv6p-file2.txt1486 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1487 Compression: zstd1488 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1489 NarSize: 1601490 References: 1491 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf14922026/08/27 09:24:30 OK 20251210153512_drop_unused_gin_index.sql (3.77ms)1493 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1494 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1495 {"version":1,"root":{"type":"regular","size":44}}14962026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures14972026/08/27 09:24:30 OK 20241026095416_initial_model.sql (13.13ms)1498--- PASS: TestNARDeduplicationMetadataUploadBug (2.45s)1499=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15002026/08/27 09:24:30 INFO Received request for more parts method=POST path=/15012026/08/27 09:24:30 OK 20251218171726_add_pins.sql (5.03ms)15022026/08/27 09:24:30 OK 20251210153512_drop_unused_gin_index.sql (3.75ms)15032026/08/27 09:24:30 OK 20260628120000_add_object_size_and_stats.sql (5.14ms)15042026/08/27 09:24:30 goose: successfully migrated database to version: 2026062812000015052026/08/27 09:24:30 OK 20251218171726_add_pins.sql (4.73ms)15062026/08/27 09:24:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15072026/08/27 09:24:30 INFO Uploading xx8h1cg1jpf2msksh1kg40b3q6cbril2-test-file.txt (152B)15082026/08/27 09:24:30 OK 1_commit_pending_closure.sql (4.11ms)15092026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures15102026/08/27 09:24:30 OK 20260628120000_add_object_size_and_stats.sql (4.67ms)15112026/08/27 09:24:30 goose: successfully migrated database to version: 2026062812000015122026/08/27 09:24:30 OK 2_object_stats_trigger.sql (2.84ms)15132026/08/27 09:24:30 goose: up to current file version: 215142026/08/27 09:24:30 OK 1_commit_pending_closure.sql (2.94ms)1515--- PASS: TestCacheStatsHandler (0.18s)1516=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15172026/08/27 09:24:30 INFO Received complete multipart upload request method=POST path=/15182026/08/27 09:24:30 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1519=== NAME TestClientWithDependencies1520 client_integration_test.go:593: Built derivation: /build/TestClientWithDependencies679006111/001/store/407f1a7j5rjf28zj8dbhw8sprvnyqfkm-test-script15212026/08/27 09:24:30 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15222026/08/27 09:24:30 OK 2_object_stats_trigger.sql (2.53ms)15232026/08/27 09:24:30 goose: up to current file version: 215242026/08/27 09:24:30 WARN Failed to register uploaded object key=xx8h1cg1jpf2msksh1kg40b3q6cbril2.ls error="server returned 404: 404 page not found\n"15252026/08/27 09:24:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15262026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures15272026/08/27 09:24:30 INFO Signed narinfos id=1 count=115282026/08/27 09:24:30 INFO Uploading 1 narinfos15292026/08/27 09:24:30 WARN Failed to register uploaded object key=xx8h1cg1jpf2msksh1kg40b3q6cbril2.narinfo error="server returned 404: 404 page not found\n"15302026/08/27 09:24:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15312026/08/27 09:24:30 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15322026/08/27 09:24:30 WARN mTLS auth: bound subjects configured but subject DN unavailable15332026/08/27 09:24:30 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1534--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.16s)15352026/08/27 09:24:30 INFO Completed upload id=11536=== CONT TestIsValidCachePath/narinfo1537=== CONT TestIsValidCachePath/random_path15382026/08/27 09:24:30 INFO Upload complete. (112ms)1539=== CONT TestIsValidCachePath/invalid_char_u1540=== CONT TestIsValidCachePath/invalid_char_e1541=== CONT TestIsValidCachePath/traversal_in_middle1542=== CONT TestIsValidCachePath/empty1543=== CONT TestIsValidCachePath/traversal_parent1544=== CONT TestIsValidCachePath/index.html1545=== CONT TestIsValidCachePath/nix-cache-info1546=== CONT TestIsValidCachePath/realisation1547=== CONT TestIsValidCachePath/log1548=== CONT TestIsValidCachePath/ls1549=== CONT TestIsValidCachePath/nar_uncompressed1550=== CONT TestIsValidCachePath/nar_zst1551=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1552=== CONT TestIsValidCachePath/wrong_extension1553=== CONT TestIsValidCachePath/short_hash1554=== CONT TestIsValidCachePath/leading_slash1555=== CONT TestIsValidCachePath/nar_xz1556=== CONT TestIsValidCachePath/nar_bz21557--- PASS: TestIsValidCachePath (0.00s)1558 --- PASS: TestIsValidCachePath/narinfo (0.00s)1559 --- PASS: TestIsValidCachePath/random_path (0.00s)1560 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1561 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1562 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1563 --- PASS: TestIsValidCachePath/empty (0.00s)1564 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1565 --- PASS: TestIsValidCachePath/index.html (0.00s)1566 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1567 --- PASS: TestIsValidCachePath/realisation (0.00s)1568 --- PASS: TestIsValidCachePath/log (0.00s)1569 --- PASS: TestIsValidCachePath/ls (0.00s)1570 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1571 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1572 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1573 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1574 --- PASS: TestIsValidCachePath/short_hash (0.00s)1575 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1576 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1577 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1578=== CONT TestParseSingleRange/none1579=== CONT TestParseSingleRange/end_clamped_to_size1580=== CONT TestParseSingleRange/open-ended1581=== CONT TestParseSingleRange/closed1582=== CONT TestParseSingleRange/malformed_end_before_start1583=== CONT TestParseSingleRange/malformed_both_empty1584=== CONT TestParseSingleRange/malformed_no_dash1585=== CONT TestParseSingleRange/multi-range_ignored1586=== CONT TestParseSingleRange/unknown_unit1587=== CONT TestParseSingleRange/start_past_EOF1588=== CONT TestParseSingleRange/suffix1589=== CONT TestParseSingleRange/single_byte1590=== CONT TestParseSingleRange/suffix_exceeds_size1591=== CONT TestParseSingleRange/start_far_past_EOF1592=== CONT TestCacheConfigHandler/full_config,_no_issuer1593--- PASS: TestParseSingleRange (0.00s)1594 --- PASS: TestParseSingleRange/none (0.00s)1595 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1596 --- PASS: TestParseSingleRange/open-ended (0.00s)1597 --- PASS: TestParseSingleRange/closed (0.00s)1598 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1599 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1600 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1601 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1602 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1603 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1604 --- PASS: TestParseSingleRange/suffix (0.00s)1605 --- PASS: TestParseSingleRange/single_byte (0.00s)1606 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1607 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1608=== CONT TestCacheConfigHandler/no_signing_keys1609=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1610=== NAME TestClientIntegration1611 client_integration_test.go:292: Retrieved narinfo from S3:1612 StorePath: /build/TestClientIntegration2587778531/002/store/xx8h1cg1jpf2msksh1kg40b3q6cbril2-test-file.txt1613=== CONT TestCacheConfigHandler/no_cache_url_configured1614--- PASS: TestCacheConfigHandler (0.00s)1615 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1616 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1617 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1618 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1619=== CONT TestClientErrorHandling/InvalidStorePath1620=== NAME TestClientIntegration1621 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1622 Compression: zstd1623 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11624 NarSize: 1521625 References: 1626 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11627--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.49s)1628=== CONT TestClientErrorHandling/ServerNotAvailable1629=== NAME TestClientIntegration1630 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1631 client_integration_test.go:293: Decompressed .ls content (64 bytes):1632 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1633 client_integration_test.go:296: Testing garbage collection...16342026-08-27 09:24:30.386 UTC [1080] ERROR: relation "goose_db_version" does not exist at character 3616352026-08-27 09:24:30.386 UTC [1080] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1636=== NAME TestClientWithDependencies1637 client_integration_test.go:595: Found 1 dependencies (including self)16382026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures16392026/08/27 09:24:30 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16402026-08-27 09:24:30.395 UTC [1117] ERROR: relation "goose_db_version" does not exist at character 3616412026-08-27 09:24:30.395 UTC [1117] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16422026/08/27 09:24:30 OK 20241026095416_initial_model.sql (13.07ms)16432026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures16442026/08/27 09:24:30 OK 20251210153512_drop_unused_gin_index.sql (3.39ms)16452026/08/27 09:24:30 OK 20251218171726_add_pins.sql (6.46ms)16462026/08/27 09:24:30 INFO Created nix-cache-info in bucket bucket=bucket3916472026/08/27 09:24:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16482026/08/27 09:24:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures16492026/08/27 09:24:30 INFO Uploading bsr470v3a221r9kjmxa6wcn5sp77rfdf-pinned-file.txt (128B)16502026/08/27 09:24:30 INFO Garbage collection started16512026/08/27 09:24:30 OK 20260628120000_add_object_size_and_stats.sql (5.44ms)16522026/08/27 09:24:30 goose: successfully migrated database to version: 2026062812000016532026/08/27 09:24:30 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16542026/08/27 09:24:30 OK 1_commit_pending_closure.sql (6.18ms)16552026/08/27 09:24:30 OK 20241026095416_initial_model.sql (25.94ms)16562026/08/27 09:24:30 INFO Aborted multipart uploads count=016572026/08/27 09:24:30 OK 2_object_stats_trigger.sql (2.78ms)16582026/08/27 09:24:30 goose: up to current file version: 216592026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures16602026/08/27 09:24:30 WARN Failed to register uploaded object key=bsr470v3a221r9kjmxa6wcn5sp77rfdf.ls error="server returned 404: 404 page not found\n"16612026/08/27 09:24:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16622026/08/27 09:24:30 INFO Signed narinfos id=1 count=116632026/08/27 09:24:30 INFO Uploading 1 narinfos16642026/08/27 09:24:30 OK 20251210153512_drop_unused_gin_index.sql (3.44ms)1665=== CONT TestClientErrorHandling/InvalidAuthToken16662026/08/27 09:24:30 WARN Force mode enabled - objects will be deleted immediately without grace period16672026/08/27 09:24:30 WARN Failed to register uploaded object key=bsr470v3a221r9kjmxa6wcn5sp77rfdf.narinfo error="server returned 404: 404 page not found\n"16682026/08/27 09:24:30 OK 20251218171726_add_pins.sql (3.85ms)16692026/08/27 09:24:30 INFO Received cleanup request method=DELETE path=/api/pending_closures16702026/08/27 09:24:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16712026/08/27 09:24:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16722026/08/27 09:24:30 INFO Uploading sv395hdwhsz5gr3n9a1hkqkjidsc0b63-ca-test (144B)16732026/08/27 09:24:30 WARN Failed to register uploaded object key=log/q60099bqgj60vycaqjw3m06h72jgs7yc-ca-test.drv error="server returned 404: 404 page not found\n"16742026/08/27 09:24:30 INFO Aborted multipart uploads count=016752026/08/27 09:24:30 OK 20260628120000_add_object_size_and_stats.sql (6.35ms)16762026/08/27 09:24:30 goose: successfully migrated database to version: 2026062812000016772026/08/27 09:24:30 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16782026/08/27 09:24:30 INFO Completed upload id=116792026/08/27 09:24:30 INFO Upload complete. (126ms)1680--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.14s)16812026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures16822026/08/27 09:24:30 WARN Failed to register uploaded object key=sv395hdwhsz5gr3n9a1hkqkjidsc0b63.ls error="server returned 404: 404 page not found\n"16832026/08/27 09:24:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16842026/08/27 09:24:30 INFO Signed narinfos id=1 count=116852026/08/27 09:24:30 INFO Uploading 1 narinfos16862026/08/27 09:24:30 OK 1_commit_pending_closure.sql (4.18ms)16872026-08-27 09:24:30.450 UTC [1210] ERROR: relation "goose_db_version" does not exist at character 3616882026-08-27 09:24:30.450 UTC [1210] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16892026/08/27 09:24:30 OK 2_object_stats_trigger.sql (2.4ms)16902026/08/27 09:24:30 goose: up to current file version: 216912026/08/27 09:24:30 WARN Failed to register uploaded object key=sv395hdwhsz5gr3n9a1hkqkjidsc0b63.narinfo error="server returned 404: 404 page not found\n"16922026/08/27 09:24:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16932026/08/27 09:24:30 INFO Completed upload id=116942026/08/27 09:24:30 INFO Upload complete. (96ms)1695=== NAME TestClientMultipleUploads1696 client_integration_test.go:338: Created store path 0: /build/TestClientMultipleUploads2505680041/001/store/4giypp0r18bngl026kx4i185fa32qx99-test-file-0.txt16972026/08/27 09:24:30 INFO Received cleanup request method=DELETE path=/api/pending_closures16982026/08/27 09:24:30 INFO Aborted multipart uploads count=11699=== NAME TestClientCADerivations1700 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3076933210/001/store/sv395hdwhsz5gr3n9a1hkqkjidsc0b63-ca-test1701 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1702 Compression: zstd1703 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1704 NarSize: 1441705 References: 1706 Deriver: /build/TestClientCADerivations3076933210/001/store/q60099bqgj60vycaqjw3m06h72jgs7yc-ca-test.drv1707 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1708 client_ca_test.go:185: Checking for realisation files in S3...1709 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1710 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17112026/08/27 09:24:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17122026/08/27 09:24:30 OK 20241026095416_initial_model.sql (11.92ms)17132026-08-27 09:24:30.468 UTC [616] ERROR: Closure does not exist: id=117142026-08-27 09:24:30.468 UTC [616] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE17152026-08-27 09:24:30.468 UTC [616] STATEMENT: -- name: CommitPendingClosure :exec1716 SELECT commit_pending_closure($1::bigint)1717 1718--- PASS: TestService_cleanupPendingClosuresHandler (2.58s)17192026/08/27 09:24:30 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17202026/08/27 09:24:30 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)17212026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures17222026/08/27 09:24:30 OK 20251218171726_add_pins.sql (11.76ms)17232026/08/27 09:24:30 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-config1724--- PASS: TestReadProxyDisabled (2.53s)17252026/08/27 09:24:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17262026/08/27 09:24:30 INFO Uploading 407f1a7j5rjf28zj8dbhw8sprvnyqfkm-test-script (136B)17272026/08/27 09:24:30 OK 20260628120000_add_object_size_and_stats.sql (5.33ms)17282026/08/27 09:24:30 goose: successfully migrated database to version: 2026062812000017292026/08/27 09:24:30 WARN Failed to register uploaded object key=log/nva2zdnfkb17m32w3m18yy8ia7dk8ad3-test-script.drv error="server returned 404: 404 page not found\n"17302026/08/27 09:24:30 OK 1_commit_pending_closure.sql (4.29ms)17312026/08/27 09:24:30 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17322026/08/27 09:24:30 OK 2_object_stats_trigger.sql (2.39ms)17332026/08/27 09:24:30 goose: up to current file version: 217342026/08/27 09:24:30 WARN Failed to register uploaded object key=407f1a7j5rjf28zj8dbhw8sprvnyqfkm.ls error="server returned 404: 404 page not found\n"17352026/08/27 09:24:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17362026/08/27 09:24:30 INFO Signed narinfos id=1 count=117372026/08/27 09:24:30 INFO Uploading 1 narinfos1738=== NAME TestClientMultipleUploads1739 client_integration_test.go:338: Created store path 1: /build/TestClientMultipleUploads2505680041/001/store/vxp0sms5y4yg8g9k351v481pnlb0k92v-test-file-1.txt17402026/08/27 09:24:30 WARN Failed to register uploaded object key=407f1a7j5rjf28zj8dbhw8sprvnyqfkm.narinfo error="server returned 404: 404 page not found\n"17412026/08/27 09:24:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1742=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1743=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1744=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1745=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1746=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1747=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1748=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1749=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1750=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1751=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1752=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1753=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured17542026/08/27 09:24:30 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]17552026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures17562026/08/27 09:24:30 INFO Completed upload id=117572026/08/27 09:24:30 INFO Upload complete. (73ms)17582026-08-27 09:24:30.509 UTC [1335] ERROR: relation "goose_db_version" does not exist at character 3617592026-08-27 09:24:30.509 UTC [1335] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17602026/08/27 09:24:30 WARN Authentication failed token_preview=eyJhbGciOi...i7coOphmMg 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]17612026/08/27 09:24:30 INFO OIDC auth successful provider=test1762--- PASS: TestService_AuthMiddleware_OIDC (0.34s)1763 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1764 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1765 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)1766 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)1767=== NAME TestClientWithDependencies1768 client_integration_test.go:597: Skipping nix copy test - isolated store (/build/TestClientWithDependencies679006111/001/store) requires matching store prefix1769--- PASS: TestGCBugBareHashReferences (0.65s)1770--- PASS: TestClientWithDependencies (0.56s)17712026/08/27 09:24:30 INFO Received cleanup request method=DELETE path=/api/pending_closures17722026/08/27 09:24:30 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17732026/08/27 09:24:30 INFO Aborted multipart uploads count=117742026/08/27 09:24:30 OK 20241026095416_initial_model.sql (10.75ms)17752026/08/27 09:24:30 OK 20251210153512_drop_unused_gin_index.sql (1.3ms)17762026/08/27 09:24:30 OK 20251218171726_add_pins.sql (7.14ms)1777--- PASS: TestMultipartCleanup (2.65s)17782026/08/27 09:24:30 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)17792026/08/27 09:24:30 goose: successfully migrated database to version: 2026062812000017802026/08/27 09:24:30 OK 1_commit_pending_closure.sql (1.72ms)17812026/08/27 09:24:30 OK 2_object_stats_trigger.sql (844.13µs)17822026/08/27 09:24:30 goose: up to current file version: 21783=== NAME TestClientMultipleUploads1784 client_integration_test.go:338: Created store path 2: /build/TestClientMultipleUploads2505680041/001/store/if88aa4grid5p641z0is2b85030p5gml-test-file-2.txt17852026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures17862026/08/27 09:24:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17872026/08/27 09:24:30 INFO Uploading hwq3j936m8wjb8n70xp39374rlsng4nf-unpinned-file.txt (128B)17882026/08/27 09:24:30 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17892026/08/27 09:24:30 WARN Failed to register uploaded object key=hwq3j936m8wjb8n70xp39374rlsng4nf.ls error="server returned 404: 404 page not found\n"17902026/08/27 09:24:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17912026/08/27 09:24:30 INFO Signed narinfos id=2 count=117922026/08/27 09:24:30 INFO Uploading 1 narinfos17932026/08/27 09:24:30 WARN Failed to register uploaded object key=hwq3j936m8wjb8n70xp39374rlsng4nf.narinfo error="server returned 404: 404 page not found\n"17942026/08/27 09:24:30 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17952026/08/27 09:24:30 INFO Completed upload id=217962026/08/27 09:24:30 INFO Upload complete. (92ms)17972026/08/27 09:24:30 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.742798ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17982026/08/27 09:24:30 INFO Received create pin request method=POST path=/api/pins/myapp17992026/08/27 09:24:30 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2242413990/001/store/bsr470v3a221r9kjmxa6wcn5sp77rfdf-pinned-file.txt narinfo_key=bsr470v3a221r9kjmxa6wcn5sp77rfdf.narinfo18002026/08/27 09:24:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures18012026/08/27 09:24:30 INFO Garbage collection started18022026/08/27 09:24:30 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18032026/08/27 09:24:30 INFO Aborted multipart uploads count=018042026/08/27 09:24:30 WARN Force mode enabled - objects will be deleted immediately without grace period1805=== NAME TestClientCADerivations1806 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1807 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1808 error: binary cache 's3://bucket37?endpoint=http://localhost:38417&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3076933210/001/store'1809 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11810--- PASS: TestClientCADerivations (0.71s)18112026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures18122026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures18132026/08/27 09:24:30 INFO Received uploads request method=POST path=/api/pending_closures18142026/08/27 09:24:30 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18152026/08/27 09:24:30 INFO Uploading 4giypp0r18bngl026kx4i185fa32qx99-test-file-0.txt (160B)18162026/08/27 09:24:30 INFO Uploading if88aa4grid5p641z0is2b85030p5gml-test-file-2.txt (160B)18172026/08/27 09:24:30 INFO Uploading vxp0sms5y4yg8g9k351v481pnlb0k92v-test-file-1.txt (160B)18182026/08/27 09:24:30 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18192026/08/27 09:24:30 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18202026/08/27 09:24:30 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18212026/08/27 09:24:30 WARN Failed to register uploaded object key=if88aa4grid5p641z0is2b85030p5gml.ls error="server returned 404: 404 page not found\n"18222026/08/27 09:24:30 WARN Failed to register uploaded object key=vxp0sms5y4yg8g9k351v481pnlb0k92v.ls error="server returned 404: 404 page not found\n"18232026/08/27 09:24:30 WARN Failed to register uploaded object key=4giypp0r18bngl026kx4i185fa32qx99.ls error="server returned 404: 404 page not found\n"18242026/08/27 09:24:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18252026/08/27 09:24:30 INFO Signed narinfos id=2 count=118262026/08/27 09:24:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign18272026/08/27 09:24:30 INFO Signed narinfos id=3 count=118282026/08/27 09:24:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18292026/08/27 09:24:30 INFO Signed narinfos id=1 count=118302026/08/27 09:24:30 INFO Uploading 3 narinfos18312026/08/27 09:24:30 WARN Failed to register uploaded object key=vxp0sms5y4yg8g9k351v481pnlb0k92v.narinfo error="server returned 404: 404 page not found\n"18322026/08/27 09:24:30 WARN Failed to register uploaded object key=if88aa4grid5p641z0is2b85030p5gml.narinfo error="server returned 404: 404 page not found\n"18332026/08/27 09:24:30 WARN Failed to register uploaded object key=4giypp0r18bngl026kx4i185fa32qx99.narinfo error="server returned 404: 404 page not found\n"18342026/08/27 09:24:30 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18352026/08/27 09:24:30 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18362026/08/27 09:24:30 INFO Completed upload id=218372026/08/27 09:24:30 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete18382026/08/27 09:24:30 INFO Completed upload id=318392026/08/27 09:24:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18402026/08/27 09:24:30 INFO Completed upload id=118412026/08/27 09:24:30 INFO Upload complete. (108ms)1842=== NAME TestClientMultipleUploads1843 client_integration_test.go:349: Uploaded 3 paths in 144.754585ms1844--- PASS: TestClientMultipleUploads (0.52s)18452026/08/27 09:24:30 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18462026/08/27 09:24:30 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=429.449962ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18472026/08/27 09:24:31 WARN mTLS auth: subject not in bound subjects subject="CN=reader"18482026/08/27 09:24:31 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1849--- PASS: TestService_NativeMTLS (3.12s)1850=== NAME TestOrphanedObjectsGC1851 orphaned_objects_gc_test.go:290: GC Test Summary:1852 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1853 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1854 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1855 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1856 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1857--- PASS: TestOrphanedObjectsGC (0.80s)18582026/08/27 09:24:31 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=862.847514ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1859--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)1860 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.09s)1861 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.12s)1862 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.31s)18632026/08/27 09:24:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18642026/08/27 09:24:31 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=018652026/08/27 09:24:31 INFO Vacuumed table table=pending_closures18662026/08/27 09:24:31 INFO Vacuumed table table=pending_objects18672026/08/27 09:24:31 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MzU2NGUxZjYtZDQxMC00NzYzLWFjMzUtNDY1ZmMyNDliYzg2LmQ5ZWUzODUxLWU4MDItNGMyNS05MDU0LThkMTc5NDcwYjc5M3gxNzg3ODIyNjY5MzE3Mjc3NTQw parts=1018682026/08/27 09:24:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18692026/08/27 09:24:31 INFO Vacuumed table table=multipart_uploads18702026/08/27 09:24:31 INFO Completed upload id=118712026/08/27 09:24:31 INFO Received uploads request method=POST path=/api/pending_closures18722026/08/27 09:24:31 INFO Vacuumed table table=closures18732026/08/27 09:24:31 INFO Received uploads request method=POST path=/api/pending_closures18742026/08/27 09:24:31 INFO Vacuumed table table=objects18752026/08/27 09:24:31 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo18762026/08/27 09:24:31 WARN Found objects in DB but missing from S3, will re-upload count=11877--- PASS: TestService_verifyS3Integrity (3.82s)18782026/08/27 09:24:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18792026/08/27 09:24:31 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MzU2NGUxZjYtZDQxMC00NzYzLWFjMzUtNDY1ZmMyNDliYzg2LjFiZGE0ZTE4LWJmZDMtNDk0Yy04NjE4LTNkMDRlZjk0NWY2M3gxNzg3ODIyNjcwMzQzMjM5OTU0 parts=121880--- PASS: TestRedundantMultipartUpload (3.94s)18812026/08/27 09:24:31 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=018822026/08/27 09:24:31 INFO Vacuumed table table=pending_closures18832026/08/27 09:24:31 INFO Vacuumed table table=pending_objects18842026/08/27 09:24:31 INFO Vacuumed table table=multipart_uploads18852026/08/27 09:24:31 INFO Vacuumed table table=closures18862026/08/27 09:24:31 INFO Vacuumed table table=objects18872026/08/27 09:24:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18882026/08/27 09:24:31 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MzU2NGUxZjYtZDQxMC00NzYzLWFjMzUtNDY1ZmMyNDliYzg2LjQzNDFhMDUyLWJlZTItNDIwNy1iOGIwLWNiNDkwNjY2NWI0NXgxNzg3ODIyNjcwNTE2NjU3MDIy parts=1218892026/08/27 09:24:31 INFO Received uploads request method=POST path=/api/pending_closures1890--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.07s)18912026/08/27 09:24:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18922026/08/27 09:24:32 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MzU2NGUxZjYtZDQxMC00NzYzLWFjMzUtNDY1ZmMyNDliYzg2LmNlY2U2ZWU5LTcyMjktNGVkMC05NTQ0LTY4N2UyMTY1NGQ0MHgxNzg3ODIyNjY5OTM5MTIxNjc0 parts=1018932026/08/27 09:24:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18942026/08/27 09:24:32 INFO Completed upload id=118952026/08/27 09:24:32 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000018962026/08/27 09:24:32 INFO Received uploads request method=POST path=/api/pending_closures18972026/08/27 09:24:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures18982026/08/27 09:24:32 INFO Aborted multipart uploads count=018992026/08/27 09:24:32 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=019002026/08/27 09:24:32 INFO Vacuumed table table=pending_closures19012026/08/27 09:24:32 INFO Vacuumed table table=pending_objects19022026/08/27 09:24:32 INFO Vacuumed table table=multipart_uploads19032026/08/27 09:24:32 INFO Vacuumed table table=closures19042026/08/27 09:24:32 INFO Vacuumed table table=objects19052026/08/27 09:24:32 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001906--- PASS: TestService_createPendingClosureHandler (4.19s)19072026/08/27 09:24:32 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.694950322s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1908=== NAME TestOrphanedObjectsGCStressTest1909 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1910 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19112026/08/27 09:24:32 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01912=== NAME TestClientIntegration1913 client_integration_test.go:303: Objects in database after GC:1914 client_integration_test.go:303: Successfully deleted all objects with GC --force1915--- PASS: TestClientIntegration (3.15s)1916=== NAME TestOrphanedObjectsGCStressTest1917 orphaned_objects_gc_test.go:509: Stress test completed successfully:1918 orphaned_objects_gc_test.go:510: - Active objects preserved: 201919 orphaned_objects_gc_test.go:511: - Objects deleted: 2101920 orphaned_objects_gc_test.go:512: - Total GC'd: 2101921--- PASS: TestOrphanedObjectsGCStressTest (2.29s)19222026/08/27 09:24:32 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01923=== NAME TestPinProtectsFromGC1924 client_integration_test.go:709: Pin successfully protected closure from garbage collection1925--- PASS: TestPinProtectsFromGC (2.69s)19262026/08/27 09:24:33 WARN Rate limiter enabled after throttle name=s3-test rate=519272026/08/27 09:24:33 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1928=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1929 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101930 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001931--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.71s)19322026/08/27 09:24:33 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"19332026/08/27 09:24:33 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_closures19342026/08/27 09:24:33 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.4455ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19352026/08/27 09:24:34 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=384.748838ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19362026/08/27 09:24:34 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=757.1179ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19372026/08/27 09:24:35 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.470772843s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1938--- PASS: TestClientErrorHandling (0.00s)1939 --- PASS: TestClientErrorHandling/InvalidStorePath (0.18s)1940 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.29s)1941 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.34s)1942PASS19432026-08-27 09:24:37.030 UTC [112] LOG: received smart shutdown request19442026-08-27 09:24:37.036 UTC [112] LOG: background worker "logical replication launcher" (PID 122) exited with exit code 119452026-08-27 09:24:37.048 UTC [117] LOG: shutting down19462026-08-27 09:24:37.048 UTC [117] LOG: checkpoint starting: shutdown immediate19472026-08-27 09:24:38.092 UTC [117] LOG: checkpoint complete: wrote 11708 buffers (71.5%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 13 recycled; write=0.221 s, sync=0.814 s, total=1.045 s; sync files=15167, longest=0.002 s, average=0.001 s; distance=208929 kB, estimate=208929 kB; lsn=0/E36C220, redo lsn=0/E36C22019482026-08-27 09:24:38.186 UTC [112] LOG: database system is shut down1949Running OIDC tests...1950=== RUN TestGlobMatch1951=== PAUSE TestGlobMatch1952=== RUN TestAudienceForIssuer1953=== PAUSE TestAudienceForIssuer1954=== RUN TestValidateToken_ValidToken1955=== PAUSE TestValidateToken_ValidToken1956=== RUN TestValidateToken_WrongAudience1957=== PAUSE TestValidateToken_WrongAudience1958=== RUN TestValidateToken_Expired1959=== PAUSE TestValidateToken_Expired1960=== RUN TestValidateToken_BoundClaimsMismatch1961=== PAUSE TestValidateToken_BoundClaimsMismatch1962=== RUN TestValidateToken_BoundSubjectMismatch1963=== PAUSE TestValidateToken_BoundSubjectMismatch1964=== RUN TestValidateToken_MultipleProviders1965=== PAUSE TestValidateToken_MultipleProviders1966=== RUN TestValidateToken_NoMatchingProvider1967=== PAUSE TestValidateToken_NoMatchingProvider1968=== CONT TestGlobMatch1969=== CONT TestValidateToken_MultipleProviders1970=== CONT TestValidateToken_BoundClaimsMismatch1971=== CONT TestValidateToken_WrongAudience1972=== RUN TestGlobMatch/foo_foo1973=== PAUSE TestGlobMatch/foo_foo1974=== RUN TestGlobMatch/foo_bar1975=== PAUSE TestGlobMatch/foo_bar1976=== RUN TestGlobMatch/*_1977=== PAUSE TestGlobMatch/*_1978=== RUN TestGlobMatch/*_anything1979=== PAUSE TestGlobMatch/*_anything1980=== RUN TestGlobMatch/foo*_foo1981=== PAUSE TestGlobMatch/foo*_foo1982=== CONT TestValidateToken_ValidToken1983=== CONT TestAudienceForIssuer1984=== CONT TestValidateToken_Expired1985=== CONT TestValidateToken_NoMatchingProvider1986=== CONT TestValidateToken_BoundSubjectMismatch1987=== RUN TestGlobMatch/foo*_foobar1988=== PAUSE TestGlobMatch/foo*_foobar1989=== RUN TestGlobMatch/foo*_bar1990=== PAUSE TestGlobMatch/foo*_bar1991=== RUN TestGlobMatch/*bar_bar1992=== PAUSE TestGlobMatch/*bar_bar1993=== RUN TestGlobMatch/*bar_foobar1994=== PAUSE TestGlobMatch/*bar_foobar1995=== RUN TestGlobMatch/*bar_foo1996=== PAUSE TestGlobMatch/*bar_foo1997=== RUN TestGlobMatch/foo*bar_foobar1998=== PAUSE TestGlobMatch/foo*bar_foobar1999=== RUN TestGlobMatch/foo*bar_foo123bar2000=== PAUSE TestGlobMatch/foo*bar_foo123bar2001=== RUN TestGlobMatch/foo*bar_foobarbaz2002=== PAUSE TestGlobMatch/foo*bar_foobarbaz2003=== RUN TestGlobMatch/*/*_foo/bar2004=== PAUSE TestGlobMatch/*/*_foo/bar2005=== RUN TestGlobMatch/*/*_foo2006--- PASS: TestAudienceForIssuer (0.00s)2007=== PAUSE TestGlobMatch/*/*_foo2008=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2009=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2010=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02011=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02012=== RUN TestGlobMatch/refs/*/main_refs/heads/main2013=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2014=== RUN TestGlobMatch/fo?_foo2015=== PAUSE TestGlobMatch/fo?_foo2016=== RUN TestGlobMatch/fo?_fo2017=== PAUSE TestGlobMatch/fo?_fo2018=== RUN TestGlobMatch/fo?_fooo2019=== PAUSE TestGlobMatch/fo?_fooo2020=== RUN TestGlobMatch/?oo_foo2021=== PAUSE TestGlobMatch/?oo_foo2022=== RUN TestGlobMatch/?oo_boo2023=== PAUSE TestGlobMatch/?oo_boo2024=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2025=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2026=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2027=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2028=== CONT TestGlobMatch/foo_foo2029=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2030=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2031=== CONT TestGlobMatch/foo*bar_foo123bar2032=== CONT TestGlobMatch/foo*bar_foobar2033=== CONT TestGlobMatch/*bar_foo2034=== CONT TestGlobMatch/foo*_foo2035=== CONT TestGlobMatch/foo*_foobar2036=== CONT TestGlobMatch/*_anything2037=== CONT TestGlobMatch/*_2038=== CONT TestGlobMatch/foo*bar_foobarbaz2039=== CONT TestGlobMatch/foo_bar2040=== CONT TestGlobMatch/fo?_foo2041=== CONT TestGlobMatch/?oo_boo2042=== CONT TestGlobMatch/?oo_foo2043=== CONT TestGlobMatch/fo?_fooo2044=== CONT TestGlobMatch/fo?_fo2045=== CONT TestGlobMatch/*bar_bar2046=== CONT TestGlobMatch/*bar_foobar2047=== CONT TestGlobMatch/foo*_bar2048=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2049=== CONT TestGlobMatch/refs/*/main_refs/heads/main2050=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02051=== CONT TestGlobMatch/*/*_foo2052=== CONT TestGlobMatch/*/*_foo/bar2053--- PASS: TestGlobMatch (0.00s)2054 --- PASS: TestGlobMatch/foo_foo (0.00s)2055 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2056 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2057 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2058 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2059 --- PASS: TestGlobMatch/*bar_foo (0.00s)2060 --- PASS: TestGlobMatch/foo*_foo (0.00s)2061 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2062 --- PASS: TestGlobMatch/*_anything (0.00s)2063 --- PASS: TestGlobMatch/*_ (0.00s)2064 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2065 --- PASS: TestGlobMatch/foo_bar (0.00s)2066 --- PASS: TestGlobMatch/fo?_foo (0.00s)2067 --- PASS: TestGlobMatch/?oo_boo (0.00s)2068 --- PASS: TestGlobMatch/?oo_foo (0.00s)2069 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2070 --- PASS: TestGlobMatch/fo?_fo (0.00s)2071 --- PASS: TestGlobMatch/*bar_bar (0.00s)2072 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2073 --- PASS: TestGlobMatch/foo*_bar (0.00s)2074 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2075 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2076 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2077 --- PASS: TestGlobMatch/*/*_foo (0.00s)2078 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)20792026/08/27 09:24:39 INFO OIDC provider initialized name=test20802026/08/27 09:24:39 INFO OIDC provider initialized name=test20812026/08/27 09:24:39 INFO OIDC provider initialized name=test20822026/08/27 09:24:39 INFO OIDC provider initialized name=test20832026/08/27 09:24:39 INFO OIDC provider initialized name=provider120842026/08/27 09:24:39 INFO OIDC provider initialized name=provider120852026/08/27 09:24:39 INFO OIDC provider initialized name=test20862026/08/27 09:24:39 INFO OIDC provider initialized name=provider22087--- PASS: TestValidateToken_Expired (0.01s)2088--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2089--- PASS: TestValidateToken_WrongAudience (0.01s)2090--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2091--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2092--- PASS: TestValidateToken_ValidToken (0.01s)2093--- PASS: TestValidateToken_MultipleProviders (0.01s)2094PASS2095Running hook tests...2096=== RUN TestSendPathsEmpty2097=== PAUSE TestSendPathsEmpty2098=== RUN TestQueueEnqueueAndFetch2099=== PAUSE TestQueueEnqueueAndFetch2100=== RUN TestQueueDeduplication2101=== PAUSE TestQueueDeduplication2102=== RUN TestQueueRemove2103=== PAUSE TestQueueRemove2104=== RUN TestQueueFetchBatchLimit2105=== PAUSE TestQueueFetchBatchLimit2106=== RUN TestQueueRetryMovesToBack2107=== PAUSE TestQueueRetryMovesToBack2108=== RUN TestQueueFetchRemoveLifecycle2109=== PAUSE TestQueueFetchRemoveLifecycle2110=== RUN TestQueueConcurrentWriters2111=== PAUSE TestQueueConcurrentWriters2112=== RUN TestServerClientIntegration2113=== PAUSE TestServerClientIntegration2114=== RUN TestServerQueueError2115=== PAUSE TestServerQueueError2116=== RUN TestGetListenerSocketActivation2117 server_test.go:210: === RUN TestGetListenerSocketActivation2118 --- PASS: TestGetListenerSocketActivation (0.00s)2119 PASS2120 2121--- PASS: TestGetListenerSocketActivation (0.01s)2122=== RUN TestDrainIsolatesPoisonPath2123=== PAUSE TestDrainIsolatesPoisonPath2124=== RUN TestRunNotBlockedByPoisonHead2125=== PAUSE TestRunNotBlockedByPoisonHead2126=== RUN TestDrainGivesUpWhenServerDown2127=== PAUSE TestDrainGivesUpWhenServerDown2128=== RUN TestFailedPathPrunedByLaterClosure2129=== PAUSE TestFailedPathPrunedByLaterClosure2130=== RUN TestWorkerUploadsAndRemoves2131=== PAUSE TestWorkerUploadsAndRemoves2132=== RUN TestWorkerSkipsGCdPaths2133=== PAUSE TestWorkerSkipsGCdPaths2134=== RUN TestWorkerPrunesClosureDeps2135=== PAUSE TestWorkerPrunesClosureDeps2136=== CONT TestSendPathsEmpty2137=== CONT TestWorkerPrunesClosureDeps2138=== CONT TestQueueDeduplication2139=== CONT TestWorkerUploadsAndRemoves2140=== CONT TestQueueConcurrentWriters2141=== CONT TestFailedPathPrunedByLaterClosure2142--- PASS: TestSendPathsEmpty (0.00s)2143=== CONT TestDrainGivesUpWhenServerDown2144=== CONT TestQueueFetchRemoveLifecycle2145=== CONT TestRunNotBlockedByPoisonHead2146=== CONT TestQueueRetryMovesToBack2147=== CONT TestDrainIsolatesPoisonPath2148=== CONT TestQueueFetchBatchLimit2149=== CONT TestServerQueueError2150=== CONT TestQueueRemove2151=== CONT TestServerClientIntegration2152=== CONT TestQueueEnqueueAndFetch2153=== CONT TestWorkerSkipsGCdPaths21542026/08/27 09:24:39 ERROR Failed to queue paths error="permission denied" count=12155--- PASS: TestServerClientIntegration (0.00s)2156--- PASS: TestServerQueueError (0.00s)21572026/08/27 09:24:39 INFO Uploading batch count=121582026/08/27 09:24:39 ERROR Upload failed error="upload failed" count=121592026/08/27 09:24:39 INFO Uploading batch count=421602026/08/27 09:24:39 ERROR Upload failed error="upload failed" count=421612026/08/27 09:24:39 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath554671632/002/bbb21622026/08/27 09:24:39 INFO Upload queue status pending=221632026/08/27 09:24:39 INFO Uploading batch count=12164--- PASS: TestQueueDeduplication (0.02s)21652026/08/27 09:24:39 INFO Uploading batch count=221662026/08/27 09:24:39 ERROR Upload failed error="upload failed" count=221672026/08/27 09:24:39 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2143981723/002/a2168--- PASS: TestQueueEnqueueAndFetch (0.02s)21692026/08/27 09:24:39 INFO Uploading batch count=121702026/08/27 09:24:39 INFO Upload queue status pending=32171--- PASS: TestQueueFetchBatchLimit (0.02s)2172--- PASS: TestQueueRetryMovesToBack (0.02s)2173--- PASS: TestQueueRemove (0.02s)21742026/08/27 09:24:39 INFO Uploading batch count=121752026/08/27 09:24:39 ERROR Upload failed error="upload failed" count=12176--- PASS: TestQueueFetchRemoveLifecycle (0.02s)21772026/08/27 09:24:39 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2143981723/002/b21782026/08/27 09:24:39 INFO Uploading batch count=121792026/08/27 09:24:39 INFO Uploading batch count=221802026/08/27 09:24:39 ERROR Upload failed error="upload failed" count=221812026/08/27 09:24:39 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2143981723/002/c21822026/08/27 09:24:39 INFO Upload queue status pending=221832026/08/27 09:24:39 INFO Upload queue status pending=221842026/08/27 09:24:39 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2143981723/002/d21852026/08/27 09:24:39 INFO Uploading batch count=121862026/08/27 09:24:39 ERROR Upload failed error="upload failed" count=121872026/08/27 09:24:39 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3299966011/002/nonexistent21882026/08/27 09:24:39 INFO Uploading batch count=221892026/08/27 09:24:39 INFO Uploading batch count=221902026/08/27 09:24:39 ERROR Upload failed error="upload failed" count=221912026/08/27 09:24:39 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2143981723/002/e21922026/08/27 09:24:39 INFO Uploading batch count=12193--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)21942026/08/27 09:24:39 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2143981723/002/f21952026/08/27 09:24:39 INFO Uploading batch count=121962026/08/27 09:24:39 ERROR Upload failed error="upload failed" count=121972026/08/27 09:24:39 ERROR Drain finished with paths left in queue remaining=1021982026/08/27 09:24:39 INFO Uploading batch count=121992026/08/27 09:24:39 ERROR Upload failed error="upload failed" count=122002026/08/27 09:24:39 ERROR Drain finished with paths left in queue remaining=12201--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2202--- PASS: TestDrainIsolatesPoisonPath (0.03s)2203--- PASS: TestWorkerPrunesClosureDeps (0.04s)2204--- PASS: TestWorkerSkipsGCdPaths (0.04s)2205--- PASS: TestWorkerUploadsAndRemoves (0.05s)2206--- PASS: TestQueueConcurrentWriters (0.22s)22072026/08/27 09:24:40 INFO Uploading batch count=122082026/08/27 09:24:40 INFO Uploading batch count=122092026/08/27 09:24:40 INFO Uploading batch count=122102026/08/27 09:24:40 ERROR Upload failed error="upload failed" count=122112026/08/27 09:24:40 INFO Uploading batch count=122122026/08/27 09:24:40 ERROR Upload failed error="upload failed" count=122132026/08/27 09:24:40 INFO Uploading batch count=122142026/08/27 09:24:40 ERROR Upload failed error="upload failed" count=122152026/08/27 09:24:40 INFO Uploading batch count=122162026/08/27 09:24:40 ERROR Upload failed error="upload failed" count=122172026/08/27 09:24:40 ERROR Drain finished with paths left in queue remaining=12218--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2219PASS