Merge branch 'stable' into develop

This commit is contained in:
Dennis Schubert 2015-06-04 04:18:34 +02:00
commit b41007fae7
41 changed files with 161 additions and 238 deletions

View file

@ -55,6 +55,7 @@ Ruby 2.0 is no longer officially supported.
* 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)

View file

@ -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')

View file

@ -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

View file

@ -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

View file

@ -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

View file

@ -1,5 +1,7 @@
module NotificationMailers
class Base
include Diaspora::Logging
attr_accessor :recipient, :sender
delegate :unconfirmed_email, :confirm_email_token,
@ -51,11 +53,7 @@ module NotificationMailers
" recipient_handle=#{@recipient.diaspora_handle}"
log_string << " sender_handle=#{@sender.diaspora_handle}" if sender_id.present?
logger.info(log_string)
end
def logger
@logger ||= ::Logging::Logger[self]
logger.info log_string
end
end
end

View file

@ -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

View file

@ -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!

View file

@ -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)

View file

@ -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

View file

@ -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)

View file

@ -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

View file

@ -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

View file

@ -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

View file

@ -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

View file

@ -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

View file

@ -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

View file

@ -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

View file

@ -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'

View file

@ -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

View file

@ -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

View file

@ -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

View file

@ -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

View file

@ -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
end

View file

@ -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

View file

@ -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

View file

@ -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,9 @@ 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
unless equal
logger.warn "the author (#{guid}) does not match the person currently being processed (#{@person.guid})"
end
equal
end
@ -167,7 +170,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 +179,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

10
lib/diaspora/logging.rb Normal file
View file

@ -0,0 +1,10 @@
# a logging mixin providing the logger
module Diaspora
module Logging
private
def logger
@logger ||= ::Logging::Logger[self]
end
end
end

View file

@ -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

View file

@ -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

View file

@ -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
end

View file

@ -1,107 +0,0 @@
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
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 = Logger.new(logfile) #constant accessible anywhere
FEDERATION_LOGGER.formatter = Formatter.new
else
FEDERATION_LOGGER = Rails.logger
end

View file

@ -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)

View file

@ -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

View file

@ -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.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
end

View file

@ -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

View file

@ -19,36 +19,33 @@ 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 +88,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

View file

@ -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

View file

@ -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]

View file

@ -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

View file

@ -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