From c6b2ea1d70e3719838221172e37e6bf939db787c Mon Sep 17 00:00:00 2001 From: kjgarza Date: Thu, 30 Jan 2020 17:09:05 +0100 Subject: [PATCH 1/4] fix test errorss --- app/models/concerns/helpable.rb | 18 ++++----- app/models/doi.rb | 72 ++++++++++++++++----------------- 2 files changed, 45 insertions(+), 45 deletions(-) diff --git a/app/models/concerns/helpable.rb b/app/models/concerns/helpable.rb index cddee8f88..1f654865c 100644 --- a/app/models/concerns/helpable.rb +++ b/app/models/concerns/helpable.rb @@ -14,12 +14,12 @@ module Helpable def register_url unless url.present? - logger.error "[Handle] Error updating DOI " + doi + ": url missing." + Rails.logger.error "[Handle] Error updating DOI " + doi + ": url missing." return OpenStruct.new(body: { "errors" => [{ "title" => "URL missing." }] }) end unless client_id.present? - logger.error "[Handle] Error updating DOI " + doi + ": client ID missing." + Rails.logger.error "[Handle] Error updating DOI " + doi + ": client ID missing." return OpenStruct.new(body: { "errors" => [{ "title" => "Client ID missing." }] }) end @@ -56,11 +56,11 @@ def register_url if [200, 201].include?(response.status) # update minted column after first successful registration in handle system self.update_attributes(minted: Time.zone.now, updated: Time.zone.now) if minted.blank? - logger.info "[Handle] URL for DOI " + doi + " updated to " + url + "." unless Rails.env.test? + Rails.logger.info "[Handle] URL for DOI " + doi + " updated to " + url + "." unless Rails.env.test? self.__elasticsearch__.index_document else - logger.error "[Handle] Error updating URL for DOI " + doi + ": " + response.body.inspect unless Rails.env.test? + Rails.logger.error "[Handle] Error updating URL for DOI " + doi + ": " + response.body.inspect unless Rails.env.test? end response @@ -71,7 +71,7 @@ def get_url response = Maremma.get(url, ssl_self_signed: true, timeout: 10) if response.status != 200 - logger.error "[Handle] Error fetching URL for DOI " + doi + ": " + response.body.inspect unless Rails.env.test? + Rails.logger.error "[Handle] Error fetching URL for DOI " + doi + ": " + response.body.inspect unless Rails.env.test? end response @@ -142,13 +142,13 @@ def get_dois(options={}) else text = "Error " + response.body["errors"].inspect - logger.error "[Handle] " + text + Rails.logger.error "[Handle] " + text User.send_notification_to_slack(text, title: "Error #{response.status.to_s}", level: "danger") unless Rails.env.test? end end end - logger.info "#{total} DOIs found." + Rails.logger.info "#{total} DOIs found." dois end @@ -163,7 +163,7 @@ def get_doi(options={}) if response.status != 200 text = "Error " + response.body["errors"].inspect - logger.error "[Handle] " + text + Rails.logger.error "[Handle] " + text User.send_notification_to_slack(text, title: "Error #{response.status.to_s}", level: "danger") unless Rails.env.test? end @@ -182,7 +182,7 @@ def delete_doi(options={}) else text = "Error " + response.body["errors"].inspect - logger.error "[Handle] " + text + Rails.logger.error "[Handle] " + text User.send_notification_to_slack(text, title: "Error #{response.status.to_s}", level: "danger") unless Rails.env.test? response end diff --git a/app/models/doi.rb b/app/models/doi.rb index 219c8d25d..7767fc181 100644 --- a/app/models/doi.rb +++ b/app/models/doi.rb @@ -756,13 +756,13 @@ def self.query(query, options={}) def self.import_one(doi_id: nil) doi = Doi.where(doi: doi_id).first unless doi.present? - logger.error "[MySQL] DOI " + doi_id + " not found." + Rails.logger.error "[MySQL] DOI " + doi_id + " not found." return nil end string = doi.current_metadata.present? ? doi.clean_xml(doi.current_metadata.xml) : nil unless string.present? - logger.error "[MySQL] No metadata for DOI " + doi.doi + " found: " + doi.current_metadata.inspect + Rails.logger.error "[MySQL] No metadata for DOI " + doi.doi + " found: " + doi.current_metadata.inspect return nil end @@ -773,10 +773,10 @@ def self.import_one(doi_id: nil) # update_attributes will trigger validations and Elasticsearch indexing doi.update_attributes(attrs) - logger.info "[MySQL] Imported metadata for DOI " + doi.doi + "." + Rails.logger.info "[MySQL] Imported metadata for DOI " + doi.doi + "." doi rescue TypeError, NoMethodError, RuntimeError, ActiveRecord::StatementInvalid, ActiveRecord::LockWaitTimeout => error - logger.error "[MySQL] Error importing metadata for " + doi.doi + ": " + error.message + Rails.logger.error "[MySQL] Error importing metadata for " + doi.doi + ": " + error.message Raven.capture_exception(error) doi end @@ -788,7 +788,7 @@ def self.import_by_ids(options={}) # get every id between from_id and end_id (from_id..until_id).step(500).each do |id| DoiImportByIdJob.perform_later(options.merge(id: id)) - logger.info "Queued importing for DOIs with IDs starting with #{id}." unless Rails.env.test? + Rails.logger.info "Queued importing for DOIs with IDs starting with #{id}." unless Rails.env.test? end (from_id..until_id).to_a.length @@ -817,21 +817,21 @@ def self.import_by_id(options={}) # log errors errors += response['items'].map { |k, v| k.values.first['error'] }.compact.length response['items'].select { |k, v| k.values.first['error'].present? }.each do |err| - logger.error "[Elasticsearch] " + err.inspect + Rails.logger.error "[Elasticsearch] " + err.inspect end count += dois.length end if errors > 1 - logger.error "[Elasticsearch] #{errors} errors importing #{count} DOIs with IDs #{id} - #{(id + 499)}." + Rails.logger.error "[Elasticsearch] #{errors} errors importing #{count} DOIs with IDs #{id} - #{(id + 499)}." elsif count > 0 - logger.info "[Elasticsearch] Imported #{count} DOIs with IDs #{id} - #{(id + 499)}." + Rails.logger.info "[Elasticsearch] Imported #{count} DOIs with IDs #{id} - #{(id + 499)}." end count rescue Elasticsearch::Transport::Transport::Errors::RequestEntityTooLarge, Faraday::ConnectionFailed, ActiveRecord::LockWaitTimeout => error - logger.info "[Elasticsearch] Error #{error.message} importing DOIs with IDs #{id} - #{(id + 499)}." + Rails.logger.info "[Elasticsearch] Error #{error.message} importing DOIs with IDs #{id} - #{(id + 499)}." count = 0 @@ -840,7 +840,7 @@ def self.import_by_id(options={}) count += 1 end - logger.info "[Elasticsearch] Imported #{count} DOIs with IDs #{id} - #{(id + 499)}." + Rails.logger.info "[Elasticsearch] Imported #{count} DOIs with IDs #{id} - #{(id + 499)}." count end @@ -894,7 +894,7 @@ def self.convert_affiliations(options={}) # get every id between from_id and end_id (from_id..until_id).step(500).each do |id| DoiConvertAffiliationByIdJob.perform_later(options.merge(id: id)) - logger.info "Queued converting affiliations for DOIs with IDs starting with #{id}." unless Rails.env.test? + Rails.logger.info "Queued converting affiliations for DOIs with IDs starting with #{id}." unless Rails.env.test? end (from_id..until_id).to_a.length @@ -910,7 +910,7 @@ def self.convert_affiliation_by_id(options={}) should_update = false creators = Array.wrap(doi.creators).map do |c| if !(c.is_a?(Hash)) - logger.error "[MySQL] creators for DOI #{doi.doi} should be a hash." + Rails.logger.error "[MySQL] creators for DOI #{doi.doi} should be a hash." elsif c["affiliation"].nil? c["affiliation"] = [] should_update = true @@ -940,7 +940,7 @@ def self.convert_affiliation_by_id(options={}) end contributors = Array.wrap(doi.contributors).map do |c| if !(c.is_a?(Hash)) - logger.error "[MySQL] creators for DOI #{doi.doi} should be a hash." + Rails.logger.error "[MySQL] creators for DOI #{doi.doi} should be a hash." elsif c["affiliation"].nil? c["affiliation"] = [] should_update = true @@ -978,16 +978,16 @@ def self.convert_affiliation_by_id(options={}) end unless (Array.wrap(doi.creators).all? { |c| c.is_a?(Hash) && c["affiliation"].is_a?(Array) && c["affiliation"].all? { |a| a.is_a?(Hash) } } && Array.wrap(doi.contributors).all? { |c| c.is_a?(Hash) && c["affiliation"].is_a?(Array) && c["affiliation"].all? { |a| a.is_a?(Hash) } }) - logger.error "[MySQL] Error converting affiliations for doi #{doi.doi}: creators #{doi.creators.inspect} contributors #{doi.contributors.inspect}." + Rails.logger.error "[MySQL] Error converting affiliations for doi #{doi.doi}: creators #{doi.creators.inspect} contributors #{doi.contributors.inspect}." fail TypeError, "Affiliation for doi #{doi.doi} is of wrong type" if Rails.env.test? end end - logger.info "[MySQL] Converted affiliations for #{count} DOIs with IDs #{id} - #{(id + 499)}." if count > 0 + Rails.logger.info "[MySQL] Converted affiliations for #{count} DOIs with IDs #{id} - #{(id + 499)}." if count > 0 count rescue TypeError, ActiveRecord::ActiveRecordError, ActiveRecord::LockWaitTimeout => error - logger.error "[MySQL] Error converting affiliations for DOIs with IDs #{id} - #{(id + 499)}." + Rails.logger.error "[MySQL] Error converting affiliations for DOIs with IDs #{id} - #{(id + 499)}." count end @@ -998,7 +998,7 @@ def self.convert_containers(options={}) # get every id between from_id and end_id (from_id..until_id).step(500).each do |id| DoiConvertContainerByIdJob.perform_later(options.merge(id: id)) - logger.info "Queued converting containers for DOIs with IDs starting with #{id}." unless Rails.env.test? + Rails.logger.info "Queued converting containers for DOIs with IDs starting with #{id}." unless Rails.env.test? end (from_id..until_id).to_a.length @@ -1017,7 +1017,7 @@ def self.convert_container_by_id(options={}) should_update = true container = {} elsif !(doi.container.is_a?(Hash)) - logger.error "[MySQL] container for DOI #{doi.doi} should be a hash." + Rails.logger.error "[MySQL] container for DOI #{doi.doi} should be a hash." elsif [doi.container["title"], doi.container["volume"], doi.container["issue"], doi.container["identifier"]].any? { |c| c.is_a?(Hash) } should_update = true container = { @@ -1037,11 +1037,11 @@ def self.convert_container_by_id(options={}) end end - logger.info "[MySQL] Converted containers for #{count} DOIs with IDs #{id} - #{(id + 499)}." if count > 0 + Rails.logger.info "[MySQL] Converted containers for #{count} DOIs with IDs #{id} - #{(id + 499)}." if count > 0 count rescue TypeError, ActiveRecord::ActiveRecordError, ActiveRecord::LockWaitTimeout => error - logger.error "[MySQL] Error converting containers for DOIs with IDs #{id} - #{(id + 499)}." + Rails.logger.error "[MySQL] Error converting containers for DOIs with IDs #{id} - #{(id + 499)}." count end @@ -1268,7 +1268,7 @@ def check_container # to be used after DOIs were transferred to another DOI RA def self.delete_dois_by_prefix(prefix, options={}) if prefix.blank? - logger.error "[Error] No prefix provided." + Rails.logger.error "[Error] No prefix provided." return nil end @@ -1276,7 +1276,7 @@ def self.delete_dois_by_prefix(prefix, options={}) size = (options[:size] || 1000).to_i response = Doi.query(nil, prefix: prefix, page: { size: 1, cursor: [] }) - logger.info "#{response.results.total} DOIs found for prefix #{prefix}." + Rails.logger.info "#{response.results.total} DOIs found for prefix #{prefix}." if prefix && response.results.total > 0 # walk through results using cursor @@ -1286,7 +1286,7 @@ def self.delete_dois_by_prefix(prefix, options={}) response = Doi.query(nil, prefix: prefix, page: { size: size, cursor: cursor }) break unless response.results.results.length > 0 - logger.info "Deleting #{response.results.results.length} DOIs starting with _id #{response.results.to_a.first[:_id]}." + Rails.logger.info "Deleting #{response.results.results.length} DOIs starting with _id #{response.results.to_a.first[:_id]}." cursor = response.results.to_a.last[:sort] response.results.results.each do |d| @@ -1302,7 +1302,7 @@ def self.delete_dois_by_prefix(prefix, options={}) # provider europ registers their DOIs in the handle system themselves and are ignored def self.set_handle response = Doi.query("-registered:* +url:* -aasm_state:draft -provider_id:europ -agency:Crossref", page: { size: 1, cursor: [] }) - logger.info "#{response.results.total} DOIs found that are not registered in the Handle system." + Rails.logger.info "#{response.results.total} DOIs found that are not registered in the Handle system." if response.results.total > 0 # walk through results using cursor @@ -1312,7 +1312,7 @@ def self.set_handle response = Doi.query("-registered:* +url:* -aasm_state:draft -provider_id:europ -agency:Crossref", page: { size: 1000, cursor: cursor }) break unless response.results.results.length > 0 - logger.info "[Handle] Register #{response.results.results.length} DOIs in the handle system starting with _id #{response.results.to_a.first[:_id]}." + Rails.logger.info "[Handle] Register #{response.results.results.length} DOIs in the handle system starting with _id #{response.results.to_a.first[:_id]}." cursor = response.results.to_a.last[:sort] response.results.results.each do |d| @@ -1324,7 +1324,7 @@ def self.set_handle def self.set_url response = Doi.query("-url:* (+provider_id:ethz OR -aasm_status:draft)", page: { size: 1, cursor: [] }) - logger.info "#{response.results.total} DOIs with no URL found in the database." + Rails.logger.info "#{response.results.total} DOIs with no URL found in the database." if response.results.total > 0 # walk through results using cursor @@ -1334,7 +1334,7 @@ def self.set_url response = Doi.query("-url:* (+provider_id:ethz OR -aasm_status:draft)", page: { size: 1000, cursor: cursor }) break unless response.results.results.length.positive? - logger.info "[Handle] Update URL for #{response.results.results.length} DOIs starting with _id #{response.results.to_a.first[:_id]}." + Rails.logger.info "[Handle] Update URL for #{response.results.results.length} DOIs starting with _id #{response.results.to_a.first[:_id]}." cursor = response.results.to_a.last[:sort] response.results.results.each do |d| @@ -1346,7 +1346,7 @@ def self.set_url def self.set_minted response = Doi.query("provider_id:ethz AND +aasm_state:draft +url:*", page: { size: 1, cursor: [] }) - logger.info "#{response.results.total} draft DOIs from provider ETHZ found in the database." + Rails.logger.info "#{response.results.total} draft DOIs from provider ETHZ found in the database." if response.results.total > 0 # walk through results using cursor @@ -1356,7 +1356,7 @@ def self.set_minted response = Doi.query("provider_id:ethz AND +aasm_state:draft +url:*", page: { size: 1000, cursor: cursor }) break unless response.results.results.length.positive? - logger.info "[MySQL] Set minted for #{response.results.results.length} DOIs starting with _id #{response.results.to_a.first[:_id]}." + Rails.logger.info "[MySQL] Set minted for #{response.results.results.length} DOIs starting with _id #{response.results.to_a.first[:_id]}." cursor = response.results.to_a.last[:sort] response.results.results.each do |d| @@ -1368,12 +1368,12 @@ def self.set_minted def self.transfer(options={}) if options[:client_id].blank? - logger.error "[Transfer] No client provided." + Rails.logger.error "[Transfer] No client provided." return nil end if options[:target_id].blank? - logger.error "[Transfer] No target client provided." + Rails.logger.error "[Transfer] No target client provided." return nil end @@ -1381,7 +1381,7 @@ def self.transfer(options={}) size = (options[:size] || 1000).to_i response = Doi.query(nil, client_id: options[:client_id], page: { size: 1, cursor: [] }) - logger.info "[Transfer] #{response.results.total} DOIs found for client #{options[:client_id]}." + Rails.logger.info "[Transfer] #{response.results.total} DOIs found for client #{options[:client_id]}." if options[:client_id] && options[:target_id] && response.results.total > 0 # walk through results using cursor @@ -1391,7 +1391,7 @@ def self.transfer(options={}) response = Doi.query(nil, client_id: options[:client_id], page: { size: size, cursor: cursor }) break unless response.results.results.length.positive? - logger.info "[Transfer] Transferring #{response.results.results.length} DOIs starting with _id #{response.results.to_a.first[:_id]}." + Rails.logger.info "[Transfer] Transferring #{response.results.results.length} DOIs starting with _id #{response.results.to_a.first[:_id]}." cursor = response.results.to_a.last[:sort] response.results.results.each do |d| @@ -1415,7 +1415,7 @@ def set_defaults end def self.migrate_landing_page(options={}) - logger.info "Starting migration" + Rails.logger.info "Starting migration" # Handle camel casing first. Doi.where.not('last_landing_page_status_result' => nil).find_each do |doi| @@ -1465,10 +1465,10 @@ def self.migrate_landing_page(options={}) doi.update_columns("landing_page": landing_page) - logger.info "Updated " + doi.doi + Rails.logger.info "Updated " + doi.doi rescue TypeError, NoMethodError => error - logger.error "Error updating landing page " + doi.doi + ": " + error.message + Rails.logger.error "Error updating landing page " + doi.doi + ": " + error.message end end end From 544e09061c596aa179491bb8608d8c0b9e5173fb Mon Sep 17 00:00:00 2001 From: kjgarza Date: Thu, 30 Jan 2020 17:09:48 +0100 Subject: [PATCH 2/4] use rails logger --- app/controllers/client_prefixes_controller.rb | 2 +- app/controllers/clients_controller.rb | 8 ++++---- app/controllers/graphql_controller.rb | 4 ++-- app/controllers/media_controller.rb | 6 +++--- app/controllers/metadata_controller.rb | 4 ++-- app/controllers/provider_prefixes_controller.rb | 2 +- app/controllers/providers_controller.rb | 8 ++++---- app/controllers/repositories_controller.rb | 8 ++++---- app/controllers/repository_prefixes_controller.rb | 2 +- 9 files changed, 22 insertions(+), 22 deletions(-) diff --git a/app/controllers/client_prefixes_controller.rb b/app/controllers/client_prefixes_controller.rb index 3b87ea910..69a0fc9ec 100644 --- a/app/controllers/client_prefixes_controller.rb +++ b/app/controllers/client_prefixes_controller.rb @@ -89,7 +89,7 @@ def create render json: ClientPrefixSerializer.new(@client_prefix, options).serialized_json, status: :created else - logger.error @client_prefix.errors.inspect + Rails.logger.error @client_prefix.errors.inspect render json: serialize_errors(@client_prefix.errors), status: :unprocessable_entity end end diff --git a/app/controllers/clients_controller.rb b/app/controllers/clients_controller.rb index 0fbc4461f..6485078af 100644 --- a/app/controllers/clients_controller.rb +++ b/app/controllers/clients_controller.rb @@ -115,7 +115,7 @@ def create render json: ClientSerializer.new(@client, options).serialized_json, status: :created else - logger.error @client.errors.inspect + Rails.logger.error @client.errors.inspect render json: serialize_errors(@client.errors), status: :unprocessable_entity end end @@ -129,7 +129,7 @@ def update render json: ClientSerializer.new(@client, options).serialized_json, status: :ok else - logger.error @client.errors.inspect + Rails.logger.error @client.errors.inspect render json: serialize_errors(@client.errors), status: :unprocessable_entity end end @@ -140,13 +140,13 @@ def destroy if @client.dois.present? message = "Can't delete client that has DOIs." status = 400 - logger.warn message + Rails.logger.warn message render json: { errors: [{ status: status.to_s, title: message }] }.to_json, status: status elsif @client.update(is_active: nil, deleted_at: Time.zone.now) @client.send_delete_email unless Rails.env.test? head :no_content else - logger.error @client.errors.inspect + Rails.logger.error @client.errors.inspect render json: serialize_errors(@client.errors), status: :unprocessable_entity end end diff --git a/app/controllers/graphql_controller.rb b/app/controllers/graphql_controller.rb index 87fbc87be..440ea63f6 100644 --- a/app/controllers/graphql_controller.rb +++ b/app/controllers/graphql_controller.rb @@ -34,8 +34,8 @@ def ensure_hash(ambiguous_param) end def handle_error_in_development(e) - logger.error e.message - logger.error e.backtrace.join("\n") + Rails.logger.error e.message + Rails.logger.error e.backtrace.join("\n") render json: { error: { message: e.message, backtrace: e.backtrace }, data: {} }, status: 500 end diff --git a/app/controllers/media_controller.rb b/app/controllers/media_controller.rb index b293864e0..4adc548ff 100644 --- a/app/controllers/media_controller.rb +++ b/app/controllers/media_controller.rb @@ -60,7 +60,7 @@ def create render json: MediaSerializer.new(@media, options).serialized_json, status: :created else - logger.error @media.errors.inspect + Rails.logger.error @media.errors.inspect render json: serialize_errors(@media.errors), status: :unprocessable_entity end end @@ -75,7 +75,7 @@ def update render json: MediaSerializer.new(@media, options).serialized_json, status: :ok else - logger.error @media.errors.inspect + Rails.logger.error @media.errors.inspect render json: serialize_errors(@media.errors), status: :unprocessable_entity end end @@ -86,7 +86,7 @@ def destroy if @media.destroy head :no_content else - logger.error @media.errors.inspect + Rails.logger.error @media.errors.inspect render json: serialize_errors(@media.errors), status: :unprocessable_entity end end diff --git a/app/controllers/metadata_controller.rb b/app/controllers/metadata_controller.rb index c4b35c42c..47c7d5772 100644 --- a/app/controllers/metadata_controller.rb +++ b/app/controllers/metadata_controller.rb @@ -65,7 +65,7 @@ def create render json: MetadataSerializer.new(@metadata, options).serialized_json, status: :created else - logger.error @metadata.errors.inspect + Rails.logger.error @metadata.errors.inspect render json: serialize_errors(@metadata.errors), status: :unprocessable_entity end end @@ -77,7 +77,7 @@ def destroy if @metadata.destroy head :no_content else - logger.error @metadata.errors.inspect + Rails.logger.error @metadata.errors.inspect render json: serialize_errors(@metadata.errors), status: :unprocessable_entity end else diff --git a/app/controllers/provider_prefixes_controller.rb b/app/controllers/provider_prefixes_controller.rb index 9dbb8b3e0..c8f4d6026 100644 --- a/app/controllers/provider_prefixes_controller.rb +++ b/app/controllers/provider_prefixes_controller.rb @@ -123,7 +123,7 @@ def create render json: ProviderPrefixSerializer.new(@provider_prefix, options).serialized_json, status: :created else - logger.error @provider_prefix.errors.inspect + Rails.logger.error @provider_prefix.errors.inspect render json: serialize_errors(@provider_prefix.errors), status: :unprocessable_entity end end diff --git a/app/controllers/providers_controller.rb b/app/controllers/providers_controller.rb index 17c16c878..d139af87c 100644 --- a/app/controllers/providers_controller.rb +++ b/app/controllers/providers_controller.rb @@ -211,7 +211,7 @@ def create render json: ProviderSerializer.new(@provider, options).serialized_json, status: :ok else - logger.error @provider.errors.inspect + Rails.logger.error @provider.errors.inspect render json: serialize_errors(@provider.errors), status: :unprocessable_entity end end @@ -243,7 +243,7 @@ def update render json: ProviderSerializer.new(@provider, options).serialized_json, status: :ok else - logger.error @provider.errors.inspect + Rails.logger.error @provider.errors.inspect render json: serialize_errors(@provider.errors), status: :unprocessable_entity end end @@ -254,13 +254,13 @@ def destroy if active_client_count(provider_id: @provider.symbol).positive? message = "Can't delete provider that has active clients." status = 400 - logger.warn message + Rails.logger.warn message render json: { errors: [{ status: status.to_s, title: message }] }.to_json, status: status elsif @provider.update_attributes(is_active: nil, deleted_at: Time.zone.now) @provider.send_delete_email unless Rails.env.test? head :no_content else - logger.error @provider.errors.inspect + Rails.logger.error @provider.errors.inspect render json: serialize_errors(@provider.errors), status: :unprocessable_entity end end diff --git a/app/controllers/repositories_controller.rb b/app/controllers/repositories_controller.rb index 25d15ac3d..0674a1c48 100644 --- a/app/controllers/repositories_controller.rb +++ b/app/controllers/repositories_controller.rb @@ -141,7 +141,7 @@ def create render json: RepositorySerializer.new(@client, options).serialized_json, status: :created else - logger.error @client.errors.inspect + Rails.logger.error @client.errors.inspect render json: serialize_errors(@client.errors), status: :unprocessable_entity end end @@ -155,7 +155,7 @@ def update render json: RepositorySerializer.new(@client, options).serialized_json, status: :ok else - logger.error @client.errors.inspect + Rails.logger.error @client.errors.inspect render json: serialize_errors(@client.errors), status: :unprocessable_entity end end @@ -166,13 +166,13 @@ def destroy if @client.dois.present? message = "Can't delete repository that has DOIs." status = 400 - logger.warn message + Rails.logger.warn message render json: { errors: [{ status: status.to_s, title: message }] }.to_json, status: status elsif @client.update_attributes(is_active: nil, deleted_at: Time.zone.now) @client.send_delete_email unless Rails.env.test? head :no_content else - logger.error @client.errors.inspect + Rails.logger.error @client.errors.inspect render json: serialize_errors(@client.errors), status: :unprocessable_entity end end diff --git a/app/controllers/repository_prefixes_controller.rb b/app/controllers/repository_prefixes_controller.rb index af714a968..5b6a92e47 100644 --- a/app/controllers/repository_prefixes_controller.rb +++ b/app/controllers/repository_prefixes_controller.rb @@ -89,7 +89,7 @@ def create render json: RepositoryPrefixSerializer.new(@client_prefix, options).serialized_json, status: :created else - logger.error @client_prefix.errors.inspect + Rails.logger.error @client_prefix.errors.inspect render json: serialize_errors(@client_prefix.errors), status: :unprocessable_entity end end From 912472531b9c5cd2fbd2c2ffd414fb8d1797599f Mon Sep 17 00:00:00 2001 From: kjgarza Date: Thu, 30 Jan 2020 17:09:59 +0100 Subject: [PATCH 3/4] use rails logger for models --- app/models/activity.rb | 14 +++++++------- app/models/concerns/crosscitable.rb | 8 ++++---- app/models/event.rb | 28 ++++++++++++++-------------- 3 files changed, 25 insertions(+), 25 deletions(-) diff --git a/app/models/activity.rb b/app/models/activity.rb index 9089fc775..4976a868c 100644 --- a/app/models/activity.rb +++ b/app/models/activity.rb @@ -220,21 +220,21 @@ def self.import_by_id(options={}) # log errors errors += response['items'].map { |k, v| k.values.first['error'] }.compact.length response['items'].select { |k, v| k.values.first['error'].present? }.each do |err| - logger.error "[Elasticsearch] " + err.inspect + Rails.logger.error "[Elasticsearch] " + err.inspect end count += activities.length end if errors > 1 - logger.error "[Elasticsearch] #{errors} errors importing #{count} activities with IDs #{id} - #{(id + 499)}." + Rails.logger.error "[Elasticsearch] #{errors} errors importing #{count} activities with IDs #{id} - #{(id + 499)}." elsif count > 0 - logger.info "[Elasticsearch] Imported #{count} activities with IDs #{id} - #{(id + 499)}." + Rails.logger.info "[Elasticsearch] Imported #{count} activities with IDs #{id} - #{(id + 499)}." end count rescue Elasticsearch::Transport::Transport::Errors::RequestEntityTooLarge, Faraday::ConnectionFailed, ActiveRecord::LockWaitTimeout => error - logger.error "[Elasticsearch] Error #{error.message} importing activities with IDs #{id} - #{(id + 499)}." + Rails.logger.error "[Elasticsearch] Error #{error.message} importing activities with IDs #{id} - #{(id + 499)}." count = 0 @@ -243,7 +243,7 @@ def self.import_by_id(options={}) count += 1 end - logger.info "[Elasticsearch] Imported #{count} activities with IDs #{id} - #{(id + 499)}." + Rails.logger.info "[Elasticsearch] Imported #{count} activities with IDs #{id} - #{(id + 499)}." count end @@ -315,11 +315,11 @@ def self.convert_affiliation_by_id(options={}) end end - logger.info "[Elasticsearch] Converted affiliations for #{count} activities with IDs #{id} - #{(id + 499)}." if count > 0 + Rails.logger.info "[Elasticsearch] Converted affiliations for #{count} activities with IDs #{id} - #{(id + 499)}." if count > 0 count rescue Elasticsearch::Transport::Transport::Errors::RequestEntityTooLarge, Faraday::ConnectionFailed, ActiveRecord::LockWaitTimeout => error - logger.info "[Elasticsearch] Error #{error.message} converting affiliations for DOIs with IDs #{id} - #{(id + 499)}." + Rails.logger.info "[Elasticsearch] Error #{error.message} converting affiliations for DOIs with IDs #{id} - #{(id + 499)}." end def uid diff --git a/app/models/concerns/crosscitable.rb b/app/models/concerns/crosscitable.rb index d594b9cad..8e126610f 100644 --- a/app/models/concerns/crosscitable.rb +++ b/app/models/concerns/crosscitable.rb @@ -51,8 +51,8 @@ def parse_xml(input, options={}) rescue NoMethodError, ArgumentError => exception Raven.capture_exception(exception) - logger.error "Error " + exception.message + " for doi " + @doi + "." - logger.error exception + Rails.logger.error "Error " + exception.message + " for doi " + @doi + "." + Rails.logger.error exception {} end @@ -117,8 +117,8 @@ def clean_xml(string) doc = Nokogiri::XML(string) { |config| config.strict.noblanks } doc.to_xml rescue ArgumentError, Encoding::CompatibilityError => exception - logger.error "Error " + exception.message + "." - logger.error exception + Rails.logger.error "Error " + exception.message + "." + Rails.logger.error exception nil end diff --git a/app/models/event.rb b/app/models/event.rb index 421527d74..37949879e 100644 --- a/app/models/event.rb +++ b/app/models/event.rb @@ -296,7 +296,7 @@ def self.import_by_ids(options = {}) # get every id between from_id and until_id (from_id..until_id).step(500).each do |id| EventImportByIdJob.perform_later(id: id) - logger.info "Queued importing for events with IDs starting with #{id}." unless Rails.env.test? + Rails.logger.info "Queued importing for events with IDs starting with #{id}." unless Rails.env.test? end end @@ -317,19 +317,19 @@ def self.import_by_id(options = {}) # log errors errors += response["items"].map { |k, v| k.values.first["error"] }.compact.length response["items"].select { |k, v| k.values.first["error"].present? }.each do |err| - logger.error "[Elasticsearch] " + err.inspect + Rails.logger.error "[Elasticsearch] " + err.inspect end count += events.length end if errors > 1 - logger.error "[Elasticsearch] #{errors} errors importing #{count} events with IDs #{id} - #{(id + 499)}." + Rails.logger.error "[Elasticsearch] #{errors} errors importing #{count} events with IDs #{id} - #{(id + 499)}." elsif count > 0 - logger.info "[Elasticsearch] Imported #{count} events with IDs #{id} - #{(id + 499)}." + Rails.logger.info "[Elasticsearch] Imported #{count} events with IDs #{id} - #{(id + 499)}." end rescue Elasticsearch::Transport::Transport::Errors::RequestEntityTooLarge, Faraday::ConnectionFailed, ActiveRecord::LockWaitTimeout => error - logger.info "[Elasticsearch] Error #{error.message} importing events with IDs #{id} - #{(id + 499)}." + Rails.logger.info "[Elasticsearch] Error #{error.message} importing events with IDs #{id} - #{(id + 499)}." count = 0 @@ -338,7 +338,7 @@ def self.import_by_id(options = {}) count += 1 end - logger.info "[Elasticsearch] Imported #{count} events with IDs #{id} - #{(id + 499)}." + Rails.logger.info "[Elasticsearch] Imported #{count} events with IDs #{id} - #{(id + 499)}." end def self.update_crossref(options = {}) @@ -346,7 +346,7 @@ def self.update_crossref(options = {}) cursor = (options[:cursor] || []) response = Event.query(nil, source_id: "crossref", page: { size: 1, cursor: [] }) - logger.info "[Update] #{response.results.total} events for source crossref." + Rails.logger.info "[Update] #{response.results.total} events for source crossref." # walk through results using cursor if response.results.total > 0 @@ -354,7 +354,7 @@ def self.update_crossref(options = {}) response = Event.query(nil, source_id: "crossref", page: { size: size, cursor: cursor }) break unless response.results.results.length > 0 - logger.info "[Update] Updating #{response.results.results.length} crossref events starting with _id #{response.results.to_a.first[:_id]}." + Rails.logger.info "[Update] Updating #{response.results.results.length} crossref events starting with _id #{response.results.to_a.first[:_id]}." cursor = response.results.to_a.last[:sort] dois = response.results.results.map(&:subj_id).uniq @@ -392,7 +392,7 @@ def self.update_datacite_ra(options = {}) source_id = "datacite-#{ra}" response = Event.query(nil, source_id: source_id, page: { size: 1, cursor: cursor }) - logger.info "[Update] #{response.results.total} events for source #{source_id}." + Rails.logger.info "[Update] #{response.results.total} events for source #{source_id}." # walk through results using cursor if response.results.total > 0 @@ -400,7 +400,7 @@ def self.update_datacite_ra(options = {}) response = Event.query(nil, source_id: source_id, page: { size: size, cursor: cursor }) break unless response.results.results.length > 0 - logger.info "[Update] Updating #{response.results.results.length} #{source_id} events starting with _id #{response.results.to_a.first[:_id]}." + Rails.logger.info "[Update] Updating #{response.results.results.length} #{source_id} events starting with _id #{response.results.to_a.first[:_id]}." cursor = response.results.to_a.last[:sort] dois = response.results.results.map(&:obj_id).uniq @@ -422,7 +422,7 @@ def self.update_registrant(options = {}) query = options[:query] || "registrant_id:*crossref.citations" response = Event.query(query, source_id: source_id, citation_type: citation_type, page: { size: 1, cursor: cursor }) - logger.info "[Update] #{response.results.total} events for sources #{source_id}." + Rails.logger.info "[Update] #{response.results.total} events for sources #{source_id}." # walk through results using cursor if response.results.total > 0 @@ -430,7 +430,7 @@ def self.update_registrant(options = {}) response = Event.query(query, source_id: source_id, citation_type: citation_type, page: { size: size, cursor: cursor }) break unless response.results.results.length > 0 - logger.info "[Update] Updating #{response.results.results.length} #{source_id} events starting with _id #{response.results.to_a.first[:_id]}." + Rails.logger.info "[Update] Updating #{response.results.results.length} #{source_id} events starting with _id #{response.results.to_a.first[:_id]}." cursor = response.results.to_a.last[:sort] ids = response.results.results.map(&:uuid).uniq @@ -447,7 +447,7 @@ def self.update_datacite_orcid_auto_update(options = {}) cursor = (options[:cursor] || []).to_i response = Event.query(nil, source_id: "datacite-orcid-auto-update", page: { size: 1, cursor: cursor }) - logger.info "[Update] #{response.results.total} events for source datacite-orcid-auto-update." + Rails.logger.info "[Update] #{response.results.total} events for source datacite-orcid-auto-update." # walk through results using cursor if response.results.total > 0 @@ -455,7 +455,7 @@ def self.update_datacite_orcid_auto_update(options = {}) response = Event.query(nil, source_id: "datacite-orcid-auto-update", page: { size: size, cursor: cursor }) break unless response.results.results.length > 0 - logger.info "[Update] Updating #{response.results.results.length} datacite-orcid-auto-update events starting with _id #{response.results.to_a.first[:_id]}." + Rails.logger.info "[Update] Updating #{response.results.results.length} datacite-orcid-auto-update events starting with _id #{response.results.to_a.first[:_id]}." cursor = response.results.to_a.last[:sort] ids = response.results.results.map(&:obj_id).uniq From 8b5cc6b35e0ce3244ebb75f9bf2c04132c07cc10 Mon Sep 17 00:00:00 2001 From: kjgarza Date: Thu, 30 Jan 2020 17:14:41 +0100 Subject: [PATCH 4/4] move lograge --- config/application.rb | 25 +++++++++++++++++++++++++ config/initializers/_lograge.rb | 26 -------------------------- 2 files changed, 25 insertions(+), 26 deletions(-) delete mode 100644 config/initializers/_lograge.rb diff --git a/config/application.rb b/config/application.rb index 9df4f3da7..abf55cad0 100644 --- a/config/application.rb +++ b/config/application.rb @@ -81,6 +81,31 @@ class Application < Rails::Application # secret_key_base is not used by Rails API, as there are no sessions config.secret_key_base = "blipblapblup" + config.lograge.enabled = true + config.lograge.formatter = Lograge::Formatters::Logstash.new + config.lograge.logger = ::LogStashLogger.new( + type: :stdout + ) + config.lograge.log_level = ENV["LOG_LEVEL"].to_sym + + config.active_job.logger = config.lograge.logger + + config.lograge.ignore_actions = ["HeartbeatController#index", "IndexController#index"] + config.lograge.ignore_custom = lambda do |event| + event.payload.inspect.length > 100000 + end + config.lograge.base_controller_class = "ActionController::API" + + config.lograge.custom_options = lambda do |event| + exceptions = %w(controller action format id) + { + params: event.payload[:params].except(*exceptions), + uid: event.payload[:uid], + } + end + config.logger = config.lograge.logger + config.active_record.logger = nil + # configure caching config.cache_store = :dalli_store, nil, { :namespace => ENV['APPLICATION'] } diff --git a/config/initializers/_lograge.rb b/config/initializers/_lograge.rb deleted file mode 100644 index eb6693412..000000000 --- a/config/initializers/_lograge.rb +++ /dev/null @@ -1,26 +0,0 @@ -# frozen_string_literal: true - -require "elasticsearch/rails/lograge" - -Rails.application.configure do - config.lograge.enabled = true - config.lograge.formatter = Lograge::Formatters::Logstash.new - config.lograge.logger = LogStashLogger.new(type: :stdout) - config.lograge.log_level = ENV["LOG_LEVEL"].to_sym - - config.active_job.logger = config.lograge.logger - - config.lograge.ignore_actions = ["HeartbeatController#index", "IndexController#index"] - config.lograge.ignore_custom = lambda do |event| - event.payload.inspect.length > 100000 - end - config.lograge.base_controller_class = "ActionController::API" - - config.lograge.custom_options = lambda do |event| - exceptions = %w(controller action format id) - { - params: event.payload[:params].except(*exceptions), - uid: event.payload[:uid], - } - end -end