maverick/docbrown
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

Upgrade Honeycomb gem, fix and improve RssReader tests (#2319)

Browse source 
* Switch from deprecated honeycomb-rails to honeycomb-beeline

* Improve error handling, tests and add refactoring

* Fix multiple fetching test and add one more

The test wasn't actually testing the correct behavior, because the class
by default force fetches. It worked because it wasn't reloading the user
from the database.

* Test that Honeycomb's client is doing its thing

* Use some defensive programming to avoid any possible problem during shutdown

* Fix typo

* Use the new API to add fields to the current measured event

* Use default instrumentation and add user info to event

* Replace user.email with user.username, less personal data around

* Use mocking instead of calling Honeycomb.init

* Freeze time before traveling

* Remove a flaky test dependent on rand
This commit is contained in:
rhymes 2019-04-07 21:27:53 +02:00 • committed by Ben Halpern
parent b4484ba06d
commit 3b4bda89df
10 changed files with 224 additions and 123 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

17
Gemfile
View file

@ -14,8 +14,8 @@ end
gem "actionpack-action_caching", "~> 1.2"
gem "active_record_union", "~> 1.3"
gem "acts-as-taggable-on", "~> 6.0"
gem "acts_as_follower", github: "thepracticaldev/acts_as_follower", branch: "master"
gem "acts-as-taggable-on", "~> 6.0"
gem "addressable", "~> 2.5", ">= 2.5.2"
gem "administrate", "~> 0.11"
gem "ahoy_email", "~> 0.5"
@ -28,8 +28,8 @@ gem "aws-sdk-lambda", "~> 1.16" # Just Lambda. For more, install aws-sdk gem
gem "bootsnap", ">= 1.1.0", require: false
gem "bourbon", "~> 5.1"
gem "buffer", "~> 0.1"
gem "carrierwave", "~> 1.3"
gem "carrierwave-bombshelter", "~> 0.2"
gem "carrierwave", "~> 1.3"
gem "cloudinary", "~> 1.11"
gem "counter_culture", "~> 2.1"
gem "csv_shaper", "~> 1.3"
@ -42,8 +42,8 @@ gem "dry-struct", "~> 0.6"
gem "email_validator", "~> 2.0"
gem "emoji_regex", "~> 1.0"
gem "envied", "~> 0.9"
gem "fastly", "~> 1.15"
gem "fastly-rails", "~> 0.8"
gem "fastly", "~> 1.15"
gem "feedjira", "~> 2.2"
gem "figaro", "~> 1.1"
gem "fog", "~> 1.41"
@ -51,32 +51,31 @@ gem "front_matter_parser", "~> 0.2"
gem "gemoji", "~> 3.0.0"
gem "gibbon", "~> 3.2"
gem "google-api-client", "~> 0.27"
gem "honeycomb-rails"
gem 'honeycomb-beeline', "~> 0.7.0"
gem "html_truncator", "~> 0.4"
gem "httparty", "~> 0.16"
gem "inline_svg", "~> 1.3"
gem "jbuilder", "~> 2.8"
gem "jquery-rails", "~> 4.3"
gem "kaminari", "~> 1.1"
gem "libhoney", "~> 1.12"
gem "liquid", "~> 4.0"
gem "nokogiri", "~> 1.10"
gem "octokit", "~> 4.13"
gem "omniauth", "~> 1.9"
gem "omniauth-github", "~> 1.3"
gem "omniauth-twitter", "~> 1.4"
gem "omniauth", "~> 1.9"
gem "pg", "~> 1.1"
gem "pry", "~> 0.12"
gem "pry-rails", "~> 0.3"
gem "pry", "~> 0.12"
gem "puma", "~> 3.12"
gem "pundit", "~> 2.0"
gem "pusher", "~> 1.3"
gem "pusher-push-notifications", "~> 1.0"
gem "pusher", "~> 1.3"
gem "rack-host-redirect", "~> 1.3"
gem "rack-timeout", "~> 0.5"
gem "rails", "~> 5.2", ">= 5.2.3"
gem "rails-assets-airbrake-js-client", "~> 1.5", source: "https://rails-assets.org"
gem "rails-observers", "~> 0.1"
gem "rails", "~> 5.2", ">= 5.2.3"
gem "recaptcha", "~> 4.13", require: "recaptcha/rails"
gem "redcarpet", "~> 3.4"
gem "reverse_markdown", "~> 1.1"

17
Gemfile.lock
View file

@ -59,6 +59,8 @@ GEM
activemodel (= 5.2.3)
activesupport (= 5.2.3)
arel (>= 9.0)
activerecord-honeycomb (0.4.0)
libhoney
activestorage (5.2.3)
actionpack (= 5.2.3)
activerecord (= 5.2.3)
@ -330,6 +332,8 @@ GEM
i18n (>= 0.7)
faraday (0.15.4)
multipart-post (>= 1.2, < 3)
faraday-honeycomb (0.3.1)
libhoney (>= 1.5.0)
faraday_middleware (0.13.1)
faraday (>= 0.7.4, < 1.0)
fastimage (2.1.1)
@ -544,9 +548,11 @@ GEM
hashie (3.6.0)
heapy (0.1.4)
hkdf (0.3.0)
honeycomb-rails (0.8.1)
libhoney (>= 1.9)
rails (>= 3.0.0)
honeycomb-beeline (0.7.0)
activerecord-honeycomb (>= 0.4.0)
faraday-honeycomb (>= 0.3.0)
libhoney (>= 1.8.1)
rack-honeycomb (>= 0.4.0)
html_tokenizer (0.0.7)
html_truncator (0.4.2)
nokogiri (~> 1.5)
@ -705,6 +711,8 @@ GEM
pusher-signature (0.1.8)
raabro (1.1.6)
rack (2.0.6)
rack-honeycomb (0.5.0)
libhoney (>= 1.5.0)
rack-host-redirect (1.3.0)
rack
rack-protection (2.0.5)
@ -1033,7 +1041,7 @@ DEPENDENCIES
guard (~> 2.15)
guard-livereload (~> 2.5)
guard-rspec (~> 4.7)
honeycomb-rails
honeycomb-beeline (~> 0.7.0)
html_truncator (~> 0.4)
httparty (~> 0.16)
inline_svg (~> 1.3)
@ -1041,7 +1049,6 @@ DEPENDENCIES
jquery-rails (~> 4.3)
kaminari (~> 1.1)
launchy (~> 2.4)
libhoney (~> 1.12)
liquid (~> 4.0)
memory_profiler (~> 0.9)
nakayoshi_fork

5
app/controllers/application_controller.rb
View file

@ -78,9 +78,4 @@ class ApplicationController < ActionController::Base
def touch_current_user
current_user.touch
end
def append_info_to_payload(payload)
super(payload)
append_to_honeycomb(request, self.class.name)
end
end

139
app/services/rss_reader.rb
View file

@ -1,7 +1,3 @@
require "nokogiri"
require "httparty"
require "securerandom"
class RssReader
def self.get_all_articles(force = true)
new.get_all_articles(force)
@ -13,15 +9,18 @@ class RssReader
def get_all_articles(force = true)
User.where.not(feed_url: [nil, ""]).find_each do |user|
next if force == false && (rand(2) == 1 || user.feed_fetched_at > 15.minutes.ago) # Don't fetch every time.
# unless forced, fetch sparingly
next if force == false && (rand(2) == 1 || user.feed_fetched_at > 15.minutes.ago)
create_articles_for_user(user)
end
end
def fetch_user(user)
Thread.current[:request_id] = @request_id
Thread.current[:span_id] = @request_id
# add request_id to thread current variables to aid Honeycomb instrumentation
Thread.current[:request_id] = request_id
Thread.current[:span_id] = request_id
create_articles_for_user(user)
end
@ -33,26 +32,34 @@ class RssReader
private
attr_reader :request_id
def create_articles_for_user(user)
with_span("create_articles_for_user", user_id: user.id, username: user.username) do |metadata|
user.update_column(:feed_fetched_at, Time.current)
feed = fetch_rss(user.feed_url.strip)
metadata[:feed_length] = feed.entries.length if feed&.entries
feed.entries.reverse_each do |item|
make_from_rss_item(item, user, feed)
rescue StandardError => e
log_error("RssReaderError: occurred while creating article for",
user: user.username,
feed_url: user.feed_url,
item_count: get_item_count_error(feed),
error: e)
log_error(
"RssReaderError: occurred while creating article",
user: user.username,
feed_url: user.feed_url,
item_count: get_item_count_error(feed),
error: e,
)
end
rescue StandardError => e
log_error("RssReaderError: occurred while fetch feed for",
user: user.username,
feed_url: user.feed_url,
item_count: get_item_count_error(feed),
error: e)
log_error(
"RssReaderError: occurred while fetching feed",
user: user.username,
feed_url: user.feed_url,
item_count: get_item_count_error(feed),
error: e,
)
end
end
@ -76,33 +83,29 @@ class RssReader
end
def make_from_rss_item(item, user, feed)
with_span("make_from_rss_item",
item_id: item.entry_id,
item_title: item.title,
item_summary_size: item.summary&.size) do |metadata|
return if medium_reply?(item) || article_exist?(user, item)
with_span(
"make_from_rss_item",
item_id: item.entry_id,
item_title: item.title,
item_summary_size: item.summary&.size,
) do |metadata|
return if medium_reply?(item) || article_exists?(user, item)
article_params = {
feed_source_url: feed_source_url = item.url.strip.split("?source=")[0],
user_id: user.id,
published_at: item.published,
published_from_feed: true,
show_comments: true,
# body_markdown: assemble_body_markdown(item, user, feed, feed_source_url),
body_markdown: RssReader::Assembler.call(item, user, feed, feed_source_url),
organization_id: user.organization_id.presence
}
article = with_timer("save_article", metadata) do
Article.create!(article_params)
feed_source_url = item.url.strip.split("?source=")[0]
Article.create!(
feed_source_url: feed_source_url,
user_id: user.id,
published_at: item.published,
published_from_feed: true,
show_comments: true,
body_markdown: RssReader::Assembler.call(item, user, feed, feed_source_url),
organization_id: user.organization_id.presence,
)
end
return unless Rails.env.production?
SlackBot.delay.ping(
"New Article Retrieved via RSS: #{article.title}\nhttps://dev.to#{article.path}",
channel: "activity",
username: "article_bot",
icon_emoji: ":robot_face:",
)
send_slack_notification(article)
end
end
@ -125,27 +128,46 @@ class RssReader
content.include?(title)
end
def article_exist?(user, item)
user.articles.find_by("title = ? OR feed_source_url = ?", item.title.strip.gsub('"', '\"'), item.url.strip.split("?source=")[0])
def article_exists?(user, item)
title = item.title.strip.gsub('"', '\"')
feed_source_url = item.url.strip.split("?source=")[0]
relation = user.articles
relation.where(title: title).or(relation.where(feed_source_url: feed_source_url)).exists?
end
def send_slack_notification(article)
return unless Rails.env.production?
SlackBot.delay.ping(
"New Article Retrieved via RSS: #{article.title}\nhttps://dev.to#{article.path}",
channel: "activity",
username: "article_bot",
icon_emoji: ":robot_face:",
)
end
def log_error(error_msg, metadata)
logger = Logger.new(STDOUT)
parts = metadata.map { |k, v| [k.upcase.to_s.sub(/_/, "-"), v].join(": ") }
parts = parts.unshift(error_msg)
logger.info(parts.join(" "))
# giving the error message a resemblance of structured logging
parts = metadata.map { |k, v| [k, v].join("=") }
parts = parts.unshift("#{error_msg}:")
Rails.logger.error(parts.join(" "))
# log error to Honeycomb if initialized
return unless Honeycomb.client
# log error to Honeycomb
ev = Honeycomb.client.event
ev.add(metadata)
ev.add_field("error_msg", error_msg)
ev.add_field("trace.trace_id", @request_id)
parent_id = Thread.current[:span_id] || @request_id
ev.add_field("trace.parent_id", parent_id)
ev.add_field("trace.trace_id", request_id)
ev.add_field("trace.parent_id", Thread.current[:span_id] || request_id)
ev.add_field("trace.span_id", SecureRandom.uuid)
ev.send
end
# NOTE: honeycomb-beeline makes "with_span" theoretically obsolete,
# unfortunately there's a bug that prevents the gem to add fields after a
# a span has been initiated, so for now we'll keep this code in.
# see <https://github.com/honeycombio/beeline-ruby/issues/8>
# This wrapper takes a span name, some optional metadata, and a block; then
# emits a "span" to Honeycomb as part of the trace begun in the RequestTracer
# middleware.
@ -155,13 +177,13 @@ class RssReader
# into the block.
def with_span(name, metadata = nil)
trace_id = Thread.current[:request_id]
return yield({}) unless trace_id
return yield({}) unless trace_id && Honeycomb.client
id = SecureRandom.uuid
start = Time.new
current_span_id = SecureRandom.uuid
start = Time.current
data = {
name: name,
"trace.span_id": id,
"trace.span_id": current_span_id,
"trace.trace_id": trace_id,
service_name: "rss_reader"
}
@ -172,10 +194,10 @@ class RssReader
# Set the current span ID before invoking the provided block, then capture
# the return value to return after emitting the Honeycomb event.
Thread.current[:span_id] = id
Thread.current[:span_id] = span_id
ret = yield data
data[:duration_ms] = (Time.new - start) * 1000
data[:duration_ms] = (Time.current - start) * 1000
data.merge!(metadata) if metadata
# log event to Honeycomb
@ -190,10 +212,9 @@ class RssReader
end
def with_timer(name, data)
start = Time.new
start = Time.current
ret = yield
data[name + "_dur_ms"] = (Time.new - start) * 1000 if data
data[name + "_dur_ms"] = (Time.current - start) * 1000 if data
ret
end
end

10
config.ru
View file

@ -1,4 +1,14 @@
# This file is used by Rack-based servers to start the application.
# Honeycomb must be initialized before the Rails app starts
# see <https://docs.honeycomb.io/getting-data-in/ruby/beeline/> for details
require "honeycomb-beeline"
Honeycomb.init(
writekey: ENV["HONEYCOMB_API_KEY"],
# NOTE: dataset should probably be set using "HONEYCOMB_DATASET" env,
# to avoid hardcoding "dev.to" as a name
dataset: "dev.to-#{ENV['RAILS_ENV']}",
)
require ::File.expand_path("../config/environment", __FILE__)
run Rails.application

27
config/initializers/honeycomb.rb
View file

@ -1,27 +0,0 @@
require "libhoney"
module Honeycomb
class << self
attr_accessor :client
end
end
key = ApplicationConfig["HONEYCOMB_API_KEY"]
dataset = "dev.to-#{Rails.env}"
Honeycomb.client = if Rails.env.development? || Rails.env.test?
Libhoney::NullClient.new
else
Libhoney::Client.new(
writekey: key,
dataset: dataset,
user_agent_addition: HoneycombRails::USER_AGENT_SUFFIX,
)
end
HoneycombRails.configure do |conf|
conf.writekey = key
conf.dataset = dataset
conf.db_dataset = "dev.to-db-#{Rails.env}"
conf.client = Honeycomb.client
end

4
config/initializers/shutdown.rb Normal file
View file

@ -0,0 +1,4 @@
# adding an exit hook to properly shutdown/close third party clients
at_exit do
Honeycomb.shutdown if defined?(Honeycomb) && Honeycomb.respond_to?(:shutdown)
end

20
lib/instrumentation.rb
View file

@ -1,22 +1,26 @@
require "rack/honeycomb/middleware"
module Instrumentation
def self.included(base)
base.before_action :add_user_info_to_honeycomb_event
end
def add_param_context(*keys)
keys.each do |key|
honeycomb_metadata[key] = params[key]
Rack::Honeycomb.add_field(request.env, key, params[key])
end
end
def add_context(metadata)
metadata.each do |key, value|
honeycomb_metadata[key] = value
Rack::Honeycomb.add_field(request.env, key, value)
end
end
def append_to_honeycomb(request, controller_name)
return if honeycomb_metadata.nil?
def add_user_info_to_honeycomb_event
return unless current_user
honeycomb_metadata["trace.trace_id"] = request.request_id
honeycomb_metadata["trace.span_id"] = request.request_id
honeycomb_metadata[:service_name] = "rails"
honeycomb_metadata[:name] = controller_name
Rack::Honeycomb.add_field(request.env, "user.id", current_user.id)
Rack::Honeycomb.add_field(request.env, "user.username", current_user.username)
end
end

0
spec/fixtures/approvals/rssreader/get_all_articles/gets_articles_for_user.approved.txt → spec/fixtures/approvals/rssreader/fetch_user/gets_articles_for_user.approved.txt vendored
View file

108
spec/services/rss_reader_spec.rb
View file

@ -6,12 +6,36 @@ vcr_option = {
allow_playback_repeats: "true"
}
class HoneycombEventStub
attr_reader :data
def initialize
@data = {}
end
def add(metadata)
@data.merge!(metadata)
end
def add_field(key, value)
@data[key] = value
end
end
RSpec.describe RssReader, vcr: vcr_option do
let(:link) { "https://medium.com/feed/@vaidehijoshi" }
let(:nonmedium_link) { "https://circleci.com/blog/feed.xml" }
let(:nonpermanent_link) { "https://medium.com/feed/@macsiri/" }
let(:rss_data) { RSS::Parser.parse(HTTParty.get(link).body, false) }
before do
# Honeycomb.init has too many side effects during testing, so we mock the client
event = HoneycombEventStub.new
allow(event).to receive(:send)
client_double = instance_double("Libhoney::TestClient", event: event, events: [event])
allow(Honeycomb).to receive(:client) { client_double }
end
describe "#get_all_articles" do
before do
[link, nonmedium_link, nonpermanent_link].each do |feed_url|
@ -43,17 +67,41 @@ RSpec.describe RssReader, vcr: vcr_option do
expect(User.find_by(feed_url: nonpermanent_link).feed_fetched_at).to be > 2.minutes.ago
end
it "does not refetch same user over and over" do
it "does refetch same user over and over by default" do
user = User.find_by(feed_url: nonpermanent_link)
user.update_column(:feed_fetched_at, Time.current)
fetched_at_time = user.feed_fetched_at
sleep(1)
described_class.new.get_all_articles
described_class.new.get_all_articles
described_class.new.get_all_articles
described_class.new.get_all_articles
described_class.new.get_all_articles
expect(user.feed_fetched_at).to eq(fetched_at_time)
Timecop.freeze(Time.current) do
user.update_column(:feed_fetched_at, Time.current)
fetched_at_time = user.reload.feed_fetched_at
# travel a few seconds in the future to simulate a new time
3.times do |i|
Timecop.travel((i + 5).seconds.from_now) { described_class.new.get_all_articles }
end
expect(user.reload.feed_fetched_at > fetched_at_time).to be(true)
end
end
it "logs an article creation error" do
reader = described_class.new
allow(reader).to receive(:make_from_rss_item).and_raise(StandardError)
allow(Rails.logger).to receive(:error)
reader.get_all_articles
expect(Rails.logger).to have_received(:error).at_least(:once)
end
it "logs a fetching error" do
reader = described_class.new
allow(reader).to receive(:fetch_rss).and_raise(StandardError)
allow(Rails.logger).to receive(:error)
reader.get_all_articles
expect(Rails.logger).to have_received(:error).at_least(:once)
end
end
describe "#fetch_user" do
before do
[link, nonmedium_link, nonpermanent_link].each do |feed_url|
create(:user, feed_url: feed_url)
end
end
it "gets articles for user" do
@ -66,6 +114,46 @@ RSpec.describe RssReader, vcr: vcr_option do
described_class.new.fetch_user(User.first)
expect(Article.all.map(&:featured_number).uniq).to eq([nil])
end
it "logs an article creation error on the standard logger" do
reader = described_class.new
allow(reader).to receive(:make_from_rss_item).and_raise(StandardError)
allow(Rails.logger).to receive(:error)
reader.fetch_user(User.first)
expect(Rails.logger).to have_received(:error).at_least(:once)
end
it "logs an article creation error on the observability tool" do
reader = described_class.new
allow(reader).to receive(:make_from_rss_item).and_raise(StandardError)
reader.fetch_user(User.first)
expected_observable_fields = [
:user, :feed_url, :item_count, :error,
"error_msg", "trace.trace_id", "trace.parent_id", "trace.span_id"
]
expect(Honeycomb.client.events.first.data.keys).to eq(expected_observable_fields)
end
it "logs a fetching error on the standard logger" do
reader = described_class.new
allow(reader).to receive(:fetch_rss).and_raise(StandardError)
allow(Rails.logger).to receive(:error)
reader.fetch_user(User.first)
expect(Rails.logger).to have_received(:error).at_least(:once)
end
it "logs a fetching error on the observability tool" do
reader = described_class.new
allow(reader).to receive(:fetch_rss).and_raise(StandardError)
reader.fetch_user(User.first)
expected_observable_fields = [
:user, :feed_url, :item_count, :error,
"error_msg", "trace.trace_id", "trace.parent_id", "trace.span_id"
]
expect(Honeycomb.client.events.first.data.keys).to eq(expected_observable_fields)
end
end
describe "#valid_feed_url?" do