diff --git a/app/controllers/application_controller.rb b/app/controllers/application_controller.rb index fe60409f75b..01a32663258 100644 --- a/app/controllers/application_controller.rb +++ b/app/controllers/application_controller.rb @@ -65,7 +65,7 @@ class ApplicationController < ActionController::Base ActionController::UnknownController, AbstractController::ActionNotFound].include? exception.class begin - ErrorLog.report_async!(exception, self, request, current_user) + Discourse.handle_request_exception(exception, self, request, current_user) rescue # dont care give up end diff --git a/app/controllers/session_controller.rb b/app/controllers/session_controller.rb index 12c736d1d20..18b239c31d3 100644 --- a/app/controllers/session_controller.rb +++ b/app/controllers/session_controller.rb @@ -92,7 +92,7 @@ class SessionController < ApplicationController SingleSignOn::ACCESSORS.each do |a| details[a] = sso.send(a) end - Discourse.handle_exception(e, details) + Discourse.handle_job_exception(e, details) render text: I18n.t("sso.unknown_error"), status: 500 end diff --git a/app/jobs/base.rb b/app/jobs/base.rb index b42b5c79f81..bd9f66c86a3 100644 --- a/app/jobs/base.rb +++ b/app/jobs/base.rb @@ -108,7 +108,7 @@ module Jobs begin retval = execute(opts) rescue => exc - Discourse.handle_exception(exc, error_context(opts)) + Discourse.handle_job_exception(exc, error_context(opts)) end return retval end @@ -172,7 +172,7 @@ module Jobs if exceptions.length > 0 exceptions.each do |exception_hash| - Discourse.handle_exception(exception_hash[:ex], + Discourse.handle_job_exception(exception_hash[:ex], error_context(opts, exception_hash[:code], exception_hash[:other])) end raise HandledExceptionWrapper.new exceptions[0][:ex] diff --git a/app/jobs/regular/notify_mailing_list_subscribers.rb b/app/jobs/regular/notify_mailing_list_subscribers.rb index 5ee78979742..b618624b71e 100644 --- a/app/jobs/regular/notify_mailing_list_subscribers.rb +++ b/app/jobs/regular/notify_mailing_list_subscribers.rb @@ -36,7 +36,7 @@ module Jobs message = UserNotifications.mailing_list_notify(user, post) Email::Sender.new(message, :mailing_list, user).send rescue => e - Discourse.handle_exception(e, error_context( + Discourse.handle_job_exception(e, error_context( args, "Sending post to mailing list subscribers", { user_id: user.id, diff --git a/app/jobs/scheduled/periodical_updates.rb b/app/jobs/scheduled/periodical_updates.rb index 60fdf0aa9ab..189ae7bd702 100644 --- a/app/jobs/scheduled/periodical_updates.rb +++ b/app/jobs/scheduled/periodical_updates.rb @@ -22,7 +22,7 @@ module Jobs unless UserAvatar.where("last_gravatar_download_attempt IS NULL").limit(1).first problems = Post.rebake_old(250) problems.each do |hash| - Discourse.handle_exception(hash[:ex], error_context(args, "Rebaking post id #{hash[:post].id}", post_id: hash[:post].id)) + Discourse.handle_job_exception(hash[:ex], error_context(args, "Rebaking post id #{hash[:post].id}", post_id: hash[:post].id)) end end @@ -30,7 +30,7 @@ module Jobs problems = UserProfile.rebake_old(250) problems.each do |hash| user_id = hash[:profile].user_id - Discourse.handle_exception(hash[:ex], error_context(args, "Rebaking user id #{user_id}", user_id: user_id)) + Discourse.handle_job_exception(hash[:ex], error_context(args, "Rebaking user id #{user_id}", user_id: user_id)) end end diff --git a/app/jobs/scheduled/poll_mailbox.rb b/app/jobs/scheduled/poll_mailbox.rb index 910b936888c..6d6f708b615 100644 --- a/app/jobs/scheduled/poll_mailbox.rb +++ b/app/jobs/scheduled/poll_mailbox.rb @@ -74,7 +74,7 @@ module Jobs client_message = RejectionMailer.send_rejection(message_template, message.from, template_args) Email::Sender.new(client_message, message_template).send else - Discourse.handle_exception(e, error_context(@args, "Unrecognized error type when processing incoming email", mail: mail_string)) + Discourse.handle_job_exception(e, error_context(@args, "Unrecognized error type when processing incoming email", mail: mail_string)) end end @@ -91,7 +91,7 @@ module Jobs pop.finish end rescue Net::POPAuthenticationError => e - Discourse.handle_exception(e, error_context(@args, "Signing in to poll incoming email")) + Discourse.handle_job_exception(e, error_context(@args, "Signing in to poll incoming email")) end end diff --git a/app/models/error_log.rb b/app/models/error_log.rb deleted file mode 100644 index 8c7944e8625..00000000000 --- a/app/models/error_log.rb +++ /dev/null @@ -1,94 +0,0 @@ -# TODO: -# a mechanism to iterate through errors in reverse -# async logging should queue, if dupe stack traces are found in batch error should be merged into prev one - -class ErrorLog - - @lock = Mutex.new - - def self.filename - "#{Rails.root}/log/#{Rails.env}_errors.log" - end - - def self.clear!(_guid) - raise NotImplementedError - end - - def self.clear_all!() - File.delete(ErrorLog.filename) if File.exists?(ErrorLog.filename) - end - - def self.report_async!(exception, controller, request, user) - Thread.new do - report!(exception, controller, request, user) - end - end - - def self.report!(exception, controller, request, user) - add_row!( - date: DateTime.now, - guid: SecureRandom.uuid, - user_id: user && user.id, - parameters: request && request.filtered_parameters.to_json, - action: controller.action_name, - controller: controller.controller_name, - backtrace: sanitize_backtrace(exception.backtrace).join("\n"), - message: exception.message, - url: "#{request.protocol}#{request.env["HTTP_X_FORWARDED_HOST"] || request.env["HTTP_HOST"]}#{request.fullpath}", - exception_class: exception.class.to_s - ) - end - - def self.add_row!(hash) - data = hash.to_xml(skip_instruct: true) - # use background thread to write the log cause it may block if it gets backed up - @lock.synchronize do - File.open(filename, "a") do |f| - f.flock(File::LOCK_EX) - f.write(data) - f.close - end - end - end - - - def self.each(&blk) - skip(0, &blk) - end - - def self.skip(skip=0) - pos = 0 - return [] unless File.exists?(filename) - - loop do - lines = "" - File.open(self.filename, "r") do |f| - f.flock(File::LOCK_SH) - f.pos = pos - while !f.eof? - line = f.readline - lines << line - break if line.starts_with? "" - end - pos = f.pos - end - if lines != "" && skip == 0 - h = {} - e = Nokogiri.parse(lines).children[0] - e.children.each do |inner| - h[inner.name] = inner.text - end - yield h - end - skip-=1 if skip > 0 - break if lines == "" - end - end - - def self.sanitize_backtrace(trace) - re = Regexp.new(/^#{Regexp.escape(Rails.root.to_s)}/) - trace.map { |line| Pathname.new(line.gsub(re, "[RAILS_ROOT]")).cleanpath.to_s } - end - - private_class_method :sanitize_backtrace -end diff --git a/config/initializers/sidekiq.rb b/config/initializers/sidekiq.rb index 5a8055cb029..d47699478ce 100644 --- a/config/initializers/sidekiq.rb +++ b/config/initializers/sidekiq.rb @@ -33,7 +33,7 @@ if Sidekiq.server? manager.tick rescue => e # the show must go on - Discourse.handle_exception(e, {message: "While ticking scheduling manager"}) + Discourse.handle_job_exception(e, {message: "While ticking scheduling manager"}) end sleep 1 end diff --git a/lib/discourse.rb b/lib/discourse.rb index 1e2827306dc..da67b3b5dcd 100644 --- a/lib/discourse.rb +++ b/lib/discourse.rb @@ -15,7 +15,7 @@ module Discourse # error_context() method in Jobs::Base to pass the job arguments and any # other desired context. # See app/jobs/base.rb for the error_context function. - def self.handle_exception(ex, context = {}, parent_logger = nil) + def self.handle_job_exception(ex, context = {}, parent_logger = nil) context ||= {} parent_logger ||= SidekiqExceptionHandler @@ -26,6 +26,29 @@ module Discourse }.merge(context)) end + def self.handle_request_exception(ex, controller, request, current_user) + cm = RailsMultisite::ConnectionManagement + context = { + current_db: cm.current_db, + current_hostname: cm.current_hostname, + rails_action: controller.action_name, + rails_controller: controller.controller_name, + } + + env = request.env.dup + + context.each do |key, value| + Logster.add_to_env(env, key, value) + end + + begin + Thread.current[Logster::Logger::LOGSTER_ENV] = env + Logster.logger.fatal("#{ex.class.to_s}: #{ex.message} in #{controller.controller_name}##{controller.action_name}") + ensure + Thread.current[Logster::Logger::LOGSTER_ENV] = nil + end + end + # Expected less matches than what we got in a find class TooManyMatches < Exception; end diff --git a/lib/oneboxer.rb b/lib/oneboxer.rb index 8bb9693b420..79227ac1f31 100644 --- a/lib/oneboxer.rb +++ b/lib/oneboxer.rb @@ -128,7 +128,7 @@ module Oneboxer } } rescue => e - Discourse.handle_exception(e, message: "While trying to onebox a URL", url: url) + Discourse.handle_job_exception(e, message: "While trying to onebox a URL", url: url) # return a blank hash, so rest of the code works {preview: "", onebox: ""} end diff --git a/lib/scheduler/defer.rb b/lib/scheduler/defer.rb index 7f20afe0cab..e055e7f9206 100644 --- a/lib/scheduler/defer.rb +++ b/lib/scheduler/defer.rb @@ -67,10 +67,10 @@ module Scheduler RailsMultisite::ConnectionManagement.establish_connection(db: db) if db job.call rescue => ex - Discourse.handle_exception(ex, {message: "Running deferred code '#{desc}'"}) + Discourse.handle_job_exception(ex, {message: "Running deferred code '#{desc}'"}) end rescue => ex - Discourse.handle_exception(ex, {message: "Processing deferred code queue"}) + Discourse.handle_job_exception(ex, {message: "Processing deferred code queue"}) ensure ActiveRecord::Base.connection_handler.clear_active_connections! end diff --git a/lib/scheduler/manager.rb b/lib/scheduler/manager.rb index 53e655c333f..fda3c300e6d 100644 --- a/lib/scheduler/manager.rb +++ b/lib/scheduler/manager.rb @@ -42,13 +42,13 @@ module Scheduler def keep_alive @manager.keep_alive rescue => ex - Discourse.handle_exception(ex, {message: "Scheduling manager keep-alive"}) + Discourse.handle_job_exception(ex, {message: "Scheduling manager keep-alive"}) end def reschedule_orphans @manager.reschedule_orphans! rescue => ex - Discourse.handle_exception(ex, {message: "Scheduling manager orphan rescheduler"}) + Discourse.handle_job_exception(ex, {message: "Scheduling manager orphan rescheduler"}) end def process_queue @@ -66,7 +66,7 @@ module Scheduler # Discourse.handle_exception was already called, and we don't have any extra info to give failed = true rescue => e - Discourse.handle_exception(e, {message: "Running a scheduled job", job: klass}) + Discourse.handle_job_exception(e, {message: "Running a scheduled job", job: klass}) failed = true end duration = ((Time.now.to_f - start) * 1000).to_i @@ -77,7 +77,7 @@ module Scheduler @mutex.synchronize { info.write! } end rescue => ex - Discourse.handle_exception(ex, {message: "Processing scheduled job queue"}) + Discourse.handle_job_exception(ex, {message: "Processing scheduled job queue"}) ensure @running = false end diff --git a/spec/components/discourse_spec.rb b/spec/components/discourse_spec.rb index ef8f86884b4..335d689cf6b 100644 --- a/spec/components/discourse_spec.rb +++ b/spec/components/discourse_spec.rb @@ -139,7 +139,7 @@ describe Discourse do it "should not fail when called" do exception = StandardError.new - Discourse.handle_exception(exception, nil, nil) + Discourse.handle_job_exception(exception, nil, nil) expect(logger.exception).to eq(exception) expect(logger.context.keys).to eq([:current_db, :current_hostname]) end @@ -147,7 +147,7 @@ describe Discourse do it "correctly passes extra context" do exception = StandardError.new - Discourse.handle_exception(exception, {message: "Doing a test", post_id: 31}, nil) + Discourse.handle_job_exception(exception, {message: "Doing a test", post_id: 31}, nil) expect(logger.exception).to eq(exception) expect(logger.context.keys.sort).to eq([:current_db, :current_hostname, :message, :post_id].sort) end diff --git a/spec/jobs/jobs_base_spec.rb b/spec/jobs/jobs_base_spec.rb index 14c76677895..bcc0680d9a2 100644 --- a/spec/jobs/jobs_base_spec.rb +++ b/spec/jobs/jobs_base_spec.rb @@ -19,7 +19,7 @@ describe Jobs::Base do raise StandardError end end - + it 'handles correct jobs' do job = GoodJob.new job.perform({}) @@ -29,9 +29,9 @@ describe Jobs::Base do it 'handles errors in multisite' do RailsMultisite::ConnectionManagement.expects(:all_dbs).returns(['default','default','default']) # one exception per database - Discourse.expects(:handle_exception).times(3) + Discourse.expects(:handle_job_exception).times(3) - bad = BadJob.new + bad = BadJob.new expect{bad.perform({})}.to raise_error expect(bad.fail_count).to eq(3) end diff --git a/spec/jobs/poll_mailbox_spec.rb b/spec/jobs/poll_mailbox_spec.rb index fb038c12902..6c1423a8d8f 100644 --- a/spec/jobs/poll_mailbox_spec.rb +++ b/spec/jobs/poll_mailbox_spec.rb @@ -34,7 +34,7 @@ describe Jobs::PollMailbox do Net::POP3.any_instance.expects(:start).raises(error) - Discourse.expects(:handle_exception) + Discourse.expects(:handle_job_exception) poller.poll_pop3 end diff --git a/spec/models/error_log_spec.rb b/spec/models/error_log_spec.rb deleted file mode 100644 index e0576ac8d1e..00000000000 --- a/spec/models/error_log_spec.rb +++ /dev/null @@ -1,58 +0,0 @@ -require 'spec_helper' -describe ErrorLog do - - def boom - raise "boom" - end - - def exception - begin - boom - rescue => e - return e - end - end - - def controller - DraftController.new - end - - def request - ActionController::TestRequest.new(host: 'test') - end - - describe "add_row!" do - it "creates a non empty file on first call" do - ErrorLog.clear_all! - ErrorLog.add_row!(hello: "world") - expect(File.exists?(ErrorLog.filename)).to eq true - end - end - - describe "logging data" do - it "is able to read the data it writes" do - ErrorLog.clear_all! - ErrorLog.report!(exception, controller, request, nil) - ErrorLog.report!(exception, controller, request, nil) - i = 0 - ErrorLog.each do |h| - i += 1 - end - expect(i).to eq 2 - end - - it "is able to skip rows" do - ErrorLog.clear_all! - ErrorLog.report!(exception, controller, request, nil) - ErrorLog.report!(exception, controller, request, nil) - ErrorLog.report!(exception, controller, request, nil) - ErrorLog.report!(exception, controller, request, nil) - i = 0 - ErrorLog.skip(3) do |h| - i += 1 - end - expect(i).to eq 1 - end - end - -end