From b6c46b3fc488b9bda12529c093ead4b4311fd557 Mon Sep 17 00:00:00 2001 From: Benjamin Neff Date: Wed, 3 Jun 2015 02:39:12 +0200 Subject: [PATCH 1/2] add logging mixin and replace federation-logger --- app/controllers/publics_controller.rb | 8 +- app/mailers/notification_mailers/base.rb | 6 +- app/models/user.rb | 2 +- app/workers/base.rb | 12 +-- app/workers/http_multi.rb | 2 +- app/workers/receive_unencrypted_salmon.rb | 9 +- config/initializers/load_libraries.rb | 1 - lib/diaspora/fetcher/public.rb | 21 ++-- lib/diaspora/logging.rb | 10 ++ lib/federated/generator.rb | 6 +- lib/federation_logger.rb | 118 ---------------------- lib/postzord/receiver.rb | 5 +- lib/postzord/receiver/local_batch.rb | 4 +- lib/postzord/receiver/private.rb | 30 +++--- lib/postzord/receiver/public.rb | 4 +- lib/webfinger.rb | 14 +-- 16 files changed, 69 insertions(+), 183 deletions(-) create mode 100644 lib/diaspora/logging.rb delete mode 100644 lib/federation_logger.rb diff --git a/app/controllers/publics_controller.rb b/app/controllers/publics_controller.rb index 3609bdefa..af9d57f9c 100644 --- a/app/controllers/publics_controller.rb +++ b/app/controllers/publics_controller.rb @@ -39,7 +39,7 @@ class PublicsController < ApplicationController return end - FEDERATION_LOGGER.info("webfinger profile request for :#{@person.id}") + logger.info "webfinger profile request for: #{@person.id}" render 'webfinger', :content_type => 'application/xrd+xml' end @@ -48,7 +48,7 @@ class PublicsController < ApplicationController end def receive_public - FEDERATION_LOGGER.info("recieved a public message") + logger.info "received a public message" Workers::ReceiveUnencryptedSalmon.perform_async(CGI::unescape(params[:xml])) render :nothing => true, :status => :ok end @@ -57,14 +57,14 @@ class PublicsController < ApplicationController person = Person.find_by_guid(params[:guid]) if person.nil? || person.owner_id.nil? - Rails.logger.error("Received post for nonexistent person #{params[:guid]}") + logger.error "Received post for nonexistent person #{params[:guid]}" render :nothing => true, :status => 404 return end @user = person.owner - FEDERATION_LOGGER.info("recieved a private message for user:#{@user.id}") + logger.info "received a private message for user: #{@user.id}" Workers::ReceiveEncryptedSalmon.perform_async(@user.id, CGI::unescape(params[:xml])) render :nothing => true, :status => 202 diff --git a/app/mailers/notification_mailers/base.rb b/app/mailers/notification_mailers/base.rb index b3cc8136a..efbde43a1 100644 --- a/app/mailers/notification_mailers/base.rb +++ b/app/mailers/notification_mailers/base.rb @@ -1,5 +1,7 @@ module NotificationMailers class Base + include Diaspora::Logging + attr_accessor :recipient, :sender delegate :unconfirmed_email, :confirm_email_token, @@ -53,9 +55,5 @@ module NotificationMailers logger.info(log_string) end - - def logger - @logger ||= ::Logging::Logger[self] - end end end diff --git a/app/models/user.rb b/app/models/user.rb index 364a33350..8de37ecaf 100644 --- a/app/models/user.rb +++ b/app/models/user.rb @@ -232,7 +232,7 @@ class User < ActiveRecord::Base end def dispatch_post(post, opts={}) - FEDERATION_LOGGER.info("user:#{self.id} dispatching #{post.class}:#{post.guid}") + logger.info "user:#{id} dispatching #{post.class}:#{post.guid}" Postzord::Dispatcher.defer_build_and_post(self, post, opts) end diff --git a/app/workers/base.rb b/app/workers/base.rb index 2a614663e..d410a103d 100644 --- a/app/workers/base.rb +++ b/app/workers/base.rb @@ -8,6 +8,8 @@ module Workers sidekiq_options backtrace: (bt = AppConfig.environment.sidekiq.backtrace.get) && bt.to_i, retry: (rt = AppConfig.environment.sidekiq.retry.get) && rt.to_i + include Diaspora::Logging + # In the long term we need to eliminate the cause of these def suppress_annoying_errors(&block) yield @@ -19,19 +21,13 @@ module Workers # Friendica seems to provoke Diaspora::NonPublic, Diaspora::XMLNotParseable => e - Rails.logger.info("error on receive: #{e.class}") + logger.warn "error on receive: #{e.class}" rescue ActiveRecord::RecordInvalid => e - Rails.logger.info("failed to save received object: #{e.record.errors.full_messages}") + logger.warn "failed to save received object: #{e.record.errors.full_messages}" raise e unless %w( "already been taken" "is ignored by the post author" ).any? {|reason| e.message.include? reason } end - - private - - def logger - @logger ||= ::Logging::Logger[self] - end end end diff --git a/app/workers/http_multi.rb b/app/workers/http_multi.rb index e370cd981..dfc1b9591 100644 --- a/app/workers/http_multi.rb +++ b/app/workers/http_multi.rb @@ -31,7 +31,7 @@ module Workers if retry_count < MAX_RETRIES Workers::HttpMulti.perform_in(1.hour, user_id, encoded_object_xml, hydra.people_to_retry, dispatcher_class_as_string, retry_count + 1) else - Rails.logger.info("event=http_multi_abandon sender_id=#{user_id} failed_recipient_ids='[#{person_ids.join(', ')}] '") + logger.info "event=http_multi_abandon sender_id=#{user_id} failed_recipient_ids='[#{person_ids.join(', ')}]'" end end end diff --git a/app/workers/receive_unencrypted_salmon.rb b/app/workers/receive_unencrypted_salmon.rb index 2f7085730..4340443bc 100644 --- a/app/workers/receive_unencrypted_salmon.rb +++ b/app/workers/receive_unencrypted_salmon.rb @@ -8,13 +8,8 @@ module Workers def perform(xml) suppress_annoying_errors do - begin - receiver = Postzord::Receiver::Public.new(xml) - receiver.perform! - rescue => e - FEDERATION_LOGGER.info(e.message) - raise e - end + receiver = Postzord::Receiver::Public.new(xml) + receiver.perform! end end end diff --git a/config/initializers/load_libraries.rb b/config/initializers/load_libraries.rb index cd3ee6065..ff4f78492 100644 --- a/config/initializers/load_libraries.rb +++ b/config/initializers/load_libraries.rb @@ -14,7 +14,6 @@ require 'diaspora' require 'direction_detector' require 'email_inviter' require 'evil_query' -require 'federation_logger' require 'h_card' require 'hydra_wrapper' require 'postzord' diff --git a/lib/diaspora/fetcher/public.rb b/lib/diaspora/fetcher/public.rb index cb920b243..acc0e6479 100644 --- a/lib/diaspora/fetcher/public.rb +++ b/lib/diaspora/fetcher/public.rb @@ -2,6 +2,7 @@ # licensed under the Affero General Public License version 3 or later. See # the COPYRIGHT file. module Diaspora; module Fetcher; class Public + include Diaspora::Logging # various states that can be assigned to a person to describe where # in the process of fetching their public posts we're currently at @@ -60,14 +61,14 @@ module Diaspora; module Fetcher; class Public begin retrieve_posts rescue => e - FEDERATION_LOGGER.error "unable to retrieve public posts for #{@person.diaspora_handle}" + logger.error "unable to retrieve public posts for #{@person.diaspora_handle}" raise e end begin process_posts rescue => e - FEDERATION_LOGGER.error "unable to process public posts for #{@person.diaspora_handle}" + logger.error "unable to process public posts for #{@person.diaspora_handle}" raise e end end @@ -77,14 +78,14 @@ module Diaspora; module Fetcher; class Public def retrieve_posts set_fetch_status Public::Status_Running - FEDERATION_LOGGER.info "fetching public posts for #{@person.diaspora_handle}" + logger.info "fetching public posts for #{@person.diaspora_handle}" resp = Faraday.get("#{@person.url}people/#{@person.guid}/stream") do |req| req.headers['Accept'] = 'application/json' req.headers['User-Agent'] = 'diaspora-fetcher' end - FEDERATION_LOGGER.debug resp.body.to_s[0..250] + logger.debug "fetched response: #{resp.body.to_s[0..250]}" @data = JSON.parse resp.body set_fetch_status Public::Status_Fetched @@ -97,9 +98,9 @@ module Diaspora; module Fetcher; class Public @data.each do |post| next unless validate(post) - FEDERATION_LOGGER.info "saving fetched post (#{post['guid']}) to database" + logger.info "saving fetched post (#{post['guid']}) to database" - FEDERATION_LOGGER.debug post.to_s[0..250] + logger.debug "post: #{post.to_s[0..250]}" # disable some stuff we don't want for bulk inserts StatusMessage.skip_callback :create, :set_guid @@ -147,7 +148,7 @@ module Diaspora; module Fetcher; class Public def check_existing post new_post = (Post.find_by_guid(post['guid']).blank?) - FEDERATION_LOGGER.warn "a post with that guid (#{post['guid']}) already exists" unless new_post + logger.warn "a post with that guid (#{post['guid']}) already exists" unless new_post new_post end @@ -158,7 +159,7 @@ module Diaspora; module Fetcher; class Public guid = post['author']['guid'] equal = (guid == @person.guid) - FEDERATION_LOGGER.warn "the author (#{guid}) does not match the person currently being processed (#{@person.guid})" unless equal + logger.warn "the author (#{guid}) does not match the person currently being processed (#{@person.guid})" unless equal equal end @@ -167,7 +168,7 @@ module Diaspora; module Fetcher; class Public def check_public post ispublic = (post['public'] == true) - FEDERATION_LOGGER.warn "the post (#{post['guid']}) is not public, this is not intended..." unless ispublic + logger.warn "the post (#{post['guid']}) is not public, this is not intended..." unless ispublic ispublic end @@ -176,7 +177,7 @@ module Diaspora; module Fetcher; class Public def check_type post type_ok = (post['post_type'] == "StatusMessage") - FEDERATION_LOGGER.warn "the post (#{post['guid']}) has a type, which cannot be handled (#{post['post_type']})" unless type_ok + logger.warn "the post (#{post['guid']}) has a type, which cannot be handled (#{post['post_type']})" unless type_ok type_ok end diff --git a/lib/diaspora/logging.rb b/lib/diaspora/logging.rb new file mode 100644 index 000000000..4fe8c04ac --- /dev/null +++ b/lib/diaspora/logging.rb @@ -0,0 +1,10 @@ +# a logging mixin providing the logger +module Diaspora + module Logging + private + + def logger + @logger ||= ::Logging::Logger[self] + end + end +end diff --git a/lib/federated/generator.rb b/lib/federated/generator.rb index ab6025ef2..4ee81511a 100644 --- a/lib/federated/generator.rb +++ b/lib/federated/generator.rb @@ -1,5 +1,7 @@ module Federated class Generator + include Diaspora::Logging + def initialize(user, target) @user = user @target = target @@ -8,7 +10,7 @@ module Federated def create!(options={}) relayable = build(options) if relayable.save! - FEDERATION_LOGGER.info("user:#{@user.id} dispatching #{relayable.class}:#{relayable.guid}") + logger.info "user:#{@user.id} dispatching #{relayable.class}:#{relayable.guid}" Postzord::Dispatcher.defer_build_and_post(@user, relayable) relayable end @@ -28,4 +30,4 @@ module Federated {} end end -end \ No newline at end of file +end diff --git a/lib/federation_logger.rb b/lib/federation_logger.rb deleted file mode 100644 index aa6097d15..000000000 --- a/lib/federation_logger.rb +++ /dev/null @@ -1,118 +0,0 @@ -#custom_logger.rb - -class ActiveSupport::BufferedLogger - def formatter=(formatter) - @log.formatter = formatter - end -end - -class Formatter - COLORS = { - 'FG' => { - 'black' => '30', - 'red' => '31', - 'green' => '32', - 'yellow' => '33', - 'blue' => '34', - 'violet' => '35', - 'cyan' => '36', - 'white' => '37', - }, - 'BG' => { - 'black' => '40', - 'red' => '41', - 'green' => '42', - 'yellow' => '43', - 'blue' => '44', - 'violet' => '45', - 'cyan' => '46', - 'white' => '47', - } - } - - DULL = '0' - BRIGHT = '1' - NULL = '00' - - ESC = "\e" - RESET = "#{ESC}[00;0;00m" - # example: \033[40;0;37m white text on black background - - SEVERITY_TO_TAG_MAP = {'DEBUG'=>'meh', 'INFO'=>'fyi', 'WARN'=>'hmm', 'ERROR'=>'wtf', 'FATAL'=>'omg', 'UNKNOWN'=>'???'} - SEVERITY_TO_COLOR_MAP = {'DEBUG'=>'white', 'INFO'=>'green', 'WARN'=>'yellow', 'ERROR'=>'red', 'FATAL'=>'red', 'UNKNOWN'=>'white'} - - def initialize - @colors_enabled = true - end - - def random - @random ||= COLORS['FG'].keys[3] - end - - def colors? - @colors_enabled - end - - def fg name - COLORS['FG'][name] - end - - def bg name - COLORS['BG'][name] - end - - def colorize(message, c_fg='white', c_bg='black', strong=0) - if colors? - "#{ESC}[#{fg(c_fg)};#{bg(c_bg)};#{strong==0 ? DULL : BRIGHT}m#{message}#{RESET}" - else - message - end - end - - def call(severity, time, progname, msg) - fmt_prefix = pretty_prefix(severity, time) - fmt_msg = pretty_message(msg) - - "#{fmt_prefix} #{fmt_msg}\n" - end - - def pretty_prefix(severity, time) - color = SEVERITY_TO_COLOR_MAP[severity] - fmt_severity = colorize(sprintf("%-3s","#{SEVERITY_TO_TAG_MAP[severity]}"), color, 'black', 1) - fmt_time = colorize(time.strftime("%s.%L")) - fmt_env = colorize(Rails.env, random, 'black', 1) - - "#{fmt_env} - #{fmt_time} [#{fmt_severity}] (pid:#{$$})" - end - - def pretty_message msg - w = 130 - txt_w = (w - Rails.env.size - 3) - - # get the prefix without colors, just for the length - @colors_enabled = false - prefix = pretty_prefix("DEBUG", Time.now).size + 1 - @colors_enabled = true # restore value - - if (msg.size <= (w-prefix)) - msg - else - output = msg.strip.scan(/.{1,#{txt_w}}/).flatten.map { |line| sprintf("%#{w}s", sprintf("%-#{txt_w}s", line)) }.join("\n") - "\n#{output}" - end - end - -end - -class FederationLogger < ActiveSupport::BufferedLogger -end - -if Rails.env.match(/integration/) - puts "using federation logger" - logfile = File.open(Rails.root.join("log", "federation_logger.log"), 'a') #create log file - logfile.sync = true #automatically flushes data to file - FEDERATION_LOGGER = FederationLogger.new(logfile) #constant accessible anywhere - FEDERATION_LOGGER.formatter = Formatter.new -else - FEDERATION_LOGGER = Rails.logger -end diff --git a/lib/postzord/receiver.rb b/lib/postzord/receiver.rb index f411de7c3..cb99c2bc2 100644 --- a/lib/postzord/receiver.rb +++ b/lib/postzord/receiver.rb @@ -4,6 +4,8 @@ class Postzord::Receiver + include Diaspora::Logging + require 'postzord/receiver/private' require 'postzord/receiver/public' require 'postzord/receiver/local_batch' @@ -14,7 +16,8 @@ class Postzord::Receiver def author_does_not_match_xml_author? if (@author.diaspora_handle != xml_author) - FEDERATION_LOGGER.info("event=receive status=abort reason='author in xml does not match retrieved person' payload_type=#{@object.class} sender=#{@author.diaspora_handle}") + logger.info "event=receive status=abort reason='author in xml does not match retrieved person' " \ + "payload_type=#{@object.class} sender=#{@author.diaspora_handle}" return true end end diff --git a/lib/postzord/receiver/local_batch.rb b/lib/postzord/receiver/local_batch.rb index 454121f6f..e45936d36 100644 --- a/lib/postzord/receiver/local_batch.rb +++ b/lib/postzord/receiver/local_batch.rb @@ -14,7 +14,7 @@ class Postzord::Receiver::LocalBatch < Postzord::Receiver end def receive! - FEDERATION_LOGGER.info("receiving local batch for #{@object.inspect}") + logger.info "receiving local batch for #{@object.inspect}" if @object.respond_to?(:relayable?) receive_relayable else @@ -25,7 +25,7 @@ class Postzord::Receiver::LocalBatch < Postzord::Receiver # 09/27/11 this is slow notify_users - FEDERATION_LOGGER.info("receiving local batch completed for #{@object.inspect}") + logger.info "receiving local batch completed for #{@object.inspect}" true end diff --git a/lib/postzord/receiver/private.rb b/lib/postzord/receiver/private.rb index 0a45f9744..224eacf78 100644 --- a/lib/postzord/receiver/private.rb +++ b/lib/postzord/receiver/private.rb @@ -19,36 +19,32 @@ class Postzord::Receiver::Private < Postzord::Receiver if @sender && self.salmon.verified_for_key?(@sender.public_key) parse_and_receive(salmon.parsed_data) else - FEDERATION_LOGGER.info("event=receive status=abort recipient=#{@user.diaspora_handle} sender=#{@salmon.author_id} reason='not_verified for key'") + logger.error "event=receive status=abort reason='not_verified for key' " \ + "recipient=#{@user.diaspora_handle} sender=#{@salmon.author_id}" false end rescue => e - #this sucks - FEDERATION_LOGGER.error("Failure to receive #{@object.class} from sender:#{@sender.id} for user:#{@user.id}: #{e.message}\n#{@object.inspect}") + logger.error "failed to receive #{@object.class} from sender:#{@sender.id} for user:#{@user.id}: #{e.message}\n" \ + "#{@object.inspect}" raise e end def parse_and_receive(xml) @object ||= Diaspora::Parser.from_xml(xml) - return if @object.nil? + return if @object.nil? - FEDERATION_LOGGER.info("user:#{@user.id} starting private receive from person:#{@sender.guid}") + logger.info "user:#{@user.id} starting private receive from person:#{@sender.guid}" - if self.validate_object - set_author! - receive_object - FEDERATION_LOGGER.info("object received: [#{@object.class}#{@object.respond_to?(:text) ? ":'#{@object.text}'" : ''}]") - else - FEDERATION_LOGGER.error("failed to receive object from #{@object.author}: #{@object.inspect}") - raise "not a valid object:#{@object.inspect}" - end + validate_object + set_author! + receive_object end # @return [Object] def receive_object obj = @object.receive(@user, @author) Notification.notify(@user, obj, @author) if obj.respond_to?(:notification_type) - FEDERATION_LOGGER.info("user:#{@user.id} successfully received private post from person #{@sender.guid}: #{@object.inspect}") + logger.info "user:#{@user.id} successfully received #{@object.class} from person #{@sender.guid}: #{@object.inspect}" obj end @@ -91,14 +87,16 @@ class Postzord::Receiver::Private < Postzord::Receiver #validations def relayable_without_parent? if @object.respond_to?(:relayable?) && @object.parent.nil? - FEDERATION_LOGGER.error("event=receive status=abort reason='received a comment but no corresponding post' recipient=#{@user_person.diaspora_handle} sender=#{@sender.diaspora_handle} payload_type=#{@object.class})") + logger.error "event=receive status=abort reason='no corresponding post' type=#{@object.class} " \ + "recipient=#{@user_person.diaspora_handle} sender=#{@sender.diaspora_handle}" return true end end def contact_required_unless_request unless @object.is_a?(Request) || @user.contact_for(@sender) - FEDERATION_LOGGER.error("event=receive status=abort reason='sender not connected to recipient' recipient=#{@user_person.diaspora_handle} sender=#{@sender.diaspora_handle}") + logger.error "event=receive status=abort reason='sender not connected to recipient' type=#{@object.class} " \ + "recipient=#{@user_person.diaspora_handle} sender=#{@sender.diaspora_handle}" return true end end diff --git a/lib/postzord/receiver/public.rb b/lib/postzord/receiver/public.rb index 8c5d51d1f..002019ae6 100644 --- a/lib/postzord/receiver/public.rb +++ b/lib/postzord/receiver/public.rb @@ -10,7 +10,7 @@ class Postzord::Receiver::Public < Postzord::Receiver @salmon = Salmon::Slap.from_xml(xml) @author = Webfinger.new(@salmon.author_id).fetch - FEDERATION_LOGGER.info("Receiving public object from person:#{@author.id}") + logger.info "Receiving public object from person:#{@author.id}" end # @return [Boolean] @@ -25,7 +25,7 @@ class Postzord::Receiver::Public < Postzord::Receiver return false unless save_object - FEDERATION_LOGGER.info("received a #{@object.inspect}") + logger.info "received a #{@object.inspect}" if @object.is_a?(SignedRetraction) # feels like a hack self.recipient_user_ids.each do |user_id| user = User.where(id: user_id).first diff --git a/lib/webfinger.rb b/lib/webfinger.rb index 385c2b40b..5c28a4e90 100644 --- a/lib/webfinger.rb +++ b/lib/webfinger.rb @@ -3,6 +3,8 @@ # the COPYRIGHT file. class Webfinger + include Diaspora::Logging + attr_accessor :host_meta_xrd, :webfinger_profile_xrd, :webfinger_profile, :hcard, :hcard_xrd, :person, :account, :ssl @@ -28,7 +30,7 @@ class Webfinger end def get(url) - Rails.logger.info("Getting: #{url} for #{account}") + logger.info "Getting: #{url} for #{account}" begin res = Faraday.get(url) unless res.success? @@ -36,10 +38,10 @@ class Webfinger end res.body rescue OpenSSL::SSL::SSLError => e - Rails.logger.info "Failed to fetch #{url}: SSL setup invalid" + logger.error "Failed to fetch #{url}: SSL setup invalid" raise e rescue => e - Rails.logger.info("Failed to fetch: #{url} for #{account}; #{e.message}") + logger.error "Failed to fetch: #{url} for #{account}; #{e.message}" raise e end end @@ -53,13 +55,13 @@ class Webfinger end def create_or_update_person_from_webfinger_profile! - FEDERATION_LOGGER.info("webfingering #{account}, it is not known or needs updating") + logger.info "webfingering #{account}, it is not known or needs updating" if person #update my profile please person.assign_new_profile_from_hcard(self.hcard) else person = make_person_from_webfinger end - FEDERATION_LOGGER.info("successfully webfingered #{@account}") if person + logger.info "successfully webfingered #{@account}" if person person end @@ -98,7 +100,7 @@ class Webfinger def webfinger_profile_xrd @webfinger_profile_xrd ||= get(webfinger_profile_url) - FEDERATION_LOGGER.warn "#{@account} doesn't exists anymore" if @webfinger_profile_xrd == false + logger.warn "#{@account} doesn't exists anymore" if @webfinger_profile_xrd == false @webfinger_profile_xrd end From 27b4a44e4a2c2013794eaabc3aaa319aa6909894 Mon Sep 17 00:00:00 2001 From: Benjamin Neff Date: Thu, 4 Jun 2015 00:11:10 +0200 Subject: [PATCH 2/2] replace Rails.logger with logging-logger closes #6041 --- Changelog.md | 1 + app/controllers/messages_controller.rb | 3 ++- app/controllers/registrations_controller.rb | 4 ++-- app/controllers/services_controller.rb | 2 +- app/mailers/notification_mailers/base.rb | 2 +- app/models/mention.rb | 2 +- app/models/person.rb | 3 ++- app/models/profile.rb | 2 +- app/models/services/facebook.rb | 4 ++-- app/models/services/tumblr.rb | 2 +- app/models/services/twitter.rb | 4 ++-- app/models/user/connecting.rb | 4 ++-- app/models/user/querying.rb | 2 +- lib/diaspora/encryptable.rb | 16 +++++++--------- lib/diaspora/federated/base.rb | 4 +++- lib/diaspora/federated/relayable_retraction.rb | 11 +++++++---- lib/diaspora/federated/request.rb | 2 +- lib/diaspora/federated/retraction.rb | 13 ++++++++----- lib/diaspora/federated/shareable.rb | 16 +++++++++++----- lib/diaspora/federated/signed_retraction.rb | 10 ++++++---- lib/diaspora/fetcher/public.rb | 4 +++- lib/diaspora/relayable.rb | 3 ++- lib/evil_query.rb | 10 ++++++---- lib/hydra_wrapper.rb | 10 +++------- lib/postzord/dispatcher.rb | 10 +++++++--- lib/postzord/receiver.rb | 2 +- lib/postzord/receiver/private.rb | 3 ++- lib/salmon/encrypted_slap.rb | 9 +++++---- lib/webfinger_profile.rb | 6 ++++-- 29 files changed, 95 insertions(+), 69 deletions(-) diff --git a/Changelog.md b/Changelog.md index c2465c412..a2eb45b02 100644 --- a/Changelog.md +++ b/Changelog.md @@ -25,6 +25,7 @@ * Increase post titles length to 50 and use configured pod name as title in the atom feed [#6020](https://github.com/diaspora/diaspora/pull/6020) * Remove deprecated Facebook permissions [#6019](https://github.com/diaspora/diaspora/pull/6019) * Make used post title lengths more consistent [#6022](https://github.com/diaspora/diaspora/pull/6022) +* Improved logging source [#6041](https://github.com/diaspora/diaspora/pull/6041) ## Bug fixes * Disable auto follow back on aspect deletion [#5846](https://github.com/diaspora/diaspora/pull/5846) diff --git a/app/controllers/messages_controller.rb b/app/controllers/messages_controller.rb index e2f435af4..e0b32f671 100644 --- a/app/controllers/messages_controller.rb +++ b/app/controllers/messages_controller.rb @@ -15,7 +15,8 @@ class MessagesController < ApplicationController message = current_user.build_message(conversation, opts) if message.save - Rails.logger.info("event=create type=comment user=#{current_user.diaspora_handle} status=success message=#{message.id} chars=#{params[:message][:text].length}") + logger.info "event=create type=comment user=#{current_user.diaspora_handle} status=success " \ + "message=#{message.id} chars=#{params[:message][:text].length}" Postzord::Dispatcher.build(current_user, message).post else flash[:error] = I18n.t('conversations.new_conversation.fail') diff --git a/app/controllers/registrations_controller.rb b/app/controllers/registrations_controller.rb index 66dd0614d..ccdeada87 100644 --- a/app/controllers/registrations_controller.rb +++ b/app/controllers/registrations_controller.rb @@ -15,12 +15,12 @@ class RegistrationsController < Devise::RegistrationsController flash[:notice] = I18n.t 'registrations.create.success' @user.seed_aspects sign_in_and_redirect(:user, @user) - Rails.logger.info("event=registration status=successful user=#{@user.diaspora_handle}") + logger.info "event=registration status=successful user=#{@user.diaspora_handle}" else @user.errors.delete(:person) flash[:error] = @user.errors.full_messages.join(" - ") - Rails.logger.info("event=registration status=failure errors='#{@user.errors.full_messages.join(', ')}'") + logger.info "event=registration status=failure errors='#{@user.errors.full_messages.join(', ')}'" render :action => 'new', :layout => 'with_header' end end diff --git a/app/controllers/services_controller.rb b/app/controllers/services_controller.rb index ccc82c28d..68a1ba853 100644 --- a/app/controllers/services_controller.rb +++ b/app/controllers/services_controller.rb @@ -32,7 +32,7 @@ class ServicesController < ApplicationController end def failure - Rails.logger.info "error in oauth #{params.inspect}" + logger.info "error in oauth #{params.inspect}" flash[:error] = t('services.failure.error') redirect_to services_url end diff --git a/app/mailers/notification_mailers/base.rb b/app/mailers/notification_mailers/base.rb index efbde43a1..bf3569fad 100644 --- a/app/mailers/notification_mailers/base.rb +++ b/app/mailers/notification_mailers/base.rb @@ -53,7 +53,7 @@ module NotificationMailers " recipient_handle=#{@recipient.diaspora_handle}" log_string << " sender_handle=#{@sender.diaspora_handle}" if sender_id.present? - logger.info(log_string) + logger.info log_string end end end diff --git a/app/models/mention.rb b/app/models/mention.rb index d03ef6483..47c2f719a 100644 --- a/app/models/mention.rb +++ b/app/models/mention.rb @@ -13,7 +13,7 @@ class Mention < ActiveRecord::Base after_destroy :delete_notification def notify_recipient - Rails.logger.info "event=mention_sent id=#{self.id} to=#{person.diaspora_handle} from=#{post.author.diaspora_handle}" + logger.info "event=mention_sent id=#{id} to=#{person.diaspora_handle} from=#{post.author.diaspora_handle}" Notification.notify(person.owner, self, post.author) unless person.remote? end diff --git a/app/models/person.rb b/app/models/person.rb index 7dd83df26..fc966c4eb 100644 --- a/app/models/person.rb +++ b/app/models/person.rb @@ -261,7 +261,8 @@ class Person < ActiveRecord::Base new_person.url = profile.seed_location #hcard_profile = HCard.find profile.hcard.first[:href] - Rails.logger.info("event=webfinger_marshal valid=#{new_person.valid?} target=#{new_person.diaspora_handle}") + ::Logging::Logger[self].info "event=webfinger_marshal valid=#{new_person.valid?} " \ + "target=#{new_person.diaspora_handle}" new_person.url = hcard[:url] new_person.assign_new_profile_from_hcard(hcard) new_person.save! diff --git a/app/models/profile.rb b/app/models/profile.rb index b10f35deb..b89959232 100644 --- a/app/models/profile.rb +++ b/app/models/profile.rb @@ -56,7 +56,7 @@ class Profile < ActiveRecord::Base def receive(user, person) person.reload # make sure to have old profile referenced - Rails.logger.info("event=receive payload_type=profile sender=#{person} to=#{user}") + logger.info "event=receive payload_type=profile sender=#{person.diaspora_handle} to=#{user.diaspora_handle}" profiles_attr = self.attributes.merge('tag_string' => self.tag_string).slice('diaspora_handle', 'first_name', 'last_name', 'image_url', 'image_url_small', 'image_url_medium', 'birthday', 'gender', 'bio', 'location', 'searchable', 'nsfw', 'tag_string') person.profile.update_attributes(profiles_attr) diff --git a/app/models/services/facebook.rb b/app/models/services/facebook.rb index 65d1006c3..e15b9ecba 100644 --- a/app/models/services/facebook.rb +++ b/app/models/services/facebook.rb @@ -9,7 +9,7 @@ class Services::Facebook < Service end def post(post, url='') - Rails.logger.debug("event=post_to_service type=facebook sender_id=#{self.user_id}") + logger.debug "event=post_to_service type=facebook sender_id=#{user_id} post=#{post.guid}" response = post_to_facebook("https://graph.facebook.com/me/feed", create_post_params(post).to_param) response = JSON.parse response.body post.facebook_id = response["id"] @@ -39,7 +39,7 @@ class Services::Facebook < Service def delete_post(post) if post.present? && post.facebook_id.present? - Rails.logger.debug("event=delete_from_service type=facebook sender_id=#{self.user_id}") + logger.debug "event=delete_from_service type=facebook sender_id=#{user_id} post=#{post.guid}" delete_from_facebook("https://graph.facebook.com/#{post.facebook_id}/", {:access_token => self.access_token}) end end diff --git a/app/models/services/tumblr.rb b/app/models/services/tumblr.rb index 65cecedef..66dafe78c 100644 --- a/app/models/services/tumblr.rb +++ b/app/models/services/tumblr.rb @@ -43,7 +43,7 @@ class Services::Tumblr < Service def delete_post(post) if post.present? && post.tumblr_ids.present? - Rails.logger.debug("event=delete_from_service type=tumblr sender_id=#{self.user_id}") + logger.debug "event=delete_from_service type=tumblr sender_id=#{user_id} post=#{post.guid}" tumblr_posts = JSON.parse(post.tumblr_ids) tumblr_posts.each do |blog_name,post_id| delete_from_tumblr(blog_name, post_id) diff --git a/app/models/services/twitter.rb b/app/models/services/twitter.rb index 7c5d246ec..82e4d8071 100644 --- a/app/models/services/twitter.rb +++ b/app/models/services/twitter.rb @@ -10,7 +10,7 @@ class Services::Twitter < Service end def post post, url='' - Rails.logger.debug "event=post_to_service type=twitter sender_id=#{self.user_id}" + logger.debug "event=post_to_service type=twitter sender_id=#{user_id} post=#{post.guid}" tweet = attempt_post post post.tweet_id = tweet.id post.save @@ -22,7 +22,7 @@ class Services::Twitter < Service def delete_post post if post.present? && post.tweet_id.present? - Rails.logger.debug "event=delete_from_service type=twitter sender_id=#{self.user_id}" + logger.debug "event=delete_from_service type=twitter sender_id=#{user_id} post=#{post.guid}" delete_from_twitter post.tweet_id end end diff --git a/app/models/user/connecting.rb b/app/models/user/connecting.rb index 507a27079..333e6bd5e 100644 --- a/app/models/user/connecting.rb +++ b/app/models/user/connecting.rb @@ -53,7 +53,7 @@ module User::Connecting def disconnect(bad_contact, opts={}) person = bad_contact.person - Rails.logger.info("event=disconnect user=#{diaspora_handle} target=#{person.diaspora_handle}") + logger.info "event=disconnect user=#{diaspora_handle} target=#{person.diaspora_handle}" retraction = Retraction.for(self) retraction.subscribers = [person]#HAX Postzord::Dispatcher.build(self, retraction).post @@ -63,7 +63,7 @@ module User::Connecting end def disconnected_by(person) - Rails.logger.info("event=disconnected_by user=#{diaspora_handle} target=#{person.diaspora_handle}") + logger.info "event=disconnected_by user=#{diaspora_handle} target=#{person.diaspora_handle}" if contact = self.contact_for(person) remove_contact(contact, :retracted => true) end diff --git a/app/models/user/querying.rb b/app/models/user/querying.rb index a307e8a42..20d52df45 100644 --- a/app/models/user/querying.rb +++ b/app/models/user/querying.rb @@ -68,7 +68,7 @@ module User::Querying end def construct_public_followings_sql(opts) - Rails.logger.debug("[EVIL-QUERY] user.construct_public_followings_sql") + logger.debug "[EVIL-QUERY] user.construct_public_followings_sql" # For PostgreSQL and MySQL/MariaDB we use a different query # see issue: https://github.com/diaspora/diaspora/issues/5014 diff --git a/lib/diaspora/encryptable.rb b/lib/diaspora/encryptable.rb index b1db82c7a..486e23fac 100644 --- a/lib/diaspora/encryptable.rb +++ b/lib/diaspora/encryptable.rb @@ -1,5 +1,7 @@ module Diaspora module Encryptable + include Diaspora::Logging + # Check that signature is a correct signature of #signable_string by person # # @param [String] signature The signature to be verified. @@ -7,19 +9,17 @@ module Diaspora # @return [Boolean] def verify_signature(signature, person) if person.nil? - Rails.logger.info("event=verify_signature status=abort reason=no_person guid=#{self.guid}") + logger.warn "event=verify_signature status=abort reason=no_person guid=#{guid}" return false elsif person.public_key.nil? - Rails.logger.info("event=verify_signature status=abort reason=no_key guid=#{self.guid}") + logger.warn "event=verify_signature status=abort reason=no_key guid=#{guid}" return false elsif signature.nil? - Rails.logger.info("event=verify_signature status=abort reason=no_signature guid=#{self.guid}") + logger.warn "event=verify_signature status=abort reason=no_signature guid=#{guid}" return false end - log_string = "event=verify_signature status=complete guid=#{self.guid}" validity = person.public_key.verify OpenSSL::Digest::SHA256.new, Base64.decode64(signature), signable_string - log_string += " validity=#{validity}" - Rails.logger.info(log_string) + logger.info "event=verify_signature status=complete guid=#{guid} validity=#{validity}" validity end @@ -27,9 +27,7 @@ module Diaspora # @return [String] A Base64 encoded signature of #signable_string with key def sign_with_key(key) sig = Base64.strict_encode64(key.sign( OpenSSL::Digest::SHA256.new, signable_string )) - log_hash = {:event => :sign_with_key, :status => :complete} - log_hash.merge(:model_id => self.id) if self.respond_to?(:persisted?) - Rails.logger.info(log_hash) + logger.info "event=sign_with_key status=complete guid=#{guid}" sig end diff --git a/lib/diaspora/federated/base.rb b/lib/diaspora/federated/base.rb index 52ebcc858..ff93dc61a 100644 --- a/lib/diaspora/federated/base.rb +++ b/lib/diaspora/federated/base.rb @@ -11,7 +11,9 @@ module Diaspora module Federated - module Base + module Base + include Diaspora::Logging + def self.included(model) model.instance_eval do include ROXML diff --git a/lib/diaspora/federated/relayable_retraction.rb b/lib/diaspora/federated/relayable_retraction.rb index 3d48f6763..64b396797 100644 --- a/lib/diaspora/federated/relayable_retraction.rb +++ b/lib/diaspora/federated/relayable_retraction.rb @@ -30,17 +30,18 @@ class RelayableRetraction < SignedRetraction end def perform receiving_user - Rails.logger.debug "Performing relayable retraction for #{target_guid}" + logger.debug "Performing relayable retraction for #{target_guid}" if not self.parent_author_signature.nil? or self.parent.author.remote? # Don't destroy a relayable unless the top-level owner has received it, otherwise it may not get relayed self.target.destroy - Rails.logger.info("event=relayable_retraction status =complete target_type=#{self.target_type} guid =#{self.target_guid}") + logger.info "event=relayable_retraction status=complete target_type=#{target_type} guid=#{target_guid}" end end def receive(recipient, sender) if self.target.nil? - Rails.logger.info("event=retraction status=abort reason='no post found' sender=#{sender.diaspora_handle} target_guid=#{target_guid}") + logger.warn "event=retraction status=abort reason='no post found' sender=#{sender.diaspora_handle} " \ + "target_guid=#{target_guid}" return elsif self.parent.author == recipient.person && self.target_author_signature_valid? #this is a retraction from the downstream object creator, and the recipient is the upstream owner @@ -51,7 +52,9 @@ class RelayableRetraction < SignedRetraction #this is a retraction from the upstream owner self.perform(recipient) else - Rails.logger.info("event=receive status=abort reason='object signature not valid' recipient=#{recipient.diaspora_handle} sender=#{self.parent.author.diaspora_handle} payload_type=#{self.class} parent_id=#{self.parent.id}") + logger.warn "event=receive status=abort reason='object signature not valid' " \ + "recipient=#{recipient.diaspora_handle} sender=#{parent.author.diaspora_handle} " \ + "payload_type=#{self.class} parent_id=#{parent.id}" return end self diff --git a/lib/diaspora/federated/request.rb b/lib/diaspora/federated/request.rb index 239c3ed4e..5de3c0099 100644 --- a/lib/diaspora/federated/request.rb +++ b/lib/diaspora/federated/request.rb @@ -73,7 +73,7 @@ class Request # @note A [Contact] may already exist if the [Request]'s recipient is sharing with the sender # @return [Request] def receive(user, person) - Rails.logger.info("event=receive payload_type=request sender=#{self.sender} to=#{self.recipient}") + logger.info("event=receive payload_type=request sender=#{sender} to=#{recipient}") contact = user.contacts.find_or_initialize_by(person_id: self.sender.id) contact.sharing = true diff --git a/lib/diaspora/federated/retraction.rb b/lib/diaspora/federated/retraction.rb index e1798ed94..5927dca85 100644 --- a/lib/diaspora/federated/retraction.rb +++ b/lib/diaspora/federated/retraction.rb @@ -40,24 +40,27 @@ class Retraction end def perform receiving_user - Rails.logger.debug "Performing retraction for #{post_guid}" + logger.debug "Performing retraction for #{post_guid}" self.target.destroy if self.target - Rails.logger.info("event=retraction status=complete type=#{self.type} guid=#{self.post_guid}") + logger.info "event=retraction status=complete type=#{type} guid=#{post_guid}" end def receive(user, person) if self.type == 'Person' unless self.person.guid.to_s == self.post_guid.to_s - Rails.logger.info("event=receive status=abort reason='sender is not the person he is trying to retract' recipient=#{self.diaspora_handle} sender=#{self.person.diaspora_handle} payload_type=#{self.class} retraction_type=person") + logger.warn "event=receive status=abort reason='sender is not the person he is trying to retract' " \ + "recipient=#{diaspora_handle} sender=#{self.person.diaspora_handle} " \ + "payload_type=#{self.class} retraction_type=person" return end user.disconnected_by(self.target) elsif self.target.nil? || self.target.author != self.person - Rails.logger.info("event=retraction status=abort reason='no post found authored by retractor' sender=#{person.diaspora_handle} post_guid=#{post_guid}") + logger.warn "event=retraction status=abort reason='no post found authored by retractor' " \ + "sender=#{person.diaspora_handle} post_guid=#{post_guid}" else self.perform(user) end self end -end \ No newline at end of file +end diff --git a/lib/diaspora/federated/shareable.rb b/lib/diaspora/federated/shareable.rb index 3921395cb..1803db314 100644 --- a/lib/diaspora/federated/shareable.rb +++ b/lib/diaspora/federated/shareable.rb @@ -24,6 +24,7 @@ module Diaspora end module InstanceMethods + include Diaspora::Logging def diaspora_handle read_attribute(:diaspora_handle) || self.author.diaspora_handle end @@ -52,7 +53,8 @@ module Diaspora self.receive_non_persisted(user, person) else - Rails.logger.info("event=receive payload_type=#{self.class} update=true status=abort sender=#{self.diaspora_handle} reason='update not from shareable owner' existing_shareable=#{self.id}") + logger.warn "event=receive payload_type=#{self.class} update=true status=abort " \ + "sender=#{diaspora_handle} reason='update not from shareable owner' existing_shareable=#{id}" false end end @@ -88,13 +90,15 @@ module Diaspora known_shareable.update_attributes(self.attributes.except("id")) true else - Rails.logger.info("event=receive payload_type=#{self.class} update=true status=abort sender=#{self.diaspora_handle} reason=immutable") #existing_shareable=#{known_shareable.id}") + logger.warn "event=receive payload_type=#{self.class} update=true status=abort " \ + "sender=#{diaspora_handle} reason=immutable existing_shareable=#{known_shareable.id}" false end else user.contact_for(person).receive_shareable(local_shareable) user.notify_if_mentioned(local_shareable) - Rails.logger.info("event=receive payload_type=#{self.class} update=true status=complete sender=#{self.diaspora_handle}") #existing_shareable=#{local_shareable.id}") + logger.info "event=receive payload_type=#{self.class} update=true status=complete " \ + "sender=#{diaspora_handle} existing_shareable=#{local_shareable.id}" true end end @@ -103,10 +107,12 @@ module Diaspora if self.save user.contact_for(person).receive_shareable(self) user.notify_if_mentioned(self) - Rails.logger.info("event=receive payload_type=#{self.class} update=false status=complete sender=#{self.diaspora_handle}") + logger.info "event=receive payload_type=#{self.class} update=false status=complete " \ + "sender=#{diaspora_handle}" true else - Rails.logger.info("event=receive payload_type=#{self.class} update=false status=abort sender=#{self.diaspora_handle} reason=#{self.errors.full_messages}") + logger.warn "event=receive payload_type=#{self.class} update=false status=abort " \ + "sender=#{diaspora_handle} reason=#{errors.full_messages}" false end end diff --git a/lib/diaspora/federated/signed_retraction.rb b/lib/diaspora/federated/signed_retraction.rb index 9a1f6d367..b2ce3fd51 100644 --- a/lib/diaspora/federated/signed_retraction.rb +++ b/lib/diaspora/federated/signed_retraction.rb @@ -72,7 +72,7 @@ class SignedRetraction end def perform receiving_user - Rails.logger.debug "Performing retraction for #{target_guid}" + logger.debug "Performing retraction for #{target_guid}" if reshare = Reshare.where(:author_id => receiving_user.person.id, :root_guid => target_guid).first onward_retraction = self.dup onward_retraction.sender = receiving_user.person @@ -81,18 +81,20 @@ class SignedRetraction if target && !target.destroyed? self.target.destroy end - Rails.logger.info("event=retraction status =complete target_type=#{self.target_type} guid =#{self.target_guid}") + logger.info "event=retraction status=complete target_type=#{target_type} guid=#{target_guid}" end def receive(recipient, sender) if self.target.nil? - Rails.logger.info("event=retraction status=abort reason='no post found' sender=#{sender.diaspora_handle} target_guid=#{target_guid}") + logger.warn "event=retraction status=abort reason='no post found' sender=#{sender.diaspora_handle} " \ + "target_guid=#{target_guid}" return elsif self.target_author_signature_valid? #this is a retraction from the upstream owner self.perform(recipient) else - Rails.logger.info("event=receive status=abort reason='object signature not valid' recipient=#{recipient.diaspora_handle} sender=#{self.sender_handle} payload_type=#{self.class}") + logger.warn "event=receive status=abort reason='object signature not valid' " \ + "recipient=#{recipient.diaspora_handle} sender=#{sender_handle} payload_type=#{self.class}" return end self diff --git a/lib/diaspora/fetcher/public.rb b/lib/diaspora/fetcher/public.rb index acc0e6479..7b7e90d1e 100644 --- a/lib/diaspora/fetcher/public.rb +++ b/lib/diaspora/fetcher/public.rb @@ -159,7 +159,9 @@ module Diaspora; module Fetcher; class Public guid = post['author']['guid'] equal = (guid == @person.guid) - logger.warn "the author (#{guid}) does not match the person currently being processed (#{@person.guid})" unless equal + unless equal + logger.warn "the author (#{guid}) does not match the person currently being processed (#{@person.guid})" + end equal end diff --git a/lib/diaspora/relayable.rb b/lib/diaspora/relayable.rb index 4f43ed402..87c19a2ff 100644 --- a/lib/diaspora/relayable.rb +++ b/lib/diaspora/relayable.rb @@ -71,7 +71,8 @@ module Diaspora # Check to make sure the signature of the comment or like comes from the person claiming to author it unless comment_or_like.parent_author == user.person || comment_or_like.verify_parent_author_signature - Rails.logger.info("event=receive status=abort reason='object signature not valid' recipient=#{user.diaspora_handle} sender=#{self.parent.author.diaspora_handle} payload_type=#{self.class} parent_id=#{self.parent.id}") + logger.warn "event=receive status=abort reason='object signature not valid' recipient=#{user.diaspora_handle} "\ + "sender=#{parent.author.diaspora_handle} payload_type=#{self.class} parent_id=#{parent.id}" return end diff --git a/lib/evil_query.rb b/lib/evil_query.rb index 395022b8b..20e0e66d6 100644 --- a/lib/evil_query.rb +++ b/lib/evil_query.rb @@ -1,5 +1,7 @@ module EvilQuery class Base + include Diaspora::Logging + def fetch_ids!(relation, id_column) #the relation should be ordered and limited by here @class.connection.select_values(id_sql(relation, id_column)) @@ -51,24 +53,24 @@ module EvilQuery end def make_relation! - Rails.logger.debug("[EVIL-QUERY] make_relation!") + logger.debug("[EVIL-QUERY] make_relation!") post_ids = aspects_post_ids! + ids!(followed_tags_posts!) + ids!(mentioned_posts) post_ids += ids!(community_spotlight_posts!) if @include_spotlight Post.where(:id => post_ids) end def aspects_post_ids! - Rails.logger.debug("[EVIL-QUERY] aspect_post_ids!") + logger.debug("[EVIL-QUERY] aspect_post_ids!") @user.visible_shareable_ids(Post, :limit => 15, :order => "#{@order} DESC", :max_time => @max_time, :all_aspects? => true, :by_members_of => @user.aspect_ids) end def followed_tags_posts! - Rails.logger.debug("[EVIL-QUERY] followed_tags_posts!") + logger.debug("[EVIL-QUERY] followed_tags_posts!") StatusMessage.public_tag_stream(@user.followed_tag_ids) end def mentioned_posts - Rails.logger.debug("[EVIL-QUERY] mentioned_posts") + logger.debug("[EVIL-QUERY] mentioned_posts") StatusMessage.where_person_is_mentioned(@user.person) end diff --git a/lib/hydra_wrapper.rb b/lib/hydra_wrapper.rb index f7f3c7c2b..7461d792a 100644 --- a/lib/hydra_wrapper.rb +++ b/lib/hydra_wrapper.rb @@ -3,6 +3,7 @@ # the COPYRIGHT file. class HydraWrapper + include Diaspora::Logging OPTS = { maxredirs: 3, @@ -90,13 +91,8 @@ class HydraWrapper end unless response.success? - message = { - event: "http_multi_fail", - sender_id: @user.id, - url: response.effective_url, - return_code: response.return_code - } - Rails.logger.info message.to_a.map { |k,v| "#{k}=#{v}" }.join(' ') + logger.warn "event=http_multi_fail sender_id=#{@user.id} url=#{response.effective_url} " \ + "return_code=#{response.return_code} response_code=#{response.response_code}" if @keep_for_retry_proc.call(response) @people_to_retry += people_for_receive_url.map(&:id) diff --git a/lib/postzord/dispatcher.rb b/lib/postzord/dispatcher.rb index 8225397d3..540d4d96d 100644 --- a/lib/postzord/dispatcher.rb +++ b/lib/postzord/dispatcher.rb @@ -4,6 +4,8 @@ class Postzord::Dispatcher + include Diaspora::Logging + require 'postzord/dispatcher/private' require 'postzord/dispatcher/public' @@ -124,7 +126,8 @@ class Postzord::Dispatcher batch_deliver_to_local(people) else people.each do |person| - Rails.logger.info("event=push route=local sender=#{@sender.diaspora_handle} recipient=#{person.diaspora_handle} payload_type=#{@object.class}") + logger.info "event=push route=local sender=#{@sender.diaspora_handle} recipient=#{person.diaspora_handle} " \ + "payload_type=#{@object.class}" Workers::Receive.perform_async(person.owner_id, @xml, @sender.person_id) end end @@ -134,11 +137,12 @@ class Postzord::Dispatcher def batch_deliver_to_local(people) ids = people.map{ |p| p.owner_id } Workers::ReceiveLocalBatch.perform_async(@object.class.to_s, @object.id, ids) - Rails.logger.info("event=push route=local sender=#{@sender.diaspora_handle} recipients=#{ids.join(',')} payload_type=#{@object.class}") + logger.info "event=push route=local sender=#{@sender.diaspora_handle} recipients=#{ids.join(',')} " \ + "payload_type=#{@object.class}" end def deliver_to_hub - Rails.logger.debug("event=post_to_service type=pubsub sender_handle=#{@sender.diaspora_handle}") + logger.debug "event=post_to_service type=pubsub sender_handle=#{@sender.diaspora_handle}" Workers::PublishToHub.perform_async(@sender.public_url) end diff --git a/lib/postzord/receiver.rb b/lib/postzord/receiver.rb index cb99c2bc2..deb44216f 100644 --- a/lib/postzord/receiver.rb +++ b/lib/postzord/receiver.rb @@ -16,7 +16,7 @@ class Postzord::Receiver def author_does_not_match_xml_author? if (@author.diaspora_handle != xml_author) - logger.info "event=receive status=abort reason='author in xml does not match retrieved person' " \ + logger.warn "event=receive status=abort reason='author in xml does not match retrieved person' " \ "payload_type=#{@object.class} sender=#{@author.diaspora_handle}" return true end diff --git a/lib/postzord/receiver/private.rb b/lib/postzord/receiver/private.rb index 224eacf78..80640383c 100644 --- a/lib/postzord/receiver/private.rb +++ b/lib/postzord/receiver/private.rb @@ -44,7 +44,8 @@ class Postzord::Receiver::Private < Postzord::Receiver def receive_object obj = @object.receive(@user, @author) Notification.notify(@user, obj, @author) if obj.respond_to?(:notification_type) - logger.info "user:#{@user.id} successfully received #{@object.class} from person #{@sender.guid}: #{@object.inspect}" + logger.info "user:#{@user.id} successfully received #{@object.class} from person #{@sender.guid}: " \ + "#{@object.inspect}" obj end diff --git a/lib/salmon/encrypted_slap.rb b/lib/salmon/encrypted_slap.rb index 21cc7409c..64c167883 100644 --- a/lib/salmon/encrypted_slap.rb +++ b/lib/salmon/encrypted_slap.rb @@ -4,6 +4,7 @@ module Salmon class EncryptedSlap < Slap + include Diaspora::Logging # Construct an encrypted header # @return [String] Header XML @@ -28,13 +29,13 @@ HEADER # @return [String, Boolean] False if RSAError; XML if no error def xml_for(person) begin - super + super rescue OpenSSL::PKey::RSAError => e - Rails.logger.info("event => :invalid_rsa_key, :identifier => #{person.diaspora_handle}") + logger.error "event=invalid_rsa_key identifier=#{person.diaspora_handle}" false end end - + # Takes in a doc of the header and sets the author id # returns an empty hash # @return [Hash] @@ -43,7 +44,7 @@ HEADER self.aes_key = doc.search('aes_key').text self.iv = doc.search('iv').text end - + # Decrypts an encrypted magic sig envelope # @param key_hash [Hash] Contains 'key' (aes) and 'iv' values # @param user [User] diff --git a/lib/webfinger_profile.rb b/lib/webfinger_profile.rb index 5fe33d705..44259e200 100644 --- a/lib/webfinger_profile.rb +++ b/lib/webfinger_profile.rb @@ -1,4 +1,6 @@ class WebfingerProfile + include Diaspora::Logging + attr_accessor :webfinger_profile, :account, :links, :hcard, :guid, :public_key, :seed_location def initialize(account, webfinger_profile) @@ -20,7 +22,7 @@ class WebfingerProfile doc.remove_namespaces! account_string = doc.css('Subject').text.gsub('acct:', '').strip - + raise "account in profile(#{account_string}) and account requested (#{@account}) do not match" if account_string != @account doc.css('Link').each do |l| @@ -41,7 +43,7 @@ class WebfingerProfile pubkey = text_of_attribute( doc.at('Link[rel=diaspora-public-key]'), 'href') @public_key = Base64.decode64 pubkey rescue => e - Rails.logger.info("event => :invalid_profile, :identifier => #{@account}") + logger.warn "event=invalid_profile identifier=#{@account}" end end