Make watch_file into state machine and leverage it throughout #74

guyboertje · 2016-01-20T21:36:10Z

NOTES:

Fixes a bug where ignored files were being opened and then closed simply to get it into the sincedb.
Fixes a bug where for some ignored files the @sincedb[@statcache[path]] returned nil.
Fixes a bug where unlimited number of files can be opened until the available file handles are exhausted - then, for example, the sincedb cannot be written and other bad things begin to happen on the system.

This is a big refactor.

WatchedFile instances become the source of truth about a file being watched.
The WatchedFile instance will be in only one state, and previous state history can be queried.
WatchedFile also holds the last stat taken, the inode and the last read size.
WatchedFile also holds the tokeniser buffer and the ruby File instance when it is opened.
The Event and WatchedFile instance is now yielded instead of the event and path.
Seeks, reads and close also go via the WatchedFile so it can update internals if needed.
In Tail the @statcache and separate @files storage hashes are gone.
The multiple File::Stat calls are reduced, one during discovery when the WatchFile instance is being constructed and one during the each iteration.
The each iteration has been split into state-based sections that iterate over WatchedFiles in that state e.g. closed, ignored, watched, active. A WatchedFile in an unwatched state is never looked at again.
the watched iteration takes a limited number of watched_files (4096), makes them active and yields :create or :create_initial but only if the watched_file does not have a history of being closed or ignored before. The implications of this is that if the close_older value is not set to close files then only the first MAX_OPEN_FILES can be tailed. There is an ENV setting for this value as it is set system wide for all instances of filewatch (e.g. multiple file inputs) and an options setting that gives each filewatch instance its own setting.

…uit thread was done

… instances add instance setting for max_open_files

suyograo · 2016-01-21T00:34:30Z

lib/filewatch/watch.rb

 end

+MAX_OPEN_FILES = ENV.fetch("MAX_OPEN_FILES", 4095).to_i


why is this an environment variable vs a config?

Its both. ENV for when the config is not available to the user.
There are precedents in using both: ENV["SINCEDB_PATH"]

In watch.rb:

... @max_active = MAX_OPEN_FILES ... def max_open_files=(value) return if value.nil? val = value.to_i @max_active = val <= 0 ? MAX_OPEN_FILES : value end

and in tail_base.rb:59

@watch.max_open_files = @opts[:max_open_files]

But it needs a test and a better name because its in the global namespace and it may be overwritten by something else loading later.

jsvd · 2016-01-21T10:09:43Z

lib/filewatch/observing_tail.rb

            listener.accept(line)
-            @sincedb[@statcache[path]] += (line.bytesize + delimiter_byte_size)


is there a reason to move this? this line is sort of the "ack" after processing. I believe it was purposefully put after the accept to prevent updating the @sincedb then suffer some nasty behaviour in accept and essentially skip that line.

You are correct. `listener.accept(line) may raise an error. I will revert this.

jsvd · 2016-01-21T10:43:39Z

running the specs failed for me (ruby mri 2.2.1):

  1) FileWatch::Watch when ignore_older is less than close_older and all files are expired yields no file events
     Failure/Error: expect(results).to eq([])

       expected: []
            got: [[:create_initial, "/var/folders/4g/v6scxgk106dcnlhspm54rl440000gn/T/studtmp-a6551ca9c3bb5bc6a82109e2dfcce27ad00440664324b4ac6200cb27f1bb/1.log"], [:modify, "/var/folders/4g/v6scxgk106dcnlhspm54rl440000gn/T/studtmp-a6551ca9c3bb5bc6a82109e2dfcce27ad00440664324b4ac6200cb27f1bb/1.log"]]

       (compared using ==)

       Diff:
       @@ -1,2 +1,5 @@
       -[]
       +[[:create_initial,
       +  "/var/folders/4g/v6scxgk106dcnlhspm54rl440000gn/T/studtmp-a6551ca9c3bb5bc6a82109e2dfcce27ad00440664324b4ac6200cb27f1bb/1.log"],
       + [:modify,
       +  "/var/folders/4g/v6scxgk106dcnlhspm54rl440000gn/T/studtmp-a6551ca9c3bb5bc6a82109e2dfcce27ad00440664324b4ac6200cb27f1bb/1.log"]]
     # ./spec/watch_spec.rb:356:in `block (3 levels) in <top (required)>'

NOTE: it is intermittent for me, can't always replicate

jsvd · 2016-01-21T10:45:24Z

spec/watch_spec.rb

-      Thread.new do
-        sleep quit_sleep
-        subject.quit
+      formatted_puts("subscribing")


this line is somewhat annoying when running the specs:

~/projects/ruby-filewatch (git)-[pr/74] % bundle exec rspec ....................W, [2016-01-21T10:42:09.185316 #96086] WARN -- : failed to open /var/folders/4g/v6scxgk106dcnlhspm54rl440000gn/T/studtmp-ec52acd1e1143e9af5432021bf1b107bc53c8077cf0a6b11c67cfe9ec5d9: No such file or directory @ rb_sysopen - /var/folders/4g/v6scxgk106dcnlhspm54rl440000gn/T/studtmp-ec52acd1e1143e9af5432021bf1b107bc53c8077cf0a6b11c67cfe9ec5d9 ............ subscribing . subscribing . subscribing . subscribing . subscribing . subscribing . subscribing . subscribing . subscribing . subscribing . subscribing . subscribing . subscribing . subscribing F subscribing .

I can fix this.

should be fixed now.

guyboertje · 2016-01-21T12:58:31Z

running the specs failed for me (ruby mri 2.2.1)

I can't get it to fail on MRI 2.2.2.
Perhaps you can try increase line 346 of watch_spec.rb to 2.1.
Tell me if that is better for you.

jordansissel · 2016-01-21T23:53:48Z

lib/filewatch/watch.rb

+        file_deleteable = []
+        # look at the closed to see if its changed
+
+        @files.values.select {|wf| wf.closed? }.each do |watched_file|


If you're worried about object churn here, you can use @files.select {|_, wf| wf.closed? }.each do |_, wf| ... end since Hash#select returns an enumerable.

Hash#select returns an enumerable

It does and over a new smaller Hash that the each iterates over. What I really want is each_selected_value(proc, block) 😄

jordansissel · 2016-01-22T00:31:16Z

lib/filewatch/watch.rb

          end
        end

-        @files.each do |path, watched_file|
+        # warning on open file limit


Let's log the number of files that we can't watch becuse it would exceed @max_active, just to let users know that this is an intentional decision by the library and not a bug.

jordansissel · 2016-01-26T21:06:57Z

@jsvd I ran the specs a few times and wasn't able to reproduce your failure. Bonus points? :P

jordansissel · 2016-01-26T23:16:56Z

Tested the logstash file input just in case, tests pass ✅

% grep filewatch *lock
      filewatch (~> 0.8.0)
  remote: /home/jls/projects/ruby-filewatch
    filewatch (0.8.0)
  filewatch!

% bundle exec rspec
Using Accessor#strict_set for specs
Run options: exclude {:redis=>true, :socket=>true, :performance=>true, :couchdb=>true, :elasticsearch=>true, :elasticsearch_secu
re=>true, :export_cypher=>true, :integration=>true, :windows=>true}
........

Finished in 9.42 seconds (files took 2.62 seconds to load)
8 examples, 0 failures

Randomized with seed 25232

jordansissel · 2016-01-26T23:22:23Z

lib/filewatch/watch.rb

      # can be called from different threads.
      @lock = Mutex.new
      # we need to be threadsafe about the quit mutation
      @quit = false
      @quit_lock = Mutex.new
+      @max_active = ENV.fetch("FILEWATCH_MAX_OPEN_FILES", 4095).to_i


My feeling is that this shouldn't be configurable from the environment. However, we can leave it as-is as long as we don't document it.

Maybe mild refactor this to use self.max_active = ...

jsvd · 2016-01-27T17:19:14Z

LGTM

Make watch_file into state machine and leverage it throughout

Guy Boertje added 12 commits January 18, 2016 10:01

apply stashed refactor

8d9fb6a

apply stashed refactor

54b18e4

add support for rspec_sequencing

1bec481

final tweaks to better handle maxed out file handles

d797364

use published gem

14d86b6

use accessed_at to decide if file can close

9a65b2c

interim changes

bccca77

I think this is it! Last tweaks.

ade1740

update version

19be4d9

there are significant changes bump to 0.8.0

52817b6

fix random spec failure where the sincedb file was rm_rf before the q…

eba6c57

…uit thread was done

remove class variables in WatchFile, they will be tainted by multiple…

42155c2

… instances add instance setting for max_open_files

guyboertje assigned jordansissel Jan 20, 2016

suyograo reviewed Jan 21, 2016
View reviewed changes

rework the global constant names and add max_open_files tests

4c01f83

guyboertje assigned jsvd and unassigned jordansissel Jan 21, 2016

jsvd reviewed Jan 21, 2016
View reviewed changes

changes from PR

ebc21de

jordansissel reviewed Jan 21, 2016
View reviewed changes

jordansissel reviewed Jan 22, 2016
View reviewed changes

Guy Boertje added 2 commits January 24, 2016 19:44

updates from comments in PR and other improvements

88853d4

rename WatchedFile size to bytes_read and adjust as necessary.

02fdc70

jordansissel reviewed Jan 26, 2016
View reviewed changes

Guy Boertje added 2 commits January 27, 2016 14:55

revert debug_log and use max_open_files= method in watch initializer

744109f

remove debug_log method

a0960bd

guyboertje mentioned this pull request Jan 27, 2016

[file input] re-using inodes leads to missing/corrupted data - please implement periodic cleanup of sincedb entries elastic/logstash#4566

Closed

guyboertje pushed a commit that referenced this pull request Jan 27, 2016

Merge pull request #74 from guyboertje/watch-fsm

cf60cb4

Make watch_file into state machine and leverage it throughout

guyboertje merged commit cf60cb4 into jordansissel:master Jan 27, 2016

guyboertje deleted the watch-fsm branch February 3, 2016 12:03

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Make watch_file into state machine and leverage it throughout #74

Make watch_file into state machine and leverage it throughout #74

guyboertje commented Jan 20, 2016

suyograo Jan 21, 2016

guyboertje Jan 21, 2016

guyboertje Jan 21, 2016

jsvd Jan 21, 2016

guyboertje Jan 21, 2016

jsvd commented Jan 21, 2016

jsvd Jan 21, 2016

guyboertje Jan 21, 2016

guyboertje Jan 21, 2016

guyboertje commented Jan 21, 2016

jordansissel Jan 21, 2016

guyboertje Jan 22, 2016

jordansissel Jan 22, 2016

jordansissel commented Jan 26, 2016

jordansissel commented Jan 26, 2016

jordansissel Jan 26, 2016

jordansissel Jan 26, 2016

jsvd commented Jan 27, 2016

		listener.accept(line)
		@sincedb[@statcache[path]] += (line.bytesize + delimiter_byte_size)

Make watch_file into state machine and leverage it throughout #74

Make watch_file into state machine and leverage it throughout #74

Conversation

guyboertje commented Jan 20, 2016

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jsvd commented Jan 21, 2016

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

guyboertje commented Jan 21, 2016

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jordansissel commented Jan 26, 2016

jordansissel commented Jan 26, 2016

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jsvd commented Jan 27, 2016