fluent-plugin-s3 test fails with fluentd v0.14.0.rc.3 and c291f75 (master) #994

okkez · 2016-05-27T04:49:26Z

How to reproduce

$ git clone git@github.com:fluent/fluent-plugin-s3.git
$ cd fluent-plugin-s3
$ echo 'gem "fluentd", "=0.14.0.rc.3"' >> Gemfile
$ bundle install
$ bundle exec rake test

Result

Some tests errored.

Error: test_chunk_to_write(S3OutputTest): NoMethodError: undefined method `format_stream' for #<:00000001e8a048>
fluentd/lib/fluent/test/output_test.rb:80:in `block in run'
fluentd/lib/fluent/test/input_test.rb:123:in `block in run'
fluentd/lib/fluent/test/base.rb:81:in `run'
fluentd/lib/fluent/test/input_test.rb:122:in `run'
fluentd/lib/fluent/test/output_test.rb:76:in `run'
fluent-plugin-s3/test/test_out_s3.rb:246:in `test_chunk_to_write'
     243:     d.emit({"a"=>2}, time)
     244:
     245:     # S3OutputTest#write returns chunk.read
  => 246:     data = d.run
     247:
     248:     assert_equal %[2011-01-02T13:14:15Z\ttest\t{"a":1}\n] +
     249:                  %[2011-01-02T13:14:15Z\ttest\t{"a":2}\n],
(snip)
Error: test_warn_for_delay(S3OutputTest): NameError: uninitialized constant Fluent::FileBufferChunk
fluent-plugin-s3/lib/fluent/plugin/out_s3.rb:271:in `hex_random'
fluent-plugin-s3/lib/fluent/plugin/out_s3.rb:200:in `write'
fluentd/lib/fluent/compat/output.rb:130:in `write'
fluentd/lib/fluent/test/output_test.rb:146:in `block (2 levels) in run'
fluentd/lib/fluent/test/output_test.rb:142:in `each'
fluentd/lib/fluent/test/output_test.rb:142:in `block in run'
fluentd/lib/fluent/test/input_test.rb:123:in `block in run'
fluentd/lib/fluent/test/base.rb:81:in `run'
fluentd/lib/fluent/test/input_test.rb:122:in `run'
fluentd/lib/fluent/test/output_test.rb:124:in `run'
fluent-plugin-s3/test/test_out_s3.rb:553:in `test_warn_for_delay'
     550:     d.emit({"a"=>1}, delayed_time.to_i)
     551:     d.emit({"a"=>2}, delayed_time.to_i)
     552:
  => 553:     d.run
     554:
     555:     logs = d.instance.log.logs
     556:     assert_true logs.any? {|log| log.include?('[warn]: out_s3: delayed events were put') }
(snip)
------------------------------------------------------------------------------------------------------------------------
35 tests, 39 assertions, 0 failures, 13 errors, 0 pendings, 0 omissions, 0 notifications
62.8571% passed
------------------------------------------------------------------------------------------------------------------------
-0.00 tests/s, -0.00 assertions/s

The text was updated successfully, but these errors were encountered:

tagomoris · 2016-05-27T05:04:09Z

Plugins should NOT depend on other plugins' internal classes.
In this case, it looks to work well to use chunk.respond_to?(:unique_id) instead of is_a?(FileBufferChunk).

sonots · 2016-05-30T07:50:24Z

format_stream would be fixed via Fix to call #format_stream of plugin themselves when RecordFilter mixin included #1005
uninitialized constant Fluent::FileBufferChunk should be fixed via fix hex_random for v0.14 fluent-plugin-s3#148

sonots · 2016-05-30T07:54:14Z

Running fluent-plugin-s3 (not test), I got following errors on hitting Ctrl-C

2016-05-30 16:51:47 +0900 [warn]: both of Plugin @id and path for <storage> are not specified. Using on-memory store.

^C2016-05-30 16:51:55 +0900 [info]: Received graceful stop
2016-05-30 16:51:56 +0900 [info]: shutting down fluentd
2016-05-30 16:52:02 +0900 [info]: shutting down output plugin type=:s3 plugin_id="object:3fc6d507aff4"
2016-05-30 16:52:02 +0900 [info]: shutting down input plugin type=:dummy plugin_id="object:3fc6d6028870"
2016-05-30 16:52:02 +0900 [info]: closing input plugin type=:dummy plugin_id="object:3fc6d6028870"
2016-05-30 16:52:02 +0900 [info]: closing output plugin type=:s3 plugin_id="object:3fc6d507aff4"
2016-05-30 16:52:03 +0900 [warn]: emit transaction failed: error_class=NoMethodError error="undefined method `[]' for nil:NilClass" tag="fluent.info"
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/buffer.rb:367:in `block in write_once'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/2.2.0/monitor.rb:211:in `mon_synchronize'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/buffer.rb:367:in `write_once'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/buffer.rb:186:in `block in write'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/buffer.rb:185:in `each'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/buffer.rb:185:in `write'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/output.rb:631:in `block in handle_stream_with_custom_format'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/output.rb:588:in `call'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/output.rb:588:in `write_guard'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/output.rb:630:in `handle_stream_with_custom_format'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/output.rb:580:in `execute_chunking'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/output.rb:522:in `emit_buffered'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/event_router.rb:90:in `emit_stream'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/event_router.rb:81:in `emit'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/engine.rb:165:in `block in log_event_loop'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/engine.rb:163:in `each'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/engine.rb:163:in `log_event_loop'
2016-05-30 16:52:03 +0900 [error]: failed to emit fluentd's log event tag="fluent.info" event={"type"=>:dummy, "plugin_id"=>"object:3fc6d6028870", "message"=>"closing input plugin type=:dummy plugin_id=\"object:3fc6d6028870\""} error_class=NoMethodError error="undefined method `[]' for nil:NilClass"
2016-05-30 16:52:03 +0900 [warn]: emit transaction failed: error_class=NoMethodError error="undefined method `index' for nil:NilClass" tag="fluent.info"
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/buffer.rb:160:in `block in add_metadata'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/2.2.0/monitor.rb:211:in `mon_synchronize'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/buffer.rb:159:in `add_metadata'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/buffer.rb:171:in `metadata'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/output.rb:560:in `metadata'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/output.rb:625:in `block in handle_stream_with_custom_format'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/event.rb:74:in `call'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/event.rb:74:in `each'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/output.rb:624:in `handle_stream_with_custom_format'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/output.rb:580:in `execute_chunking'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/plugin/output.rb:522:in `emit_buffered'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/event_router.rb:90:in `emit_stream'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/event_router.rb:81:in `emit'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/engine.rb:165:in `block in log_event_loop'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/engine.rb:163:in `each'
  2016-05-30 16:52:03 +0900 [warn]: /Users/seo.naotoshi/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/bundler/gems/fluentd-fa3bc388813b/lib/fluent/engine.rb:163:in `log_event_loop'
2016-05-30 16:52:03 +0900 [error]: failed to emit fluentd's log event tag="fluent.info" event={"type"=>:s3, "plugin_id"=>"object:3fc6d507aff4", "message"=>"closing output plugin type=:s3 plugin_id=\"object:3fc6d507aff4\""} error_class=NoMethodError error="undefined method `index' for nil:NilClass"

with config like below

<source>
  @type dummy
  tag dummy
  dummy {"foo":"foo"}
</source>

<match **>
  @type s3
  aws_key_id xxxxxxxxxxxxxxxxxxxxxx
  aws_sec_key xxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
  s3_bucket xxxxxxxxxxxxxxxxxxxxxxxxxx
  s3_region us-east-1
  s3_object_key_format %{path}%{time_slice}_%{index}.%{hex_random}.%{file_extension}
  hex_random_length 16
  path logs/
  # buffer_path logs/
  buffer_type memory
  time_slice_format %Y%m%d-%H%M%S
  time_slice_wait 1s
  utc
</match>

tagomoris · 2016-05-30T09:48:19Z

It looks that any input plugin (in_dummy?) does emit after terminating output plugins.

tagomoris · 2016-05-30T10:07:06Z

#1009 may solve this problem.
@sonots Could you check it?

sonots · 2016-05-30T13:25:40Z

I still get same errors

sonots · 2016-05-30T13:29:35Z

BTW, I get the warning

2016-05-30 22:26:15 +0900 [warn]: plugin/storage_local.rb:34:configure: both of Plugin @id and path for <storage> are not specified. Using on-memory store.

for configuration like below (file buffer):

<source>
  @type dummy
  tag dummy
  dummy {"foo":"foo"}
</source>

<match **>
  @type s3
  aws_key_id xxxxxxxxxxxxxxxxxxxxxx
  aws_sec_key xxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
  s3_bucket xxxxxxxxxxxxxxxxxxxxxxxxxx
  s3_region us-east-1
  s3_object_key_format %{path}%{time_slice}_%{index}.%{hex_random}.%{file_extension}
  hex_random_length 16
  path logs/
  buffer_path logs/
  time_slice_format %Y%m%d-%H%M%S
  time_slice_wait 1s
  utc
</match>

The generated conf by fluentd was as below:

2016-05-30 22:29:54 +0900 [info]: fluent/engine.rb:123:configure: using configuration file: <ROOT>
  <source>
    @type dummy
    tag "dummy"
    dummy {"foo":"foo"}
  </source>
  <match **>
    @type s3
    aws_key_id xxxxxx
    aws_sec_key xxxxxx
    s3_bucket xxxxxxxx
    s3_region "us-east-1"
    s3_object_key_format "%{path}%{time_slice}_%{index}.%{hex_random}.%{file_extension}"
    hex_random_length 16
    path "logs/"
    buffer_path logs/
    time_slice_format "%Y%m%d-%H%M%S"
    time_slice_wait 1s
    utc
    <buffer time>
      flush_mode lazy
      retry_type exponential_backoff
      path logs/
      timekey_wait 1s
      timekey 1
    </buffer>
  </match>
</ROOT>

tagomoris · 2016-05-31T01:20:15Z

That warning is intentional one. It's about persistency of in_dummy sequence.

tagomoris · 2016-06-30T03:06:46Z

Is this still occurring with v0.14.1?

shawnbutts · 2016-07-01T18:46:45Z

i'm seeing this with v0.14.1 with fluent-plugin-s3 0.6.8 as well.

repeatedly · 2016-07-01T19:09:07Z

The problem is fluent-plugin-s3's test, not fluentd.
So I closed this issue and I will commit the fix soon.

tagomoris added the v0.14 label May 27, 2016

sonots mentioned this issue May 30, 2016

fix hex_random for v0.14 fluent/fluent-plugin-s3#148

Merged

repeatedly closed this as completed Jul 1, 2016

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fluent-plugin-s3 test fails with fluentd v0.14.0.rc.3 and c291f75 (master) #994

fluent-plugin-s3 test fails with fluentd v0.14.0.rc.3 and c291f75 (master) #994

okkez commented May 27, 2016

tagomoris commented May 27, 2016

sonots commented May 30, 2016

sonots commented May 30, 2016 •

edited

Loading

tagomoris commented May 30, 2016

tagomoris commented May 30, 2016

sonots commented May 30, 2016

sonots commented May 30, 2016 •

edited

Loading

tagomoris commented May 31, 2016

tagomoris commented Jun 30, 2016

shawnbutts commented Jul 1, 2016 •

edited

Loading

repeatedly commented Jul 1, 2016 •

edited

Loading

fluent-plugin-s3 test fails with fluentd v0.14.0.rc.3 and c291f75 (master) #994

fluent-plugin-s3 test fails with fluentd v0.14.0.rc.3 and c291f75 (master) #994

Comments

okkez commented May 27, 2016

How to reproduce

Result

tagomoris commented May 27, 2016

sonots commented May 30, 2016

sonots commented May 30, 2016 • edited Loading

tagomoris commented May 30, 2016

tagomoris commented May 30, 2016

sonots commented May 30, 2016

sonots commented May 30, 2016 • edited Loading

tagomoris commented May 31, 2016

tagomoris commented Jun 30, 2016

shawnbutts commented Jul 1, 2016 • edited Loading

repeatedly commented Jul 1, 2016 • edited Loading

sonots commented May 30, 2016 •

edited

Loading

sonots commented May 30, 2016 •

edited

Loading

shawnbutts commented Jul 1, 2016 •

edited

Loading

repeatedly commented Jul 1, 2016 •

edited

Loading