error_class=NoMethodError error="undefined method `next_time' for nil:NilClass" #1555

cosmok · 2017-04-28T03:08:46Z

fluentd 0.14.14

getting the following error;

2017-04-28 07:06:07 +1000 [error]: #0 error on output thread error_class=NoMethodError error="undefined method `next_time' for nil:NilClass"
  2017-04-28 07:06:07 +1000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.14.14/lib/fluent/plugin/output.rb:1262:in `block in flush_thread_run'
  2017-04-28 07:06:07 +1000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.14.14/lib/fluent/plugin/output.rb:1262:in `synchronize'
  2017-04-28 07:06:07 +1000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.14.14/lib/fluent/plugin/output.rb:1262:in `flush_thread_run'
  2017-04-28 07:06:07 +1000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.14.14/lib/fluent/plugin/output.rb:415:in `block (2 levels) in start'

flow is; tail a few files, process then store results.

Not sure where exactly in the flow the error is being triggered.

Result being that fewer than expected lines are being processed.

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

igorpeshansky · 2017-05-08T12:45:34Z

Hi. Can you please explain why you closed this? Is this no longer an issue for you?

cosmok · 2017-05-09T21:27:17Z

Hi,

I closed it primarily because it got no response ;( . But now that it's attracted some attention, I would like to add some additional details.

My setup is like I mentioned here:

#1516 (comment)

I noticed that when I changed my script to ignore jumbled records (and not exit(1) inside the script - as I had done before) this error went away. But, at the cost of not processing some rows.

gcs-github · 2017-05-31T08:22:43Z

I think I just ran into a similar problem on fluentd 0.14.13.

My forward instance became unavailable for a moment -> receiving an ack failed -> started to see errors about next_time lacking from the chunks to retry

2017-05-30 17:15:11 +0000 [warn]: #0 destination node closed the connection. regard it as unavailable. host="127.0.0.1" port=24224
2017-05-30 17:15:11 +0000 [error]: #0 unexpected error while receiving ack error_class=NoMethodError error="undefined method `unpack' for nil:NilClass"
  2017-05-30 17:15:11 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/unique_id.rb:26:in `hex'
  2017-05-30 17:15:11 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/unique_id.rb:35:in `dump_unique_id_hex'
  2017-05-30 17:15:11 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/plugin/output.rb:923:in `commit_write'
  2017-05-30 17:15:11 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/plugin/out_forward.rb:495:in `block in ack_reader'
  2017-05-30 17:15:11 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/plugin/out_forward.rb:493:in `each'
  2017-05-30 17:15:11 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/plugin/out_forward.rb:493:in `ack_reader'
  2017-05-30 17:15:11 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/plugin_helper/thread.rb:78:in `block in thread_create'
2017-05-30 17:16:09 +0000 [warn]: #0 destination node closed the connection. regard it as unavailable. host="127.0.0.1" port=24224
2017-05-30 17:16:09 +0000 [error]: #0 unexpected error while receiving ack error_class=NoMethodError error="undefined method `unpack' for nil:NilClass"
  2017-05-30 17:16:09 +0000 [error]: #0 suppressed same stacktrace
2017-05-30 17:16:51 +0000 [warn]: #0 destination node closed the connection. regard it as unavailable. host="127.0.0.1" port=24224
2017-05-30 17:16:51 +0000 [error]: #0 unexpected error while receiving ack error_class=NoMethodError error="undefined method `unpack' for nil:NilClass"
  2017-05-30 17:16:51 +0000 [error]: #0 suppressed same stacktrace
2017-05-30 17:17:44 +0000 [warn]: #0 destination node closed the connection. regard it as unavailable. host="127.0.0.1" port=24224
2017-05-30 17:17:44 +0000 [error]: #0 unexpected error while receiving ack error_class=NoMethodError error="undefined method `unpack' for nil:NilClass"
  2017-05-30 17:17:44 +0000 [error]: #0 suppressed same stacktrace
2017-05-30 17:18:26 +0000 [warn]: #0 failed to flush the buffer chunk, timeout to commit. chunk_id="550c0f0d6c36078b55e7e870825cdfa3" flushed_at=2017-05-30 17:15:08 +0000
2017-05-30 17:18:44 +0000 [warn]: #0 retry succeeded. chunk_id="550c0f0d6c36078b55e7e870825cdfa3"
2017-05-30 17:19:24 +0000 [warn]: #0 failed to flush the buffer chunk, timeout to commit. chunk_id="550c0f4798b0b0b2b2f7a9166889b72a" flushed_at=2017-05-30 17:16:04 +0000
2017-05-30 17:19:35 +0000 [warn]: #0 retry succeeded. chunk_id="550c1009faf1183d6ddc6c6385fae7ea"
2017-05-30 17:19:37 +0000 [error]: #0 error on output thread error_class=NoMethodError error="undefined method `next_time' for nil:NilClass"
  2017-05-30 17:19:38 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/plugin/output.rb:1262:in `block in flush_thread_run'
  2017-05-30 17:19:38 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/plugin/output.rb:1262:in `synchronize'
  2017-05-30 17:19:38 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/plugin/output.rb:1262:in `flush_thread_run'
  2017-05-30 17:19:38 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/plugin/output.rb:415:in `block (2 levels) in start'
  2017-05-30 17:19:38 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/plugin_helper/thread.rb:78:in `block in thread_create'
2017-05-30 17:19:41 +0000 [warn]: #0 thread exited by unexpected error plugin=Fluent::Plugin::ForwardOutput title=:flush_thread_11 error_class=NoMethodError error="undefined method `next_time' for nil:NilClass"
2017-05-30 17:19:42 +0000 [error]: #0 unexpected error error_class=NoMethodError error="undefined method `next_time' for nil:NilClass"
  2017-05-30 17:19:42 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/plugin/output.rb:1262:in `block in flush_thread_run'
  2017-05-30 17:19:42 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/plugin/output.rb:1262:in `synchronize'
  2017-05-30 17:19:42 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/plugin/output.rb:1262:in `flush_thread_run'
  2017-05-30 17:19:42 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/plugin/output.rb:415:in `block (2 levels) in start'
  2017-05-30 17:19:42 +0000 [error]: #0 /usr/lib64/ruby/gems/2.3.0/gems/fluentd-0.14.13/lib/fluent/plugin_helper/thread.rb:78:in `block in thread_create'
2017-05-30 17:19:43 +0000 [error]: #0 unexpected error error_class=NoMethodError error="undefined method `next_time' for nil:NilClass"

Config

<source>
  @type tail
  from_encoding utf-8
  encoding utf-8
  tag client.client
  path /var/log/client.stderr.log
  pos_file /var/lib/fluentd/client.stderr.pos
  enable_watch_timer false
  refresh_interval 0.001
  rotate_wait 5
  <parse>
    @type multi_format
    <pattern>
      format json
      time_format %Y-%m-%dT%H:%M:%S.%NZ
    </pattern>
    <pattern>
      format /^(?<unprocessed_message>.*)$/
    </pattern>
  </parse>
</source>

<filter client.client>
  @type record_transformer
  auto_typecast
  enable_ruby
  <record>
    level ${if record["long_level"].to_s.empty?; then case record["long_level"]; when "info"; 5; when "warning"; 4; when "error"; 3; when "fatal"; 2; else 0; end; else 5; end}
    logfile "client.stderr.log"
  </record>
</filter>

<system>
  log_level info
  emit_error_log_interval 1s
</system>

<filter client.*>
  @type record_transformer
  <record>
    client_service ${tag_parts[1]}
  </record>
</filter>

<filter **>
  @type record_transformer
  auto_typecast
  enable_ruby
  <record>
    client_environment "production"
    host "censored.some.tld"
    nanosecond_timestamp "${time.to_f}"
  </record>
</filter>

<match>
  @type forward
  disable_retry_limit true
  require_ack_response true
  send_timeout 20s
  heartbeat_type none
  flush_interval 1s
  buffer_type file
  num_threads 16
  buffer_path /var/lib/fluentd/local.buf

  <server>
    name local_stunnel
    port 24224
    weight 60
    host 127.0.0.1
  </server>
</match>

gcs-github · 2017-05-31T21:29:09Z

I just saw the blog post for 0.14.17, mentioning fixes related to require_ack_response. I'll update. OP didn't seem to have a forwarding configuration though, so this might not be the end of it.

repeatedly · 2017-05-31T23:19:26Z

I'm now working on fixing this problem.
Maybe, this is the last blocker for v0.14 stable :)

repeatedly · 2017-07-11T23:42:26Z

Sorry for the delay. Patch for this issue: #1623

repeatedly · 2017-07-12T20:59:04Z

Released v0.14.19 with the patch.

cosmok closed this as completed May 4, 2017

igorpeshansky mentioned this issue May 8, 2017

unknown method during chunks sending uken/fluent-plugin-elasticsearch#246

Closed

cosmok reopened this May 9, 2017

repeatedly added bug Something isn't working v0.14 labels May 16, 2017

igorpeshansky mentioned this issue Jun 1, 2017

Fix fluentd-gcp image kubernetes-retired/contrib#2625

Merged

igorpeshansky mentioned this issue Jul 7, 2017

v0.14 migration GoogleCloudPlatform/fluent-plugin-google-cloud#136

Closed

repeatedly mentioned this issue Jul 11, 2017

Fix race condition of retry state in flush thread #1623

Merged

repeatedly closed this as completed in #1623 Jul 12, 2017

Lawouach mentioned this issue Mar 1, 2018

Seems not to work on GKE humio/kubernetes2humio#2

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

error_class=NoMethodError error="undefined method `next_time' for nil:NilClass" #1555

error_class=NoMethodError error="undefined method `next_time' for nil:NilClass" #1555

cosmok commented Apr 28, 2017 •

edited

Loading

igorpeshansky commented May 8, 2017

cosmok commented May 9, 2017

gcs-github commented May 31, 2017

gcs-github commented May 31, 2017 •

edited

Loading

repeatedly commented May 31, 2017

repeatedly commented Jul 11, 2017

repeatedly commented Jul 12, 2017

error_class=NoMethodError error="undefined method `next_time' for nil:NilClass" #1555

error_class=NoMethodError error="undefined method `next_time' for nil:NilClass" #1555

Comments

cosmok commented Apr 28, 2017 • edited Loading

igorpeshansky commented May 8, 2017

cosmok commented May 9, 2017

gcs-github commented May 31, 2017

gcs-github commented May 31, 2017 • edited Loading

repeatedly commented May 31, 2017

repeatedly commented Jul 11, 2017

repeatedly commented Jul 12, 2017

cosmok commented Apr 28, 2017 •

edited

Loading

gcs-github commented May 31, 2017 •

edited

Loading