Publicar usando la API muestra advertencia de error

Siempre que se publican mensajes a través de la API, aparece la siguiente advertencia de error en el registro:

DistributedMutex(“memoize_lock_post##2f7d40f44a4b0fa66a711ca8f2ff9278fed9fa72”): retenido durante demasiado tiempo, máximo esperado: 1 seg, tardó 1 seg adicional

activesupport-8.0.5/lib/active_support/broadcast_logger.rb:218:in ‘block in ActiveSupport::BroadcastLogger#dispatch’

activesupport-8.0.5/lib/active_support/broadcast_logger.rb:217:in ‘Array#map’

activesupport-8.0.5/lib/active_support/broadcast_logger.rb:217:in ‘ActiveSupport::BroadcastLogger#dispatch’

activesupport-8.0.5/lib/active_support/broadcast_logger.rb:129:in ‘ActiveSupport::BroadcastLogger#warn’

/var/www/discourse/lib/distributed_mutex.rb:103:in ‘DistributedMutex#warn’

/var/www/discourse/lib/distributed_mutex.rb:57:in ‘block in DistributedMutex#synchronize’

/var/www/discourse/lib/distributed_mutex.rb:49:in ‘Thread::Mutex#synchronize’

/var/www/discourse/lib/distributed_mutex.rb:49:in ‘DistributedMutex#synchronize’

/var/www/discourse/lib/distributed_mutex.rb:34:in ‘DistributedMutex.synchronize’

/var/www/discourse/lib/distributed_memoizer.rb:12:in ‘DistributedMemoizer.memoize’

/var/www/discourse/app/controllers/posts_controller.rb:208:in ‘PostsController#create’

actionpack-8.0.5/lib/action_controller/metal/basic_implicit_render.rb:8:in ‘ActionController::BasicImplicitRender#send_action’

actionpack-8.0.5/lib/abstract_controller/base.rb:215:in ‘AbstractController::Base#process_action’

actionpack-8.0.5/lib/action_controller/metal/rendering.rb:193:in ‘ActionController::Rendering#process_action’

actionpack-8.0.5/lib/abstract_controller/callbacks.rb:261:in ‘block in AbstractController::Callbacks#process_action’

activesupport-8.0.5/lib/active_support/callbacks.rb:120:in ‘block in ActiveSupport::Callbacks#run_callbacks’

/var/www/discourse/app/controllers/application_controller.rb:452:in ‘block in ApplicationController#with_resolved_locale’

i18n-1.14.8/lib/i18n.rb:354:in ‘I18n::Base#with_locale’

/var/www/discourse/app/controllers/application_controller.rb:452:in ‘ApplicationController#with_resolved_locale’

activesupport-8.0.5/lib/active_support/callbacks.rb:129:in ‘block in ActiveSupport::Callbacks#run_callbacks’

/var/www/discourse/app/controllers/application_controller.rb:1103:in ‘ApplicationController#ensure_dont_cache_page’

activesupport-8.0.5/lib/active_support/callbacks.rb:129:in ‘block in ActiveSupport::Callbacks#run_callbacks’

activesupport-8.0.5/lib/active_support/callbacks.rb:140:in ‘ActiveSupport::Callbacks#run_callbacks’

actionpack-8.0.5/lib/abstract_controller/callbacks.rb:260:in ‘AbstractController::Callbacks#process_action’

actionpack-8.0.5/lib/action_controller/metal/rescue.rb:27:in ‘ActionController::Rescue#process_action’

actionpack-8.0.5/lib/action_controller/metal/instrumentation.rb:76:in ‘block in ActionController::Instrumentation#process_action’

activesupport-8.0.5/lib/active_support/notifications.rb:210:in ‘block in ActiveSupport::Notifications.instrument’

activesupport-8.0.5/lib/active_support/notifications/instrumenter.rb:58:in ‘ActiveSupport::Notifications::Instrumenter#instrument’

activesupport-8.0.5/lib/active_support/notifications.rb:210:in ‘ActiveSupport::Notifications.instrument’

actionpack-8.0.5/lib/action_controller/metal/instrumentation.rb:75:in ‘ActionController::Instrumentation#process_action’

actionpack-8.0.5/lib/action_controller/metal/params_wrapper.rb:259:in ‘ActionController::ParamsWrapper#process_action’

activerecord-8.0.5/lib/active_record/railties/controller_runtime.rb:39:in ‘ActiveRecord::Railties::ControllerRuntime#process_action’

actionpack-8.0.5/lib/abstract_controller/base.rb:152:in ‘AbstractController::Base#process’

actionview-8.0.5/lib/action_view/rendering.rb:40:in ‘ActionView::Rendering#process’

rack-mini-profiler-4.0.1/lib/mini_profiler/profiling_methods.rb:90:in ‘block in ActionController::Base#profile_method’

actionpack-8.0.5/lib/action_controller/metal.rb:252:in ‘ActionController::Metal#dispatch’

actionpack-8.0.5/lib/action_controller/metal.rb:335:in ‘ActionController::Metal.dispatch’

actionpack-8.0.5/lib/action_dispatch/routing/route_set.rb:67:in ‘ActionDispatch::Routing::RouteSet::Dispatcher#dispatch’

actionpack-8.0.5/lib/action_dispatch/routing/route_set.rb:50:in ‘ActionDispatch::Routing::RouteSet::Dispatcher#serve’

actionpack-8.0.5/lib/action_dispatch/journey/router.rb:53:in ‘block in ActionDispatch::Journey::Router#serve’

actionpack-8.0.5/lib/action_dispatch/journey/router.rb:133:in ‘block in ActionDispatch::Journey::Router#find_routes’

actionpack-8.0.5/lib/action_dispatch/journey/router.rb:126:in ‘Array#each’

actionpack-8.0.5/lib/action_dispatch/journey/router.rb:126:in ‘ActionDispatch::Journey::Router#find_routes’

actionpack-8.0.5/lib/action_dispatch/journey/router.rb:34:in ‘ActionDispatch::Journey::Router#serve’

actionpack-8.0.5/lib/action_dispatch/routing/route_set.rb:908:in ‘ActionDispatch::Routing::RouteSet#call’

/var/www/discourse/lib/middleware/omniauth_bypass_middleware.rb:35:in ‘Middleware::OmniauthBypassMiddleware#call’

/var/www/discourse/lib/middleware/crawler_hooks.rb:13:in ‘Middleware::CrawlerHooks#call’

rack-2.2.23/lib/rack/tempfile_reaper.rb:15:in ‘Rack::TempfileReaper#call’

rack-2.2.23/lib/rack/conditional_get.rb:40:in ‘Rack::ConditionalGet#call’

rack-2.2.23/lib/rack/head.rb:12:in ‘Rack::Head#call’

actionpack-8.0.5/lib/action_dispatch/http/permissions_policy.rb:38:in ‘ActionDispatch::PermissionsPolicy::Middleware#call’

/var/www/discourse/lib/content_security_policy/middleware.rb:12:in ‘ContentSecurityPolicy::Middleware#call’

/var/www/discourse/lib/middleware/anonymous_cache.rb:420:in ‘Middleware::AnonymousCache#call’

/var/www/discourse/lib/middleware/csp_script_nonce_injector.rb:12:in ‘Middleware::CspScriptNonceInjector#call’

/var/www/discourse/lib/middleware/track_view_session_id_injector.rb:12:in ‘Middleware::TrackViewSessionIdInjector#call’

/var/www/discourse/config/initializers/008-rack-cors.rb:14:in ‘Discourse::Cors#call’

rack-2.2.23/lib/rack/session/abstract/id.rb:266:in ‘Rack::Session::Abstract::Persisted#context’

rack-2.2.23/lib/rack/session/abstract/id.rb:260:in ‘Rack::Session::Abstract::Persisted#call’

actionpack-8.0.5/lib/action_dispatch/middleware/cookies.rb:706:in ‘ActionDispatch::Cookies#call’

actionpack-8.0.5/lib/action_dispatch/middleware/callbacks.rb:31:in ‘block in ActionDispatch::Callbacks#call’

activesupport-8.0.5/lib/active_support/callbacks.rb:100:in ‘ActiveSupport::Callbacks#run_callbacks’

actionpack-8.0.5/lib/action_dispatch/middleware/callbacks.rb:30:in ‘ActionDispatch::Callbacks#call’

actionpack-8.0.5/lib/action_dispatch/middleware/debug_exceptions.rb:31:in ‘ActionDispatch::DebugExceptions#call’

actionpack-8.0.5/lib/action_dispatch/middleware/show_exceptions.rb:32:in ‘ActionDispatch::ShowExceptions#call’

logster-2.21.0/lib/logster/middleware/reporter.rb:40:in ‘Logster::Middleware::Reporter#call’

/var/www/discourse/lib/middleware/default_headers.rb:13:in ‘Middleware::DefaultHeaders#call’

railties-8.0.5/lib/rails/rack/logger.rb:41:in ‘Rails::Rack::Logger#call_app’

railties-8.0.5/lib/rails/rack/logger.rb:29:in ‘Rails::Rack::Logger#call’

/var/www/discourse/config/initializers/100-quiet_logger.rb:20:in ‘DiscourseRackQuietAssetsLogger#call’

/var/www/discourse/config/initializers/100-silence_logger.rb:29:in ‘SilenceLogger#call’

actionpack-8.0.5/lib/action_dispatch/middleware/request_id.rb:34:in ‘ActionDispatch::RequestId#call’

/var/www/discourse/lib/middleware/enforce_hostname.rb:23:in ‘Middleware::EnforceHostname#call’

rack-2.2.23/lib/rack/method_override.rb:24:in ‘Rack::MethodOverride#call’

actionpack-8.0.5/lib/action_dispatch/middleware/executor.rb:16:in ‘ActionDispatch::Executor#call’

rack-2.2.23/lib/rack/sendfile.rb:127:in ‘Rack::Sendfile#call’

rack-mini-profiler-4.0.1/lib/mini_profiler.rb:191:in ‘Rack::MiniProfiler#call’

message_bus-4.5.2/lib/message_bus/rack/middleware.rb:60:in ‘MessageBus::Rack::Middleware#call’

/var/www/discourse/lib/middleware/request_tracker.rb:372:in ‘Middleware::RequestTracker#call’

actionpack-8.0.5/lib/action_dispatch/middleware/remote_ip.rb:96:in ‘ActionDispatch::RemoteIp#call’

/var/www/discourse/lib/middleware/overload_protections.rb:18:in ‘Middleware::OverloadProtections#call’

/var/www/discourse/lib/middleware/processing_request.rb:14:in ‘Middleware::ProcessingRequest#call’

railties-8.0.5/lib/rails/engine.rb:535:in ‘Rails::Engine#call’

railties-8.0.5/lib/rails/railtie.rb:226:in ‘Kernel#public_send’

railties-8.0.5/lib/rails/railtie.rb:226:in ‘Rails::Railtie.method_missing’

rack-2.2.23/lib/rack/urlmap.rb:74:in ‘block in Rack::URLMap#call’

rack-2.2.23/lib/rack/urlmap.rb:58:in ‘Array#each’

rack-2.2.23/lib/rack/urlmap.rb:58:in ‘Rack::URLMap#call’

rack-2.2.23/lib/rack/tempfile_reaper.rb:15:in ‘Rack::TempfileReaper#call’

pitchfork-0.18.2/lib/pitchfork/chunked.rb:105:in ‘Pitchfork::Chunked#call’

rack-2.2.23/lib/rack/content_length.rb:17:in ‘Rack::ContentLength#call’

pitchfork-0.18.2/lib/pitchfork/http_server.rb:868:in ‘Pitchfork::HttpServer#process_client’

pitchfork-0.18.2/lib/pitchfork/http_server.rb:1017:in ‘Pitchfork::HttpServer#worker_loop’

pitchfork-0.18.2/lib/pitchfork/http_server.rb:616:in ‘block in Pitchfork::HttpServer#spawn_worker’

pitchfork-0.18.2/lib/pitchfork/http_server.rb:1222:in ‘block in Pitchfork::HttpServer#fork_sibling’

pitchfork-0.18.2/lib/pitchfork.rb:170:in ‘block in Pitchfork.clean_fork’

pitchfork-0.18.2/lib/pitchfork.rb:168:in ‘Kernel#catch’

pitchfork-0.18.2/lib/pitchfork.rb:168:in ‘Pitchfork.clean_fork’

pitchfork-0.18.2/lib/pitchfork/http_server.rb:690:in ‘Pitchfork::HttpServer#spawn_initial_mold’

pitchfork-0.18.2/lib/pitchfork/http_server.rb:176:in ‘Pitchfork::HttpServer#start’

pitchfork-0.18.2/exe/pitchfork:110:in ‘<top (required)>’

/var/www/discourse/vendor/bundle/ruby/3.4.0/bin/pitchfork:25:in ‘Kernel#load’

/var/www/discourse/vendor/bundle/ruby/3.4.0/bin/pitchfork:25:in '<

Esto probablemente no es causado directamente por el proxy inverso.

Para las publicaciones creadas mediante API, Discourse utiliza DistributedMemoizer alrededor de PostsController#create para evitar la creación duplicada de publicaciones. Este memoizer usa un DistributedMutex respaldado por Redis con un tiempo de validez muy corto de 1 segundo. La advertencia indica que el trabajo de creación o serialización de la publicación dentro de ese bloqueo tomó más tiempo del esperado.

Por lo tanto:

  • si la publicación de la API se crea correctamente, esto es una advertencia y no el fallo raíz;
  • expected max: 1 secs, took an extra 1 secs significa que el bloqueo se mantuvo durante aproximadamente 2 segundos;
  • es más probable que esté relacionado con el rendimiento del servidor, la latencia de Redis/Postgres, la E/S del disco, la presión de CPU/RAM, los plugins o el procesamiento lento de publicaciones que con el propio proxy inverso nginx/1Panel;
  • la razón por la que solo aparece al publicar mediante API es que esta ruta del memoizer se utiliza para las solicitudes de API.

Aspectos que vale la pena verificar:

  1. ¿La solicitud de API tiene éxito y crea solo una publicación?
  2. ¿Cuánto tiempo tarda la solicitud de API desde el lado del cliente?
  3. ¿Están saturados la CPU, la memoria, el intercambio (swap) o la E/S del disco durante la publicación mediante API?
  4. ¿Están Redis y Postgres dentro del mismo contenedor/host y funcionan correctamente?
  5. ¿Sigue apareciendo la advertencia con una publicación de texto plano muy pequeña y sin imágenes/subidas?
  6. ¿Hay plugins no estándar instalados?

Dado que se trata de una implementación en 1Panel/contenedor en lugar de la instalación estándar de Discourse con Docker, también podría ser útil reproducir el problema en una instalación oficial soportada, si es posible, antes de considerarlo un error del núcleo de Discourse.