2013-02-05 14:16:51 -05:00
|
|
|
module Jobs
|
|
|
|
|
2013-03-22 11:35:32 -04:00
|
|
|
def self.queued
|
|
|
|
Sidekiq::Stats.new.enqueued
|
|
|
|
end
|
|
|
|
|
|
|
|
def self.last_job_performed_at
|
|
|
|
Sidekiq.redis do |r|
|
|
|
|
int = r.get('last_job_perform_at')
|
|
|
|
int ? Time.at(int.to_i) : nil
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2013-04-22 13:37:16 -04:00
|
|
|
def self.num_email_retry_jobs
|
2015-04-12 08:26:48 -04:00
|
|
|
Sidekiq::RetrySet.new.count { |job| job.klass =~ /Email$/ }
|
2013-04-22 13:37:16 -04:00
|
|
|
end
|
|
|
|
|
2013-02-05 14:16:51 -05:00
|
|
|
class Base
|
2019-03-05 06:19:11 -05:00
|
|
|
class JobInstrumenter
|
|
|
|
def initialize(job_class:, opts:, db:)
|
|
|
|
return unless enabled?
|
|
|
|
@data = {}
|
|
|
|
|
|
|
|
@data["hostname"] = `hostname`.strip # Hostname
|
|
|
|
@data["pid"] = Process.pid # Pid
|
|
|
|
@data["database"] = db # DB name - multisite db name it ran on
|
|
|
|
@data["job_name"] = job_class.name # Job Name - eg: Jobs::AboutStats
|
|
|
|
@data["job_type"] = job_class.try(:scheduled?) ? "scheduled" : "regular" # Job Type - either s for scheduled or r for regular
|
2019-03-05 12:44:49 -05:00
|
|
|
@data["opts"] = opts.to_json # Params - json encoded params for the job
|
2019-03-05 06:19:11 -05:00
|
|
|
|
|
|
|
@data["status"] = 'pending'
|
|
|
|
@start_timestamp = Process.clock_gettime(Process::CLOCK_MONOTONIC)
|
|
|
|
|
|
|
|
self.class.ensure_interval_logging!
|
|
|
|
@@active_jobs ||= []
|
|
|
|
@@active_jobs << self
|
|
|
|
|
|
|
|
MethodProfiler.ensure_discourse_instrumentation!
|
|
|
|
MethodProfiler.start
|
|
|
|
end
|
2013-09-29 23:22:19 -04:00
|
|
|
|
2019-03-05 06:19:11 -05:00
|
|
|
def stop(exception:)
|
|
|
|
return unless enabled?
|
2013-09-29 23:22:19 -04:00
|
|
|
|
2019-03-05 06:19:11 -05:00
|
|
|
profile = MethodProfiler.stop
|
2013-09-29 23:22:19 -04:00
|
|
|
|
2019-03-05 06:19:11 -05:00
|
|
|
@@active_jobs.delete(self)
|
2013-09-29 23:22:19 -04:00
|
|
|
|
2019-03-05 06:19:11 -05:00
|
|
|
@data["duration"] = profile[:total_duration] # Duration - length in seconds it took to run
|
|
|
|
@data["sql_duration"] = profile.dig(:sql, :duration) || 0 # Sql Duration (s)
|
|
|
|
@data["sql_calls"] = profile.dig(:sql, :calls) || 0 # Sql Statements - how many statements ran
|
|
|
|
@data["redis_duration"] = profile.dig(:redis, :duration) || 0 # Redis Duration (s)
|
|
|
|
@data["redis_calls"] = profile.dig(:redis, :calls) || 0 # Redis commands
|
|
|
|
@data["net_duration"] = profile.dig(:net, :duration) || 0 # Redis Duration (s)
|
|
|
|
@data["net_calls"] = profile.dig(:net, :calls) || 0 # Redis commands
|
|
|
|
|
|
|
|
if exception.present?
|
|
|
|
@data["exception"] = exception # Exception - if job fails a json encoded exception
|
|
|
|
@data["status"] = 'failed'
|
|
|
|
else
|
|
|
|
@data["status"] = 'success' # Status - fail, success, pending
|
2013-09-29 23:22:19 -04:00
|
|
|
end
|
2019-03-05 06:19:11 -05:00
|
|
|
|
|
|
|
write_to_log
|
2013-09-29 23:22:19 -04:00
|
|
|
end
|
|
|
|
|
2019-03-05 06:19:11 -05:00
|
|
|
def self.raw_log(message)
|
|
|
|
@@logger ||= Logger.new("#{Rails.root}/log/sidekiq.log")
|
|
|
|
@@log_queue ||= Queue.new
|
2019-03-06 05:11:31 -05:00
|
|
|
@@log_thread ||= Thread.new do
|
|
|
|
begin
|
|
|
|
loop { @@logger << @@log_queue.pop }
|
|
|
|
rescue Exception => e
|
|
|
|
Discourse.warn_exception(e, message: "Sidekiq logging thread terminated unexpectedly")
|
2019-03-05 06:19:11 -05:00
|
|
|
end
|
|
|
|
end
|
|
|
|
@@log_queue.push(message)
|
2013-09-29 23:22:19 -04:00
|
|
|
end
|
|
|
|
|
2019-03-05 06:19:11 -05:00
|
|
|
def current_duration
|
|
|
|
Process.clock_gettime(Process::CLOCK_MONOTONIC) - @start_timestamp
|
|
|
|
end
|
|
|
|
|
|
|
|
def write_to_log
|
|
|
|
return unless enabled?
|
|
|
|
@data["@timestamp"] = Time.now
|
|
|
|
@data["duration"] = current_duration if @data["status"] == "pending"
|
|
|
|
self.class.raw_log("#{@data.to_json}\n")
|
|
|
|
end
|
|
|
|
|
|
|
|
def enabled?
|
|
|
|
ENV["DISCOURSE_LOG_SIDEKIQ"] == "1"
|
|
|
|
end
|
2013-02-05 14:16:51 -05:00
|
|
|
|
2019-03-05 06:19:11 -05:00
|
|
|
def self.ensure_interval_logging!
|
|
|
|
interval = ENV["DISCOURSE_LOG_SIDEKIQ_INTERVAL"]
|
|
|
|
return if !interval
|
|
|
|
@@interval_thread ||= Thread.new do
|
|
|
|
begin
|
|
|
|
loop do
|
|
|
|
sleep interval.to_i
|
|
|
|
@@active_jobs.each { |j| j.write_to_log if j.current_duration > interval }
|
|
|
|
end
|
|
|
|
rescue Exception => e
|
|
|
|
Discourse.warn_exception(e, message: "Sidekiq interval logging thread terminated unexpectedly")
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
2013-09-29 23:22:19 -04:00
|
|
|
end
|
|
|
|
|
2019-03-05 06:19:11 -05:00
|
|
|
include Sidekiq::Worker
|
|
|
|
|
2013-06-30 14:00:23 -04:00
|
|
|
def log(*args)
|
|
|
|
args.each do |arg|
|
|
|
|
Rails.logger.info "#{Time.now.to_formatted_s(:db)}: [#{self.class.name.upcase}] #{arg}"
|
|
|
|
end
|
|
|
|
true
|
|
|
|
end
|
|
|
|
|
2014-07-17 16:22:46 -04:00
|
|
|
# Construct an error context object for Discourse.handle_exception
|
|
|
|
# Subclasses are encouraged to use this!
|
|
|
|
#
|
|
|
|
# `opts` is the arguments passed to execute().
|
|
|
|
# `code_desc` is a short string describing what the code was doing (optional).
|
|
|
|
# `extra` is for any other context you logged.
|
|
|
|
# Note that, when building your `extra`, that :opts, :job, and :code are used by this method,
|
|
|
|
# and :current_db and :current_hostname are used by handle_exception.
|
|
|
|
def error_context(opts, code_desc = nil, extra = {})
|
|
|
|
ctx = {}
|
|
|
|
ctx[:opts] = opts
|
|
|
|
ctx[:job] = self.class
|
2014-07-17 18:19:58 -04:00
|
|
|
ctx[:message] = code_desc if code_desc
|
2014-07-17 16:22:46 -04:00
|
|
|
ctx.merge!(extra) if extra != nil
|
|
|
|
ctx
|
|
|
|
end
|
|
|
|
|
2017-07-27 21:20:09 -04:00
|
|
|
def self.delayed_perform(opts = {})
|
2013-02-05 14:16:51 -05:00
|
|
|
self.new.perform(opts)
|
|
|
|
end
|
|
|
|
|
2017-07-27 21:20:09 -04:00
|
|
|
def execute(opts = {})
|
2013-02-05 14:16:51 -05:00
|
|
|
raise "Overwrite me!"
|
|
|
|
end
|
|
|
|
|
2013-09-29 23:22:19 -04:00
|
|
|
def last_db_duration
|
|
|
|
@db_duration || 0
|
|
|
|
end
|
|
|
|
|
2013-08-07 13:25:05 -04:00
|
|
|
def perform(*args)
|
|
|
|
opts = args.extract_options!.with_indifferent_access
|
2013-02-25 11:42:20 -05:00
|
|
|
|
2013-03-22 11:35:32 -04:00
|
|
|
if SiteSetting.queue_jobs?
|
|
|
|
Sidekiq.redis do |r|
|
|
|
|
r.set('last_job_perform_at', Time.now.to_i)
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2013-02-05 14:16:51 -05:00
|
|
|
if opts.delete(:sync_exec)
|
2013-03-04 19:42:44 -05:00
|
|
|
if opts.has_key?(:current_site_id) && opts[:current_site_id] != RailsMultisite::ConnectionManagement.current_db
|
2013-02-05 14:16:51 -05:00
|
|
|
raise ArgumentError.new("You can't connect to another database when executing a job synchronously.")
|
|
|
|
else
|
2014-07-17 16:22:46 -04:00
|
|
|
begin
|
|
|
|
retval = execute(opts)
|
|
|
|
rescue => exc
|
2015-02-09 15:47:46 -05:00
|
|
|
Discourse.handle_job_exception(exc, error_context(opts))
|
2014-07-17 16:22:46 -04:00
|
|
|
end
|
|
|
|
return retval
|
2013-02-05 14:16:51 -05:00
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
dbs =
|
2013-02-25 11:42:20 -05:00
|
|
|
if opts[:current_site_id]
|
2013-02-05 14:16:51 -05:00
|
|
|
[opts[:current_site_id]]
|
2013-02-25 11:42:20 -05:00
|
|
|
else
|
2013-02-05 14:16:51 -05:00
|
|
|
RailsMultisite::ConnectionManagement.all_dbs
|
|
|
|
end
|
|
|
|
|
2014-02-20 23:31:15 -05:00
|
|
|
exceptions = []
|
2013-02-05 14:16:51 -05:00
|
|
|
dbs.each do |db|
|
|
|
|
begin
|
2017-10-09 06:23:25 -04:00
|
|
|
exception = {}
|
|
|
|
|
2017-10-11 05:45:19 -04:00
|
|
|
RailsMultisite::ConnectionManagement.with_connection(db) do
|
2019-03-05 06:19:11 -05:00
|
|
|
job_instrumenter = JobInstrumenter.new(job_class: self.class, opts: opts, db: db)
|
2013-08-15 23:08:23 -04:00
|
|
|
begin
|
2017-10-11 05:17:03 -04:00
|
|
|
I18n.locale = SiteSetting.default_locale || "en"
|
|
|
|
I18n.ensure_all_loaded!
|
|
|
|
begin
|
2018-09-04 02:05:21 -04:00
|
|
|
logster_env = {}
|
|
|
|
Logster.add_to_env(logster_env, :job, self.class.to_s)
|
2018-08-15 22:38:25 -04:00
|
|
|
Logster.add_to_env(logster_env, :db, db)
|
2018-09-04 02:05:21 -04:00
|
|
|
Thread.current[Logster::Logger::LOGSTER_ENV] = logster_env
|
|
|
|
|
2017-10-11 05:17:03 -04:00
|
|
|
execute(opts)
|
|
|
|
rescue => e
|
|
|
|
exception[:ex] = e
|
|
|
|
exception[:other] = { problem_db: db }
|
|
|
|
end
|
2013-08-15 23:08:23 -04:00
|
|
|
rescue => e
|
2017-10-09 06:23:25 -04:00
|
|
|
exception[:ex] = e
|
2017-10-11 05:17:03 -04:00
|
|
|
exception[:message] = "While establishing database connection to #{db}"
|
2017-10-09 06:23:25 -04:00
|
|
|
exception[:other] = { problem_db: db }
|
2017-10-11 05:17:03 -04:00
|
|
|
ensure
|
2019-03-05 06:19:11 -05:00
|
|
|
job_instrumenter.stop(exception: exception)
|
2013-08-15 23:08:23 -04:00
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2017-10-09 06:23:25 -04:00
|
|
|
exceptions << exception unless exception.empty?
|
2013-02-05 14:16:51 -05:00
|
|
|
end
|
|
|
|
end
|
2013-05-19 10:22:31 -04:00
|
|
|
|
2018-08-15 22:38:25 -04:00
|
|
|
Thread.current[Logster::Logger::LOGSTER_ENV] = nil
|
|
|
|
|
2014-02-20 23:31:15 -05:00
|
|
|
if exceptions.length > 0
|
2014-07-17 16:22:46 -04:00
|
|
|
exceptions.each do |exception_hash|
|
2016-05-09 14:37:33 -04:00
|
|
|
Discourse.handle_job_exception(exception_hash[:ex], error_context(opts, exception_hash[:code], exception_hash[:other]))
|
2014-02-20 23:31:15 -05:00
|
|
|
end
|
2016-05-09 14:37:33 -04:00
|
|
|
raise HandledExceptionWrapper.new(exceptions[0][:ex])
|
2014-02-20 23:31:15 -05:00
|
|
|
end
|
|
|
|
|
2014-07-17 16:22:46 -04:00
|
|
|
nil
|
2013-05-19 10:22:31 -04:00
|
|
|
ensure
|
|
|
|
ActiveRecord::Base.connection_handler.clear_active_connections!
|
2013-02-05 14:16:51 -05:00
|
|
|
end
|
2013-05-19 10:22:31 -04:00
|
|
|
|
2013-02-05 14:16:51 -05:00
|
|
|
end
|
|
|
|
|
2015-03-22 21:20:50 -04:00
|
|
|
class HandledExceptionWrapper < StandardError
|
2014-07-17 16:22:46 -04:00
|
|
|
attr_accessor :wrapped
|
|
|
|
def initialize(ex)
|
|
|
|
super("Wrapped #{ex.class}: #{ex.message}")
|
|
|
|
@wrapped = ex
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2013-08-07 13:25:05 -04:00
|
|
|
class Scheduled < Base
|
2018-07-31 17:12:55 -04:00
|
|
|
extend MiniScheduler::Schedule
|
2016-01-11 12:31:28 -05:00
|
|
|
|
|
|
|
def perform(*args)
|
2018-08-28 22:36:59 -04:00
|
|
|
if (Jobs::Heartbeat === self) || !Discourse.readonly_mode?
|
|
|
|
super
|
|
|
|
end
|
2016-01-11 12:31:28 -05:00
|
|
|
end
|
2013-08-07 13:25:05 -04:00
|
|
|
end
|
2013-02-05 14:16:51 -05:00
|
|
|
|
2017-07-27 21:20:09 -04:00
|
|
|
def self.enqueue(job_name, opts = {})
|
2013-08-07 13:25:05 -04:00
|
|
|
klass = "Jobs::#{job_name.to_s.camelcase}".constantize
|
2013-02-05 14:16:51 -05:00
|
|
|
|
|
|
|
# Unless we want to work on all sites
|
|
|
|
unless opts.delete(:all_sites)
|
|
|
|
opts[:current_site_id] ||= RailsMultisite::ConnectionManagement.current_db
|
|
|
|
end
|
|
|
|
|
|
|
|
# If we are able to queue a job, do it
|
|
|
|
if SiteSetting.queue_jobs?
|
2019-01-08 16:57:20 -05:00
|
|
|
hash = {
|
|
|
|
'class' => klass,
|
|
|
|
'args' => [opts]
|
|
|
|
}
|
|
|
|
|
|
|
|
if delay = opts.delete(:delay_for)
|
|
|
|
if delay.to_f > 0
|
|
|
|
hash['at'] = Time.now.to_f + delay.to_f
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
if queue = opts.delete(:queue)
|
|
|
|
hash['queue'] = queue
|
2013-02-05 14:16:51 -05:00
|
|
|
end
|
2019-01-08 16:57:20 -05:00
|
|
|
|
|
|
|
klass.client_push(hash)
|
|
|
|
|
2013-02-05 14:16:51 -05:00
|
|
|
else
|
|
|
|
# Otherwise execute the job right away
|
|
|
|
opts.delete(:delay_for)
|
2019-01-08 16:57:20 -05:00
|
|
|
opts.delete(:queue)
|
|
|
|
|
2013-02-05 14:16:51 -05:00
|
|
|
opts[:sync_exec] = true
|
2017-10-30 22:48:47 -04:00
|
|
|
if Rails.env == "development"
|
|
|
|
Scheduler::Defer.later("job") do
|
|
|
|
klass.new.perform(opts)
|
|
|
|
end
|
|
|
|
else
|
|
|
|
klass.new.perform(opts)
|
|
|
|
end
|
2013-02-05 14:16:51 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
end
|
|
|
|
|
2017-07-27 21:20:09 -04:00
|
|
|
def self.enqueue_in(secs, job_name, opts = {})
|
2013-02-05 14:16:51 -05:00
|
|
|
enqueue(job_name, opts.merge!(delay_for: secs))
|
|
|
|
end
|
|
|
|
|
2017-07-27 21:20:09 -04:00
|
|
|
def self.enqueue_at(datetime, job_name, opts = {})
|
2015-07-29 10:34:21 -04:00
|
|
|
secs = [(datetime - Time.zone.now).to_i, 0].max
|
|
|
|
enqueue_in(secs, job_name, opts)
|
2013-05-07 14:25:41 -04:00
|
|
|
end
|
|
|
|
|
2017-07-27 21:20:09 -04:00
|
|
|
def self.cancel_scheduled_job(job_name, opts = {})
|
2016-08-12 07:10:52 -04:00
|
|
|
scheduled_for(job_name, opts).each(&:delete)
|
2013-05-15 15:19:41 -04:00
|
|
|
end
|
|
|
|
|
2017-07-27 21:20:09 -04:00
|
|
|
def self.scheduled_for(job_name, opts = {})
|
2016-08-12 07:10:52 -04:00
|
|
|
opts = opts.with_indifferent_access
|
|
|
|
unless opts.delete(:all_sites)
|
|
|
|
opts[:current_site_id] ||= RailsMultisite::ConnectionManagement.current_db
|
|
|
|
end
|
|
|
|
|
2013-05-07 14:25:41 -04:00
|
|
|
job_class = "Jobs::#{job_name.to_s.camelcase}"
|
2016-04-13 12:30:25 -04:00
|
|
|
Sidekiq::ScheduledSet.new.select do |scheduled_job|
|
|
|
|
if scheduled_job.klass.to_s == job_class
|
|
|
|
matched = true
|
|
|
|
job_params = scheduled_job.item["args"][0].with_indifferent_access
|
2016-08-12 07:10:52 -04:00
|
|
|
opts.each do |key, value|
|
2016-04-13 12:30:25 -04:00
|
|
|
if job_params[key] != value
|
|
|
|
matched = false
|
|
|
|
break
|
2013-05-07 14:25:41 -04:00
|
|
|
end
|
|
|
|
end
|
2016-04-13 12:30:25 -04:00
|
|
|
matched
|
|
|
|
else
|
|
|
|
false
|
2013-05-07 14:25:41 -04:00
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
2013-02-05 14:16:51 -05:00
|
|
|
end
|
|
|
|
|
2017-07-27 21:20:09 -04:00
|
|
|
Dir["#{Rails.root}/app/jobs/onceoff/*.rb"].each { |file| require_dependency file }
|
|
|
|
Dir["#{Rails.root}/app/jobs/regular/*.rb"].each { |file| require_dependency file }
|
|
|
|
Dir["#{Rails.root}/app/jobs/scheduled/*.rb"].each { |file| require_dependency file }
|