Broken third party plugins can break logging?

pfaffman · August 8, 2018, 11:13pm

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 #&lt;WebhooksController:0x00007f0aafebe248&gt; /var/www/discourse/config/initializers/101-lograge.rb:22:in `block (2 levels) in &lt;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>'

codinghorror · August 8, 2018, 11:19pm

This is with all third party plugins disabled?

pfaffman · August 8, 2018, 11:20pm

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.

tgxworld · August 20, 2018, 3:05am

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

https://github.com/discourse/discourse/commit/6d588e43cc5f7d5107668253323b0b0ca153169b

Thank you for reporting @pfaffman

Topic		Replies	Views
The software powering this discussion forum encountered an unexpected problem Support	9	5197	April 19, 2019
"Error updating information, contact site admin" WordPress	26	4906	February 18, 2016
Upgrade button is 500-ing for me Support docker	10	2659	February 14, 2015
The discourse stopped working with error 500 Internal Server Error Bug	2	2973	March 7, 2017
Adding a custom emoji broke the site Bug	2	972	March 22, 2017

Broken third party plugins can break logging?

BUT

Related topics