Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Plugin fails to implement filter method #35

Closed
micahhausler opened this issue Sep 2, 2016 · 23 comments
Closed

Plugin fails to implement filter method #35

micahhausler opened this issue Sep 2, 2016 · 23 comments

Comments

@micahhausler
Copy link

Error Message

2016-09-02 14:31:16 +0000 [info]: adding filter pattern="docker.var.lib.docker.containers.*.*.log" type="kubernetes_metadata"
/usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/plugin/filter.rb:88:in `has_filter_with_time?': BUG: Filter plugins MUST be implmented either `filter` or `filter_with_time` (NotImplementedError)
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/plugin/filter.rb:37:in `initialize'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/plugin_helper/inject.rb:82:in `initialize'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/compat/filter.rb:31:in `initialize'
    from /usr/local/bundle/gems/fluent-plugin-kubernetes_metadata_filter-0.24.0/lib/fluent/plugin/filter_kubernetes_metadata.rb:99:in `initialize'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/plugin.rb:149:in `new'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/plugin.rb:149:in `new_impl'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/plugin.rb:108:in `new_filter'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/agent.rb:148:in `add_filter'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/agent.rb:67:in `block in configure'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/agent.rb:63:in `each'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/agent.rb:63:in `configure'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/root_agent.rb:86:in `configure'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/engine.rb:119:in `configure'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/engine.rb:93:in `run_configure'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/supervisor.rb:673:in `run_configure'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/supervisor.rb:435:in `block in run_worker'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/supervisor.rb:606:in `main_process'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/supervisor.rb:431:in `run_worker'
    from /usr/local/bundle/gems/fluentd-0.14.4/lib/fluent/command/fluentd.rb:271:in `<top (required)>'
    from /usr/local/lib/ruby/site_ruby/2.3.0/rubygems/core_ext/kernel_require.rb:55:in `require'
    from /usr/local/lib/ruby/site_ruby/2.3.0/rubygems/core_ext/kernel_require.rb:55:in `require'
    from /usr/local/bundle/gems/fluentd-0.14.4/bin/fluentd:5:in `<top (required)>'
    from /usr/local/bundle/bin/fluentd:22:in `load'
    from /usr/local/bundle/bin/fluentd:22:in `<main>'
2016-09-02 14:31:16 +0000 [info]: Worker 0 finished unexpectedly with status 1

Configuration

    <match fluent.**>
      @type null
    </match>

    <source>
      @type tail
      path /var/log/containers/*.log
      pos_file /tmp/docker-containers.log.pos
      time_format %Y-%m-%dT%H:%M:%S.%NZ
      tag docker.*
      format json
      read_from_head true
    </source>

    <filter docker.var.lib.docker.containers.*.*.log>
      @type kubernetes_metadata
    </filter>

    <match docker.**>
      @type file
      path /tmp/fluent-docker.log
      time_slice_format %Y%m%d
      time_slice_wait 10m
      time_format %Y%m%dT%H%M%S%z
      #compress gzip
      utc
    </match>

Versions

root@fluentd-forwarder-1235g:/tmp# ruby -v
ruby 2.3.1p112 (2016-04-26 revision 54768) [x86_64-linux]
root@fluentd-forwarder-1235g:/tmp# gem -v
2.6.6
root@fluentd-forwarder-1235g:/tmp# fluentd --version
fluentd 0.14.4
root@fluentd-forwarder-1235g:/tmp# gem list

*** LOCAL GEMS ***

activesupport (5.0.0.1)
addressable (2.4.0)
aws-sdk-core (2.5.8)
bigdecimal (default: 1.2.8)
bundler (1.12.5)
concurrent-ruby (1.0.2)
cool.io (1.4.5)
did_you_mean (1.0.0)
docker-api (1.31.0)
domain_name (0.5.20160826)
excon (0.52.0)
ffi (1.9.14)
fluent-mixin-config-placeholders (0.4.0)
fluent-plugin-cloudwatch-logs (0.3.3)
fluent-plugin-docker_metadata_filter (0.1.3)
fluent-plugin-kubernetes_metadata_filter (0.24.0)
fluent-plugin-record-reformer (0.8.2)
fluent-plugin-systemd (0.0.4)
fluentd (0.14.4)
http (0.9.8)
http-cookie (1.0.2)
http-form_data (1.0.1)
http_parser.rb (0.6.0)
i18n (0.7.0)
io-console (default: 0.4.5)
jmespath (1.3.1)
json (default: 1.8.3)
kubeclient (1.1.4)
lru_redux (1.1.0)
mime-types (3.1)
mime-types-data (3.2016.0521)
minitest (5.8.3)
msgpack (1.0.0)
net-telnet (0.1.1)
netrc (0.11.0)
power_assert (0.2.6)
psych (default: 2.0.17)
rake (10.4.2)
rdoc (default: 4.2.1)
recursive-open-struct (1.0.0)
rest-client (2.0.0)
rubygems-update (2.6.6)
serverengine (2.0.0)
sigdump (0.2.4)
strptime (0.1.8)
systemd-journal (1.2.2)
test-unit (3.1.5)
thread_safe (0.3.5)
tzinfo (1.2.2)
tzinfo-data (1.2016.6)
unf (0.1.4)
unf_ext (0.0.7.2)
uuidtools (2.1.5)
yajl-ruby (1.2.1)

Am I just using the wrong version of Ruby?

@jchauncey
Copy link
Contributor

Newer version of fluentd cause this issue (0.14.0 wasnt affected)

@micahhausler
Copy link
Author

@jchauncey is that a plugin bug or a fluentd bug then?

@jchauncey
Copy link
Contributor

its a plugin bug

@jimmidyson
Copy link
Contributor

Will look at this & corresponding PR tomorrow. Bit annoying that breaking change in a minor release...

@gamkiller77
Copy link

Yah I ran in to this exact problem today when I updated my log-forwarder container I have. Is there an update to when this may be patched?

@jimmidyson
Copy link
Contributor

Fixed by #36, just need to release which I will do tomorrow unless I forget (again!).

@repeatedly
Copy link

repeatedly commented Sep 8, 2016

Bit annoying that breaking change in a minor release...

This is our mistake. We can't check all plugins, so we assume all filters define filter, filter_with_time or filter_stream statically...

@jimmidyson
Copy link
Contributor

@repeatedly No I take my criticism back now you've explained what's gone wrong - it is a sane & safe assumption you made. Just our fault for dynamically aliasing the method. Thanks for your help with fixing this.

@jimmidyson
Copy link
Contributor

Fixed in #37. Releasing now.

@jimmidyson
Copy link
Contributor

Released v0.25.1. Enjoy!

@gamkiller77
Copy link

hate to say it but see new error about this and the error is below.

2016-09-08 17:11:26 +0000 [info]: fluent/event_router.rb:213:optimizable?: Filtering works with worse performance, because [Fluent::KubernetesMetadataFilter, Fluent::Plugin::RecordTransformerFilter] uses#filter_streammethod.

The filtering works with worse performance is a problem it is now doing a buffer over flow with KAFKA. I will reach out to the other plugin that stated here too.

@jimmidyson
Copy link
Contributor

Can you raise a separate issue please? With a PR to fix would be amazing too if possible!

@repeatedly
Copy link

repeatedly commented Sep 8, 2016

This is info, not error.
This message means fluentd can't optimize filter pipeline because XxxFilter uses filter_stream.
Maybe, worse performance words is bad for users.
kubernetes_metadata_filter and record_transformer_filter work without no problem.

@jimmidyson
Copy link
Contributor

So no performance issue?

@repeatedly
Copy link

Yes. Performance should be same with v0.12.
For example, if we have input -> filter -> filter -> output pipeline,

  • In v0.12, fluentd iterates event stream for each filter. This case fluentd do two iterations.
  • In v0.14, fluentd combines two filters into one and fluentd applies combined filters in 1 iteration.

In this result, v0.14 reduces iteration cost and new object allocation cost. But this optimization has one limitation. We can optimize filter pipeline when filter uses filter or filter_with_time method. Fluentd stops this optimization when one filter uses filter_stream.

@repeatedly
Copy link

repeatedly commented Sep 8, 2016

I want to know this filter performance.
Can we test this filter on normal machine, e.g. macbook or Linux on VM?
Need actual k8s environment for applying filter?

@jimmidyson
Copy link
Contributor

@repeatedly I would love some help with performance tuning so would love your help with that. You need a k8s environment to retrieve metadata to enrich records but that could easily be stubbed.

@repeatedly
Copy link

that could easily be stubbed.

Could you give me a resource or link?

@jimmidyson
Copy link
Contributor

Switched discussion on performance to #39.

@Sam123ben
Copy link

Sam123ben commented Jun 6, 2018

Hi, is this issue resolved, as I find the same issue trying to run the fluent in my cluster.

➜ vof_env_nonprod_ta git:(master) ✗ kubectl logs fluentd-elasticsearch-wjsr7 -n kube-system
2018-06-06 12:35:33 +0000 [info]: parsing config file is succeeded path="/etc/td-agent/td-agent.conf"
2018-06-06 12:35:33 +0000 [warn]: 'type' is deprecated parameter name. use '@type' instead.
2018-06-06 12:35:33 +0000 [warn]: 'type' is deprecated parameter name. use '@type' instead.
/opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-1.2.1/lib/fluent/plugin/filter.rb:88:in has_filter_with_time?': BUG: Filter plugins MUST implement either filterorfilter_with_time(NotImplementedError) from /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-1.2.1/lib/fluent/plugin/filter.rb:37:ininitialize'
from /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-1.2.1/lib/fluent/plugin_helper/inject.rb:92:in initialize' from /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-1.2.1/lib/fluent/compat/filter.rb:31:in initialize'
from /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-kubernetes_metadata_filter-0.24.0/lib/fluent/plugin/filter_kubernetes_metadata.rb:99:in initialize' from /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-1.2.1/lib/fluent/plugin.rb:149:in new'
from /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-1.2.1/lib/fluent/plugin.rb:149:in new_impl' from /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-1.2.1/lib/fluent/plugin.rb:108:in new_filter'
from /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-1.2.1/lib/fluent/agent.rb:150:in add_filter' from /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-1.2.1/lib/fluent/agent.rb:70:in block in configure'
from /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-1.2.1/lib/fluent/agent.rb:64:in each' from /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-1.2.1/lib/fluent/agent.rb:64:in configure'
from /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-1.2.1/lib/fluent/root_agent.rb:112:in configure' from /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-1.2.1/lib/fluent/engine.rb:131:in configure'

My td-agent.conf file snippet as below:

@type tail format multiline multiline_flush_interval 5s format_firstline /^\w\d{4}/ format1 /^(?\w)(?\d{4} [^\s]*)\s+(?\d+)\s+(?[^ \]]+)\] (?.*)/ time_format %m%d %H:%M:%S.%N path /var/log/cluster-autoscaler.log pos_file /var/log/es-cluster-autoscaler.log.pos tag cluster-autoscaler

<filter_with_time kubernetes.java.**>
@type concat
key log
multiline_start_regexp /^\d{4}-\d{1,2}-\d{1,2} \d{1,2}:\d{1,2}:\d{1,2}.\d{1,3}/
</filter_with_time>

<filter_with_time kubernetes.**>
@type kubernetes_metadata
</filter_with_time>

@jcantrill
Copy link
Contributor

@Sam123ben Please open a new issue with details about the environment and gems you are using so we may properly investigate.

@mhobotpplnet
Copy link

Has this been fixed?

@jcantrill
Copy link
Contributor

@mhobotpplnet My suspicion is no as there has not been much love given to the latest release of fluentd. PR are welcome

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

8 participants