Tail.rb self.new_observing initialization issue

[bdanziger]

Unless I do not understand what is happening in tail.rb I believe there is a bug when creating a new Tail object when using self.new_observing from file.rb. For the new.tap code in tail.rb below, it is creating a new Tail object and calls the initialization method that is in this file. If I understand the code correctly, it will be overriding the instance.target from (YieldingTail) but regardless, the initialization from the tap.new does not pass in the opts arguments. So, initialization receives no opts args. Then, YieldingTail.new(opts) passes in no opts args. Then in turn tail_base.rb initialization receives no opts args.

You might ask, why is this an issue if YieldingTail just gets overwritten.
I set my sincedb_path config for file.rb
In tail_base.rb, since it receives no opts, it never sees my sincedb_path config value. I am now forced to set HOME or SINCEDB_DIR environment variables because it is not seeing that I passed in a sincedb_path option in the opts.

---

This is the code that causes this :
when using :
new.tap do | instance |
instance.target = ObservingTail.new(opts)
end

---

Below, I show a simple fix :
new(opts).tap should be used instead of new.tap

so, it would be

new(opts).tap do | instance |
instance.target = ObservingTail.new(opts)
end

This code now properly passes in my opts, and I never need to set ENV HOME or SINCEDB_DIR since I am already setting it as a file config parameter.

[guyboertje]

@bdanziger - I don't understand either. Tail.new_observing(opts) is a mechanism to invoke the observer/listener callbacks and Tail.new(opts) is backward compatible to use the ruby block based callback. You should not need to use new_observing unless you have changed your code to supply a listener when ObservingTail asks for one in the subscribe method.

The tests in tail_spec.rb show that the opts are passed into YieldingTail.

In

module FileWatch
  class Tail
    extend Forwardable

    def_delegators :@target, :tail, :logger=, :subscribe, :sincedb_record_uid, :sincedb_write, :quit, :close_file

    attr_writer :target

    def self.new_observing(opts = {})
      new.tap do |instance|
        instance.target = ObservingTail.new(opts)
      end
    end

    def initialize(opts = {})
      @target = YieldingTail.new(opts)
    end
  end
end

the Tail class is a delegator that delegates to either YieldingTail or ObservingTail depending on whether one invokes it with new or new_observing.

For me, it is a bug that, when using new_observing, an instance of YieldingTail is created and thrown away and then an instance of ObservingTail is created and used as the delegation target.

[bdanziger]

Interesting. I am using Logstash and my logstash config file is using the "file" plugin. I traced the code and logstash is calling the new_observing method in tail.rb. I see my opts. Then, it runs the new.tap line and it calls initialize in tail.rb. I print out opts and it is empty. Then it calls YieldingTail.new(opts) with an empty opts. I can show you two stack traces. VERY VERBOSE. MY PRINT STATEMENTS SO IT IS CLEARER. The first stacktrace shows it not passing the args. The second shows it working properly, where I change the new.tap to new(opts).tap. I can send a standard stacktrace if necessary. Thanks

---

Below is the trace with the code as is. YieldingTail is called with no opts. The only way I can fix this without changing code is I now have to set SINCEDB_DIR or HOME environment variable

in pipeline.rb and about to call register
in file.rb register with path of '["/home/vagrant/logstash.in"]'
in file.rb register sincedb_path is set to : /home/vagrant/sincedbfile
in pipeline.rb finished register about to start_input
in pipeline.rb start_input about to create new thread
in pipeline.rb start_input finished creating new thread
in pipeline.rb in inputworker (the new thread) and about to call RUN
in file.rb run about to begin_tailing
in file.rb begin_tailing about to call new_observing with the tail_config params
in tail.rb self.new_observing about to call Observing Tail new with tail_config options
in tail.rb self.new_observing about to call Observing Tail with tail_config options of: {:exclude=>nil, :stat_interval=>1, :discover_interval=>15, :sincedb_write_interval=>15, :delimiter=>"\n", :ignore_older=>86400, :close_older=>3600, :max_open_files=>nil, :sincedb_path=>"/home/vagrant/sincedbfile"}
in tail.rb initialize about to call Yielding tail with tail_config options
in tail.rb initialize about to call Yielding Tail with tail_config options of: {}
in tail_base.rb initialize
opts inbound: {}
@opts premerge:
Logstash startup completed
A plugin had an unrecoverable error. Will restart this plugin.
Plugin: <LogStash::Inputs::File path=>["/home/vagrant/logstash.in"], sincedb_path=>"/home/vagrant/sincedbfile", codec=><LogStash::Codecs::Plain charset=>"UTF-8">, stat_interval=>1, discover_interval=>15, sincedb_write_interval=>15, start_position=>"end", delimiter=>"\n", ignore_older=>86400, close_older=>3600>
Error: No HOME or SINCEDB_PATH set in environment. I need one of these set so I can keep track of the files I am following. {:level=>:error}

---

BELOW is with the code new(opts).tap that I changed.
Settings: Default pipeline workers: 1
in pipeline.rb and about to call register
in file.rb register with path of '["/home/vagrant/logstash.in"]'
in file.rb register sincedb_path is set to : /home/vagrant/sincedbfile
in pipeline.rb finished register about to start_input
in pipeline.rb start_input about to create new thread
in pipeline.rb start_input finished creating new thread
Logstash startup completed
in pipeline.rb in inputworker (the new thread) and about to call RUN
in file.rb run about to begin_tailing
in file.rb begin_tailing about to call new_observing with the tail_config params
in tail.rb self.new_observing about to call Observing Tail new with tail_config options
in tail.rb self.new_observing about to call Observing Tail with tail_config options of: {:exclude=>nil, :stat_interval=>1, :discover_interval=>15, :sincedb_write_interval=>15, :delimiter=>"\n", :ignore_older=>86400, :close_older=>3600, :max_open_files=>nil, :sincedb_path=>"/home/vagrant/sincedbfile"}
in tail.rb initialize about to call Yielding tail with tail_config options
in tail.rb initialize about to call Yielding Tail with tail_config options of: {:exclude=>nil, :stat_interval=>1, :discover_interval=>15, :sincedb_write_interval=>15, :delimiter=>"\n", :ignore_older=>86400, :close_older=>3600, :max_open_files=>nil, :sincedb_path=>"/home/vagrant/sincedbfile"}
in tail_base.rb initialize
opts inbound: {:exclude=>nil, :stat_interval=>1, :discover_interval=>15, :sincedb_write_interval=>15, :delimiter=>"\n", :ignore_older=>86400, :close_older=>3600, :max_open_files=>nil, :sincedb_path=>"/home/vagrant/sincedbfile"}
@opts premerge:
@opts after merge: {:sincedb_write_interval=>15, :stat_interval=>1, :discover_interval=>15, :exclude=>nil, :start_new_files_at=>:end, :delimiter=>"\n", :ignore_older=>86400, :close_older=>3600, :max_open_files=>nil, :sincedb_path=>"/home/vagrant/sincedbfile"}
in tail.rb initialize finished calling Yielding Tail with tail_config options of: {:exclude=>nil, :stat_interval=>1, :discover_interval=>15, :sincedb_write_interval=>15, :delimiter=>"\n", :ignore_older=>86400, :close_older=>3600, :max_open_files=>nil, :sincedb_path=>"/home/vagrant/sincedbfile"}
in tail_base.rb initialize
opts inbound: {:exclude=>nil, :stat_interval=>1, :discover_interval=>15, :sincedb_write_interval=>15, :delimiter=>"\n", :ignore_older=>86400, :close_older=>3600, :max_open_files=>nil, :sincedb_path=>"/home/vagrant/sincedbfile"}
@opts premerge:
@opts after merge: {:sincedb_write_interval=>15, :stat_interval=>1, :discover_interval=>15, :exclude=>nil, :start_new_files_at=>:end, :delimiter=>"\n", :ignore_older=>86400, :close_older=>3600, :max_open_files=>nil, :sincedb_path=>"/home/vagrant/sincedbfile"}
in file.rb begin_tailing finished call to new_observing with the tail_config params
in file.rb begin_tailing about to call tail on the path
in file.rb begin_tailing finished call tail on the path
in file.rb run finished call begin_tailing
in file.rb run about to subscribe to tail
in observing_tail.rb in subscribe

[guyboertje]

@bdanziger - I see now. The problem is when the redundant YieldingTail is created with empty opts. None of the Logstash team have noticed this bug before - we must all have HOME set. As I said before the real problem is creating a YieldingTail object and then immediately throwing it away.

Please accept my apologies, I will fix this. In the meantime can you set HOME to a valid path.

I will need to release a new version of the file input.

[bdanziger]

Yes, I didn't know enough about the code to know whether the throw away call to YieldingTail was the issue or if for some unknown reason it needed to be called and it wasn't passing the opts, which caused me to have an issue. Either way, this triggers the issue. I can keep HOME or SINCEDB_DIR set to something to prevent. Thank you, but no apology needed. I am just trying to help.

[guyboertje]

No need to apologise. Your help is gladly accepted. It threw me that you
created an issue here and not in the LS file input.

On Tue, 16 Feb 2016 20:33 Bruce Danziger notifications@github.com wrote:

Yes, I didn't know enough about the code to know whether the throw away
call to YieldingTail was the issue or if for some unknown reason it needed
to be called and it wasn't passing the opts, which caused me to have an
issue. Either way, this triggers the issue. I can keep HOME or SINCEDB_DIR
set to something to prevent. Thank you, but no apology needed. I am just
trying to help.

—
Reply to this email directly or view it on GitHub
#76 (comment)
.

[bdanziger]

I guess I don't understand something. I was going to report it under Logstash, but I thought the issue was with the filewatch plugin? Tail.rb is part of filewatch, so that is where I logged the issue. I thought the bug should be reported with the plugin, unless I am really missing something here.

[guyboertje]

It's no biggie. As the problem manifests in LS, people usually report it
there. Few go to the lengths that you did to delve deeper. Thanks once
again, honestly, your diligence is commendable.

On Tue, 16 Feb 2016 20:51 Bruce Danziger notifications@github.com wrote:

I guess I don't understand something. I was going to report it under
Logstash, but I thought the issue was with the filewatch plugin? Tail.rb is
part of filewatch, so that is where I logged the issue. I thought the bug
should be reported with the plugin, unless I am really missing something
here.

—
Reply to this email directly or view it on GitHub
#76 (comment)
.