Merge pull request #140 from fluent/fix_logged_error

Fix logged error

app/models/fluentd/agent/local_common.rb

@@ -117,12 +117,14 @@ class Fluentd
               #           2014-06-30 11:24:08 +0900 [error]: /Users/uu59/.rbenv/versions/2.1.2/lib/ruby/2.1.0/socket.rb:461:in `block in tcp_server_sockets'
               #         ]
               #       }
-              subject, *notes = *buf.reverse
-              block.call({
-                subject: subject,
-                notes: notes,
-              })
+              split_error_lines_to_error_units(buf.reverse).each do |error_unit|
+                block.call({
+                  subject: error_unit[:subject],
+                  notes: error_unit[:notes],
+                })
+              end
             end
+
             buf = []
             next
           end
@@ -132,6 +134,37 @@ class Fluentd
         io && io.close
       end
 
+      def split_error_lines_to_error_units(buf)
+        # NOTE: if a following log is given
+        #
+        #2014-05-27 10:54:37 +0900 [error]: unexpected error error_class=Errno::EADDRINUSE error=#<Errno::#EADDRINUSE: Address already in use - bind(2) for "0.0.0.0" port 24224>
+        #2014-05-27 10:55:40 +0900 [error]: unexpected error error_class=Errno::EADDRINUSE error=#<Errno::#EADDRINUSE: Address already in use - bind(2) for "0.0.0.0" port 24224>
+        #  2014-05-27 10:55:40 +0900 [error]: /Users/uu59/.rbenv/versions/2.1.0/lib/ruby/gems/2.1.0/gems/cool.io-1.2.4/lib/cool.io/server.rb:57:in `initialize'
+        #  2014-05-27 10:55:40 +0900 [error]: /Users/uu59/.rbenv/versions/2.1.0/lib/ruby/gems/2.1.0/gems/cool.io-1.2.4/lib/cool.io/server.rb:57:in `new'
+        #
+        #the first line and second line must be each "error_unit". and after third lines lines are "notes" of second error unit of .
+        # [
+        #   { subject: "2014-05-27 10:54:37 +0900 [error]: unexpected error error_class=Errno::EADDRINUSE error=#<Errno::#EADDRINUSE: Address already in use - bind(2) for "0.0.0.0" port 24224>          ",
+        #     notes: [] },
+        #   { subject: "2014-05-27 10:55:40 +0900 [error]: unexpected error error_class=Errno::EADDRINUSE error=#<Errno::#EADDRINUSE: Address already in use - bind(2) for "0.0.0.0" port 24224>          ",
+        #     notes: [
+        #       "2014-05-27 10:55:40 +0900 [error]: /Users/uu59/.rbenv/versions/2.1.0/lib/ruby/gems/2.1.0/gems/cool.io-1.2.4/lib/cool.io/server.rb:57:in `initialize'",
+        #       "2014-05-27 10:55:40 +0900 [error]: /Users/uu59/.rbenv/versions/2.1.0/lib/ruby/gems/2.1.0/gems/cool.io-1.2.4/lib/cool.io/server.rb:57:in `new'"
+        #     ]
+        #   },
+        # ]
+        #
+        return_array = []
+        buf.each_with_index do |b, i|
+          if b.match(/\A /)
+            return_array[-1][:notes] << b
+          else
+            return_array << { subject: b, notes: [] }
+          end
+        end
+        return return_array.reverse
+      end
+
       def detached_command(cmd)
         thread = Bundler.with_clean_env do
           pid = spawn(cmd)

lib/file_reverse_reader.rb

@@ -7,26 +7,24 @@ class FileReverseReader
   end
 
   def each_line(&block)
+    #read from the end of file
     io.seek(0, IO::SEEK_END)
     buf = ""
     loop do
       if reach_start_of_file?
-        last_pos = io.pos
-        io.seek(0, IO::SEEK_SET)
-        buf.insert(0, io.read(last_pos))
-        split_each_line(buf, &block)
+        read_rest(buf, &block)
         break
       end
 
-      io.seek(-1 * step, IO::SEEK_CUR)
-      buf.insert(0, io.read(step))
-      io.seek(-1 * step, IO::SEEK_CUR)
-      next if buf[$/].nil?
-      gap = buf.index($/)
-      buf.gsub!(/\A.*?\n/, "")
-      split_each_line(buf, &block)
-      buf = ""
-      io.seek(gap, IO::SEEK_CUR)
+      read_to_buf_by_step(buf)
+
+      #if buffer dose not include multi lines, seek more.
+      if buf[$/].nil?
+        next
+      else
+        split_only_whole_lines(buf, &block)
+        buf = ""
+      end
     end
   end
 
@@ -43,6 +41,33 @@ class FileReverseReader
 
   private
 
+  def read_rest(buf, &block)
+    last_pos = io.pos
+    io.seek(0, IO::SEEK_SET)
+    buf.insert(0, io.read(last_pos))
+    split_each_line(buf, &block)
+  end
+
+  def read_to_buf_by_step(buf)
+    #move up file pointer by one step
+    io.seek(-1 * step, IO::SEEK_CUR) #point[A]
+    #read strings by one step from the pointer, and insert to buffer
+    #(on io.read, file pointer returns down to the point before [A])
+    buf.insert(0, io.read(step))
+    #forword file pointer to [A]
+    io.seek(-1 * step, IO::SEEK_CUR)
+  end
+
+  def split_only_whole_lines(buf, &block)
+    #if budder includes multi lines,
+    gap = buf.index($/)
+    #cut off first line (*first* line because it's seeking from end of file, and first line may be broken-line)
+    buf.gsub!(/\A.*?\n/, "")
+    split_each_line(buf, &block)
+    #move file pointer to the gap(= the end of *first* line)
+    io.seek(gap, IO::SEEK_CUR)
+  end
+
   def split_each_line(buf, &block)
     return unless buf.force_encoding('utf-8').valid_encoding?
     buf.split($/).reverse.each do |line|

spec/support/fixtures/error3.log

@@ -0,0 +1,7 @@
+2014-05-27 10:54:37 +0900 [info]: listening fluent socket on 0.0.0.0:24224
+2014-05-27 10:54:37 +0900 [error]: unexpected error error_class=Errno::EADDRINUSE error=#<Errno::EADDRINUSE: 1 Address already in use - bind(2) for "0.0.0.0" port 24224>
+2014-05-27 10:55:40 +0900 [error]: unexpected error error_class=Errno::EADDRINUSE error=#<Errno::EADDRINUSE: 2 Address already in use - bind(2) for "0.0.0.0" port 24224>
+  2014-05-27 10:55:40 +0900 [error]: /Users/uu59/.rbenv/versions/2.1.0/lib/ruby/gems/2.1.0/gems/cool.io-1.2.4/lib/cool.io/server.rb:57:in `initialize'
+  2014-05-27 10:55:40 +0900 [error]: /Users/uu59/.rbenv/versions/2.1.0/lib/ruby/gems/2.1.0/gems/cool.io-1.2.4/lib/cool.io/server.rb:57:in `new'
+2014-05-27 11:28:12 +0900 [error]: unexpected error error_class=Errno::EADDRINUSE error=#<Errno::EADDRINUSE: 3 Address already in use - bind(2) for "0.0.0.0" port 24224>
+  2014-05-27 11:28:12 +0900 [error]: /Users/uu59/.rbenv/versions/2.1.0/lib/ruby/gems/2.1.0/gems/cool.io-1.2.4/lib/cool.io/server.rb:57:in `initialize'

spec/support/fluentd_agent_common_behavior.rb

@@ -108,6 +108,20 @@ shared_examples_for "Fluentd::Agent has common behavior" do |klass|
           one.should >= two
         end
       end
+
+      context "have 3 errors log includeing sequential 2 error log" do
+        let(:logfile) { File.expand_path("./spec/support/fixtures/error3.log", Rails.root) }
+        subject { instance.recent_errors(3) }
+
+        it "count 3 errors" do
+          subject[0][:subject].should include("3 Address already in use - bind(2)")
+          subject[0][:notes].size.should be 1
+          subject[1][:subject].should include("2 Address already in use - bind(2)")
+          subject[1][:notes].size.should be 2
+          subject[2][:subject].should include("1 Address already in use - bind(2)")
+          subject[2][:notes].size.should be 0
+        end
+      end
     end
   end
 end