fluentd
fluentd copied to clipboard
unexpected error error_class=TypeError error="no implicit conversion of Symbol into Integer"
always output error log unexpected error error_class=TypeError error="no implicit conversion of Symbol into Integer"
, restart is the same error. log is from other fluentd forward.
- fluentd version 1.1.
- docker.
fluentd config:
<source>
@type forward
port 9988
</source>
<system>
workers 20
root_dir /data/fluentd-buffer/
</system>
<match log.*>
@type bigquery
@id bigquery
method insert
auth_method json_key
json_key /etc/td-agent/bigquery.json
project test
dataset logs
table ${tag[3]}
fetch_schema true
<buffer tag>
@type file
flush_mode interval
flush_interval 5s
chunk_limit_records 10000
chunk_limit_size 4m
retry_forever true
retry_wait 1
retry_type periodic
retry_max_interval 3
timekey_zone +0900
flush_thread_count 16
</buffer>
</match>
error log:
2018-03-15 11:23:39 +0900 [error]: #15 unexpected error error_class=TypeError error="no implicit conversion of Symbol into Integer"
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/plugin/buffer/file_chunk.rb:219:in `[]'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/plugin/buffer/file_chunk.rb:219:in `restore_metadata'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/plugin/buffer/file_chunk.rb:322:in `load_existing_staged_chunk'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/plugin/buffer/file_chunk.rb:51:in `initialize'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/plugin/buf_file.rb:144:in `new'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/plugin/buf_file.rb:144:in `block in resume'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/plugin/buf_file.rb:133:in `glob'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/plugin/buf_file.rb:133:in `resume'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/plugin/buffer.rb:171:in `start'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/plugin/buf_file.rb:120:in `start'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/plugin/output.rb:415:in `start'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/plugin_helper/formatter.rb:96:in `start'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluent-plugin-bigquery-1.2.0/lib/fluent/plugin/out_bigquery.rb:265:in `start'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/root_agent.rb:165:in `block in start'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/root_agent.rb:154:in `block (2 levels) in lifecycle'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/root_agent.rb:153:in `each'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/root_agent.rb:153:in `block in lifecycle'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/root_agent.rb:140:in `each'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/root_agent.rb:140:in `lifecycle'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/root_agent.rb:164:in `start'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/engine.rb:274:in `start'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/engine.rb:219:in `run'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/supervisor.rb:774:in `run_engine'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/supervisor.rb:523:in `block in run_worker'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/supervisor.rb:699:in `main_process'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/supervisor.rb:518:in `run_worker'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/lib/fluent/command/fluentd.rb:316:in `<top (required)>'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:in `require'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:in `require'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/lib/ruby/gems/2.4.0/gems/fluentd-1.1.0/bin/fluentd:8:in `<top (required)>'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/bin/fluentd:23:in `load'
2018-03-15 11:23:39 +0900 [error]: #15 /usr/bin/fluentd:23:in `<main>'
2018-03-15 11:23:39 +0900 [error]: #15 unexpected error error_class=TypeError error="no implicit conversion of Symbol into Integer"
2018-03-15 11:23:39 +0900 [error]: #15 suppressed same stacktrace
2018-03-15 11:23:39 +0900 [info]: Worker 15 finished unexpectedly with status 1
I see buffer file is empty, meta file length 84, ASCII value of character is “0”, base64 encode is
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
file list like that:
ls -lh
-rw-r--r--. 1 fluent fluent 0 Mar 14 22:06 buffer.b5675f0b95908a6a2c1dc824da48c5104.log
-rw-r--r--. 1 fluent fluent 84 Mar 14 22:06 buffer.b5675f0b95908a6a2c1dc824da48c5104.log.meta
-rw-r--r--. 1 fluent fluent 0 Mar 14 22:06 buffer.b5675f0b959fcbbc5c3362de4d9026c9e.log
-rw-r--r--. 1 fluent fluent 83 Mar 14 22:06 buffer.b5675f0b959fcbbc5c3362de4d9026c9e.log.meta
-rw-r--r--. 1 fluent fluent 0 Mar 14 22:06 buffer.b5675f0b9b5cc0b7f12f9de5787dd7bef.log
-rw-r--r--. 1 fluent fluent 85 Mar 14 22:06 buffer.b5675f0b9b5cc0b7f12f9de5787dd7bef.log.meta
-rw-r--r--. 1 fluent fluent 0 Mar 14 22:06 buffer.b5675f0b9b731e613fc0d681b54af8008.log
-rw-r--r--. 1 fluent fluent 83 Mar 14 22:06 buffer.b5675f0b9b731e613fc0d681b54af8008.log.meta
-rw-r--r--. 1 fluent fluent 0 Mar 14 22:06 buffer.b5675f0b9c0fe552888d1abb09832ac97.log
-rw-r--r--. 1 fluent fluent 88 Mar 14 22:06 buffer.b5675f0b9c0fe552888d1abb09832ac97.log.meta
-rw-r--r--. 1 fluent fluent 0 Mar 14 22:06 buffer.b5675f0b9c7d3fdfde3022fe491780e53.log
-rw-r--r--. 1 fluent fluent 82 Mar 14 22:06 buffer.b5675f0b9c7d3fdfde3022fe491780e53.log.meta
-rw-r--r--. 1 fluent fluent 0 Mar 14 22:06 buffer.b5675f0b9cbce9da5554dcbcb13f914bf.log
-rw-r--r--. 1 fluent fluent 86 Mar 14 22:06 buffer.b5675f0b9cbce9da5554dcbcb13f914bf.log.meta
-rw-r--r--. 1 fluent fluent 0 Mar 14 22:06 buffer.b5675f0b9e27ab7e0a579153f6190a36d.log
-rw-r--r--. 1 fluent fluent 84 Mar 14 22:06 buffer.b5675f0b9e27ab7e0a579153f6190a36d.log.meta
-rw-r--r--. 1 fluent fluent 0 Mar 14 22:06 buffer.b5675f0badda9da22b770b6276a0745f6.log
-rw-r--r--. 1 fluent fluent 86 Mar 14 22:06 buffer.b5675f0badda9da22b770b6276a0745f6.log.meta
-rw-r--r--. 1 fluent fluent 0 Mar 14 22:06 buffer.b5675f0bae32f344e4bb5cb2679ce6382.log
-rw-r--r--. 1 fluent fluent 84 Mar 14 22:06 buffer.b5675f0bae32f344e4bb5cb2679ce6382.log.meta
-rw-r--r--. 1 fluent fluent 0 Mar 14 22:06 buffer.b5675f0bb3583e43330d2b8694f1ce830.log
-rw-r--r--. 1 fluent fluent 83 Mar 14 22:06 buffer.b5675f0bb3583e43330d2b8694f1ce830.log.meta
-rw-r--r--. 1 fluent fluent 0 Mar 14 22:06 buffer.b5675f0bc96f10431ef8d8a042b9cf016.log
-rw-r--r--. 1 fluent fluent 84 Mar 14 22:06 buffer.b5675f0bc96f10431ef8d8a042b9cf016.log.meta
It is same with https://github.com/fluent/fluentd/issues/1760. v1.1.1 should fix this problem. Try it.
And hmm... you also use docker. We need to investigate why docker has this broken file problem.
Do you use alpine image?
@repeatedly yes, it's alpine. thank you very much.
If you can, could you check this problem happens on Debian image? By the way, we recommend to use debian image because it uses jemalloc for memory allocator.
I want to know what is the cause for investigating this problem.
- Alpine and musl have a problem
- Docker and volume mount have a problem
- Fluentd's buf_file has a problem
fluentd's buf_file doesn't have \0
fill code in metadata file handling, so I assume several factors cause it.
The Dockerfile I use is you provided in github. the problem occurred at #1895 . I don't know why there are so many residual buffer files. There were millions of small buffer files at the time.
Same thing without Docker:
2018-05-17 13:36:42 +0000 [error]: #0 unexpected error error_class=TypeError error="no implicit conversion of Symbol into Integer"
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/plugin/buffer/file_chunk.rb:219:in `[]'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/plugin/buffer/file_chunk.rb:219:in `restore_metadata'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/plugin/buffer/file_chunk.rb:357:in `load_existing_enqueued_chunk'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/plugin/buffer/file_chunk.rb:52:in `initialize'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/plugin/buf_file.rb:144:in `new'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/plugin/buf_file.rb:144:in `block in resume'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/plugin/buf_file.rb:133:in `glob'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/plugin/buf_file.rb:133:in `resume'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/plugin/buffer.rb:171:in `start'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/plugin/buf_file.rb:120:in `start'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/plugin/output.rb:415:in `start'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/root_agent.rb:165:in `block in start'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/root_agent.rb:154:in `block (2 levels) in lifecycle'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/root_agent.rb:153:in `each'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/root_agent.rb:153:in `block in lifecycle'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/root_agent.rb:140:in `each'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/root_agent.rb:140:in `lifecycle'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/root_agent.rb:164:in `start'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/engine.rb:274:in `start'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/engine.rb:219:in `run'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/supervisor.rb:774:in `run_engine'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/supervisor.rb:523:in `block in run_worker'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/supervisor.rb:699:in `main_process'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/supervisor.rb:518:in `run_worker'
2018-05-17 13:36:42 +0000 [error]: #0 /opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/command/fluentd.rb:316:in `<main>'
2018-05-17 13:36:42 +0000 [error]: #0 unexpected error error_class=TypeError error="no implicit conversion of Symbol into Integer"
2018-05-17 13:36:42 +0000 [error]: #0 suppressed same stacktrace
2018-05-17 13:36:43 +0000 [info]: Worker 0 finished unexpectedly with status 1
2018-05-17 13:36:44 +0000 [info]: gem 'fluent-plugin-elasticsearch' version '2.4.0'
2018-05-17 13:36:44 +0000 [info]: gem 'fluent-plugin-flowcounter' version '1.3.0'
2018-05-17 13:36:44 +0000 [info]: gem 'fluent-plugin-kafka' version '0.6.5'
2018-05-17 13:36:44 +0000 [info]: gem 'fluent-plugin-multiprocess' version '0.2.2'
2018-05-17 13:36:44 +0000 [info]: gem 'fluent-plugin-prometheus' version '1.0.1'
2018-05-17 13:36:44 +0000 [info]: gem 'fluent-plugin-rewrite-tag-filter' version '2.0.1'
2018-05-17 13:36:44 +0000 [info]: gem 'fluent-plugin-s3' version '1.1.0'
2018-05-17 13:36:44 +0000 [info]: gem 'fluent-plugin-td' version '1.0.0'
2018-05-17 13:36:44 +0000 [info]: gem 'fluent-plugin-td-monitoring' version '0.2.3'
2018-05-17 13:36:44 +0000 [info]: gem 'fluent-plugin-webhdfs' version '1.2.2'
2018-05-17 13:36:44 +0000 [info]: gem 'fluentd' version '1.0.2'
2018-05-17 13:36:44 +0000 [info]: adding filter pattern="**" type="record_transformer"
2018-05-17 13:36:44 +0000 [info]: adding match pattern="**" type="copy"
2018-05-17 13:36:44 +0000 [info]: adding source type="forward"
root@harvester-gce-be-2:/var/lib/td-agent/buffers/output_elasticsearch-1# ls -la
total 6656
drwxr-xr-x 2 td-agent td-agent 6787072 May 17 13:35 .
drwxr-x--- 19 td-agent adm 4096 Apr 28 18:23 ..
-rw-r--r-- 1 td-agent td-agent 0 May 17 13:35 buffer.b56c66e9a26dad9cf0a805dd8de468a41.log
-rw-r--r-- 1 td-agent td-agent 84 May 17 13:35 buffer.b56c66e9a26dad9cf0a805dd8de468a41.log.meta
-rw-r--r-- 1 td-agent td-agent 0 May 17 13:35 buffer.b56c66e9a6bc9931e744c071c41132ffc.log
-rw-r--r-- 1 td-agent td-agent 80 May 17 13:35 buffer.b56c66e9a6bc9931e744c071c41132ffc.log.meta
-rw-r--r-- 1 td-agent td-agent 0 May 17 13:35 buffer.b56c66e9ad01d5ad1873e202808db8835.log
-rw-r--r-- 1 td-agent td-agent 83 May 17 13:35 buffer.b56c66e9ad01d5ad1873e202808db8835.log.meta
-rw-r--r-- 1 td-agent td-agent 0 May 17 13:35 buffer.q56c66e992379d1bd2a3836249ba7ce97.log
-rw-r--r-- 1 td-agent td-agent 75 May 17 13:35 buffer.q56c66e992379d1bd2a3836249ba7ce97.log.meta
root@harvester-gce-be-2:/var/lib/td-agent/buffers/output_elasticsearch-1# cat buffer.q56c66e992379d1bd2a3836249ba7ce97.log.meta
root@harvester-gce-be-2:/var/lib/td-agent/buffers/output_elasticsearch-1# file buffer.q56c66e992379d1bd2a3836249ba7ce97.log.meta
buffer.q56c66e992379d1bd2a3836249ba7ce97.log.meta: data
root@harvester-gce-be-2:/var/lib/td-agent/buffers/output_elasticsearch-1# ^C
root@harvester-gce-be-2:/var/lib/td-agent/buffers/output_elasticsearch-1# ls -la
total 6656
drwxr-xr-x 2 td-agent td-agent 6787072 May 17 13:35 .
drwxr-x--- 19 td-agent adm 4096 Apr 28 18:23 ..
-rw-r--r-- 1 td-agent td-agent 0 May 17 13:35 buffer.b56c66e9a26dad9cf0a805dd8de468a41.log
-rw-r--r-- 1 td-agent td-agent 84 May 17 13:35 buffer.b56c66e9a26dad9cf0a805dd8de468a41.log.meta
-rw-r--r-- 1 td-agent td-agent 0 May 17 13:35 buffer.b56c66e9a6bc9931e744c071c41132ffc.log
-rw-r--r-- 1 td-agent td-agent 80 May 17 13:35 buffer.b56c66e9a6bc9931e744c071c41132ffc.log.meta
-rw-r--r-- 1 td-agent td-agent 0 May 17 13:35 buffer.b56c66e9ad01d5ad1873e202808db8835.log
-rw-r--r-- 1 td-agent td-agent 83 May 17 13:35 buffer.b56c66e9ad01d5ad1873e202808db8835.log.meta
-rw-r--r-- 1 td-agent td-agent 0 May 17 13:35 buffer.q56c66e992379d1bd2a3836249ba7ce97.log
-rw-r--r-- 1 td-agent td-agent 75 May 17 13:35 buffer.q56c66e992379d1bd2a3836249ba7ce97.log.meta
root@harvester-gce-be-2:/var/lib/td-agent/buffers/output_elasticsearch-1# file buffer.q56c66e992379d1bd2a3836249ba7ce97.log.meta
buffer.q56c66e992379d1bd2a3836249ba7ce97.log.meta: data
root@harvester-gce-be-2:/var/lib/td-agent/buffers/output_elasticsearch-1# hexdump -C buffer.q56c66e992379d1bd2a3836249ba7ce97.log.meta
00000000 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
*
0000004b
We know that such an error occurs when a chunk file is corrupted due to an abnormal outage, etc. We are working on improving the feature for chunk file corruption in this issue.
- #3970
So I close this issue now, but if you are still experiencing these errors even though an abnormal outage doesn't occur, please contact us.