Commit f13bc74853837cd7fbc7719bc884ad85910a5ef8

Authored by Stephen Crosby
1 parent 9c40727d
Exists in master and in 1 other branch production

rework the problem cache and refingerprinting code

Now that it is easy to change fingerprinting logic, it is important that
users have a way to regenerate fingerprints on existing notices. This
commit reorganizes and unifies problem refingerprinting between both
merge/unmerge and the global refingerprinting rake task.
app/interactors/notice_refingerprinter.rb 0 → 100644
... ... @@ -0,0 +1,36 @@
  1 +class NoticeRefingerprinter
  2 + LOG_EVERY = 100
  3 + LOG_ITR = '%.1f%% complete, %i notice(s) remaining'
  4 + LOG_START = 'Regenerating notice fingerprints for %i notices'
  5 +
  6 + def self.run
  7 + count = Notice.count
  8 + puts format(LOG_START, count)
  9 +
  10 + Notice.no_timeout.each_with_index do |notice, index|
  11 + refingerprint(notice)
  12 +
  13 + next unless (index + 1) % LOG_EVERY == 0
  14 + puts format(LOG_ITR, (index * 100 / count), count - index)
  15 + end
  16 +
  17 + puts 'Finished generating notice fingerprints'
  18 + end
  19 +
  20 + def self.apps
  21 + @apps ||= App.all.index_by(&:id)
  22 + end
  23 +
  24 + def self.refingerprint(notice)
  25 + app = apps[notice.try(:err).try(:problem).try(:app_id)]
  26 + app.find_or_create_err!(
  27 + error_class: notice.error_class,
  28 + environment: notice.environment_name,
  29 + fingerprint: app.notice_fingerprinter.generate(app.api_key, notice, notice.backtrace)
  30 + )
  31 + end
  32 +
  33 + def self.puts(*args)
  34 + Rails.logger.info(*args)
  35 + end
  36 +end
... ...
app/interactors/problem_merge.rb
... ... @@ -16,13 +16,7 @@ class ProblemMerge
16 16 problem.reload # deference all associate objet to avoid delete him after
17 17 ProblemDestroy.execute(problem)
18 18 end
19   - reset_cached_attributes
  19 + merged_problem.recache
20 20 merged_problem
21 21 end
22   -
23   - private
24   -
25   - def reset_cached_attributes
26   - ProblemUpdaterCache.new(merged_problem).update
27   - end
28 22 end
... ...
app/interactors/problem_recacher.rb 0 → 100644
... ... @@ -0,0 +1,24 @@
  1 +class ProblemRecacher
  2 + LOG_EVERY = 100
  3 + LOG_ITR = '%.1f%% complete, %i problem(s) remaining'
  4 + LOG_START = 'Re-caching problem attributes for %i problems'
  5 +
  6 + def self.run
  7 + count = Problem.count
  8 + puts format(LOG_START, count)
  9 +
  10 + Problem.no_timeout.each_with_index do |problem, index|
  11 + problem.recache
  12 + problem.destroy if problem.notices_count == 0
  13 +
  14 + next unless (index + 1) % LOG_EVERY == 0
  15 + puts format(LOG_ITR, (index * 100 / count), count - index)
  16 + end
  17 +
  18 + puts "Finished re-caching problem attributes"
  19 + end
  20 +
  21 + def self.puts(*args)
  22 + Rails.logger.info(*args)
  23 + end
  24 +end
... ...
app/interactors/problem_updater_cache.rb
... ... @@ -1,88 +0,0 @@
1   -class ProblemUpdaterCache
2   - def initialize(problem, notice=nil)
3   - @problem = problem
4   - @notice = notice
5   - end
6   - attr_reader :problem
7   -
8   - ##
9   - # Update cache information about child associate to this problem
10   - #
11   - # update the notices count, and some notice informations
12   - #
13   - # @return [ Problem ] the problem with this update
14   - #
15   - def update
16   - update_notices_count
17   - update_notices_cache
18   - problem
19   - end
20   -
21   - private
22   -
23   - def update_notices_count
24   - if @notice
25   - problem.inc(notices_count: 1)
26   - else
27   - problem.update_attribute(
28   - :notices_count, problem.notices.count
29   - )
30   - end
31   - end
32   -
33   - ##
34   - # Update problem statistique from some notice information
35   - #
36   - def update_notices_cache
37   - first_notice = notices.first
38   - last_notice = notices.last
39   - notice ||= @notice || first_notice
40   -
41   - attrs = {}
42   - attrs[:first_notice_at] = first_notice.created_at if first_notice
43   - attrs[:last_notice_at] = last_notice.created_at if last_notice
44   - attrs.merge!(
45   - :message => notice.message,
46   - :where => notice.where,
47   - :messages => attribute_count(:message, messages),
48   - :hosts => attribute_count(:host, hosts),
49   - :user_agents => attribute_count(:user_agent_string, user_agents)
50   - ) if notice
51   - problem.update_attributes!(attrs)
52   - end
53   -
54   - def notices
55   - @notices ||= @notice ? [@notice].sort(&:created_at) : problem.notices.order_by([:created_at, :asc])
56   - end
57   -
58   - def messages
59   - @notice ? problem.messages : {}
60   - end
61   -
62   - def hosts
63   - @notice ? problem.hosts : {}
64   - end
65   -
66   - def user_agents
67   - @notice ? problem.user_agents : {}
68   - end
69   -
70   - private
71   -
72   - def attribute_count(value, init)
73   - init.tap do |counts|
74   - notices.each do |notice|
75   - counts[attribute_index(notice.send(value))] ||= {
76   - 'value' => notice.send(value),
77   - 'count' => 0
78   - }
79   - counts[attribute_index(notice.send(value))]['count'] += 1
80   - end
81   - end
82   - end
83   -
84   - def attribute_index(value)
85   - @attributes_index ||= {}
86   - @attributes_index[value.to_s] ||= Digest::MD5.hexdigest(value.to_s)
87   - end
88   -end
app/models/notice.rb
... ... @@ -48,7 +48,8 @@ class Notice
48 48 end
49 49  
50 50 def environment_name
51   - server_environment['server-environment'] || server_environment['environment-name']
  51 + n = server_environment['server-environment'] || server_environment['environment-name']
  52 + n.blank? ? 'development' : n
52 53 end
53 54  
54 55 def component
... ... @@ -119,6 +120,12 @@ class Notice
119 120 end
120 121 end
121 122  
  123 + # filter memory addresses out of object strings
  124 + # example: "#<Object:0x007fa2b33d9458>" becomes "#<Object>"
  125 + def filtered_message
  126 + message.gsub(/(#<.+?):[0-9a-f]x[0-9a-f]+(>)/, '\1\2')
  127 + end
  128 +
122 129 protected
123 130  
124 131 def problem_recache
... ...
app/models/notice_fingerprinter.rb
... ... @@ -16,7 +16,7 @@ class NoticeFingerprinter
16 16 def generate(api_key, notice, backtrace)
17 17 material = []
18 18 material << notice.error_class if error_class
19   - material << notice.message if message
  19 + material << notice.filtered_message if message
20 20 material << notice.component if component
21 21 material << notice.action if action
22 22 material << notice.environment_name if environment_name
... ...
app/models/problem.rb
... ... @@ -142,16 +142,22 @@ class Problem
142 142 { "$match" => { err_id: { "$in" => err_ids } } },
143 143 { "$group" => { _id: "$#{v}", count: {"$sum" => 1} } }
144 144 ]).each do |agg|
145   - next if agg[:_id] == nil
146   -
147   - send(k)[Digest::MD5.hexdigest(agg[:_id])] = {
148   - value: agg[:_id],
149   - count: agg[:count]
  145 + send(k)[Digest::MD5.hexdigest(agg[:_id] || 'N/A')] = {
  146 + 'value' => agg[:_id] || 'N/A',
  147 + 'count' => agg[:count]
150 148 }
151 149 end
152 150 end
153 151  
154   - self.notices_count = Notice.where({ err_id: { "$in" => err_ids }}).count
  152 + first_notice = notices.order_by([:created_at, :asc]).first
  153 + last_notice = notices.order_by([:created_at, :desc]).first
  154 +
  155 + self.notices_count = notices.count
  156 + self.first_notice_at = first_notice.created_at if first_notice
  157 + self.message = first_notice.message if first_notice
  158 + self.where = first_notice.where if first_notice
  159 + self.last_notice_at = last_notice.created_at if last_notice
  160 +
155 161 save
156 162 end
157 163  
... ...
lib/tasks/errbit/database.rake
1   -require 'digest/sha1'
2   -
3 1 namespace :errbit do
4   - namespace :db do
5   -
6   - desc "Updates cached attributes on Problem"
7   - task :update_problem_attrs => :environment do
8   - puts "Updating problems"
9   - Problem.no_timeout.all.each do |problem|
10   - ProblemUpdaterCache.new(problem).update
11   - end
12   - end
13   -
14   - desc "Updates Problem#notices_count"
15   - task :update_notices_count => :environment do
16   - puts "Updating problem.notices_count"
17   - Problem.no_timeout.all.each do |pr|
18   - pr.update_attributes(:notices_count => pr.notices.count)
19   - end
20   - end
21   -
22   - desc "Delete resolved errors from the database. (Useful for limited heroku databases)"
23   - task :clear_resolved => :environment do
24   - require 'resolved_problem_clearer'
25   - puts "=== Cleared #{ResolvedProblemClearer.new.execute} resolved errors from the database."
26   - end
27   -
28   - desc "Regenerate fingerprints"
29   - task :regenerate_fingerprints => :environment do
30   -
31   - def normalize_backtrace(backtrace)
32   - backtrace[0...3].map do |trace|
33   - trace.merge 'method' => trace['method'].to_s.gsub(/[0-9_]{10,}+/, "__FRAGMENT__")
34   - end
35   - end
  2 + desc "Updates cached attributes on Problem"
  3 + task :problem_recache => :environment do
  4 + ProblemRecacher.run
  5 + end
36 6  
37   - def fingerprint(source)
38   - Digest::SHA1.hexdigest(source.to_s)
39   - end
  7 + desc "Delete resolved errors from the database. (Useful for limited heroku databases)"
  8 + task :clear_resolved => :environment do
  9 + require 'resolved_problem_clearer'
  10 + puts "=== Cleared #{ResolvedProblemClearer.new.execute} resolved errors from the database."
  11 + end
40 12  
41   - puts "Regenerating Err fingerprints"
42   - Err.create_indexes
43   - Err.all.each do |err|
44   - next if err.notices.count == 0
45   - source = {
46   - :backtrace => normalize_backtrace(err.notices.first.backtrace).to_s,
47   - :error_class => err.error_class,
48   - :component => err.component,
49   - :action => err.action,
50   - :environment => err.environment,
51   - :api_key => err.app.api_key
52   - }
53   - err.update_attributes(:fingerprint => fingerprint(source))
54   - end
55   - end
  13 + desc "Regenerate fingerprints"
  14 + task :notice_refingerprint => :environment do
  15 + NoticeRefingerprinter.run
  16 + ProblemRecacher.run
  17 + end
56 18  
57   - desc "Remove notices in batch"
58   - task :notices_delete, [ :problem_id ] => [ :environment ] do
59   - BATCH_SIZE = 1000
60   - if args[:problem_id]
61   - item_count = Problem.find(args[:problem_id]).notices.count
62   - removed_count = 0
63   - puts "Notices to remove: #{item_count}"
64   - while item_count > 0
65   - Problem.find(args[:problem_id]).notices.limit(BATCH_SIZE).each do |notice|
66   - notice.remove
67   - removed_count += 1
68   - end
69   - item_count -= BATCH_SIZE
70   - puts "Removed #{removed_count} notices"
  19 + desc "Remove notices in batch"
  20 + task :notices_delete, [ :problem_id ] => [ :environment ] do
  21 + BATCH_SIZE = 1000
  22 + if args[:problem_id]
  23 + item_count = Problem.find(args[:problem_id]).notices.count
  24 + removed_count = 0
  25 + puts "Notices to remove: #{item_count}"
  26 + while item_count > 0
  27 + Problem.find(args[:problem_id]).notices.limit(BATCH_SIZE).each do |notice|
  28 + notice.remove
  29 + removed_count += 1
71 30 end
  31 + item_count -= BATCH_SIZE
  32 + puts "Removed #{removed_count} notices"
72 33 end
73 34 end
74 35 end
... ...
spec/fabricators/backtrace_fabricator.rb 0 → 100644
... ... @@ -0,0 +1,19 @@
  1 +Fabricator :backtrace do
  2 + lines(:count => 99) do
  3 + {
  4 + number: rand(999),
  5 + file: "/path/to/file/#{SecureRandom.hex(4)}.rb",
  6 + method: ActiveSupport.methods.shuffle.first
  7 + }
  8 + end
  9 +end
  10 +
  11 +Fabricator :short_backtrace do
  12 + lines(:count => 5) do
  13 + {
  14 + number: rand(999),
  15 + file: "/path/to/file/#{SecureRandom.hex(4)}.rb",
  16 + method: ActiveSupport.methods.shuffle.first
  17 + }
  18 + end
  19 +end
... ...
spec/fabricators/err_fabricator.rb
... ... @@ -2,29 +2,3 @@ Fabricator :err do
2 2 problem
3 3 fingerprint 'some-finger-print'
4 4 end
5   -
6   -Fabricator :notice do
7   - app
8   - err
9   - error_class 'FooError'
10   - message 'Too Much Bar'
11   - backtrace
12   - server_environment { {'environment-name' => 'production'} }
13   - request {{ 'component' => 'foo', 'action' => 'bar' }}
14   - notifier {{ 'name' => 'Notifier', 'version' => '1', 'url' => 'http://toad.com' }}
15   -
16   - after_create do
17   - Problem.cache_notice(err.problem_id, self)
18   - problem.reload
19   - end
20   -end
21   -
22   -Fabricator :backtrace do
23   - lines(:count => 99) do
24   - {
25   - number: rand(999),
26   - file: "/path/to/file/#{SecureRandom.hex(4)}.rb",
27   - method: ActiveSupport.methods.shuffle.first
28   - }
29   - end
30   -end
... ...
spec/fabricators/notice_fabricator.rb 0 → 100644
... ... @@ -0,0 +1,14 @@
  1 +Fabricator :notice do
  2 + err
  3 + error_class 'FooError'
  4 + message 'Too Much Bar'
  5 + backtrace
  6 + server_environment {{ 'environment-name' => 'production' }}
  7 + request {{ 'component' => 'foo', 'action' => 'bar' }}
  8 + notifier {{ 'name' => 'Notifier', 'version' => '1', 'url' => 'http://toad.com' }}
  9 +
  10 + after_create do
  11 + Problem.cache_notice(err.problem_id, self)
  12 + problem.reload
  13 + end
  14 +end
... ...
spec/interactors/notice_refingerprinter_spec.rb 0 → 100644
... ... @@ -0,0 +1,16 @@
  1 +describe NoticeRefingerprinter do
  2 + let(:backtrace) do
  3 + Fabricate(:backtrace)
  4 + end
  5 +
  6 + let(:notices) do
  7 + 5.times.map do
  8 + Fabricate(:notice, backtrace: backtrace)
  9 + end
  10 + end
  11 +
  12 + it 'shits' do
  13 + binding.pry
  14 + 1
  15 + end
  16 +end
... ...
spec/interactors/problem_merge_spec.rb
... ... @@ -47,7 +47,7 @@ describe ProblemMerge do
47 47 end
48 48  
49 49 it 'update problem cache' do
50   - expect(ProblemUpdaterCache).to receive(:new).with(problem).and_return(double(:update => true))
  50 + expect(problem).to receive(:recache)
51 51 problem_merge.merge
52 52 end
53 53  
... ...
spec/interactors/problem_updater_cache_spec.rb
... ... @@ -1,145 +0,0 @@
1   -describe ProblemUpdaterCache do
2   - let(:problem) { Fabricate(:problem_with_errs) }
3   - let(:first_errs) { problem.errs }
4   - let!(:notice) { Fabricate(:notice, :err => first_errs.first) }
5   -
6   - describe "#update" do
7   - context "without notice pass args" do
8   - before do
9   - problem.update_attribute(:notices_count, 0)
10   - end
11   -
12   - it 'update the notice_count' do
13   - expect {
14   - ProblemUpdaterCache.new(problem).update
15   - }.to change{
16   - problem.notices_count
17   - }.from(0).to(1)
18   - end
19   -
20   - context "with only one notice" do
21   - before do
22   - problem.update_attributes!(:messages => {})
23   - ProblemUpdaterCache.new(problem).update
24   - end
25   -
26   - it 'update information about this notice' do
27   - expect(problem.message).to eq notice.message
28   - expect(problem.where).to eq notice.where
29   - end
30   -
31   - it 'update first_notice_at' do
32   - expect(problem.first_notice_at).to eq notice.reload.created_at
33   - end
34   -
35   - it 'update last_notice_at' do
36   - expect(problem.last_notice_at).to eq notice.reload.created_at
37   - end
38   -
39   - it 'update stats messages' do
40   - expect(problem.messages).to eq({
41   - Digest::MD5.hexdigest(notice.message) => {'value' => notice.message, 'count' => 1}
42   - })
43   - end
44   -
45   - it 'update stats hosts' do
46   - expect(problem.hosts).to eq({
47   - Digest::MD5.hexdigest(notice.host) => {'value' => notice.host, 'count' => 1}
48   - })
49   - end
50   -
51   - it 'update stats user_agents' do
52   - expect(problem.user_agents).to eq({
53   - Digest::MD5.hexdigest(notice.user_agent_string) => {'value' => notice.user_agent_string, 'count' => 1}
54   - })
55   - end
56   - end
57   -
58   - context "with several notices" do
59   - let!(:notice_2) { Fabricate(:notice, :err => first_errs.first) }
60   - let!(:notice_3) { Fabricate(:notice, :err => first_errs.first) }
61   - before do
62   - problem.update_attributes!(:messages => {})
63   - ProblemUpdaterCache.new(problem).update
64   - end
65   - it 'update information about this notice' do
66   - expect(problem.message).to eq notice.message
67   - expect(problem.where).to eq notice.where
68   - end
69   -
70   - it 'update first_notice_at' do
71   - expect(problem.first_notice_at.to_i).to be_within(2).of(notice.created_at.to_i)
72   - end
73   -
74   - it 'update last_notice_at' do
75   - expect(problem.last_notice_at.to_i).to be_within(2).of(notice.created_at.to_i)
76   - end
77   -
78   - it 'update stats messages' do
79   - expect(problem.messages).to eq({
80   - Digest::MD5.hexdigest(notice.message) => {'value' => notice.message, 'count' => 3}
81   - })
82   - end
83   -
84   - it 'update stats hosts' do
85   - expect(problem.hosts).to eq({
86   - Digest::MD5.hexdigest(notice.host) => {'value' => notice.host, 'count' => 3}
87   - })
88   - end
89   -
90   - it 'update stats user_agents' do
91   - expect(problem.user_agents).to eq({
92   - Digest::MD5.hexdigest(notice.user_agent_string) => {'value' => notice.user_agent_string, 'count' => 3}
93   - })
94   - end
95   -
96   - end
97   - end
98   -
99   - context "with notice pass in args" do
100   -
101   - before do
102   - ProblemUpdaterCache.new(problem, notice).update
103   - end
104   -
105   - it 'increase notices_count by 1' do
106   - expect {
107   - ProblemUpdaterCache.new(problem, notice).update
108   - }.to change{
109   - problem.notices_count
110   - }.by(1)
111   - end
112   -
113   - it 'update information about this notice' do
114   - expect(problem.message).to eq notice.message
115   - expect(problem.where).to eq notice.where
116   - end
117   -
118   - it 'update first_notice_at' do
119   - expect(problem.first_notice_at).to eq notice.created_at
120   - end
121   -
122   - it 'update last_notice_at' do
123   - expect(problem.last_notice_at).to eq notice.created_at
124   - end
125   -
126   - it 'inc stats messages' do
127   - expect(problem.messages).to eq({
128   - Digest::MD5.hexdigest(notice.message) => {'value' => notice.message, 'count' => 2}
129   - })
130   - end
131   -
132   - it 'inc stats hosts' do
133   - expect(problem.hosts).to eq({
134   - Digest::MD5.hexdigest(notice.host) => {'value' => notice.host, 'count' => 2}
135   - })
136   - end
137   -
138   - it 'inc stats user_agents' do
139   - expect(problem.user_agents).to eq({
140   - Digest::MD5.hexdigest(notice.user_agent_string) => {'value' => notice.user_agent_string, 'count' => 2}
141   - })
142   - end
143   - end
144   - end
145   -end
spec/models/problem_spec.rb
... ... @@ -397,4 +397,100 @@ describe Problem, type: &#39;model&#39; do
397 397 end
398 398 end
399 399 end
  400 +
  401 + describe '#recache' do
  402 + let(:problem) { Fabricate(:problem_with_errs) }
  403 + let(:first_errs) { problem.errs }
  404 + let!(:notice) { Fabricate(:notice, :err => first_errs.first) }
  405 +
  406 + before do
  407 + problem.update_attribute(:notices_count, 0)
  408 + end
  409 +
  410 + it 'update the notice_count' do
  411 + expect {
  412 + problem.recache
  413 + }.to change{
  414 + problem.notices_count
  415 + }.from(0).to(1)
  416 + end
  417 +
  418 + context "with only one notice" do
  419 + before do
  420 + problem.update_attributes!(:messages => {})
  421 + problem.recache
  422 + end
  423 +
  424 + it 'update information about this notice' do
  425 + expect(problem.message).to eq notice.message
  426 + expect(problem.where).to eq notice.where
  427 + end
  428 +
  429 + it 'update first_notice_at' do
  430 + expect(problem.first_notice_at).to eq notice.reload.created_at
  431 + end
  432 +
  433 + it 'update last_notice_at' do
  434 + expect(problem.last_notice_at).to eq notice.reload.created_at
  435 + end
  436 +
  437 + it 'update stats messages' do
  438 + expect(problem.messages).to eq({
  439 + Digest::MD5.hexdigest(notice.message) => {'value' => notice.message, 'count' => 1}
  440 + })
  441 + end
  442 +
  443 + it 'update stats hosts' do
  444 + expect(problem.hosts).to eq({
  445 + Digest::MD5.hexdigest(notice.host) => {'value' => notice.host, 'count' => 1}
  446 + })
  447 + end
  448 +
  449 + it 'update stats user_agents' do
  450 + expect(problem.user_agents).to eq({
  451 + Digest::MD5.hexdigest(notice.user_agent_string) => {'value' => notice.user_agent_string, 'count' => 1}
  452 + })
  453 + end
  454 + end
  455 +
  456 + context "with several notices" do
  457 + let!(:notice_2) { Fabricate(:notice, :err => first_errs.first) }
  458 + let!(:notice_3) { Fabricate(:notice, :err => first_errs.first) }
  459 + before do
  460 + problem.update_attributes!(:messages => {})
  461 + problem.recache
  462 + end
  463 +
  464 + it 'update information about this notice' do
  465 + expect(problem.message).to eq notice.message
  466 + expect(problem.where).to eq notice.where
  467 + end
  468 +
  469 + it 'update first_notice_at' do
  470 + expect(problem.first_notice_at.to_i).to be_within(2).of(notice.created_at.to_i)
  471 + end
  472 +
  473 + it 'update last_notice_at' do
  474 + expect(problem.last_notice_at.to_i).to be_within(2).of(notice.created_at.to_i)
  475 + end
  476 +
  477 + it 'update stats messages' do
  478 + expect(problem.messages).to eq({
  479 + Digest::MD5.hexdigest(notice.message) => {'value' => notice.message, 'count' => 3}
  480 + })
  481 + end
  482 +
  483 + it 'update stats hosts' do
  484 + expect(problem.hosts).to eq({
  485 + Digest::MD5.hexdigest(notice.host) => {'value' => notice.host, 'count' => 3}
  486 + })
  487 + end
  488 +
  489 + it 'update stats user_agents' do
  490 + expect(problem.user_agents).to eq({
  491 + Digest::MD5.hexdigest(notice.user_agent_string) => {'value' => notice.user_agent_string, 'count' => 3}
  492 + })
  493 + end
  494 + end
  495 + end
400 496 end
... ...