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

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

Closed
luthienberen opened this issue Sep 7, 2019 · 3 comments · Fixed by #2615
Closed

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

luthienberen opened this issue Sep 7, 2019 · 3 comments · Fixed by #2615
Labels
bug Something isn't working

Comments

@luthienberen
Copy link

luthienberen commented Sep 7, 2019

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!

@ganmacs
Copy link
Member

ganmacs commented Sep 9, 2019

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
Copy link

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 ganmacs added the bug Something isn't working label Sep 11, 2019
@ganmacs
Copy link
Member

ganmacs commented Sep 11, 2019

@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>

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants