Home Explore Help
Register Sign In
J1X
/
huginn
Watch 2
Star 0
Fork 0

Browse Source
Merge pull request #84 from cantino/add_more_logging

Create agent logs when delayed jobs fail

Andrew Cantino 10 years ago
parent
17b3897733 582345ebd1
commit
907936e368
4 changed files with 64 additions and 22 deletions
Show Diff Stats
  1. 20 6
      app/models/agent.rb
  2. 1 1
      app/models/agents/digest_email_agent.rb
  3. 3 3
      app/models/agents/website_agent.rb
  4. 40 12
      spec/models/agent_spec.rb

+ 20 - 6
app/models/agent.rb
View File 

@@ -144,6 +144,10 @@ class Agent < ActiveRecord::Base
144 144 
     AgentLog.log_for_agent(self, message, options)
145 145 
   end
146 146
147 
+  def error(message, options = {})
148 
+    log(message, options.merge(:level => 4))
149 
+  end
150 
+
147 151 
   # Class Methods
148 152 
   class << self
149 153 
     def cannot_be_scheduled!
 
@@ -201,9 +205,14 @@ class Agent < ActiveRecord::Base
201 205 
     # and Event ids instead of a literal ActiveRecord models because it is preferable to serialize delayed_jobs with ids.
202 206 
     def async_receive(agent_id, event_ids)
203 207 
       agent = Agent.find(agent_id)
204 
-      agent.receive(Event.where(:id => event_ids))
205 
-      agent.last_receive_at = Time.now
206 
-      agent.save!
208 
+      begin
209 
+        agent.receive(Event.where(:id => event_ids))
210 
+        agent.last_receive_at = Time.now
211 
+        agent.save!
212 
+      rescue => e
213 
+        agent.error "Exception during receive: #{e.message} -- #{e.backtrace}"
214 
+        raise
215 
+      end
207 216 
     end
208 217 
     handle_asynchronously :async_receive
209 218 
 
@@ -228,9 +237,14 @@ class Agent < ActiveRecord::Base
228 237 
     # id instead of a literal Agent because it is preferable to serialize delayed_jobs with ids.
229 238 
     def async_check(agent_id)
230 239 
       agent = Agent.find(agent_id)
231 
-      agent.check
232 
-      agent.last_check_at = Time.now
233 
-      agent.save!
240 
+      begin
241 
+        agent.check
242 
+        agent.last_check_at = Time.now
243 
+        agent.save!
244 
+      rescue => e
245 
+        agent.error "Exception during check: #{e.message} -- #{e.backtrace}"
246 
+        raise
247 
+      end
234 248 
     end
235 249 
     handle_asynchronously :async_check
236 250 
   end

+ 1 - 1
app/models/agents/digest_email_agent.rb
View File 

@@ -38,7 +38,7 @@ module Agents
38 38 
     def check
39 39 
       if self.memory[:queue] && self.memory[:queue].length > 0
40 40 
         lines = self.memory[:queue].map {|item| present(item) }
41 
-        puts "Sending mail to #{user.email}..." unless Rails.env.test?
41 
+        log "Sending digest mail to #{user.email}"
42 42 
         SystemMailer.delay.send_message(:to => user.email, :subject => options[:subject], :headline => options[:headline], :lines => lines)
43 43 
         self.memory[:queue] = []
44 44 
       end

+ 3 - 3
app/models/agents/website_agent.rb
View File 

@@ -69,7 +69,7 @@ module Agents
69 69 
       log "Fetching #{options[:url]}"
70 70 
       request = Typhoeus::Request.new(options[:url], :followlocation => true)
71 71 
       request.on_failure do |response|
72 
-        log "Failed: #{response.inspect}"
72 
+        error "Failed: #{response.inspect}"
73 73 
       end
74 74 
       request.on_success do |response|
75 75 
         doc = parse(response.body)
 
@@ -84,7 +84,7 @@ module Agents
84 84 
                        elsif extraction_details[:text]
85 85 
                          node.text()
86 86 
                        else
87 
-                         log ":attr or :text is required on HTML or XML extraction patterns"
87 
+                         error ":attr or :text is required on HTML or XML extraction patterns"
88 88 
                          return
89 89 
                        end
90 90 
                      }
 
@@ -95,7 +95,7 @@ module Agents
95 95 
         num_unique_lengths = options[:extract].keys.map { |name| output[name].length }.uniq
96 96
97 97 
         if num_unique_lengths.length != 1
98 
-          log "Got an uneven number of matches for #{options[:name]}: #{options[:extract].inspect}", :level => 4
98 
+          error "Got an uneven number of matches for #{options[:name]}: #{options[:extract].inspect}"
99 99 
           return
100 100 
         end
101 101

+ 40 - 12
spec/models/agent_spec.rb
View File 

@@ -125,25 +125,40 @@ describe Agent do
125 125 
     end
126 126
127 127 
     describe ".async_check" do
128 
-      it "records last_check_at and calls check on the given Agent" do
129 
-        checker = Agents::SomethingSource.new(:name => "something")
130 
-        checker.user = users(:bob)
131 
-        checker.save!
128 
+      before do
129 
+        @checker = Agents::SomethingSource.new(:name => "something")
130 
+        @checker.user = users(:bob)
131 
+        @checker.save!
132 
+      end
132 133
133 
-        mock(checker).check.once {
134 
-          checker.options[:new] = true
134 
+      it "records last_check_at and calls check on the given Agent" do
135 
+        mock(@checker).check.once {
136 
+          @checker.options[:new] = true
135 137 
         }
136 138
137 
-        mock(Agent).find(checker.id) { checker }
139 
+        mock(Agent).find(@checker.id) { @checker }
140 
+
141 
+        @checker.last_check_at.should be_nil
142 
+        Agents::SomethingSource.async_check(@checker.id)
143 
+        @checker.reload.last_check_at.should be_within(2).of(Time.now)
144 
+        @checker.reload.options[:new].should be_true # Show that we save options
145 
+      end
138 146
139 
-        checker.last_check_at.should be_nil
140 
-        Agents::SomethingSource.async_check(checker.id)
141 
-        checker.reload.last_check_at.should be_within(2).of(Time.now)
142 
-        checker.reload.options[:new].should be_true # Show that we save options
147 
+      it "should log exceptions" do
148 
+        mock(@checker).check.once {
149 
+          raise "foo"
150 
+        }
151 
+        mock(Agent).find(@checker.id) { @checker }
152 
+        lambda {
153 
+          Agents::SomethingSource.async_check(@checker.id)
154 
+        }.should raise_error
155 
+        log = @checker.logs.first
156 
+        log.message.should =~ /Exception/
157 
+        log.level.should == 4
143 158 
       end
144 159 
     end
145 160
146 
-    describe ".receive!" do
161 
+    describe ".receive! and .async_receive" do
147 162 
       before do
148 163 
         stub_request(:any, /wunderground/).to_return(:body => File.read(Rails.root.join("spec/data_fixtures/weather.json")), :status => 200)
149 164 
         stub.any_instance_of(Agents::WeatherAgent).is_tomorrow?(anything) { true }
 
@@ -155,6 +170,19 @@ describe Agent do
155 170 
         Agent.receive!
156 171 
       end
157 172
173 
+      it "should log exceptions" do
174 
+        mock.any_instance_of(Agents::TriggerAgent).receive(anything).once {
175 
+          raise "foo"
176 
+        }
177 
+        Agent.async_check(agents(:bob_weather_agent).id)
178 
+        lambda {
179 
+          Agent.receive!
180 
+        }.should raise_error
181 
+        log = agents(:bob_rain_notifier_agent).logs.first
182 
+        log.message.should =~ /Exception/
183 
+        log.level.should == 4
184 
+      end
185 
+
158 186 
       it "should track when events have been seen and not received them again" do
159 187 
         mock.any_instance_of(Agents::TriggerAgent).receive(anything).once
160 188 
         Agent.async_check(agents(:bob_weather_agent).id)