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.

Sign up for GitHub

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

Jump to bottom

pos file error #1953

Closed
jl2005 opened this issue Apr 18, 2018 · 2 comments
Closed

pos file error #1953

jl2005 opened this issue Apr 18, 2018 · 2 comments

Comments

@jl2005
Copy link
Contributor

jl2005 commented Apr 18, 2018 •
edited
Loading

fluentd or td-agent version.

fluentd 0.12.42

Environment information, e.g. OS.

Linux version 4.4.113-1.el7.elrepo.x86_64 (mockbuild@Build64R7) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-16) (GCC) ) #1 SMP Tue Jan 23 18:27:06 EST 2018

Start

/usr/bin/ruby2.3 /usr/local/bin/fluentd -p /etc/fluent/plugins --no-supervisor -q

Your configuration

<source>
  @type tail
  tag raw.kubernetes.*
  path /var/log/containers/*.log
  pos_file /var/log/fluentd-containers.log.pos
  format json
  time_key not-parse-time
  read_from_head true
</source>

<match **fluentd**>
  @type null
</match>

<match **kubernetes-log-tail-bigdatalog**>
  @type null
</match>

<match raw.**>
  @type detect_exceptions
  remove_tag_prefix raw
  languages java, go, php
  message log
  stream stream
  multiline_flush_interval 0.1
  max_bytes 500000
  max_lines 1000
</match>

<filter kubernetes.**>
  @type kubernetes_metadata
  annotation_match ["^log-filter-.*", "^log-type-hints-.*"]
  merge_json_log false
</filter>

<filter kubernetes.**>
  @type kubernetes_annotations
</filter>

<source>
  @type tail
  tag kubernetes_core
  path /var/log/calico/*/current
  pos_file /var/log/fluentd-calico.log.pos
  read_from_head true
  format none
</source>

<source>
  @type systemd
  tag kubernetes_core
  path /var/log/journal
  filters [{ "_SYSTEMD_UNIT": ["kubelet.service", "etcd.service", "docker.service"]}]
  read_from_head true
  pos_file /var/log/fluentd-systemd.log.pos
</source>

<filter kubernetes_core.**>
  @type record_transformer
  <record>
    topic k8s_kubernetes_core
  </record>
</filter>

<source>
  @type monitor_agent
   bind 0.0.0.0
   port 24220
</source>

# input plugin that is required to expose metrics by other prometheus # plugins, such as the prometheus_monitor input below.
<source>
  @type prometheus
  bind 0.0.0.0
  port 24231
  metrics_path /metrics
</source>

# input plugin that collects metrics from MonitorAgent and exposes them
# as prometheus metrics
<source>
  @type prometheus_monitor
  # update the metrics every 5 seconds
  interval 5
</source>

<source>
  @type prometheus_output_monitor
  interval 5
</source>

<source>
  @type prometheus_tail_monitor
  interval 5
</source>

<match **>
   @type kafka_buffered

   brokers "#{ENV['FLUENT_KAFKA_BROKERS']}"
   default_topic k8s_unexpected-logs
   #get_kafka_client_log true

   output_include_tag false
   output_include_time false
   exclude_topic_key false
   exclude_partition_key true

   output_data_type json

   buffer_type file
   buffer_path /var/log/td-agent/buffer/td
   buffer_chunk_limit 64M
   buffer_queue_limit 512
   flush_interval 3s

   kafka_agg_max_bytes 1M
   compression_codec gzip
   required_acks 1
   num_threads 4
   max_send_retries 3
   max_retry_wait 10
   disable_retry_limit
</match>

Your problem explanation. If you have an error logs, write it together.

I use fluentd read k8s log, but pos_file ( /var/log/fluentd-containers.log.pos) get wrong. like this

/var/log/containers/percona-server-31280-6b48fb6848-ghr2t_xxpc_percona-server-31280-1e394dcc11b6675088b7d5e30c05df137cd04383bfd6cd5ed53ac176d2262a23.log	000000000000214b00000000005b7dad8

\t become 0

when I stat this file, get

root@fluentd-dnfj8:/var/log# stat /var/lib/docker/containers/1e394dcc11b6675088b7d5e30c05df137cd04383bfd6cd5ed53ac176d2262a23/1e394dcc11b6675088b7d5e30c05df137cd04383bfd6cd5ed53ac176d2262a23-json.log
  File: /var/lib/docker/containers/1e394dcc11b6675088b7d5e30c05df137cd04383bfd6cd5ed53ac176d2262a23/1e394dcc11b6675088b7d5e30c05df137cd04383bfd6cd5ed53ac176d2262a23-json.log
  Size: 8523      	Blocks: 24         IO Block: 4096   regular file
Device: 803h/2051d	Inode: 5898424     Links: 1
Access: (0640/-rw-r-----)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2018-04-17 06:56:14.893796062 +0000
Modify: 2018-04-03 06:56:13.469851071 +0000
Change: 2018-04-03 06:56:13.469851071 +0000
 Birth: -

In pos file, It is file size is right, but it is inode is not right.

prometheus get result:

# curl -s 10.233.96.184:24231/metrics |grep 1e394dcc11b6675088b7d5e30c05df137cd04383bfd6cd5ed53ac176d2262a23

fluentd_tail_file_position{plugin_id="object:3f8988b4e370",type="tail",path="/var/log/containers/percona-server-31280-6b48fb6848-ghr2t_xxpc_percona-server-31280-1e394dcc11b6675088b7d5e30c05df137cd04383bfd6cd5ed53ac176d2262a23.log"} 8523.0
fluentd_tail_file_inode{plugin_id="object:3f8988b4e370",type="tail",path="/var/log/containers/percona-server-31280-6b48fb6848-ghr2t_xxpc_percona-server-31280-1e394dcc11b6675088b7d5e30c05df137cd04383bfd6cd5ed53ac176d2262a23.log"} 95935192.0

It is inode is match pos file.

dump file:

Sigdump at 2018-04-18 06:59:05 +0000 process 9 (/usr/local/bin/fluentd)
  Thread #<Thread:0x007f131a17e1a0> status=run priority=0
      /var/lib/gems/2.3.0/gems/sigdump-0.2.4/lib/sigdump.rb:52:in `backtrace'
      /var/lib/gems/2.3.0/gems/sigdump-0.2.4/lib/sigdump.rb:52:in `dump_backtrace'
      /var/lib/gems/2.3.0/gems/sigdump-0.2.4/lib/sigdump.rb:34:in `block in dump_all_thread_backtrace'
      /var/lib/gems/2.3.0/gems/sigdump-0.2.4/lib/sigdump.rb:33:in `each'
      /var/lib/gems/2.3.0/gems/sigdump-0.2.4/lib/sigdump.rb:33:in `dump_all_thread_backtrace'
      /var/lib/gems/2.3.0/gems/sigdump-0.2.4/lib/sigdump.rb:16:in `block in dump'
      /var/lib/gems/2.3.0/gems/sigdump-0.2.4/lib/sigdump.rb:136:in `open'
      /var/lib/gems/2.3.0/gems/sigdump-0.2.4/lib/sigdump.rb:136:in `_open_dump_path'
      /var/lib/gems/2.3.0/gems/sigdump-0.2.4/lib/sigdump.rb:14:in `dump'
      /var/lib/gems/2.3.0/gems/sigdump-0.2.4/lib/sigdump.rb:7:in `block in setup'
      /var/lib/gems/2.3.0/gems/cool.io-1.5.3/lib/cool.io/loop.rb:88:in `run_once'
      /var/lib/gems/2.3.0/gems/cool.io-1.5.3/lib/cool.io/loop.rb:88:in `run'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/engine.rb:199:in `run'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/supervisor.rb:570:in `run_engine'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/supervisor.rb:176:in `block in start'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/supervisor.rb:366:in `main_process'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/supervisor.rb:170:in `start'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/command/fluentd.rb:173:in `<top (required)>'
      /usr/lib/ruby/2.3.0/rubygems/core_ext/kernel_require.rb:55:in `require'
      /usr/lib/ruby/2.3.0/rubygems/core_ext/kernel_require.rb:55:in `require'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/bin/fluentd:8:in `<top (required)>'
      /usr/local/bin/fluentd:22:in `load'
      /usr/local/bin/fluentd:22:in `<main>'
  Thread #<Thread:0x007f1314012358> status=sleep priority=0
      /var/lib/gems/2.3.0/gems/fluent-plugin-detect-exceptions-0.0.9/lib/fluent/plugin/out_detect_exceptions.rb:115:in `sleep'
      /var/lib/gems/2.3.0/gems/fluent-plugin-detect-exceptions-0.0.9/lib/fluent/plugin/out_detect_exceptions.rb:115:in `block (2 levels) in check_flush_loop'
      /var/lib/gems/2.3.0/gems/fluent-plugin-detect-exceptions-0.0.9/lib/fluent/plugin/out_detect_exceptions.rb:114:in `loop'
      /var/lib/gems/2.3.0/gems/fluent-plugin-detect-exceptions-0.0.9/lib/fluent/plugin/out_detect_exceptions.rb:114:in `block in check_flush_loop'
      /var/lib/gems/2.3.0/gems/fluent-plugin-detect-exceptions-0.0.9/lib/fluent/plugin/out_detect_exceptions.rb:113:in `synchronize'
      /var/lib/gems/2.3.0/gems/fluent-plugin-detect-exceptions-0.0.9/lib/fluent/plugin/out_detect_exceptions.rb:113:in `check_flush_loop'
  Thread #<Thread:0x007f1310ad5be0> status=sleep priority=0
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/output.rb:174:in `sleep'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/output.rb:174:in `wait'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/output.rb:174:in `cond_wait'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/output.rb:158:in `run'
  Thread #<Thread:0x007f1310ad5a00> status=sleep priority=0
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/output.rb:174:in `sleep'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/output.rb:174:in `wait'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/output.rb:174:in `cond_wait'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/output.rb:158:in `run'
  Thread #<Thread:0x007f1310ad5820> status=sleep priority=0
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/output.rb:174:in `sleep'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/output.rb:174:in `wait'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/output.rb:174:in `cond_wait'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/output.rb:158:in `run'
  Thread #<Thread:0x007f1310ad5640> status=sleep priority=0
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/output.rb:174:in `sleep'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/output.rb:174:in `wait'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/output.rb:174:in `cond_wait'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/output.rb:158:in `run'
  Thread #<Thread:0x007f1313fe8328> status=sleep priority=0
      /var/lib/gems/2.3.0/gems/cool.io-1.5.3/lib/cool.io/loop.rb:88:in `run_once'
      /var/lib/gems/2.3.0/gems/cool.io-1.5.3/lib/cool.io/loop.rb:88:in `run'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/plugin/in_tail.rb:316:in `run'
  Thread #<Thread:0x007f130f74d8e8> status=sleep priority=0
      /var/lib/gems/2.3.0/gems/cool.io-1.5.3/lib/cool.io/loop.rb:88:in `run_once'
      /var/lib/gems/2.3.0/gems/cool.io-1.5.3/lib/cool.io/loop.rb:88:in `run'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/plugin/in_tail.rb:316:in `run'
  Thread #<Thread:0x007f130f74d758> status=sleep priority=0
      /var/lib/gems/2.3.0/gems/fluent-plugin-systemd-0.0.9/lib/fluent/plugin/systemd/pos_writer.rb:43:in `sleep'
      /var/lib/gems/2.3.0/gems/fluent-plugin-systemd-0.0.9/lib/fluent/plugin/systemd/pos_writer.rb:43:in `work'
  Thread #<Thread:0x007f130f74d528> status=sleep priority=0
      /var/lib/gems/2.3.0/gems/fluent-plugin-systemd-0.0.9/lib/fluent/plugin/in_systemd.rb:97:in `sleep'
      /var/lib/gems/2.3.0/gems/fluent-plugin-systemd-0.0.9/lib/fluent/plugin/in_systemd.rb:97:in `watch'
      /var/lib/gems/2.3.0/gems/fluent-plugin-systemd-0.0.9/lib/fluent/plugin/in_systemd.rb:70:in `run'
  Thread #<Thread:0x007f13125df1e8> status=sleep priority=0
      /usr/lib/ruby/2.3.0/webrick/server.rb:177:in `select'
      /usr/lib/ruby/2.3.0/webrick/server.rb:177:in `block in start'
      /usr/lib/ruby/2.3.0/webrick/server.rb:33:in `start'
      /usr/lib/ruby/2.3.0/webrick/server.rb:164:in `start'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/plugin/in_monitor_agent.rb:265:in `block in start'
  Thread #<Thread:0x007f13125de108> status=sleep priority=0
      /usr/lib/ruby/2.3.0/webrick/server.rb:177:in `select'
      /usr/lib/ruby/2.3.0/webrick/server.rb:177:in `block in start'
      /usr/lib/ruby/2.3.0/webrick/server.rb:33:in `start'
      /usr/lib/ruby/2.3.0/webrick/server.rb:164:in `start'
      /var/lib/gems/2.3.0/gems/fluent-plugin-prometheus-0.3.0/lib/fluent/plugin/in_prometheus.rb:33:in `block in start'
  Thread #<Thread:0x007f13125ddd48> status=sleep priority=0
      /var/lib/gems/2.3.0/gems/cool.io-1.5.3/lib/cool.io/loop.rb:88:in `run_once'
      /var/lib/gems/2.3.0/gems/cool.io-1.5.3/lib/cool.io/loop.rb:88:in `run'
      /var/lib/gems/2.3.0/gems/fluent-plugin-prometheus-0.3.0/lib/fluent/plugin/in_prometheus_monitor.rb:82:in `run'
  Thread #<Thread:0x007f13125dda78> status=sleep priority=0
      /var/lib/gems/2.3.0/gems/cool.io-1.5.3/lib/cool.io/loop.rb:88:in `run_once'
      /var/lib/gems/2.3.0/gems/cool.io-1.5.3/lib/cool.io/loop.rb:88:in `run'
      /var/lib/gems/2.3.0/gems/fluent-plugin-prometheus-0.3.0/lib/fluent/plugin/in_prometheus_output_monitor.rb:109:in `run'
  Thread #<Thread:0x007f13125dd730> status=sleep priority=0
      /var/lib/gems/2.3.0/gems/cool.io-1.5.3/lib/cool.io/loop.rb:88:in `run_once'
      /var/lib/gems/2.3.0/gems/cool.io-1.5.3/lib/cool.io/loop.rb:88:in `run'
      /var/lib/gems/2.3.0/gems/fluent-plugin-prometheus-0.3.0/lib/fluent/plugin/in_prometheus_tail_monitor.rb:79:in `run'
  Thread #<Thread:0x007f13125dd488> status=sleep priority=0
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/engine.rb:167:in `sleep'
      /var/lib/gems/2.3.0/gems/fluentd-0.12.42/lib/fluent/engine.rb:167:in `log_event_loop'
  Thread #<WEBrick::Utils::TimeoutHandler::Thread:0x007f1312d9c480> status=sleep priority=0
      /usr/lib/ruby/2.3.0/webrick/utils.rb:177:in `pop'
      /usr/lib/ruby/2.3.0/webrick/utils.rb:177:in `block in initialize'
  GC stat:
      count: 7459
      heap_allocated_pages: 1173
      heap_sorted_length: 1368
      heap_allocatable_pages: 0
      heap_available_slots: 478120
      heap_live_slots: 476734
      heap_free_slots: 1386
      heap_final_slots: 0
      heap_marked_slots: 176641
      heap_swept_slots: 55565
      heap_eden_pages: 1173
      heap_tomb_pages: 0
      total_allocated_pages: 1233
      total_freed_pages: 60
      total_allocated_objects: 2244134096
      total_freed_objects: 2243657362
      malloc_increase_bytes: 1631440
      malloc_increase_bytes_limit: 19844138
      minor_gc_count: 6528
      major_gc_count: 931
      remembered_wb_unprotected_objects: 6649
      remembered_wb_unprotected_objects_limit: 7536
      old_objects: 165491
      old_objects_limit: 298694
      oldmalloc_increase_bytes: 16953200
      oldmalloc_increase_bytes_limit: 46921085
  Built-in objects:
   478,120: TOTAL
   242,420: T_STRING
    63,352: T_ARRAY
    45,815: T_DATA
    42,819: T_IMEMO
    33,885: T_HASH
    33,141: T_OBJECT
     4,947: T_STRUCT
     3,767: T_CLASS
     2,593: T_NODE
     1,508: T_MATCH
     1,280: FREE
     1,225: T_REGEXP
       332: T_SYMBOL
       263: T_MODULE
       262: T_ICLASS
       257: T_BIGNUM
       141: T_FILE
       103: T_RATIONAL
         9: T_FLOAT
         1: T_COMPLEX
@jl2005
Copy link
Contributor Author

jl2005 commented Apr 18, 2018

@repeatedly Can you help me?

@jl2005 jl2005 mentioned this issue Apr 28, 2018
Closed
@jl2005
Copy link
Contributor Author

jl2005 commented Apr 28, 2018

This conflict is cause by prometheus_tail_monitor concurrent access to Fluent::Plugin::TailInput

Detail Info see

fluent/fluent-plugin-prometheus#49

jl2005 added a commit to jl2005/fluentd that referenced this issue Apr 28, 2018
@jl2005
change read_pos and read_ino. relate fluent#1953 fluent#1804
7e17b93 
Signed-off-by: 焦龙 <jiaolongdy@163.com>
repeatedly added a commit that referenced this issue Jun 11, 2018
@repeatedly
Merge pull request #1963 from jl2005/master
31fb6a4 
change read_pos and read_ino. relate #1953 #1804
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@repeatedly @jl2005