error_class=ZeroDivisionError error="divided by 0" #2607

luthienberen · 2019-09-07T14:22:20Z

Describe the issue

I've deployed fluentd daemonset and now fluentd logs returns following errors

Your Error Log

kubectl logs fluentd-xzgzv -f

2019-09-07 13:23:35 +0000 [info]: parsing config file is succeeded path="/fluentd/etc/fluent.conf"
2019-09-07 13:23:36 +0000 [warn]: [out_es] 'flush_interval' is ignored because default 'flush_mode' is not 'interval': 'lazy'
2019-09-07 13:23:36 +0000 [warn]: [out_es] Detected ES 7.x or above: `_doc` will be used as the document `_type`.
2019-09-07 13:23:37 +0000 [info]: using configuration file: <ROOT>
  <source>
    @id bridge-containers.log
    @type tail
    path "/var/log/name0-changed/*/*.log,/var/log/name0-changed/name1-changed/*/*.log"
    pos_file "/var/log/name0-changed/name2-changed.log.pos"
    tag "name-changed0"
    read_from_head true
    <parse>
      @type "json"
    </parse>
  </source>
  <source>
    @type tail
    @id in_tail_container_logs
    path "/var/log/containers/*.log"
    pos_file "/var/log/fluentd-containers.log.pos"
    tag "kubernetes"
    read_from_head true
    <parse>
      @type "json"
      time_format "%Y-%m-%dT%H:%M:%S.%NZ"
      time_type string
    </parse>
  </source>
  <filter kubernetes.**>
    @type kubernetes_metadata
    @id filter_kube_metadata
  </filter>
  <source>
    @type tail
    @id in_tail_kube_apiserver_audit
    multiline_flush_interval 5s
    path "/var/log/kubernetes/kube-apiserver-audit.log"
    pos_file "/var/log/kube-apiserver-audit.log.pos"
    tag "kube-apiserver-audit"
    <parse>
      @type "multiline"
      format_firstline "/^\\S+\\s+AUDIT:/"
      format1 /^(?<time>\S+) AUDIT:(?: (?:id="(?<id>(?:[^"\\]|\\.)*)"|ip="(?<ip>(?:[^"\\]|\\.)*)"|method="(?<method>(?:[^"\\]|\\.)*)"|user="(?<user>(?:[^"\\]|\\.)*)"|groups="(?<groups>(?:[^"\\]|\\.)*)"|as="(?<as>(?:[^"\\]|\\.)*)"|asgroups="(?<asgroups>(?:[^"\\]|\\.)*)"|namespace="(?<namespace>(?:[^"\\]|\\.)*)"|uri="(?<uri>(?:[^"\\]|\\.)*)"|response="(?<response>(?:[^"\\]|\\.)*)"|\w+="(?:[^"\\]|\\.)*"))*/
      time_format "%Y-%m-%dT%T.%L%Z"
    </parse>
  </source>
  <source>
    @type systemd
    @id in_systemd_docker
    matches [{"_SYSTEMD_UNIT":"docker.service"}]
    read_from_head true
    tag "docker"
    <storage>
      @type "local"
      persistent true
      path "/var/log/fluentd-journald-docker-cursor.json"
    </storage>
    <entry>
      fields_strip_underscores true
    </entry>
  </source>
  <source>
    @type systemd
    @id in_systemd_kubelet
    matches [{"_SYSTEMD_UNIT":"kubelet.service"}]
    read_from_head true
    tag "kubelet"
    <storage>
      @type "local"
      persistent true
      path "/var/log/fluentd-journald-kubelet-cursor.json"
    </storage>
    <entry>
      fields_strip_underscores true
    </entry>
  </source>
  <source>
    @id kernel
    @type systemd
    matches [{"_TRANSPORT":"kernel"}]
    read_from_head true
    tag "kernel"
    <storage>
      @type "local"
      persistent true
      path "/var/log/fluentd-kernel-cursor.json"
    </storage>
    <entry>
      fields_strip_underscores true
      fields_lowercase true
    </entry>
  </source>
  <source>
    @id prometheus
    @type prometheus
    bind "0.0.0.0"
    port 24231
    metrics_path "/metrics"
  </source>
  <source>
    @id monitor_agent
    @type monitor_agent
  </source>
  <source>
    @id prometheus_monitor
    @type prometheus_monitor
    <labels>
      host ${hostname}
    </labels>
  </source>
  <source>
    @id prometheus_output_monitor
    @type prometheus_output_monitor
    <labels>
      host ${hostname}
    </labels>
  </source>
  <source>
    @id prometheus_tail_monitor
    @type prometheus_tail_monitor
    <labels>
      host ${hostname}
    </labels>
  </source>
  <system>
    root_dir "/tmp/fluentd-buffers/"
  </system>
  <match fluentd.**>
    @type null
  </match>
  <source>
    @id forward
    @type forward
  </source>
  <match **>
    @id out_es
    @type elasticsearch
    @log_level "info"
    verify_es_version_at_startup false
    default_elasticsearch_version 7
    reload_connections false
    reconnect_on_error true
    reload_on_failure true
    request_timeout 120s
    resurrect_after 5s
    include_tag_key true
    type_name "fluentd"
    host "elasticsearch-client"
    port 9200
    scheme http
    ssl_verify true
    ssl_version TLSv1
    logstash_format false
    index_name "fluentd.${tag}"
    unrecoverable_error_types ["out_of_memory_error"]
    <buffer tag, time>
      @type "file"
      timekey @timestamp
      path "/var/log/fluentd-buffers/kubernetes.system.buffer"
      flush_thread_count 8
      flush_interval 5s
      retry_forever true
      retry_max_interval 30
      chunk_limit_size 2M
      queue_limit_length 32
    </buffer>
  </match>
</ROOT>
2019-09-07 13:23:37 +0000 [info]: starting fluentd-1.7.0 pid=7 ruby="2.6.3"
2019-09-07 13:23:37 +0000 [info]: spawn command to main:  cmdline=["/usr/local/bin/ruby", "-Eascii-8bit:ascii-8bit", "/fluentd/vendor/bundle/ruby/2.6.0/bin/fluentd", "-c", "/fluentd/etc/fluent.conf", "-p", "/fluentd/plugins", "--gemfile", "/fluentd/Gemfile", "--under-supervisor"]
2019-09-07 13:23:39 +0000 [info]: gem 'fluent-plugin-concat' version '2.3.0'
2019-09-07 13:23:39 +0000 [info]: gem 'fluent-plugin-elasticsearch' version '3.5.5'
2019-09-07 13:23:39 +0000 [info]: gem 'fluent-plugin-grok-parser' version '2.5.1'
2019-09-07 13:23:39 +0000 [info]: gem 'fluent-plugin-json-in-json-2' version '1.0.2'
2019-09-07 13:23:39 +0000 [info]: gem 'fluent-plugin-kubernetes_metadata_filter' version '2.3.0'
2019-09-07 13:23:39 +0000 [info]: gem 'fluent-plugin-multi-format-parser' version '1.0.0'
2019-09-07 13:23:39 +0000 [info]: gem 'fluent-plugin-prometheus' version '1.5.0'
2019-09-07 13:23:39 +0000 [info]: gem 'fluent-plugin-record-modifier' version '2.0.1'
2019-09-07 13:23:39 +0000 [info]: gem 'fluent-plugin-rewrite-tag-filter' version '2.2.0'
2019-09-07 13:23:39 +0000 [info]: gem 'fluent-plugin-systemd' version '1.0.2'
2019-09-07 13:23:39 +0000 [info]: gem 'fluentd' version '1.7.0'
2019-09-07 13:23:39 +0000 [info]: adding filter pattern="kubernetes.**" type="kubernetes_metadata"
2019-09-07 13:23:40 +0000 [info]: adding match pattern="fluentd.**" type="null"
2019-09-07 13:23:40 +0000 [info]: adding match pattern="**" type="elasticsearch"
2019-09-07 13:23:41 +0000 [warn]: #0 [out_es] 'flush_interval' is ignored because default 'flush_mode' is not 'interval': 'lazy'
2019-09-07 13:23:41 +0000 [warn]: #0 [out_es] Detected ES 7.x or above: `_doc` will be used as the document `_type`.
2019-09-07 13:23:41 +0000 [info]: adding source type="tail"
2019-09-07 13:23:41 +0000 [info]: adding source type="tail"
2019-09-07 13:23:41 +0000 [info]: adding source type="tail"
2019-09-07 13:23:41 +0000 [info]: adding source type="systemd"
2019-09-07 13:23:41 +0000 [info]: adding source type="systemd"
2019-09-07 13:23:41 +0000 [info]: adding source type="systemd"
2019-09-07 13:23:41 +0000 [info]: adding source type="prometheus"
2019-09-07 13:23:41 +0000 [info]: adding source type="monitor_agent"
2019-09-07 13:23:41 +0000 [info]: adding source type="prometheus_monitor"
2019-09-07 13:23:41 +0000 [info]: adding source type="prometheus_output_monitor"
2019-09-07 13:23:41 +0000 [info]: adding source type="prometheus_tail_monitor"
2019-09-07 13:23:41 +0000 [info]: adding source type="forward"
2019-09-07 13:23:41 +0000 [info]: #0 starting fluentd worker pid=12 ppid=7 worker=0
2019-09-07 13:23:41 +0000 [info]: #0 [forward] listening port port=24224 bind="0.0.0.0"
2019-09-07 13:23:41 +0000 [error]: #0 [out_es] unexpected error while checking flushed chunks. ignored. error_class=ZeroDivisionError error="divided by 0"
  2019-09-07 13:23:41 +0000 [error]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:1379:in `%'
  2019-09-07 13:23:41 +0000 [error]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:1379:in `enqueue_thread_run'
  2019-09-07 13:23:41 +0000 [error]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin_helper/thread.rb:78:in `block in thread_create'
2019-09-07 13:23:41 +0000 [info]: #0 [in_tail_container_logs] following tail of /var/log/containers/elasticsearch-client-854bc5db48-5dfxn_logging_sysctl-04ac2b076f4254cd239aa7c7e7c241b734e01a32d16ad858ac11e0eb152e45bb.log
2019-09-07 13:23:41 +0000 [info]: #0 [in_tail_container_logs] following tail of /var/log/containers/fluentd-xzgzv_logging_fluentd-elasticsearch-5eb328828a5f7047742b2d411e26e6c0d817ced571afe4f2181c1786482cb030.log
2019-09-07 13:23:41 +0000 [warn]: #0 emit transaction failed: error_class=ZeroDivisionError error="divided by 0" location="/fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:851:in `%'" tag="kubernetes"
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:851:in `%'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:851:in `calculate_timekey'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:829:in `metadata'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:962:in `block in handle_stream_with_standard_format'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/event.rb:197:in `block in each'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/event.rb:196:in `each'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/event.rb:196:in `each'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:961:in `handle_stream_with_standard_format'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:871:in `execute_chunking'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:797:in `emit_buffered'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/event_router.rb:160:in `emit_events'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/event_router.rb:97:in `emit_stream'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/in_tail.rb:410:in `receive_lines'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/in_tail.rb:528:in `wrap_receive_lines'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/in_tail.rb:762:in `block in handle_notify'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/in_tail.rb:806:in `with_io'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/in_tail.rb:742:in `handle_notify'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/in_tail.rb:738:in `block in on_notify'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/in_tail.rb:738:in `synchronize'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/in_tail.rb:738:in `on_notify'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/in_tail.rb:558:in `on_notify'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/in_tail.rb:532:in `attach'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/in_tail.rb:281:in `setup_watcher'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/in_tail.rb:312:in `block in start_watchers'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/in_tail.rb:298:in `each'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/in_tail.rb:298:in `start_watchers'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/in_tail.rb:275:in `refresh_watchers'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/in_tail.rb:203:in `start'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/root_agent.rb:203:in `block in start'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/root_agent.rb:192:in `block (2 levels) in lifecycle'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/root_agent.rb:191:in `each'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/root_agent.rb:191:in `block in lifecycle'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/root_agent.rb:178:in `each'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/root_agent.rb:178:in `lifecycle'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/root_agent.rb:202:in `start'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/engine.rb:274:in `start'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/engine.rb:219:in `run'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/supervisor.rb:808:in `run_engine'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/supervisor.rb:551:in `block in run_worker'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/supervisor.rb:733:in `main_process'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/supervisor.rb:546:in `run_worker'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/command/fluentd.rb:320:in `<top (required)>'
  2019-09-07 13:23:41 +0000 [warn]: #0 /usr/local/lib/ruby/2.6.0/rubygems/core_ext/kernel_require.rb:54:in `require'
  2019-09-07 13:23:41 +0000 [warn]: #0 /usr/local/lib/ruby/2.6.0/rubygems/core_ext/kernel_require.rb:54:in `require'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/bin/fluentd:8:in `<top (required)>'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/bin/fluentd:23:in `load'
  2019-09-07 13:23:41 +0000 [warn]: #0 /fluentd/vendor/bundle/ruby/2.6.0/bin/fluentd:23:in `<main>'
2019-09-07 13:23:41 +0000 [info]: #0 [in_tail_container_logs] following tail of /var/log/containers/kube-proxy-lgttx_kube-system_kube-proxy-db6caa21d6facf61ee2d7a0782ba9b36a1e7e65ef8811c476c94817944be0441.log
2019-09-07 13:23:41 +0000 [info]: #0 [in_tail_container_logs] following tail of /var/log/containers/weave-net-5mqvj_kube-system_weave-ea77b3fcfaccb6412a85ed2193af4c44fc4b9f51935fbb9c572972d0ef17c1f5.log
2019-09-07 13:23:41 +0000 [warn]: #0 emit transaction failed: error_class=ZeroDivisionError error="divided by 0" location="/fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:851:in `%'" tag="kubernetes"
  2019-09-07 13:23:41 +0000 [warn]: #0 suppressed same stacktrace
2019-09-07 13:23:41 +0000 [info]: #0 [in_tail_container_logs] following tail of /var/log/containers/weave-net-5mqvj_kube-system_weave-npc-f52c8616fa657478e6c9bdbabdd6501bc26a8a8a037a7f674b580d22db9e9b62.log
2019-09-07 13:23:41 +0000 [warn]: #0 emit transaction failed: error_class=ZeroDivisionError error="divided by 0" location="/fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:851:in `%'" tag="kubernetes"
  2019-09-07 13:23:41 +0000 [warn]: #0 suppressed same stacktrace
2019-09-07 13:23:41 +0000 [info]: #0 [in_tail_container_logs] following tail of /var/log/containers/weave-scope-agent-dbtxc_weave_scope-agent-307b86ec2c9cae0a716b12bb44916d7ad96481bdaaf600b50c95b2fd996ea456.log
2019-09-07 13:23:41 +0000 [info]: #0 [in_tail_container_logs] following tail of /var/log/containers/harbor-portal-7fd6cfc989-snn8f_harbor_portal-fadbfc0cef525c8c1ddbfce13e2989d8211728b9d7020144435861965d0669b1.log
2019-09-07 13:23:41 +0000 [warn]: #0 emit transaction failed: error_class=ZeroDivisionError error="divided by 0" location="/fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:851:in `%'" tag="kubernetes"
  2019-09-07 13:23:41 +0000 [warn]: #0 suppressed same stacktrace
...

Following with a lot of 'ZeroDivisionError's

...
2019-09-07 13:30:47 +0000 [warn]: #0 emit transaction failed: error_class=ZeroDivisionError error="divided by 0" location="/fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:851:in `%'" tag="kubernetes"
  2019-09-07 13:30:47 +0000 [warn]: #0 suppressed same stacktrace
2019-09-07 13:30:47 +0000 [warn]: #0 emit transaction failed: error_class=ZeroDivisionError error="divided by 0" location="/fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:851:in `%'" tag="fluent.warn"
  2019-09-07 13:30:47 +0000 [warn]: #0 suppressed same stacktrace
2019-09-07 13:30:47 +0000 [error]: #0 failed to emit fluentd's log event tag="fluent.warn" event={"error"=>"#<ZeroDivisionError: divided by 0>", "location"=>"/fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:851:in `%'", "tag"=>"kubernetes", "message"=>"emit transaction failed: error_class=ZeroDivisionError error=\"divided by 0\" location=\"/fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:851:in `%'\" tag=\"kubernetes\""} error_class=ZeroDivisionError error="divided by 0"
2019-09-07 13:30:47 +0000 [warn]: #0 emit transaction failed: error_class=ZeroDivisionError error="divided by 0" location="/fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:851:in `%'" tag="fluent.warn"
  2019-09-07 13:30:47 +0000 [warn]: #0 suppressed same stacktrace
2019-09-07 13:30:47 +0000 [error]: #0 failed to emit fluentd's log event tag="fluent.warn" event={"error"=>"#<ZeroDivisionError: divided by 0>", "location"=>"/fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:851:in `%'", "tag"=>"kubernetes", "message"=>"emit transaction failed: error_class=ZeroDivisionError error=\"divided by 0\" location=\"/fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:851:in `%'\" tag=\"kubernetes\""} error_class=ZeroDivisionError error="divided by 0"
2019-09-07 13:30:48 +0000 [error]: #0 [out_es] unexpected error while checking flushed chunks. ignored. error_class=ZeroDivisionError error="divided by 0"
  2019-09-07 13:30:48 +0000 [error]: #0 suppressed same stacktrace
...

Data is not written, elasticsearch is empty.

Your Environment

CentOS 7.6
Kubernetes: 1.14.1
Fluentd image: fluent/fluentd-kubernetes-daemonset:v1.7.0-debian-elasticsearch7-1.1
Elasticsearch image: docker.elastic.co/elasticsearch/elasticsearch:7.3.0

Your Configuration

Fluentd config map can be found in the beginning of the log

Daemonset yaml:

apiVersion: apps/v1
kind: DaemonSet
metadata:
  name: fluentd
  namespace: logging
  labels:
    app: fluentd
spec:
  updateStrategy:
    type: RollingUpdate
  selector:
    matchLabels:
      app: fluentd
  template:
    metadata:
      labels:
        app: fluentd
      annotations:
        prometheus.io/port: "24231"
        prometheus.io/scrape: "true"
    spec:
      serviceAccountName: fluentd
      containers:
      - name: fluentd-elasticsearch
        image: fluent/fluentd-kubernetes-daemonset:v1.7.0-debian-elasticsearch7-1.1
        imagePullPolicy: Always
        env:
        - name: FLUENT_ELASTICSEARCH_HOST
          value: "elasticsearch-client"
        - name: FLUENT_ELASTICSEARCH_PORT
          value: "9200"
        - name: K8S_NODE_NAME
          valueFrom:
            fieldRef:
              fieldPath: spec.nodeName
        resources:
          limits:
            cpu: 512m
            memory: 1Gi
          requests:
            cpu: 256m
            memory: 500Mi
        volumeMounts:
        - name: varlog
          mountPath: /var/log
        - name: varlibdockercontainers
          mountPath: /var/lib/docker/containers
          readOnly: true
        - name: config-volume
          mountPath: /fluentd/etc
      terminationGracePeriodSeconds: 30
      volumes:
      - name: varlog
        hostPath:
          path: /var/log
      - name: varlibdockercontainers
        hostPath:
          path: /var/lib/docker/containers
      - name: config-volume
        configMap:
          name: fluentd
      tolerations:
      - effect: NoSchedule
        key: node-role.kubernetes.io/master
        operator: Exists

Additional comments

Couldn't find anything about this exception in the internet and posting it as an issue here

I hope someone will help me with this

Thanks in advance!

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

ganmacs · 2019-09-09T03:28:31Z

I'm not sure why this error happens. but according to the log, Time.now.to_i returns 0 in your environment(now_int is calculated in L1360).

Did you set any env vars or something?

https://github.com/fluent/fluentd/blob/v1.7.0/lib/fluent/plugin/output.rb#L1379

2019-09-07 13:23:41 +0000 [error]: #0 [out_es] unexpected error while checking flushed chunks. ignored. error_class=ZeroDivisionError error="divided by 0"
2019-09-07 13:23:41 +0000 [error]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:1379:in %' 2019-09-07 13:23:41 +0000 [error]: #0 /fluentd/vendor/bundle/ruby/2.6.0/gems/fluentd-1.7.0/lib/fluent/plugin/output.rb:1379:in enqueue_thread_run'
2019-09-07 13:23:41 +0000 [error]: #0 /fluentd/vendor/bundle

yelavalli · 2019-09-10T09:36:58Z

Looks like timekey is declared but not assigned any value in the buffer configs.
"timekey @timestamp". As @ganmacs pointed, the key is used in timechunk calculation and will raise this error when not defined.

ganmacs · 2019-09-11T06:05:23Z

@yelavalli Thanks for additional info.
Right. @timestamp in the config seems not to set any value. and if timekey is not set a value, timekey is 0.0 in fluentd. Below config is minimal one to reproduce this error.
This behavior is pretty unkindly for users. so I made PR to raise an error when timekey is set no value or less than equal 0. #2615

<source>
  @type dummy
  tag dummy
</source>

<match dummy>
  @type stdout

  <buffer time>
    timekey
  </buffer>
</match>

ganmacs added the bug Something isn't working label Sep 11, 2019

ganmacs mentioned this issue Sep 11, 2019

validate if timkey is less than equal 0 #2615

Merged

ganmacs mentioned this issue Sep 11, 2019

Add option to make config value more stricitive #2616

Closed

ganmacs closed this as completed in #2615 Sep 11, 2019

ashie mentioned this issue Nov 6, 2019

Make config values more strictly and enable to set nil or default #2685

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

error_class=ZeroDivisionError error="divided by 0" #2607

error_class=ZeroDivisionError error="divided by 0" #2607

luthienberen commented Sep 7, 2019 •

edited

Loading

ganmacs commented Sep 9, 2019

yelavalli commented Sep 10, 2019

ganmacs commented Sep 11, 2019

error_class=ZeroDivisionError error="divided by 0" #2607

error_class=ZeroDivisionError error="divided by 0" #2607

Comments

luthienberen commented Sep 7, 2019 • edited Loading

ganmacs commented Sep 9, 2019

yelavalli commented Sep 10, 2019

ganmacs commented Sep 11, 2019

luthienberen commented Sep 7, 2019 •

edited

Loading