Broken third party plugins can break logging?

I can’t tell if this lograge error is a symptom or a cause of some other problems like this, and this, or it’s a coincidence.

Failed to append custom payload: undefined method `current_user' for #<WebhooksController:0x00007f0aafebe248> /var/www/discourse/config/initializers/101-lograge.rb:22:in `block (2 levels) in <top (req
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/logster-1.2.9/lib/logster/logger.rb:93:in `add_with_opts'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/logster-1.2.9/lib/logster/logger.rb:50:in `add'
/usr/local/lib/ruby/2.5.0/logger.rb:536:in `warn'
/var/www/discourse/config/initializers/101-lograge.rb:39:in `rescue in block (2 levels) in <top (required)>'
/var/www/discourse/config/initializers/101-lograge.rb:19:in `block (2 levels) in <top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/lograge-0.10.0/lib/lograge.rb:165:in `block in extend_base_controller_class'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_controller/metal/instrumentation.rb:38:in `block in process_action'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.0/lib/active_support/notifications.rb:168:in `block in instrument'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.0/lib/active_support/notifications/instrumenter.rb:23:in `instrument'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.0/lib/active_support/notifications.rb:168:in `instrument'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_controller/metal/params_wrapper.rb:256:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/railties/controller_runtime.rb:24:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/abstract_controller/base.rb:134:in `process'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionview-5.2.0/lib/action_view/rendering.rb:32:in `process'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rack-mini-profiler-1.0.0/lib/mini_profiler/profiling_methods.rb:78:in `block in profile_method'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_controller/metal.rb:191:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_controller/metal.rb:252:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_dispatch/routing/route_set.rb:52:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_dispatch/routing/route_set.rb:34:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_dispatch/journey/router.rb:52:in `block in serve'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_dispatch/journey/router.rb:35:in `each'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_dispatch/journey/router.rb:35:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_dispatch/routing/route_set.rb:840:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rack-protection-2.0.3/lib/rack/protection/frame_options.rb:31:in `call'
/var/www/discourse/lib/middleware/omniauth_bypass_middleware.rb:24:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rack-2.0.5/lib/rack/tempfile_reaper.rb:15:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rack-2.0.5/lib/rack/conditional_get.rb:38:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rack-2.0.5/lib/rack/head.rb:12:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_dispatch/http/content_security_policy.rb:18:in `call'
/var/www/discourse/lib/middleware/anonymous_cache.rb:214:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:232:in `context'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:226:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_dispatch/middleware/cookies.rb:670:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.0/lib/active_support/callbacks.rb:98:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_dispatch/middleware/debug_exceptions.rb:61:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/logster-1.2.9/lib/logster/middleware/reporter.rb:31:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/lograge-0.10.0/lib/lograge/rails_ext/rack/logger.rb:15:in `call_app'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/railties-5.2.0/lib/rails/rack/logger.rb:28:in `call'
/var/www/discourse/config/initializers/100-quiet_logger.rb:16:in `call'
/var/www/discourse/config/initializers/100-silence_logger.rb:29:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_dispatch/middleware/request_id.rb:27:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rack-2.0.5/lib/rack/method_override.rb:22:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/actionpack-5.2.0/lib/action_dispatch/middleware/executor.rb:14:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rack-2.0.5/lib/rack/sendfile.rb:111:in `call'
/var/www/discourse/plugins/discourse-prometheus/lib/middleware/metrics.rb:17:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rack-mini-profiler-1.0.0/lib/mini_profiler/profiler.rb:174:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/message_bus-2.1.5/lib/message_bus/rack/middleware.rb:63:in `call'
/var/www/discourse/lib/middleware/request_tracker.rb:180:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/railties-5.2.0/lib/rails/engine.rb:524:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/railties-5.2.0/lib/rails/railtie.rb:190:in `public_send'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/railties-5.2.0/lib/rails/railtie.rb:190:in `method_missing'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rack-2.0.5/lib/rack/urlmap.rb:68:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rack-2.0.5/lib/rack/urlmap.rb:53:in `each'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rack-2.0.5/lib/rack/urlmap.rb:53:in `call'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/unicorn-5.4.0/lib/unicorn/http_server.rb:606:in `process_client'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/unicorn-5.4.0/lib/unicorn/http_server.rb:701:in `worker_loop'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/unicorn-5.4.0/lib/unicorn/http_server.rb:549:in `spawn_missing_workers'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/unicorn-5.4.0/lib/unicorn/http_server.rb:142:in `start'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/unicorn-5.4.0/bin/unicorn:126:in `<top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.5.0/bin/unicorn:23:in `load'
/var/www/discourse/vendor/bundle/ruby/2.5.0/bin/unicorn:23:in `<main>'
1 Like

This is with all third party plugins disabled?

EDIT: Who’s online was enabled. I don’t know what made it happen, so I don’t know how to see if the problem is gone now.

BUT

If 3rd party plugins can break logging, then I’m less excited about lograge. If an errant plugin can make it so that errors aren’t logged then. . . that seems worse than unreadable logs.

2 Likes

This is a bug in our lograge configuration and I’ve fixed it in

Thank you for reporting @pfaffman

5 Likes