search

uken / fluent-plugin-elasticsearch

Apache License 2.0
891 stars 310 forks source link

GatewayTimeout error="[504] #372

Closed TamerDev closed 6 years ago

TamerDev commented 6 years ago

I'm running FluentD-Elastic-Kibana on my local windows 10 dev box and I'm having some issues. When I run the following from td-agent command prompt: echo {"tst":"errrr"} | fluent-cat my.logs

I get the following message on the other td-agent command prompt that is running fluentd:

2018-03-02 16:09:38 -0500 [info]: #0 listening port port=24224 bind="0.0.0.0"
2018-03-02 16:09:38 -0500 [info]: #0 fluentd worker is now running worker=0
2018-03-02 16:09:51 -0500 [warn]: #0 failed to flush the buffer. retry_time=0 next_retry_seconds=2018-03-02 16:09:52 -0500 chunk="56674658e9b26de5b9645d864671f3d4" error_class=Elasticsearch::Transport::Transport::Errors::GatewayTimeout error="[504] "
  2018-03-02 16:09:51 -0500 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/elasticsearch-transport-5.0.4/lib/elasticsearch/transport/transport/base.rb:202:in `__raise_transport_error'
  2018-03-02 16:09:51 -0500 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/elasticsearch-transport-5.0.4/lib/elasticsearch/transport/transport/base.rb:319:in `perform_request'
  2018-03-02 16:09:51 -0500 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/elasticsearch-transport-5.0.4/lib/elasticsearch/transport/transport/http/faraday.rb:20:in `perform_request'
  2018-03-02 16:09:51 -0500 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/elasticsearch-transport-5.0.4/lib/elasticsearch/transport/client.rb:131:in `perform_request'
  2018-03-02 16:09:51 -0500 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/elasticsearch-api-5.0.4/lib/elasticsearch/api/actions/ping.rb:20:in `ping'
  2018-03-02 16:09:51 -0500 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluent-plugin-elasticsearch-2.4.0/lib/fluent/plugin/out_elasticsearch.rb:199:in `client'
  2018-03-02 16:09:51 -0500 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluent-plugin-elasticsearch-2.4.0/lib/fluent/plugin/out_elasticsearch.rb:430:in `rescue in send_bulk'
  2018-03-02 16:09:51 -0500 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluent-plugin-elasticsearch-2.4.0/lib/fluent/plugin/out_elasticsearch.rb:424:in `send_bulk'
  2018-03-02 16:09:51 -0500 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluent-plugin-elasticsearch-2.4.0/lib/fluent/plugin/out_elasticsearch.rb:411:in `write'
  2018-03-02 16:09:51 -0500 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/plugin/output.rb:1093:in `try_flush'
  2018-03-02 16:09:51 -0500 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/plugin/output.rb:1318:in `flush_thread_run'
  2018-03-02 16:09:51 -0500 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/plugin/output.rb:439:in `block (2 levels) in start'
  2018-03-02 16:09:51 -0500 [warn]: #0 C:/opt/td-agent/embedded/lib/ruby/gems/2.4.0/gems/fluentd-1.0.2/lib/fluent/plugin_helper/thread.rb:78:in `block in thread_create'
2018-03-02 16:09:52 -0500 [warn]: #0 failed to flush the buffer. retry_time=0 next_retry_seconds=2018-03-02 16:09:52 -0500 chunk="56674658e9b26de5b9645d864671f3d4" error_class=Elasticsearch::Transport::Transport::Errors::GatewayTimeout error="[504] "
  2018-03-02 16:09:52 -0500 [warn]: #0 suppressed same stacktrace
2018-03-02 16:09:53 -0500 [warn]: #0 failed to flush the buffer. retry_time=1 next_retry_seconds=2018-03-02 16:09:53 -0500 chunk="56674658e9b26de5b9645d864671f3d4" error_class=Elasticsearch::Transport::Transport::Errors::GatewayTimeout error="[504] "

Expected Behavior or What you need to ask

I should be able to write the message to elastic

Using Fluentd and ES plugin versions

Here is my setup: java 9 jdk rubyinstaller-2.3.3-x64 along with the DevKit (ruby dk.rb init and ruby dk.rb install to bind it to ruby installations in your path.) td-agent 3.1.1.0 (fluentd 1.0.2) Elastic MSI 6.2.2 elastic plugin: by running "gem install fluent-plugin-elasticsearch" Latest Kibana and Cerebro

My td-agent.conf has the following content:

<source>
  @type forward
</source>
<match my.logs>
    @type elasticsearch
    @type elasticsearch
    host localhost
    port 9200
    index_name fluentd
    type_name fluentd
    flush_interval 1
</match>

Gem List:

WARN: Unresolved specs during Gem::Specification.reset:
      win32-api (>= 1.4.5)
WARN: Clearing out unresolved specs.
Please report a bug if this causes problems.

*** LOCAL GEMS ***

addressable (2.5.2)
aws-partitions (1.42.0)
aws-sdk-core (3.11.0)
aws-sdk-kms (1.3.0)
aws-sdk-s3 (1.8.0)
aws-sdk-sqs (1.3.0)
aws-sigv4 (1.0.2)
bigdecimal (default: 1.3.0)
bundler (1.16.0)
cool.io (1.5.3)
did_you_mean (1.1.0)
dig_rb (1.0.1)
elasticsearch (5.0.4)
elasticsearch-api (5.0.4)
elasticsearch-transport (5.0.4)
excon (0.60.0)
faraday (0.14.0)
ffi (1.9.18)
ffi-win32-extensions (1.0.3)
fluent-logger (0.7.2)
fluent-plugin-elasticsearch (2.4.0)
fluent-plugin-kafka (0.6.5)
fluent-plugin-rewrite-tag-filter (2.0.1)
fluent-plugin-s3 (1.1.0)
fluent-plugin-td (1.0.0)
fluent-plugin-td-monitoring (0.2.3)
fluent-plugin-webhdfs (1.2.2)
fluent-plugin-windows-eventlog (0.2.2)
fluentd (1.0.2)
hirb (0.7.3)
http_parser.rb (0.6.0)
httpclient (2.8.2.4)
io-console (default: 0.4.6)
ipaddress (0.8.3)
jmespath (1.3.1)
json (default: 2.0.4)
ltsv (0.1.0)
mini_portile2 (2.3.0)
minitest (5.10.1)
mixlib-cli (1.7.0)
mixlib-config (2.2.4)
mixlib-log (1.7.1)
mixlib-shellout (2.2.7 universal-mingw32)
msgpack (1.2.0)
multi_json (1.13.1)
multipart-post (2.0.0)
net-telnet (0.1.1)
nokogiri (1.8.1 x64-mingw32)
ohai (6.20.0)
oj (3.3.9)
openssl (default: 2.0.5)
parallel (1.12.1)
power_assert (0.4.1)
psych (default: 2.2.2)
public_suffix (3.0.1)
rake (12.0.0)
rdoc (default: 5.0.0)
ruby-kafka (0.5.1)
ruby-progressbar (1.9.0)
rubyzip (1.2.1)
serverengine (2.0.5)
sigdump (0.2.4)
strptime (0.2.3)
systemu (2.5.2)
td (0.15.7)
td-client (1.0.4)
td-logger (0.3.27)
test-unit (3.2.3)
thread_safe (0.3.6)
tzinfo (1.2.4)
tzinfo-data (1.2017.3)
webhdfs (0.8.0)
win32-api (1.7.1 universal-mingw32, 1.7.0 universal-mingw32)
win32-event (0.6.3)
win32-eventlog (0.6.7)
win32-ipc (0.7.0, 0.6.6)
win32-process (0.8.3)
win32-service (0.8.10)
windows-api (0.4.4)
windows-pr (1.2.6)
wmi-lite (1.0.0)
xmlrpc (0.2.1)
yajl-ruby (1.3.1)
zip-zip (0.3)
cosmo0920 commented 6 years ago

I've tried to reproduce this issue with the following environment.

OS: Windows 10 Home 17.09 ES plugin: master JDK: 9 Fluentd: 1.1.0

But I always couldn't reproduce this issue.

PS> git clone git@github.com:uken/fluent-plugin-elasticsearch.git
PS> cd fluent-plugin-elasticsearch
PS> ridk.ps1 exec bundle install --path vendor/bundle
PS> bundle exec fluentd -c fluent.conf -p .\lib\fluent\plugin
2018-03-05 17:10:18 +0900 [info]: parsing config file is succeeded path="fluent.conf"
2018-03-05 17:10:18 +0900 [info]: 'flush_interval' is configured at out side of <buffer>. 'flush_mode' is set to 'interval' to keep existing behaviour
2018-03-05 17:10:18 +0900 [info]: using configuration file: <ROOT>
  <source>
    @type forward
  </source>
  <match my.logs>
    @type elasticsearch
    host "localhost"
    port 9200
    index_name "fluentd"
    type_name "fluentd"
    flush_interval 1
    <buffer>
      flush_interval 1
    </buffer>
  </match>
</ROOT>
2018-03-05 17:10:18 +0900 [info]: starting fluentd-1.1.0 pid=15352 ruby="2.4.1"
2018-03-05 17:10:18 +0900 [info]: spawn command to main:  cmdline=["C:/Ruby24/bin/ruby.exe", "-Eascii-8bit:ascii-8bit", "-rbundler/setup", "C:/Users/hhatake/Documents/GitHub/fluent-plugin-elasticsearch/vendor/bundle/ruby/2.4.0/bin/fluentd", "-c", "fluent.conf", "-p", ".\\lib\\fluent\\plugin", "--under-supervisor"]
2018-03-05 17:10:19 +0900 [info]: gem 'fluentd' version '1.1.0'
2018-03-05 17:10:19 +0900 [info]: gem 'fluent-plugin-elasticsearch' version '2.7.0'
2018-03-05 17:10:19 +0900 [info]: adding match pattern="my.logs" type="elasticsearch"
2018-03-05 17:10:19 +0900 [info]: #0 'flush_interval' is configured at out side of <buffer>. 'flush_mode' is set to 'interval' to keep existing behaviour
2018-03-05 17:10:19 +0900 [info]: adding source type="forward"
2018-03-05 17:10:19 +0900 [info]: #0 starting fluentd worker pid=7752 ppid=15352 worker=0
2018-03-05 17:10:19 +0900 [info]: #0 listening port port=24224 bind="0.0.0.0"
2018-03-05 17:10:19 +0900 [info]: #0 fluentd worker is now running worker=0
2018-03-05 17:10:25 +0900 [info]: #0 Connection opened to Elasticsearch cluster => {:host=>"localhost", :port=>9200, :scheme=>"http"}
2018-03-05 17:10:43 +0900 [info]: Received graceful stop
2018-03-05 17:10:43 +0900 [info]: #0 fluentd worker is now stopping worker=0
2018-03-05 17:10:43 +0900 [info]: #0 shutting down fluentd worker worker=0
2018-03-05 17:10:43 +0900 [info]: #0 shutting down input plugin type=:forward plugin_id="object:3045054"
2018-03-05 17:10:43 +0900 [info]: #0 shutting down output plugin type=:elasticsearch plugin_id="object:2e27278"
2018-03-05 17:10:55 +0900 [warn]: #0 Could not push logs to Elasticsearch, resetting connection and trying again. read timeout reached
2018-03-05 17:10:57 +0900 [info]: #0 Connection opened to Elasticsearch cluster => {:host=>"localhost", :port=>9200, :scheme=>"http"}
2018-03-05 17:11:10 +0900 [info]: Received graceful stop
2018-03-05 17:11:11 +0900 [info]: Received graceful stop
2018-03-05 17:11:11 +0900 [info]: Received graceful stop
2018-03-05 17:11:13 +0900 [info]: Received graceful stop
2018-03-05 17:11:27 +0900 [warn]: #0 Could not push logs to Elasticsearch, resetting connection and trying again. read timeout reached
2018-03-05 17:11:30 +0900 [info]: Received graceful stop
2018-03-05 17:11:31 +0900 [info]: #0 Connection opened to Elasticsearch cluster => {:host=>"localhost", :port=>9200, :scheme=>"http"}
2018-03-05 17:11:53 +0900 [warn]: #0 buffer flush took longer time than slow_flush_log_threshold: elapsed_time=88.44143269897904 slow_flush_log_threshold=20.0 plugin_id="object:2e27278"
2018-03-05 17:11:54 +0900 [info]: Worker 0 finished with status 0
# next try
2018-03-05 17:12:18 +0900 [info]: starting fluentd-1.1.0 pid=7252 ruby="2.4.1"
2018-03-05 17:12:18 +0900 [info]: spawn command to main:  cmdline=["C:/Ruby24/bin/ruby.exe", "-Eascii-8bit:ascii-8bit", "-rbundler/setup", "C:/Users/hhatake/Documents/GitHub/fluent-plugin-elasticsearch/vendor/bundle/ruby/2.4.0/bin/fluentd", "-c", "fluent.conf", "-p", ".\\lib\\fluent\\plugin", "--under-supervisor"]
2018-03-05 17:12:19 +0900 [info]: gem 'fluentd' version '1.1.0'
2018-03-05 17:12:19 +0900 [info]: gem 'fluent-plugin-elasticsearch' version '2.7.0'
2018-03-05 17:12:19 +0900 [info]: adding match pattern="my.logs" type="elasticsearch"
2018-03-05 17:12:19 +0900 [info]: #0 'flush_interval' is configured at out side of <buffer>. 'flush_mode' is set to 'interval' to keep existing behaviour
2018-03-05 17:12:19 +0900 [info]: adding source type="forward"
2018-03-05 17:12:19 +0900 [info]: #0 starting fluentd worker pid=12552 ppid=7252 worker=0
2018-03-05 17:12:19 +0900 [info]: #0 listening port port=24224 bind="0.0.0.0"
2018-03-05 17:12:19 +0900 [info]: #0 fluentd worker is now running worker=0
2018-03-05 17:12:23 +0900 [info]: #0 Connection opened to Elasticsearch cluster => {:host=>"localhost", :port=>9200, :scheme=>"http"}
2018-03-05 17:13:56 +0900 [info]: Received graceful stop
2018-03-05 17:13:56 +0900 [info]: #0 fluentd worker is now stopping worker=0
2018-03-05 17:13:56 +0900 [info]: #0 shutting down fluentd worker worker=0
2018-03-05 17:13:56 +0900 [info]: #0 shutting down input plugin type=:forward plugin_id="object:2fc6f28"
2018-03-05 17:13:56 +0900 [info]: #0 shutting down output plugin type=:elasticsearch plugin_id="object:2db2c38"
2018-03-05 17:13:57 +0900 [info]: Worker 0 finished with status 0

ES log:

PS C:\Users\hhatake\Downloads\elasticsearch-6.2.2\elasticsearch-6.2.2> .\bin\elasticsearch.bat
Java HotSpot(TM) 64-Bit Server VM warning: Option UseConcMarkSweepGC was deprecated in version 9.0 and will likely be removed in a future release.
[2018-03-05T16:58:22,841][INFO ][o.e.n.Node               ] [] initializing ...
[2018-03-05T16:58:23,091][INFO ][o.e.e.NodeEnvironment    ] [bxlU7r4] using [1] data paths, mounts [[Windows (C:)]], net usable_space [326.9gb], net total_space [464.5gb], types [NTFS]
[2018-03-05T16:58:23,091][INFO ][o.e.e.NodeEnvironment    ] [bxlU7r4] heap size [990.7mb], compressed ordinary object pointers [true]
[2018-03-05T16:58:23,091][INFO ][o.e.n.Node               ] node name [bxlU7r4] derived from node ID [bxlU7r4VT-qgFmRB2ICGZg]; set [node.name] to override
[2018-03-05T16:58:23,091][INFO ][o.e.n.Node               ] version[6.2.2], pid[15092], build[10b1edd/2018-02-16T19:01:30.685723Z], OS[Windows 10/10.0/amd64], JVM[Oracle Corporation/Java HotSpot(TM) 64-Bit Server VM/9.0.4/9.0.4+11]
[2018-03-05T16:58:23,091][INFO ][o.e.n.Node               ] JVM arguments [-Xms1g, -Xmx1g, -XX:+UseConcMarkSweepGC, -XX:CMSInitiatingOccupancyFraction=75, -XX:+UseCMSInitiatingOccupancyOnly, -XX:+AlwaysPreTouch, -Xss1m, -Djava.awt.headless=true, -Dfile.encoding=UTF-8, -Djna.nosys=true, -XX:-OmitStackTraceInFastThrow, -Dio.netty.noUnsafe=true, -Dio.netty.noKeySetOptimization=true, -Dio.netty.recycler.maxCapacityPerThread=0, -Dlog4j.shutdownHookEnabled=false, -Dlog4j2.disable.jmx=true, -Djava.io.tmpdir=C:\Users\hhatake\AppData\Local\Temp\elasticsearch, -XX:+HeapDumpOnOutOfMemoryError, -Xlog:gc*,gc+age=trace,safepoint:file=logs/gc.log:utctime,pid,tags:filecount=32,filesize=64m, -Djava.locale.providers=COMPAT, -Delasticsearch, -Des.path.home=C:\Users\hhatake\Downloads\elasticsearch-6.2.2\elasticsearch-6.2.2, -Des.path.conf=C:\Users\hhatake\Downloads\elasticsearch-6.2.2\elasticsearch-6.2.2\config]
[2018-03-05T16:58:23,856][INFO ][o.e.p.PluginsService     ] [bxlU7r4] loaded module [aggs-matrix-stats]
[2018-03-05T16:58:23,856][INFO ][o.e.p.PluginsService     ] [bxlU7r4] loaded module [analysis-common]
[2018-03-05T16:58:23,856][INFO ][o.e.p.PluginsService     ] [bxlU7r4] loaded module [ingest-common]
[2018-03-05T16:58:23,856][INFO ][o.e.p.PluginsService     ] [bxlU7r4] loaded module [lang-expression]
[2018-03-05T16:58:23,856][INFO ][o.e.p.PluginsService     ] [bxlU7r4] loaded module [lang-mustache]
[2018-03-05T16:58:23,856][INFO ][o.e.p.PluginsService     ] [bxlU7r4] loaded module [lang-painless]
[2018-03-05T16:58:23,856][INFO ][o.e.p.PluginsService     ] [bxlU7r4] loaded module [mapper-extras]
[2018-03-05T16:58:23,856][INFO ][o.e.p.PluginsService     ] [bxlU7r4] loaded module [parent-join]
[2018-03-05T16:58:23,856][INFO ][o.e.p.PluginsService     ] [bxlU7r4] loaded module [percolator]
[2018-03-05T16:58:23,856][INFO ][o.e.p.PluginsService     ] [bxlU7r4] loaded module [rank-eval]
[2018-03-05T16:58:23,856][INFO ][o.e.p.PluginsService     ] [bxlU7r4] loaded module [reindex]
[2018-03-05T16:58:23,856][INFO ][o.e.p.PluginsService     ] [bxlU7r4] loaded module [repository-url]
[2018-03-05T16:58:23,856][INFO ][o.e.p.PluginsService     ] [bxlU7r4] loaded module [transport-netty4]
[2018-03-05T16:58:23,856][INFO ][o.e.p.PluginsService     ] [bxlU7r4] loaded module [tribe]
[2018-03-05T16:58:23,856][INFO ][o.e.p.PluginsService     ] [bxlU7r4] no plugins loaded
[2018-03-05T16:58:26,588][INFO ][o.e.d.DiscoveryModule    ] [bxlU7r4] using discovery type [zen]
[2018-03-05T16:58:27,135][INFO ][o.e.n.Node               ] initialized
[2018-03-05T16:58:27,135][INFO ][o.e.n.Node               ] [bxlU7r4] starting ...
[2018-03-05T16:58:27,792][INFO ][o.e.t.TransportService   ] [bxlU7r4] publish_address {127.0.0.1:9300}, bound_addresses {127.0.0.1:9300}, {[::1]:9300}
[2018-03-05T16:58:30,868][INFO ][o.e.c.s.MasterService    ] [bxlU7r4] zen-disco-elected-as-master ([0] nodes joined), reason: new_master {bxlU7r4}{bxlU7r4VT-qgFmRB2ICGZg}{ymOVNkGSQRO97FvwB10qxQ}{127.0.0.1}{127.0.0.1:9300}
[2018-03-05T16:58:30,868][INFO ][o.e.c.s.ClusterApplierService] [bxlU7r4] new_master {bxlU7r4}{bxlU7r4VT-qgFmRB2ICGZg}{ymOVNkGSQRO97FvwB10qxQ}{127.0.0.1}{127.0.0.1:9300}, reason: apply cluster state (from master [master {bxlU7r4}{bxlU7r4VT-qgFmRB2ICGZg}{ymOVNkGSQRO97FvwB10qxQ}{127.0.0.1}{127.0.0.1:9300} committed version [1] source [zen-disco-elected-as-master ([0] nodes joined)]])
[2018-03-05T16:58:30,900][INFO ][o.e.g.GatewayService     ] [bxlU7r4] recovered [0] indices into cluster_state
[2018-03-05T16:58:31,212][INFO ][o.e.h.n.Netty4HttpServerTransport] [bxlU7r4] publish_address {127.0.0.1:9200}, bound_addresses {127.0.0.1:9200}, {[::1]:9200}
[2018-03-05T16:58:31,212][INFO ][o.e.n.Node               ] [bxlU7r4] started
[2018-03-05T17:10:25,104][INFO ][o.e.c.m.MetaDataCreateIndexService] [bxlU7r4] [fluentd] creating index, cause [auto(bulk api)], templates [], shards [5]/[1], mappings []
[2018-03-05T17:11:52,900][WARN ][o.e.c.s.MasterService    ] [bxlU7r4] cluster state update task [create-index [fluentd], cause [auto(bulk api)]] took [1.4m] above the warn threshold of 30s
[2018-03-05T17:11:53,166][INFO ][o.e.c.m.MetaDataMappingService] [bxlU7r4] [fluentd/pux2hJpDSeGfE2cDS99paA] create_mapping [fluentd]
# Delete index
[2018-03-05T17:13:48,993][INFO ][o.e.c.m.MetaDataDeleteIndexService] [bxlU7r4] [fluentd/pux2hJpDSeGfE2cDS99paA] deleting index
[2018-03-05T17:14:09,462][INFO ][o.e.c.m.MetaDataCreateIndexService] [bxlU7r4] [fluentd] creating index, cause [auto(bulk api)], templates [], shards [5]/[1], mappings []
[2018-03-05T17:14:09,634][INFO ][o.e.c.m.MetaDataMappingService] [bxlU7r4] [fluentd/QrIp8ouwS1KT4OafDY-Eyg] create_mapping [fluentd]
[2018-03-05T17:17:04,103][INFO ][o.e.n.Node               ] [bxlU7r4] stopping ...
[2018-03-05T17:17:04,166][INFO ][o.e.n.Node               ] [bxlU7r4] stopped
[2018-03-05T17:17:04,166][INFO ][o.e.n.Node               ] [bxlU7r4] closing ...
[2018-03-05T17:17:04,181][INFO ][o.e.n.Node               ] [bxlU7r4] closed
# next try
PS C:\Users\hhatake\Downloads\elasticsearch-6.2.2\elasticsearch-6.2.2> cd ..
PS C:\Users\hhatake\Downloads\elasticsearch-6.2.2> cd ..
PS C:\Users\hhatake\Downloads> cd .\elasticsearch-6.2.2\elasticsearch-6.2.2\
PS C:\Users\hhatake\Downloads\elasticsearch-6.2.2\elasticsearch-6.2.2> .\bin\elasticsearch.bat
Java HotSpot(TM) 64-Bit Server VM warning: Option UseConcMarkSweepGC was deprecated in version 9.0 and will likely be removed in a future release.
[2018-03-05T17:17:48,729][INFO ][o.e.n.Node               ] [] initializing ...
[2018-03-05T17:17:48,964][INFO ][o.e.e.NodeEnvironment    ] [ZIYJy2I] using [1] data paths, mounts [[Windows (C:)]], net usable_space [326.5gb], net total_space [464.5gb], types [NTFS]
[2018-03-05T17:17:48,964][INFO ][o.e.e.NodeEnvironment    ] [ZIYJy2I] heap size [990.7mb], compressed ordinary object pointers [true]
[2018-03-05T17:17:48,964][INFO ][o.e.n.Node               ] node name [ZIYJy2I] derived from node ID [ZIYJy2IVTt24H_1mxGfSLw]; set [node.name] to override
[2018-03-05T17:17:48,964][INFO ][o.e.n.Node               ] version[6.2.2], pid[1988], build[10b1edd/2018-02-16T19:01:30.685723Z], OS[Windows 10/10.0/amd64], JVM[Oracle Corporation/Java HotSpot(TM) 64-Bit Server VM/9.0.4/9.0.4+11]
[2018-03-05T17:17:48,964][INFO ][o.e.n.Node               ] JVM arguments [-Xms1g, -Xmx1g, -XX:+UseConcMarkSweepGC, -XX:CMSInitiatingOccupancyFraction=75, -XX:+UseCMSInitiatingOccupancyOnly, -XX:+AlwaysPreTouch, -Xss1m, -Djava.awt.headless=true, -Dfile.encoding=UTF-8, -Djna.nosys=true, -XX:-OmitStackTraceInFastThrow, -Dio.netty.noUnsafe=true, -Dio.netty.noKeySetOptimization=true, -Dio.netty.recycler.maxCapacityPerThread=0, -Dlog4j.shutdownHookEnabled=false, -Dlog4j2.disable.jmx=true, -Djava.io.tmpdir=C:\Users\hhatake\AppData\Local\Temp\elasticsearch, -XX:+HeapDumpOnOutOfMemoryError, -Xlog:gc*,gc+age=trace,safepoint:file=logs/gc.log:utctime,pid,tags:filecount=32,filesize=64m, -Djava.locale.providers=COMPAT, -Delasticsearch, -Des.path.home=C:\Users\hhatake\Downloads\elasticsearch-6.2.2\elasticsearch-6.2.2, -Des.path.conf=C:\Users\hhatake\Downloads\elasticsearch-6.2.2\elasticsearch-6.2.2\config]
[2018-03-05T17:17:49,620][INFO ][o.e.p.PluginsService     ] [ZIYJy2I] loaded module [aggs-matrix-stats]
[2018-03-05T17:17:49,620][INFO ][o.e.p.PluginsService     ] [ZIYJy2I] loaded module [analysis-common]
[2018-03-05T17:17:49,620][INFO ][o.e.p.PluginsService     ] [ZIYJy2I] loaded module [ingest-common]
[2018-03-05T17:17:49,635][INFO ][o.e.p.PluginsService     ] [ZIYJy2I] loaded module [lang-expression]
[2018-03-05T17:17:49,635][INFO ][o.e.p.PluginsService     ] [ZIYJy2I] loaded module [lang-mustache]
[2018-03-05T17:17:49,635][INFO ][o.e.p.PluginsService     ] [ZIYJy2I] loaded module [lang-painless]
[2018-03-05T17:17:49,635][INFO ][o.e.p.PluginsService     ] [ZIYJy2I] loaded module [mapper-extras]
[2018-03-05T17:17:49,635][INFO ][o.e.p.PluginsService     ] [ZIYJy2I] loaded module [parent-join]
[2018-03-05T17:17:49,635][INFO ][o.e.p.PluginsService     ] [ZIYJy2I] loaded module [percolator]
[2018-03-05T17:17:49,635][INFO ][o.e.p.PluginsService     ] [ZIYJy2I] loaded module [rank-eval]
[2018-03-05T17:17:49,635][INFO ][o.e.p.PluginsService     ] [ZIYJy2I] loaded module [reindex]
[2018-03-05T17:17:49,635][INFO ][o.e.p.PluginsService     ] [ZIYJy2I] loaded module [repository-url]
[2018-03-05T17:17:49,635][INFO ][o.e.p.PluginsService     ] [ZIYJy2I] loaded module [transport-netty4]
[2018-03-05T17:17:49,635][INFO ][o.e.p.PluginsService     ] [ZIYJy2I] loaded module [tribe]
[2018-03-05T17:17:49,635][INFO ][o.e.p.PluginsService     ] [ZIYJy2I] no plugins loaded
[2018-03-05T17:17:51,822][INFO ][o.e.d.DiscoveryModule    ] [ZIYJy2I] using discovery type [zen]
[2018-03-05T17:17:52,447][INFO ][o.e.n.Node               ] initialized
[2018-03-05T17:17:52,447][INFO ][o.e.n.Node               ] [ZIYJy2I] starting ...
[2018-03-05T17:17:53,072][INFO ][o.e.t.TransportService   ] [ZIYJy2I] publish_address {127.0.0.1:9300}, bound_addresses {127.0.0.1:9300}, {[::1]:9300}
[2018-03-05T17:17:56,131][INFO ][o.e.c.s.MasterService    ] [ZIYJy2I] zen-disco-elected-as-master ([0] nodes joined), reason: new_master {ZIYJy2I}{ZIYJy2IVTt24H_1mxGfSLw}{HZ1XitkVSmeOg5vxhuuvhw}{127.0.0.1}{127.0.0.1:9300}
[2018-03-05T17:17:56,136][INFO ][o.e.c.s.ClusterApplierService] [ZIYJy2I] new_master {ZIYJy2I}{ZIYJy2IVTt24H_1mxGfSLw}{HZ1XitkVSmeOg5vxhuuvhw}{127.0.0.1}{127.0.0.1:9300}, reason: apply cluster state (from master [master {ZIYJy2I}{ZIYJy2IVTt24H_1mxGfSLw}{HZ1XitkVSmeOg5vxhuuvhw}{127.0.0.1}{127.0.0.1:9300} committed version [1] source [zen-disco-elected-as-master ([0] nodes joined)]])
[2018-03-05T17:17:56,167][INFO ][o.e.g.GatewayService     ] [ZIYJy2I] recovered [0] indices into cluster_state
[2018-03-05T17:17:56,495][INFO ][o.e.h.n.Netty4HttpServerTransport] [ZIYJy2I] publish_address {127.0.0.1:9200}, bound_addresses {127.0.0.1:9200}, {[::1]:9200}
[2018-03-05T17:17:56,495][INFO ][o.e.n.Node               ] [ZIYJy2I] started
[2018-03-05T17:18:27,322][INFO ][o.e.c.m.MetaDataCreateIndexService] [ZIYJy2I] [fluentd] creating index, cause [auto(bulk api)], templates [], shards [5]/[1], mappings []
[2018-03-05T17:18:27,712][INFO ][o.e.c.m.MetaDataMappingService] [ZIYJy2I] [fluentd/xpX21h3iQ5G7kYBKuILaLQ] create_mapping [fluentd]
cosmo0920 commented 6 years ago

Perhaps, this issue is elasticsearch-ruby's Bug on Windows environment. On the first connection, es-ruby transport returns Faraday::ConnectionFailed or Faraday::TimeoutError error, but index creation is succeeded.

cosmo0920 commented 6 years ago

Or, could you try longer timeout?

<source>
  @type forward
</source>
<match my.logs>
    @type elasticsearch
    @type elasticsearch
    host localhost
    port 9200
    index_name fluentd
    type_name fluentd
    flush_interval 1
    # default is 5 second. But, it seems too short to handle request on Windows. 
    request_timeout 15
</match>
TamerDev commented 6 years ago

Did not work after increasing time out. same set of binaries work on a windows 2008 R2 server. my machine is a windows 10 pro.

TamerDev commented 6 years ago

I tried the same setup on another machine with the same windows version and I'm getting the same error. Is there a specific log that might shed some light on why this is happening? I also changed the port for elastic .yml file and changed the config file accordingly but getting the same message.

cosmo0920 commented 6 years ago

Is there a specific log that might shed some light on why this is happening?

Because default behavior throws away transporter log.

Adding the following configuration

with_transporter_log true

will add transporter log into Fluentd log.

TamerDev commented 6 years ago

2018-03-06 12:11:05 -0500 [warn]: parameter 'with_transporter_log' in

@type elasticsearch host "localhost" port 9200 index_name "fluentd" type_name "fluentd" flush_interval 1 request_timeout 15 with_transporter_log true flush_mode interval retry_type exponential_backoff flush_interval 1 is not used. I'm still not sure why it works on another windows server 2008 r2 box, and not on my windows 10 box. I tried another windows 10 box and same errors. On Mon, Mar 5, 2018 at 8:07 PM, Hiroshi Hatake wrote: > Is there a specific log that might shed some light on why this is > happening? > > Because default behavior throws away transporter log. > > Adding the following configuration > > with_transporter_log true > > will add transporter log into Fluentd log. > > — > You are receiving this because you authored the thread. > Reply to this email directly, view it on GitHub > , > or mute the thread > > . >
cosmo0920 commented 6 years ago

@TamerDev Could you upgrade ES plugin to v2.4.1 and run again with above configuration?

TamerDev commented 6 years ago

getting same error. I updated java to java version "9.0.4", kept ruby at: ruby 2.3.3p222 (2016-11-21 revision 56859) [x64-mingw32] td-agent v3.0.0 div kit for ruby 2.3.3: DevKit-mingw64-64-4.7.2-20130224-1432-sfx

List of GEMs: C:\Users\tyousef1>gem list
*** LOCAL GEMS ***
bigdecimal (1.2.8)
cool.io (1.5.3 x64-mingw32)
did_you_mean (1.0.0)
dig_rb (1.0.1)
elasticsearch (6.0.1)
elasticsearch-api (6.0.1)
elasticsearch-transport (6.0.1)
excon (0.60.0)
faraday (0.14.0)
fluent-plugin-elasticsearch (2.4.1)
fluentd (1.1.1)
http_parser.rb (0.6.0)
io-console (0.4.5)
json (1.8.3)
minitest (5.8.5)
msgpack (1.2.4 x64-mingw32)
multi_json (1.13.1)
multipart-post (2.0.0)
net-telnet (0.1.1)
power_assert (0.2.6)
psych (2.1.0)
rake (10.4.2)
rdoc (4.2.1)
serverengine (2.0.6)
sigdump (0.2.4)
strptime (0.2.3)
test-unit (3.1.5)
thread_safe (0.3.6)
tzinfo (1.2.5)
tzinfo-data (1.2018.3)
yajl-ruby (1.3.1)

Log from fluentd td-agent after I send a message to it:

2018-03-07 11:45:34 -0500 [info]: HEAD http://127.0.0.1:9200/ [status:504, request:0.060s, query:N/A]
2018-03-07 11:45:34 -0500 [fatal]: [504]
2018-03-07 11:45:34 -0500 [info]: HEAD http://127.0.0.1:9200/ [status:504, request:0.028s, query:N/A]
2018-03-07 11:45:34 -0500 [fatal]: [504]
2018-03-07 11:45:34 -0500 [warn]: failed to flush the buffer. retry_time=0 next_retry_seconds=2018-03-07 11:45:35 -0500 chunk="566d54999b5d217c36cfd74309fedb2a" error_class=Elasticsearch::Transport::Transport::Errors::GatewayTimeout error="[504] "
  2018-03-07 11:45:34 -0500 [warn]: C:/opt/td-agent/embedded/lib/ruby/gems/2.3.0/gems/elasticsearch-transport-5.0.0/lib/elasticsearch/transport/transport/base.rb:201:in `__raise_transport_error'
  2018-03-07 11:45:34 -0500 [warn]: C:/opt/td-agent/embedded/lib/ruby/gems/2.3.0/gems/elasticsearch-transport-5.0.0/lib/elasticsearch/transport/transport/base.rb:312:in `perform_request'
  2018-03-07 11:45:34 -0500 [warn]: C:/opt/td-agent/embedded/lib/ruby/gems/2.3.0/gems/elasticsearch-transport-5.0.0/lib/elasticsearch/transport/transport/http/faraday.rb:20:in `perform_request'
  2018-03-07 11:45:34 -0500 [warn]: C:/opt/td-agent/embedded/lib/ruby/gems/2.3.0/gems/elasticsearch-transport-5.0.0/lib/elasticsearch/transport/client.rb:128:in `perform_request'
  2018-03-07 11:45:34 -0500 [warn]: C:/opt/td-agent/embedded/lib/ruby/gems/2.3.0/gems/elasticsearch-api-5.0.0/lib/elasticsearch/api/actions/ping.rb:20:in `ping'
  2018-03-07 11:45:34 -0500 [warn]: C:/opt/td-agent/embedded/lib/ruby/gems/2.3.0/gems/fluent-plugin-elasticsearch-2.4.1/lib/fluent/plugin/out_elasticsearch.rb:206:in `client'
  2018-03-07 11:45:34 -0500 [warn]: C:/opt/td-agent/embedded/lib/ruby/gems/2.3.0/gems/fluent-plugin-elasticsearch-2.4.1/lib/fluent/plugin/out_elasticsearch.rb:437:in `rescue in send_bulk'
  2018-03-07 11:45:34 -0500 [warn]: C:/opt/td-agent/embedded/lib/ruby/gems/2.3.0/gems/fluent-plugin-elasticsearch-2.4.1/lib/fluent/plugin/out_elasticsearch.rb:431:in `send_bulk'
  2018-03-07 11:45:34 -0500 [warn]: C:/opt/td-agent/embedded/lib/ruby/gems/2.3.0/gems/fluent-plugin-elasticsearch-2.4.1/lib/fluent/plugin/out_elasticsearch.rb:418:in `write'
  2018-03-07 11:45:34 -0500 [warn]: C:/opt/td-agent/embedded/lib/ruby/gems/2.3.0/gems/fluentd-0.14.11/lib/fluent/plugin/output.rb:1009:in `try_flush'
  2018-03-07 11:45:34 -0500 [warn]: C:/opt/td-agent/embedded/lib/ruby/gems/2.3.0/gems/fluentd-0.14.11/lib/fluent/plugin/output.rb:1234:in `flush_thread_run'
  2018-03-07 11:45:34 -0500 [warn]: C:/opt/td-agent/embedded/lib/ruby/gems/2.3.0/gems/fluentd-0.14.11/lib/fluent/plugin/output.rb:398:in `block (2 levels) in start'
  2018-03-07 11:45:34 -0500 [warn]: C:/opt/td-agent/embedded/lib/ruby/gems/2.3.0/gems/fluentd-0.14.11/lib/fluent/plugin_helper/thread.rb:66:in `block in thread_create'
2018-03-07 11:45:35 -0500 [info]: HEAD http://127.0.0.1:9200/ [status:504, request:0.024s, query:N/A]
2018-03-07 11:45:35 -0500 [fatal]: [504]
2018-03-07 11:45:35 -0500 [info]: HEAD http://127.0.0.1:9200/ [status:504, request:0.024s, query:N/A]
2018-03-07 11:45:35 -0500 [fatal]: [504]
2018-03-07 11:45:35 -0500 [warn]: failed to flush the buffer. retry_time=0 next_retry_seconds=2018-03-07 11:45:35 -0500 chunk="566d54999b5d217c36cfd74309fedb2a" error_class=Elasticsearch::Transport::Transport::Errors::GatewayTimeout error="[504] "
  2018-03-07 11:45:35 -0500 [warn]: suppressed same stacktrace
cosmo0920 commented 6 years ago

Perhaps, do you use proxy related environment variables? How about changing your environment variable like SET HTTP_PROXY= to clear it?

TamerDev commented 6 years ago

Can you explain more on the HTTP_PROXY? I had (and I have removed them now) Env Variable in windows for HTTP_PROXY & HTTPS_PROXY , they are removed. But I'm getting the same transport error message. Is there a setting on FluentD side or in the agent for the proxy?

Both Elastic Search and also FluentD TD agent are running on the same machine. There is a corporate level proxy set for internet options (this is what you get in the internet settings from the browser window: http://blabla.someCompany.com/proxy.js) Are you thinking Fluentd agent is using that proxy by default? if so where do u clear it?

Thanks!!!

cosmo0920 commented 6 years ago

Are you thinking Fluentd agent is using that proxy by default?

Fluentd does not refer network proxy settings. Thanks.