Refactoring: Improved error logging

- Remove unnecessary "ERROR" prefix
- Log missing ES index as WARN instead of INFO
- Log actual JSON ES payload in cases of an error (for e.g. manual cURL replaying) if possible

app/models/channel/email_parser.rb

@@ -118,9 +118,9 @@ returns
     # store unprocessable email for bug reporting
     filename = archive_mail('unprocessable_mail', msg)
 
-    message = "ERROR: Can't process email, you will find it for bug reporting under #{filename}, please create an issue at https://github.com/zammad/zammad/issues"
+    message = "Can't process email, you will find it for bug reporting under #{filename}, please create an issue at https://github.com/zammad/zammad/issues"
 
-    p message # rubocop:disable Rails/Output
+    p 'ERROR: ' + message # rubocop:disable Rails/Output
     p 'ERROR: ' + e.inspect # rubocop:disable Rails/Output
     Rails.logger.error message
     Rails.logger.error e

app/models/channel/filter/identify_sender.rb

@@ -120,8 +120,8 @@ module Channel::Filter::IdentifySender
         # parse not parsable fields by mail gem like
         #  - Max Kohl | [example.com] <kohl@example.com>
         #  - Max Kohl <max.kohl <max.kohl@example.com>
-        Rails.logger.error 'ERROR: ' + e.inspect
+        Rails.logger.error e
-        Rails.logger.error "ERROR: try it by my self (#{item}): #{mail[item.to_sym]}"
+        Rails.logger.error "try it by my self (#{item}): #{mail[item.to_sym]}"
         recipients = mail[item.to_sym].to_s.split(',')
         recipients.each do |recipient|
           address = nil

app/models/channel/filter/sender_is_system_address.rb

@@ -26,7 +26,7 @@ module Channel::Filter::SenderIsSystemAddress
         return true
       end
     rescue => e
-      Rails.logger.error 'ERROR: SenderIsSystemAddress: ' + e.inspect
+      Rails.logger.error 'SenderIsSystemAddress: ' + e.inspect
     end
 
     # check if sender is agent
@@ -41,7 +41,7 @@ module Channel::Filter::SenderIsSystemAddress
       mail['x-zammad-article-sender'.to_sym] = 'Agent'
       return true
     rescue => e
-      Rails.logger.error 'ERROR: SenderIsSystemAddress: ' + e.inspect
+      Rails.logger.error 'SenderIsSystemAddress: ' + e.inspect
     end
 
     true

app/models/external_sync.rb

@@ -17,7 +17,7 @@ class ExternalSync < ApplicationModel
           object[attribute] = value
           changed         ||= true
         rescue => e
-          Rails.logger.error "ERROR: Unable to assign attribute #{attribute} to object #{object.class.name}: #{e.inspect}"
+          Rails.logger.error "Unable to assign attribute #{attribute} to object #{object.class.name}: #{e.inspect}"
         end
       end
       changed

app/models/object_manager/attribute.rb

@@ -393,7 +393,7 @@ use "force: true" to delete also not editable fields
     elsif data[:object_lookup_id]
       data[:object] = ObjectLookup.by_id(data[:object_lookup_id])
     else
-      raise 'ERROR: need object or object_lookup_id param!'
+      raise 'need object or object_lookup_id param!'
     end
 
     data[:name].downcase!
@@ -404,17 +404,17 @@ use "force: true" to delete also not editable fields
       name:             data[:name],
     )
     if !record
-      raise "ERROR: No such field #{data[:object]}.#{data[:name]}"
+      raise "No such field #{data[:object]}.#{data[:name]}"
     end
 
     if !data[:force] && !record.editable
-      raise "ERROR: #{data[:object]}.#{data[:name]} can't be removed!"
+      raise "#{data[:object]}.#{data[:name]} can't be removed!"
     end
 
     # check to make sure that no triggers, overviews, or schedulers references this attribute
     if ObjectManager::Attribute.attribute_used_by_references?(data[:object], data[:name])
       text = ObjectManager::Attribute.attribute_used_by_references_humaniced(data[:object], data[:name])
-      raise "ERROR: #{data[:object]}.#{data[:name]} is referenced by #{text} and thus cannot be deleted!"
+      raise "#{data[:object]}.#{data[:name]} is referenced by #{text} and thus cannot be deleted!"
     end
 
     # if record is to create, just destroy it

app/models/package.rb

@@ -420,7 +420,7 @@ execute all pending package migrations at once
       data = File.open(location, 'rb')
       contents = data.read
     rescue => e
-      raise 'ERROR: ' + e.inspect
+      raise e
     end
     contents
   end
@@ -462,7 +462,7 @@ execute all pending package migrations at once
       file.close
       File.chmod(permission.to_s.to_i(8), location)
     rescue => e
-      raise 'ERROR: ' + e.inspect
+      raise e
     end
     true
   end

app/models/scheduler.rb

@@ -347,7 +347,7 @@ class Scheduler < ApplicationModel
       loop do
         success, failure = Delayed::Worker.new.work_off
         if failure.nonzero?
-          raise "ERROR: #{failure} failed background jobs: #{Delayed::Job.where('last_error IS NOT NULL').inspect}"
+          raise "#{failure} failed background jobs: #{Delayed::Job.where('last_error IS NOT NULL').inspect}"
         end
         break if success.zero?
       end

app/models/store/provider/file.rb

@@ -29,7 +29,7 @@ class Store::Provider::File
     # check sha
     local_sha = Digest::SHA256.hexdigest(get(sha))
     if sha != local_sha
-      raise "ERROR: Corrupt file in fs #{location}, sha should be #{sha} but is #{local_sha}"
+      raise "Corrupt file in fs #{location}, sha should be #{sha} but is #{local_sha}"
     end
 
     true
@@ -40,7 +40,7 @@ class Store::Provider::File
     location = get_location(sha)
     Rails.logger.debug { "read from fs #{location}" }
     if !File.exist?(location)
-      raise "ERROR: No such file #{location}"
+      raise "No such file #{location}"
     end
 
     data    = File.open(location, 'rb')
@@ -49,7 +49,7 @@ class Store::Provider::File
     # check sha
     local_sha = Digest::SHA256.hexdigest(content)
     if local_sha != sha
-      raise "ERROR: Corrupt file in fs #{location}, sha should be #{sha} but is #{local_sha}"
+      raise "Corrupt file in fs #{location}, sha should be #{sha} but is #{local_sha}"
     end
 
     content

app/models/ticket.rb

@@ -1398,8 +1398,8 @@ result
       begin
         next if recipient_email.match?(/#{send_no_auto_response_reg_exp}/i)
       rescue => e
-        logger.error "ERROR: Invalid regex '#{send_no_auto_response_reg_exp}' in setting send_no_auto_response_reg_exp"
+        logger.error "Invalid regex '#{send_no_auto_response_reg_exp}' in setting send_no_auto_response_reg_exp"
-        logger.error 'ERROR: ' + e.inspect
+        logger.error e
         next if recipient_email.match?(/(mailer-daemon|postmaster|abuse|root|noreply|noreply.+?|no-reply|no-reply.+?)@.+?/i)
       end
 

lib/search_index_backend.rb

@@ -216,7 +216,7 @@ remove whole data from index
       url:      url,
       response: response,
     )
-    Rails.logger.info "NOTICE: can't delete index: #{humanized_error}"
+    Rails.logger.warn "Can't delete index: #{humanized_error}"
     false
   end
 
@@ -754,10 +754,13 @@ generate url for index or document access (only for internal use)
 
   def self.humanized_error(verb:, url:, payload: nil, response:)
     prefix = "Unable to process #{verb} request to elasticsearch URL '#{url}'."
-    suffix = "\n\nResponse:\n#{response.inspect}\n\nPayload:\n#{payload.inspect}"
+    suffix = "\n\nResponse:\n#{response.inspect}\n\n"
 
     if payload.respond_to?(:to_json)
+      suffix += "Payload:\n#{payload.to_json}"
       suffix += "\n\nPayload size: #{payload.to_json.bytesize / 1024 / 1024}M"
+    else
+      suffix += "Payload:\n#{payload.inspect}"
     end
 
     message = if response&.error&.match?('Connection refused')

lib/service/geo_calendar/zammad.rb

@@ -28,7 +28,7 @@ class Service::GeoCalendar::Zammad
         },
       )
       if !response.success? && response.code.to_s !~ /^40.$/
-        raise "ERROR: #{response.code}/#{response.body}"
+        raise "#{response.code}/#{response.body}"
       end
 
       data = response.data

lib/service/geo_ip/zammad.rb

@@ -26,7 +26,7 @@ class Service::GeoIp::Zammad
         },
       )
       if !response.success? && response.code.to_s !~ /^40.$/
-        raise "ERROR: #{response.code}/#{response.body}"
+        raise "#{response.code}/#{response.body}"
       end
 
       data = response.data

spec/support/searchindex_backend.rb

@@ -30,7 +30,7 @@ prepares elasticsearch
     if ENV['ES_URL'].blank?
       return if !required
 
-      raise "ERROR: Need ES_URL - hint ES_URL='http://127.0.0.1:9200'"
+      raise "Need ES_URL - hint ES_URL='http://127.0.0.1:9200'"
     end
 
     Setting.set('es_url', ENV['ES_URL'])
@@ -46,7 +46,7 @@ prepares elasticsearch
       ENV['ES_INDEX']  = "es_index_#{test_method_name.downcase}_#{rand_id}_#{rand(999_999_999)}"
     end
     if ENV['ES_INDEX'].blank?
-      raise "ERROR: Need ES_INDEX - hint ES_INDEX='estest.local_zammad'"
+      raise "Need ES_INDEX - hint ES_INDEX='estest.local_zammad'"
     end
 
     Setting.set('es_index', ENV['ES_INDEX'])