base.rb in qless-0.10.1

- old
+ new

@@ -108,17 +108,21 @@
         end
       end
 
       # Actually perform the job
       def perform(job)
+        start_time = Time.now.to_f
         around_perform(job)
       rescue JobLockLost
         log(:warn, "Lost lock for job #{job.jid}")
       rescue Exception => error
         fail_job(job, error, caller)
       else
         try_complete(job)
+      ensure
+        elapsed_time = Time.now.to_f - start_time
+        log(:info, "Job #{job.description} took #{elapsed_time} seconds")
       end
 
       # Allow middleware modules to be mixed in and override the
       # definition of around_perform while providing a default
       # implementation so our code can assume the method is present.
@@ -148,11 +152,11 @@
       # Continue taking new jobs
       def unpause(in_signal_handler=true)
         @paused = false
       end
 
-      # Set the proceline. Not supported on all systems
+      # Set the procline. Not supported on all systems
       def procline(value, in_signal_handler=true)
         $0 = "Qless-#{Qless::VERSION}: #{value} at #{Time.now.iso8601}"
         log(:debug, $PROGRAM_NAME) unless in_signal_handler
       end
 
@@ -166,10 +170,10 @@
         #   - The job is being worked on by another worker
         #   - The job has been cancelled
         #
         # We don't want to (or are able to) fail the job with this error in
         # any of these cases, so the best we can do is log the failure.
-        log(:error, "Failed to complete #{job.inspect}: #{e.message}")
+        log(:warn, "Failed to complete #{job.inspect}: #{e.message}")
       end
 
       def fail_job(job, error, worker_backtrace)
         failure = Qless.failure_formatter.format(job, error, worker_backtrace)
         log(:error, "Got #{failure.group} failure from #{job.inspect}\n#{failure.message}" )