search

elastic / logstash

Logstash - transport and process your logs, events, or other data
https://www.elastic.co/products/logstash
Other
95 stars 3.51k forks source link

Memory leak in 1.5.3? #3722

Closed styxke closed 8 years ago

styxke commented 9 years ago

I seem to have a memory issue with logstash 1.5.3 (also tried 1.5.4 snapshot2). After a couple of hours, the java runtime takes up all available ram and after a period of time it just crashes. Logstash 1.4.4 does not have this problem with the same config. When I monitor the java runtime, it continuously and steadily takes up more and more ram until it crashes.

This is the output:

There is insufficient memory for the Java Runtime Environment to continue.
Native memory allocation (malloc) failed to allocate 65552 bytes for Chunk::new
Possible reasons:
  The system is out of physical RAM or swap space
  In 32 bit mode, the process size limit was hit
Possible solutions:
  Reduce memory load on the system
  Increase physical memory or swap space
  Check if swap backing store is full
  Use 64 bit Java on a 64 bit OS
  Decrease Java heap size (-Xmx/-Xms)
  Decrease number of Java threads
  Decrease Java thread stack sizes (-Xss)
  Set larger code cache with -XX:ReservedCodeCacheSize=
This output file may be truncated or incomplete.

What can I do more to help fix this?

jsvd commented 9 years ago

can you show the configuration file?

styxke commented 9 years ago

sure:

input 
{ 
    file {
        path => "d:/debugnet/910/BASE/AAA/AAA*.log"
        type => "aaa"
        start_position => "beginning" 
        sincedb_path => "d:/debugnet/sincedb/aaa_since.db"
        codec => multiline {
            pattern => "^\[\] \[%{DATE_US} %{TIME}\] "
            negate => true
            what => "previous"
        }
    }
    file {
        type => "iis"
        path => "C:/inetpub/logs/LogFiles/W3SVC2/u_ex*.log"
        start_position => "beginning"
        sincedb_path => "d:/debugnet/sincedb/iis_since.db"
    }
    file {
        path => "D:/debugnet/BASE/910/CentralCore/CentralCore*.log"
        type => "centralcore"
        start_position => "beginning"
        sincedb_path => "d:/debugnet/sincedb/central_since.db"
        codec => multiline {
            pattern => "^\[%{DATE_EU:date} %{TIME:time}\] "
            negate => true
            what => "previous"
        }
    }
    file {
        path => "D:/debugnet/BASE/910/ResellerCore/ResellerCore*.log"
        type => "resellercore"
        start_position => "beginning"
        sincedb_path => "d:/debugnet/sincedb/reseller_since.db"
        codec => multiline {
            pattern => "^\[%{DATE_EU:date} %{TIME:time}\] "
            negate => true
            what => "previous"
        }
    }
}

filter {
    if [type] == "aaa"
    {
        mutate
        {   
            gsub => ["message", "\n", " "]
            gsub => ["message", "\r", " "]
        }
        grok {
            match => [
                "message", "\[\] \[%{DATE_US:date} %{TIME:time}\] - %{NUMBER:threadid:int} - \[%{UUID:correlationid}\] %{GREEDYDATA:service}: %{GREEDYDATA:methodcall} %{WORD:calltype} from %{WORD:node} %{GREEDYDATA:data}",
                "message", "\[\] \[%{DATE_US:date} %{TIME:time}\] - %{NUMBER:threadid:int} - \[%{UUID:correlationid}\] %{GREEDYDATA:data}"      
            ]
            add_field => ["log_timestamp", "%{date} %{time}"]
        }
        mutate {
            strip => [ "data" ]
        }
        #Set the Event Timestamp from the log
        date {
            match => [ "log_timestamp", "MM/dd/YYYY HH:mm:ss.SSS"]
            timezone => "Europe/Brussels"
        }
        date {
            match => [ "log_timestamp", "MM/dd/YYYY HH:mm:ss.SSS"]
            timezone => "Europe/Brussels"
            target => "logtimestamp"
        }
        mutate {
            remove_field => [ "message", "log_timestamp", "date", "time" ]
        }
    }
    if [type] == "iis"
    {
        #ignore log comments
        if [message] =~ "^#" {
            drop {}
        }
        grok {
            # check that fields match your IIS log settings
            match => ["message", "%{TIMESTAMP_ISO8601:log_timestamp} %{IPORHOST:site} %{WORD:method} %{URIPATH:page} %{NOTSPACE:querystring} %{NUMBER:port:int} %{NOTSPACE:username} %{IPORHOST:clienthost} %{NOTSPACE:useragent} %{NOTSPACE:useragent2} %{NUMBER:response:int} %{NUMBER:subresponse:int} %{NUMBER:scstatus:int} %{NUMBER:time_taken:int}"]
        }
        #Set the Event Timesteamp from the log
        date {
            match => [ "log_timestamp", "YYYY-MM-dd HH:mm:ss" ]
            timezone => "Etc/UCT"
        }   
        date {
            match => [ "log_timestamp", "YYYY-MM-dd HH:mm:ss"]
            timezone => "Europe/Brussels"
            target => "logtimestamp"
        }
        useragent {
            source=> "useragent"
            prefix=> "browser"
        }
        mutate {
            remove_field => [ "log_timestamp"]
            remove_field => [ "message"]
        }
    }
    if [type] == "centralcore"
    {
        mutate
        {
            gsub => ["message", "\n", " "]
            gsub => ["message", "\r", " "]
        }
        grok {
            match => ["message", "\[%{DATE_EU:date} %{TIME:time}\] - \[\] - %{NUMBER:threadid:int} - \[%{UUID:correlationid}\] %{GREEDYDATA:data}"]
            add_field => ["log_timestamp", "%{date} %{time}"]
        }
        mutate {
            strip => [ "data" ]
        }
        #Set the Event Timestamp from the log
        date {
            match => [ "log_timestamp", "dd/MM/YYYY HH:mm:ss.SSS"]
            timezone => "Europe/Brussels"
        }
        date {
            match => [ "log_timestamp", "dd/MM/YYYY HH:mm:ss.SSS"]
            timezone => "Europe/Brussels"
            target => "logtimestamp"
        }
        mutate {
            remove_field => [ "message", "log_timestamp", "date", "time" ]
        }
    }
    if [type] == "resellercore"
    {
        mutate
        {
            gsub => ["message", "\n", " "]
            gsub => ["message", "\r", " "]
        }
        grok {
            match => ["message", "\[%{DATE_EU:date} %{TIME:time}\] - \[\] - %{NUMBER:threadid:int} - \[%{UUID:correlationid}\] %{GREEDYDATA:data}"]
            add_field => ["log_timestamp", "%{date} %{time}"]
        }
        mutate {
            strip => [ "data" ]
        }
        #Set the Event Timestamp from the log
        date {
            match => [ "log_timestamp", "dd/MM/YYYY HH:mm:ss.SSS"]
            timezone => "Europe/Brussels"
        }
        date {
            match => [ "log_timestamp", "dd/MM/YYYY HH:mm:ss.SSS"]
            timezone => "Europe/Brussels"
            target => "logtimestamp"
        }
        mutate {
            remove_field => [ "message", "log_timestamp", "date", "time" ]
        }
    }
}

output {
    if [type] == "aaa"
    {
        elasticsearch {
            host => "10.100.206.33"
            port => "9200"
            protocol => "http"
            flush_size => 10000
            index => "aaa-%{+YYYY.MM.dd}"
        }
    }
    if [type] == "iis"
    {
        elasticsearch {
            host => "10.100.206.33"
            port => "9200"
            protocol => "http"
            flush_size => 10000
            index => "iis-%{+YYYY.MM.dd}"
        }
    }
    if [type] == "centralcore"
    {
        elasticsearch {
            host => "10.100.206.33"
            port => "9200"
            protocol => "http"
            flush_size => 10000
            index => "centralcore-%{+YYYY.MM.dd}"
        }
    }
    if [type] == "resellercore"
    {
        elasticsearch {
            host => "10.100.206.33"
            port => "9200"
            protocol => "http"
            flush_size => 10000
            index => "resellercore-%{+YYYY.MM.dd}"
        }
    }
}
elvarb commented 9 years ago

What does the log file say?

Could be related to https://github.com/logstash-plugins/logstash-output-elasticsearch/issues/144

Balanc3 commented 9 years ago

I too have this issue.

Config:

input {
 file {
   type => "iis"
    path => "C:/inetpub/logs/LogFiles/W3SVC2/*.log"
    start_position => "beginning"   
  }
  file {
  type => "dataservice_debug"
    path => "C:/volo/DataService.debug.log.json*"
    codec => "json"
    start_position => "beginning"
  }
  file {
  type => "kpi_generator"
    path => "C:/volo/Kpi.Generator*.log.json*"
    codec => "json"
    start_position => "beginning"
  }
  file {
  type => "task_runner"
    path => "C:/volo/TaskRunner*.log.json*"
    codec => "json"
    start_position => "beginning"
  }
  file {
  type => "data_cleaner"
    path => "C:/volo/DataCleaner*.log.json*"
    codec => "json"
    start_position => "beginning"
  }
  file {
 type => "loadgroupings_debug"
    path => "C:/volo/LoadGroupingsWizard.debug.log.json*"
    codec => "json"
    start_position => "beginning"
  }
  file {
  type => "loadgroupings_debug"
    path => "C:/volo/LoadGroupingsWizard.error.log.json*"
    codec => "json"
    start_position => "beginning"
  }
  file {
  type => "extractor_logs"
    path => "D:/ExtractorOutput/VoloMetrix/**/extractor.json*"
    codec => "json"
    start_position => "beginning"
  }
}

filter {

 if [type] =~ "iis" {

  #ignore log comments
  if [message] =~ "^#" { drop {} }
    grok {
        match => {"message" => "%{TIMESTAMP_ISO8601:log_timestamp} %{IPORHOST:site} %{WORD:method} %{URIPATH:page} %{NOTSPACE:querystring} %{NUMBER:port} %{NOTSPACE:username} %{IPORHOST:clienthost} %{NOTSPACE:useragent} %{NUMBER:response} %{NUMBER:subresponse} %{NUMBER:scstatus} %{NUMBER:time_taken}"}
        tag_on_failure => [parsefail1]
        }
    if  "parsefail1" in [tags] {
        grok {
        match => {"message" => "%{TIMESTAMP_ISO8601:log_timestamp} %{IPORHOST:site} %{WORD:method} %{URIPATH:page} %{NOTSPACE:querystring} %{NUMBER:port} %{NOTSPACE:username} %{IPORHOST:clienthost} %{NOTSPACE:useragent} %{NOTSPACE:fullurl} %{NUMBER:response} %{NUMBER:subresponse} %{NUMBER:scstatus} %{NUMBER:time_taken}"}
        tag_on_failure => [parsefail2]
        }
    }   
  date {
    match => [ "log_timestamp", "YYYY-MM-dd HH:mm:ss" ]
      timezone => "UTC"
    }   
  useragent {
    source=> "useragent"
    prefix=> "browser"
    }
  mutate { 
    remove_field => [ "log_timestamp"] 
    }
}

if [type] =~ "dataservice_debug" {
        grok {
            match => {"message" => "%{WORD:Status} report %{WORD:reportName} with params ##\| cadence=%{WORD:cadence} \| dates=%{DATE_US:startdate};%{DATE_US:enddate} \| pid=%{INT:pid} %{NOTSPACE:throwaway} in %{TIME:timetaken}"}
            tag_on_failure => [parsefail1]
            }
        if  "parsefail1" in [tags] {
        grok {
            match => {"message" => "%{WORD:Status} report %{WORD:reportName} with params ##\| cadence=%{WORD:cadence} \| dates=%{DATE_US:startdate};%{DATE_US:enddate} \| pid=%{INT:pid}"}
            tag_on_failure => [parsefail2]
            }
        }
        date {
            match => ["date", "ISO8601"]
            timezone => "UTC"
        }
          mutate {
            remove_field => [ "date"]
            remove_field => [ "throwaway"]
            }
    }

if [type] =~ "kpi_generator" {

        date {
            match => ["date", "ISO8601"]
            timezone => "UTC"
        }
        mutate {
            remove_field => [ "date"]
            }
    }

if [type] =~ "task_runner" {

        date {
            match => ["date", "ISO8601"]
            timezone => "UTC"
        }
        mutate {
            remove_field => [ "date"]
            }
    }   

if [type] =~ "data_cleaner" {

        date {
            match => ["date", "ISO8601"]
            timezone => "UTC"
        }
        mutate {
            remove_field => [ "date"]
            }
    }   

if [type] =~ "loadgroupings_debug" {

        date {
            match => ["date", "ISO8601"]
            timezone => "UTC"
        }
        mutate {
            remove_field => [ "date"]
            }
    }   

if [type] =~ "extractor_logs" {

        date {
            match => ["date", "ISO8601"]
            timezone => "UTC"
        }
        mutate {
            remove_field => [ "date"]
            }
    }

    mutate { add_field => ["customer", "customer"] }
}

output {
    stdout { codec => rubydebug }
    elasticsearch { 
        host => "10.0.1.42" 
        port => "9200"
        protocol => "http"

}
    }

Note:

I was able to repo with 1.5.2 too.

I have tried reducing workers and it hasn't helped.

JRE version:

java version "1.8.0_51" Java(TM) SE Runtime Environment (build 1.8.0_51-b16) Java HotSpot(TM) 64-Bit Server VM (build 25.51-b03, mixed mode)

styxke commented 9 years ago

This is the complete output

I have a 'replay log' also, but it's 500KB in size.

#
# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (malloc) failed to allocate 32744 bytes for ChunkPool::allocate
# Possible reasons:
#   The system is out of physical RAM or swap space
#   In 32 bit mode, the process size limit was hit
# Possible solutions:
#   Reduce memory load on the system
#   Increase physical memory or swap space
#   Check if swap backing store is full
#   Use 64 bit Java on a 64 bit OS
#   Decrease Java heap size (-Xmx/-Xms)
#   Decrease number of Java threads
#   Decrease Java thread stack sizes (-Xss)
#   Set larger code cache with -XX:ReservedCodeCacheSize=
# This output file may be truncated or incomplete.
#
#  Out of Memory Error (allocation.cpp:273), pid=9548, tid=41788
#
# JRE version: Java(TM) SE Runtime Environment (8.0_51-b16) (build 1.8.0_51-b16)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (25.51-b03 mixed mode windows-amd64 compressed oops)
# Failed to write core dump. 
#

---------------  T H R E A D  ---------------

Current thread (0x0000000016386800):  VMThread [stack: 0x0000000016b90000,0x0000000016c90000] [id=41788]

Stack: [0x0000000016b90000,0x0000000016c90000]
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [jvm.dll+0x32b4ca]

VM_Operation (0x000000001e52cf40): GenCollectFull, mode: safepoint, requested by thread 0x000000001a1b7000

---------------  P R O C E S S  ---------------

Java Threads: ( => current thread )
  0x0000000019552000 JavaThread ">output" daemon [_thread_blocked, id=5016, stack(0x0000000022260000,0x0000000022460000)]
  0x0000000019551800 JavaThread "Ruby-0-Thread-33: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/logstash-output-elasticsearch-1.0.5-java/lib/logstash/outputs/elasticsearch.rb:459" daemon [_thread_blocked, id=25500, stack(0x0000000022060000,0x0000000022260000)]
  0x0000000019550800 JavaThread "Ruby-0-Thread-32: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/logstash-output-elasticsearch-1.0.5-java/lib/logstash/outputs/elasticsearch.rb:452" daemon [_thread_blocked, id=14744, stack(0x0000000021e60000,0x0000000022060000)]
  0x000000001954d000 JavaThread "Ruby-0-Thread-31: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/stud-0.0.20/lib/stud/buffer.rb:92" daemon [_thread_blocked, id=27984, stack(0x0000000021c60000,0x0000000021e60000)]
  0x0000000019550000 JavaThread "Ruby-0-Thread-30: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/manticore-0.4.2-java/lib/manticore/client.rb:366" daemon [_thread_blocked, id=44020, stack(0x0000000021a60000,0x0000000021c60000)]
  0x000000001954e800 JavaThread "Ruby-0-Thread-29: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/logstash-output-elasticsearch-1.0.5-java/lib/logstash/outputs/elasticsearch.rb:459" daemon [_thread_blocked, id=25348, stack(0x0000000021860000,0x0000000021a60000)]
  0x000000001954f000 JavaThread "Ruby-0-Thread-28: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/logstash-output-elasticsearch-1.0.5-java/lib/logstash/outputs/elasticsearch.rb:452" daemon [_thread_blocked, id=15772, stack(0x0000000021660000,0x0000000021860000)]
  0x000000001954d800 JavaThread "Ruby-0-Thread-27: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/stud-0.0.20/lib/stud/buffer.rb:92" daemon [_thread_blocked, id=5968, stack(0x0000000021460000,0x0000000021660000)]
  0x0000000019549000 JavaThread "Ruby-0-Thread-26: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/manticore-0.4.2-java/lib/manticore/client.rb:366" daemon [_thread_blocked, id=18448, stack(0x0000000021260000,0x0000000021460000)]
  0x000000001954c000 JavaThread "Ruby-0-Thread-25: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/logstash-output-elasticsearch-1.0.5-java/lib/logstash/outputs/elasticsearch.rb:459" daemon [_thread_blocked, id=22384, stack(0x0000000021060000,0x0000000021260000)]
  0x0000000019548800 JavaThread "Ruby-0-Thread-24: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/logstash-output-elasticsearch-1.0.5-java/lib/logstash/outputs/elasticsearch.rb:452" daemon [_thread_blocked, id=4396, stack(0x0000000020e60000,0x0000000021060000)]
  0x000000001954b800 JavaThread "Ruby-0-Thread-23: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/stud-0.0.20/lib/stud/buffer.rb:92" daemon [_thread_blocked, id=21780, stack(0x0000000020c60000,0x0000000020e60000)]
  0x000000001954a000 JavaThread "Ruby-0-Thread-22: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/manticore-0.4.2-java/lib/manticore/client.rb:366" daemon [_thread_blocked, id=32776, stack(0x0000000020a60000,0x0000000020c60000)]
  0x000000001954a800 JavaThread "Ruby-0-Thread-21: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/logstash-output-elasticsearch-1.0.5-java/lib/logstash/outputs/elasticsearch.rb:459" daemon [_thread_blocked, id=20692, stack(0x0000000020860000,0x0000000020a60000)]
  0x0000000019544800 JavaThread "Ruby-0-Thread-20: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/logstash-output-elasticsearch-1.0.5-java/lib/logstash/outputs/elasticsearch.rb:452" daemon [_thread_blocked, id=18980, stack(0x0000000020660000,0x0000000020860000)]
  0x0000000019545800 JavaThread "Ruby-0-Thread-19: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/stud-0.0.20/lib/stud/buffer.rb:92" daemon [_thread_blocked, id=45708, stack(0x0000000020460000,0x0000000020660000)]
  0x0000000019547800 JavaThread "Ruby-0-Thread-18: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/manticore-0.4.2-java/lib/manticore/client.rb:366" daemon [_thread_blocked, id=43512, stack(0x0000000020260000,0x0000000020460000)]
  0x0000000019544000 JavaThread "Ruby-0-Thread-17: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/logstash-output-elasticsearch-1.0.5-java/lib/logstash/outputs/elasticsearch.rb:459" daemon [_thread_blocked, id=29464, stack(0x0000000020060000,0x0000000020260000)]
  0x0000000019547000 JavaThread "Ruby-0-Thread-16: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/logstash-output-elasticsearch-1.0.5-java/lib/logstash/outputs/elasticsearch.rb:452" daemon [_thread_blocked, id=31124, stack(0x000000001fe60000,0x0000000020060000)]
  0x0000000019543000 JavaThread "Ruby-0-Thread-15: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/stud-0.0.20/lib/stud/buffer.rb:92" daemon [_thread_blocked, id=19116, stack(0x000000001fc60000,0x000000001fe60000)]
  0x0000000019546000 JavaThread "Ruby-0-Thread-14: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/manticore-0.4.2-java/lib/manticore/client.rb:366" daemon [_thread_blocked, id=44268, stack(0x000000001f660000,0x000000001f860000)]
  0x0000000016e1a000 JavaThread "Ruby-0-Thread-13: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/manticore-0.4.2-java/lib/manticore/client.rb:366" daemon [_thread_blocked, id=24324, stack(0x000000001f460000,0x000000001f660000)]
  0x0000000016e19800 JavaThread "Ruby-0-Thread-12: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.3-java/lib/logstash/pipeline.rb:160" daemon [_thread_blocked, id=28260, stack(0x000000001f060000,0x000000001f260000)]
  0x0000000016e1b000 JavaThread "|worker" daemon [_thread_blocked, id=34624, stack(0x000000001ed30000,0x000000001ef30000)]
  0x0000000016e16800 JavaThread "jnr.ffi.util.ref.internal.Finalizer" daemon [_thread_blocked, id=35712, stack(0x000000001eb30000,0x000000001ed30000)]
  0x0000000019d43800 JavaThread "<file" daemon [_thread_blocked, id=37344, stack(0x000000001e930000,0x000000001eb30000)]
  0x00000000193a2800 JavaThread "<file" daemon [_thread_blocked, id=21556, stack(0x000000001e730000,0x000000001e930000)]
  0x0000000019a8d000 JavaThread "<file" daemon [_thread_blocked, id=21056, stack(0x000000001e530000,0x000000001e730000)]
  0x000000001a1b7000 JavaThread "<file" daemon [_thread_blocked, id=20712, stack(0x000000001e330000,0x000000001e530000)]
  0x000000001c477000 JavaThread "Thread-6" daemon [_thread_in_native, id=30820, stack(0x000000001e020000,0x000000001e220000)]
  0x0000000019cfd800 JavaThread "Ruby-0-Thread-5: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/logstash-input-perfmon-0.1.3/lib/logstash/inputs/typeperf_wrapper.rb:56" daemon [_thread_in_native, id=45048, stack(0x000000001de20000,0x000000001e020000)]
  0x00000000198b8800 JavaThread "<perfmon" daemon [_thread_blocked, id=43844, stack(0x000000001dc20000,0x000000001de20000)]
  0x0000000018900000 JavaThread "Ruby-0-Thread-3: D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/gems/stud-0.0.20/lib/stud/task.rb:10" daemon [_thread_blocked, id=42312, stack(0x000000001d820000,0x000000001da20000)]
  0x0000000019e94000 JavaThread "jnr.ffi.util.ref.internal.Finalizer" daemon [_thread_blocked, id=11936, stack(0x000000001be50000,0x000000001c050000)]
  0x0000000016e97800 JavaThread "Service Thread" daemon [_thread_blocked, id=13648, stack(0x0000000017e70000,0x0000000018070000)]
  0x0000000016e15800 JavaThread "C1 CompilerThread2" daemon [_thread_in_native, id=23992, stack(0x0000000017d70000,0x0000000017e70000)]
  0x0000000016e10800 JavaThread "C2 CompilerThread1" daemon [_thread_blocked, id=45792, stack(0x0000000017c70000,0x0000000017d70000)]
  0x0000000016e07800 JavaThread "C2 CompilerThread0" daemon [_thread_blocked, id=41072, stack(0x0000000017b70000,0x0000000017c70000)]
  0x0000000016e06000 JavaThread "Attach Listener" daemon [_thread_blocked, id=11224, stack(0x0000000017970000,0x0000000017b70000)]
  0x0000000016e04800 JavaThread "Signal Dispatcher" daemon [_thread_blocked, id=25760, stack(0x0000000017770000,0x0000000017970000)]
  0x0000000016e03800 JavaThread "Surrogate Locker Thread (Concurrent GC)" daemon [_thread_blocked, id=39836, stack(0x0000000017570000,0x0000000017770000)]
  0x000000001638e000 JavaThread "Finalizer" daemon [_thread_blocked, id=3848, stack(0x0000000017370000,0x0000000017570000)]
  0x000000001638b000 JavaThread "Reference Handler" daemon [_thread_blocked, id=20656, stack(0x0000000017170000,0x0000000017370000)]
  0x0000000002690800 JavaThread "LogStash::Runner" [_thread_blocked, id=20896, stack(0x00000000027a0000,0x00000000029a0000)]

Other Threads:
=>0x0000000016386800 VMThread [stack: 0x0000000016b90000,0x0000000016c90000] [id=41788]
  0x0000000016ea1000 WatcherThread [stack: 0x0000000018070000,0x0000000018170000] [id=25444]

VM state:at safepoint (normal execution)

VM Mutex/Monitor currently owned by a thread:  ([mutex/lock_event])
[0x000000000268ca80] Threads_lock - owner thread: 0x0000000016386800
[0x000000000268dc10] Heap_lock - owner thread: 0x000000001a1b7000

Heap:
 par new generation   total 135680K, used 3143K [0x00000000c0000000, 0x00000000c9330000, 0x00000000d5550000)
  eden space 120640K,   2% used [0x00000000c0000000, 0x00000000c0311c78, 0x00000000c75d0000)
  from space 15040K,   0% used [0x00000000c8480000, 0x00000000c8480000, 0x00000000c9330000)
  to   space 15040K,   0% used [0x00000000c75d0000, 0x00000000c75d0000, 0x00000000c8480000)
 concurrent mark-sweep generation total 301332K, used 106262K [0x00000000d5550000, 0x00000000e7b95000, 0x0000000100000000)
 Metaspace       used 46660K, capacity 51038K, committed 51180K, reserved 1091584K
  class space    used 7481K, capacity 8435K, committed 8468K, reserved 1048576K

Card table byte_map: [0x0000000012360000,0x0000000012570000] byte_map_base: 0x0000000011d60000

Marking Bits: (CMSBitMap*) 0x00000000027044b8
 Bits: [0x0000000012d50000, 0x00000000137fac00)

Mod Union Table: (CMSBitMap*) 0x0000000002704578
 Bits: [0x0000000013800000, 0x000000001382aab0)

Polling page: 0x0000000002630000

CodeCache: size=245760Kb used=39685Kb max_used=39894Kb free=206074Kb
 bounds [0x00000000029a0000, 0x0000000005150000, 0x00000000119a0000]
 total_blobs=9931 nmethods=9345 adapters=498
 compilation: enabled

Compilation events (10 events):
Event: 51532.998 Thread 0x0000000016e07800 13970       4       org.jruby.RubyString::equals (35 bytes)
Event: 51533.007 Thread 0x0000000016e07800 nmethod 13970 0x0000000003db1b10 code [0x0000000003db1c60, 0x0000000003db1f58]
Event: 51533.008 Thread 0x0000000016e10800 nmethod 13969 0x0000000003b41650 code [0x0000000003b417e0, 0x0000000003b42488]
Event: 53934.580 Thread 0x0000000016e15800 13971       3       com.fasterxml.jackson.databind.ser.std.NumberSerializers$LongSerializer::serialize (11 bytes)
Event: 53934.580 Thread 0x0000000016e15800 nmethod 13971 0x00000000036cad50 code [0x00000000036caee0, 0x00000000036cb3a8]
Event: 53934.586 Thread 0x0000000016e15800 13972       3       com.fasterxml.jackson.core.json.WriterBasedJsonGenerator::writeNumber (54 bytes)
Event: 53934.586 Thread 0x0000000016e15800 nmethod 13972 0x0000000003e9c990 code [0x0000000003e9cb20, 0x0000000003e9cef8]
Event: 53934.588 Thread 0x0000000016e10800 13973       4       com.fasterxml.jackson.core.io.NumberOutput::leading3 (63 bytes)
Event: 53934.589 Thread 0x0000000016e10800 nmethod 13973 0x0000000004c9f7d0 code [0x0000000004c9f920, 0x0000000004c9fad8]
Event: 54556.182 Thread 0x0000000016e15800 13974       3       java.util.GregorianCalendar::computeFields (1571 bytes)

GC Heap History (10 events):
Event: 54581.011 GC heap after
Heap after GC invocations=16271 (full 2870):
 par new generation   total 135680K, used 0K [0x00000000c0000000, 0x00000000c9330000, 0x00000000d5550000)
  eden space 120640K,   0% used [0x00000000c0000000, 0x00000000c0000000, 0x00000000c75d0000)
  from space 15040K,   0% used [0x00000000c8480000, 0x00000000c8480000, 0x00000000c9330000)
  to   space 15040K,   0% used [0x00000000c75d0000, 0x00000000c75d0000, 0x00000000c8480000)
 concurrent mark-sweep generation total 301332K, used 106252K [0x00000000d5550000, 0x00000000e7b95000, 0x0000000100000000)
 Metaspace       used 46660K, capacity 51038K, committed 51180K, reserved 1091584K
  class space    used 7481K, capacity 8435K, committed 8468K, reserved 1048576K
}
Event: 54581.011 GC heap before
{Heap before GC invocations=16271 (full 2870):
 par new generation   total 135680K, used 2363K [0x00000000c0000000, 0x00000000c9330000, 0x00000000d5550000)
  eden space 120640K,   1% used [0x00000000c0000000, 0x00000000c024ef28, 0x00000000c75d0000)
  from space 15040K,   0% used [0x00000000c8480000, 0x00000000c8480000, 0x00000000c9330000)
  to   space 15040K,   0% used [0x00000000c75d0000, 0x00000000c75d0000, 0x00000000c8480000)
 concurrent mark-sweep generation total 301332K, used 106252K [0x00000000d5550000, 0x00000000e7b95000, 0x0000000100000000)
 Metaspace       used 46660K, capacity 51038K, committed 51180K, reserved 1091584K
  class space    used 7481K, capacity 8435K, committed 8468K, reserved 1048576K
Event: 54581.391 GC heap after
Heap after GC invocations=16272 (full 2871):
 par new generation   total 135680K, used 0K [0x00000000c0000000, 0x00000000c9330000, 0x00000000d5550000)
  eden space 120640K,   0% used [0x00000000c0000000, 0x00000000c0000000, 0x00000000c75d0000)
  from space 15040K,   0% used [0x00000000c8480000, 0x00000000c8480000, 0x00000000c9330000)
  to   space 15040K,   0% used [0x00000000c75d0000, 0x00000000c75d0000, 0x00000000c8480000)
 concurrent mark-sweep generation total 301332K, used 106254K [0x00000000d5550000, 0x00000000e7b95000, 0x0000000100000000)
 Metaspace       used 46660K, capacity 51038K, committed 51180K, reserved 1091584K
  class space    used 7481K, capacity 8435K, committed 8468K, reserved 1048576K
}
Event: 54581.391 GC heap before
{Heap before GC invocations=16272 (full 2871):
 par new generation   total 135680K, used 1093K [0x00000000c0000000, 0x00000000c9330000, 0x00000000d5550000)
  eden space 120640K,   0% used [0x00000000c0000000, 0x00000000c0111488, 0x00000000c75d0000)
  from space 15040K,   0% used [0x00000000c8480000, 0x00000000c8480000, 0x00000000c9330000)
  to   space 15040K,   0% used [0x00000000c75d0000, 0x00000000c75d0000, 0x00000000c8480000)
 concurrent mark-sweep generation total 301332K, used 106254K [0x00000000d5550000, 0x00000000e7b95000, 0x0000000100000000)
 Metaspace       used 46660K, capacity 51038K, committed 51180K, reserved 1091584K
  class space    used 7481K, capacity 8435K, committed 8468K, reserved 1048576K
Event: 54581.754 GC heap after
Heap after GC invocations=16273 (full 2872):
 par new generation   total 135680K, used 0K [0x00000000c0000000, 0x00000000c9330000, 0x00000000d5550000)
  eden space 120640K,   0% used [0x00000000c0000000, 0x00000000c0000000, 0x00000000c75d0000)
  from space 15040K,   0% used [0x00000000c8480000, 0x00000000c8480000, 0x00000000c9330000)
  to   space 15040K,   0% used [0x00000000c75d0000, 0x00000000c75d0000, 0x00000000c8480000)
 concurrent mark-sweep generation total 301332K, used 106254K [0x00000000d5550000, 0x00000000e7b95000, 0x0000000100000000)
 Metaspace       used 46660K, capacity 51038K, committed 51180K, reserved 1091584K
  class space    used 7481K, capacity 8435K, committed 8468K, reserved 1048576K
}
Event: 54581.755 GC heap before
{Heap before GC invocations=16273 (full 2872):
 par new generation   total 135680K, used 2387K [0x00000000c0000000, 0x00000000c9330000, 0x00000000d5550000)
  eden space 120640K,   1% used [0x00000000c0000000, 0x00000000c0254e08, 0x00000000c75d0000)
  from space 15040K,   0% used [0x00000000c8480000, 0x00000000c8480000, 0x00000000c9330000)
  to   space 15040K,   0% used [0x00000000c75d0000, 0x00000000c75d0000, 0x00000000c8480000)
 concurrent mark-sweep generation total 301332K, used 106254K [0x00000000d5550000, 0x00000000e7b95000, 0x0000000100000000)
 Metaspace       used 46660K, capacity 51038K, committed 51180K, reserved 1091584K
  class space    used 7481K, capacity 8435K, committed 8468K, reserved 1048576K
Event: 54582.115 GC heap after
Heap after GC invocations=16274 (full 2873):
 par new generation   total 135680K, used 0K [0x00000000c0000000, 0x00000000c9330000, 0x00000000d5550000)
  eden space 120640K,   0% used [0x00000000c0000000, 0x00000000c0000000, 0x00000000c75d0000)
  from space 15040K,   0% used [0x00000000c8480000, 0x00000000c8480000, 0x00000000c9330000)
  to   space 15040K,   0% used [0x00000000c75d0000, 0x00000000c75d0000, 0x00000000c8480000)
 concurrent mark-sweep generation total 301332K, used 106281K [0x00000000d5550000, 0x00000000e7b95000, 0x0000000100000000)
 Metaspace       used 46660K, capacity 51038K, committed 51180K, reserved 1091584K
  class space    used 7481K, capacity 8435K, committed 8468K, reserved 1048576K
}
Event: 54582.116 GC heap before
{Heap before GC invocations=16274 (full 2873):
 par new generation   total 135680K, used 2451K [0x00000000c0000000, 0x00000000c9330000, 0x00000000d5550000)
  eden space 120640K,   2% used [0x00000000c0000000, 0x00000000c0264db8, 0x00000000c75d0000)
  from space 15040K,   0% used [0x00000000c8480000, 0x00000000c8480000, 0x00000000c9330000)
  to   space 15040K,   0% used [0x00000000c75d0000, 0x00000000c75d0000, 0x00000000c8480000)
 concurrent mark-sweep generation total 301332K, used 106281K [0x00000000d5550000, 0x00000000e7b95000, 0x0000000100000000)
 Metaspace       used 46660K, capacity 51038K, committed 51180K, reserved 1091584K
  class space    used 7481K, capacity 8435K, committed 8468K, reserved 1048576K
Event: 54582.472 GC heap after
Heap after GC invocations=16275 (full 2874):
 par new generation   total 135680K, used 0K [0x00000000c0000000, 0x00000000c9330000, 0x00000000d5550000)
  eden space 120640K,   0% used [0x00000000c0000000, 0x00000000c0000000, 0x00000000c75d0000)
  from space 15040K,   0% used [0x00000000c8480000, 0x00000000c8480000, 0x00000000c9330000)
  to   space 15040K,   0% used [0x00000000c75d0000, 0x00000000c75d0000, 0x00000000c8480000)
 concurrent mark-sweep generation total 301332K, used 106262K [0x00000000d5550000, 0x00000000e7b95000, 0x0000000100000000)
 Metaspace       used 46660K, capacity 51038K, committed 51180K, reserved 1091584K
  class space    used 7481K, capacity 8435K, committed 8468K, reserved 1048576K
}
Event: 54582.478 GC heap before
{Heap before GC invocations=16275 (full 2874):
 par new generation   total 135680K, used 3143K [0x00000000c0000000, 0x00000000c9330000, 0x00000000d5550000)
  eden space 120640K,   2% used [0x00000000c0000000, 0x00000000c0311c78, 0x00000000c75d0000)
  from space 15040K,   0% used [0x00000000c8480000, 0x00000000c8480000, 0x00000000c9330000)
  to   space 15040K,   0% used [0x00000000c75d0000, 0x00000000c75d0000, 0x00000000c8480000)
 concurrent mark-sweep generation total 301332K, used 106262K [0x00000000d5550000, 0x00000000e7b95000, 0x0000000100000000)
 Metaspace       used 46660K, capacity 51038K, committed 51180K, reserved 1091584K
  class space    used 7481K, capacity 8435K, committed 8468K, reserved 1048576K

Deoptimization events (10 events):
Event: 49731.810 Thread 0x0000000016e1b000 Uncommon trap: reason=class_check action=maybe_recompile pc=0x0000000003547064 method=org.jruby.RubyString.splitCommon19(Lorg/jruby/runtime/builtin/IRubyObject;ZIILorg/jruby/runtime/ThreadContext;Z)Lorg/jruby/RubyArray; @ 1
Event: 49731.810 Thread 0x0000000016e1b000 Uncommon trap: reason=class_check action=maybe_recompile pc=0x0000000003d878dc method=rubyjit.LogStash::Util::PathCache$$get_1cf4309fa8241e2313fa7337bebb0e953931d5c91836019240.__file__(Lrubyjit/LogStash::Util::PathCache$$get_1cf4309fa8241e2313fa7337bebb0e9íÝzèyHè@
Event: 49731.810 Thread 0x0000000016e1b000 Uncommon trap: reason=class_check action=maybe_recompile pc=0x0000000003547064 method=org.jruby.RubyString.splitCommon19(Lorg/jruby/runtime/builtin/IRubyObject;ZIILorg/jruby/runtime/ThreadContext;Z)Lorg/jruby/RubyArray; @ 1
Event: 49731.810 Thread 0x0000000016e1b000 Uncommon trap: reason=unstable_if action=reinterpret pc=0x0000000003ee07e4 method=org.jruby.ext.thread_safe.jsr166e.ConcurrentHashMapV8.internalPut(Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object; @ 508
Event: 49731.814 Thread 0x0000000016e1b000 Uncommon trap: reason=class_check action=maybe_recompile pc=0x0000000003d878dc method=rubyjit.LogStash::Util::PathCache$$get_1cf4309fa8241e2313fa7337bebb0e953931d5c91836019240.__file__(Lrubyjit/LogStash::Util::PathCache$$get_1cf4309fa8241e2313fa7337bebb0e9ÎÙ§zHè@
Event: 49731.814 Thread 0x0000000016e1b000 Uncommon trap: reason=class_check action=maybe_recompile pc=0x0000000003547064 method=org.jruby.RubyString.splitCommon19(Lorg/jruby/runtime/builtin/IRubyObject;ZIILorg/jruby/runtime/ThreadContext;Z)Lorg/jruby/RubyArray; @ 1
Event: 51035.259 Thread 0x00000000198b8800 Uncommon trap: reason=unstable_if action=reinterpret pc=0x00000000041a5cd8 method=org.jruby.RubyString.equals(Ljava/lang/Object;)Z @ 28
Event: 53933.573 Thread 0x0000000019552000 Uncommon trap: reason=unstable_if action=reinterpret pc=0x00000000035d1290 method=com.fasterxml.jackson.core.io.NumberOutput.outputLong(J[CI)I @ 73
Event: 53934.580 Thread 0x000000001954b800 Uncommon trap: reason=unstable_if action=reinterpret pc=0x00000000046b966c method=com.fasterxml.jackson.core.io.NumberOutput.outputLong(J[CI)I @ 73
Event: 54556.172 Thread 0x0000000019543000 Uncommon trap: reason=unstable_if action=reinterpret pc=0x00000000042443ac method=java.util.GregorianCalendar.computeFields(II)I @ 199

Internal exceptions (10 events):
Event: 7.496 Thread 0x0000000018900000 Exception <a 'java/lang/ArrayIndexOutOfBoundsException': 28> (0x00000000c2796438) thrown at [C:\re\workspace\8-2-build-windows-amd64-cygwin\jdk8u51\3951\hotspot\src\share\vm\interpreter\interpreterRuntime.cpp, line 366]
Event: 7.497 Thread 0x0000000018900000 Exception <a 'java/lang/ArrayIndexOutOfBoundsException': 18> (0x00000000c2797748) thrown at [C:\re\workspace\8-2-build-windows-amd64-cygwin\jdk8u51\3951\hotspot\src\share\vm\interpreter\interpreterRuntime.cpp, line 366]
Event: 7.497 Thread 0x0000000018900000 Exception <a 'java/lang/ArrayIndexOutOfBoundsException': 60> (0x00000000c2798c90) thrown at [C:\re\workspace\8-2-build-windows-amd64-cygwin\jdk8u51\3951\hotspot\src\share\vm\interpreter\interpreterRuntime.cpp, line 366]
Event: 16.118 Thread 0x00000000198b8800 Implicit null exception at 0x0000000003095bcf to 0x0000000003095c99
Event: 147.233 Thread 0x0000000016e1b000 Implicit null exception at 0x0000000003dba125 to 0x0000000003db9bb1
Event: 179.941 Thread 0x0000000019d43800 Implicit null exception at 0x0000000003044ee4 to 0x000000000304551d
Event: 858.037 Thread 0x000000001638e000 Implicit null exception at 0x00000000038c23e3 to 0x00000000038c2521
Event: 1120.703 Thread 0x0000000016e1b000 Implicit null exception at 0x0000000004268a45 to 0x00000000042696a1
Event: 3729.915 Thread 0x0000000019543000 Implicit null exception at 0x0000000004860d31 to 0x000000000486a69d
Event: 7658.412 Thread 0x000000001c529000 Implicit null exception at 0x00000000045c7d7c to 0x00000000045c8451

Events (10 events):
Event: 54581.391 Executing VM operation: GenCollectFull done
Event: 54581.391 Executing VM operation: GenCollectFull
Event: 54581.754 Executing VM operation: GenCollectFull done
Event: 54581.754 Executing VM operation: GenCollectFull
Event: 54582.115 Executing VM operation: GenCollectFull done
Event: 54582.116 Executing VM operation: GenCollectFull
Event: 54582.472 Executing VM operation: GenCollectFull done
Event: 54582.473 loading class com/jrjackson/PackageVersion
Event: 54582.473 loading class com/jrjackson/PackageVersion done
Event: 54582.477 Executing VM operation: GenCollectFull

Dynamic libraries:
0x00007ff66cc20000 - 0x00007ff66cc57000     C:\Progra~1\Java\jre1.8.0_51\bin\java.exe
0x00007ff9cc5c0000 - 0x00007ff9cc76c000     C:\Windows\SYSTEM32\ntdll.dll
0x00007ff9c9ca0000 - 0x00007ff9c9dde000     C:\Windows\system32\KERNEL32.DLL
0x00007ff9c98e0000 - 0x00007ff9c99f5000     C:\Windows\system32\KERNELBASE.dll
0x00007ff9c8030000 - 0x00007ff9c80be000     C:\Windows\system32\apphelp.dll
0x00007ff9a2570000 - 0x00007ff9a25c3000     C:\Windows\AppPatch\AppPatch64\AcGenral.DLL
0x00007ff9ca4b0000 - 0x00007ff9ca55a000     C:\Windows\system32\msvcrt.dll
0x00007ff9c94e0000 - 0x00007ff9c950e000     C:\Windows\SYSTEM32\SspiCli.dll
0x00007ff9cc2d0000 - 0x00007ff9cc324000     C:\Windows\system32\SHLWAPI.dll
0x00007ff9cbfc0000 - 0x00007ff9cc137000     C:\Windows\system32\USER32.dll
0x00007ff9ca080000 - 0x00007ff9ca214000     C:\Windows\system32\ole32.dll
0x00007ff9ca8f0000 - 0x00007ff9cbe08000     C:\Windows\system32\SHELL32.dll
0x00007ff9c8cb0000 - 0x00007ff9c8cd1000     C:\Windows\SYSTEM32\USERENV.dll
0x00007ff9ca3e0000 - 0x00007ff9ca48a000     C:\Windows\system32\ADVAPI32.dll
0x00007ff9c3560000 - 0x00007ff9c357e000     C:\Windows\SYSTEM32\MPR.dll
0x00007ff9cbe10000 - 0x00007ff9cbf51000     C:\Windows\system32\RPCRT4.dll
0x00007ff9c9c40000 - 0x00007ff9c9c99000     C:\Windows\SYSTEM32\sechost.dll
0x00007ff9cc390000 - 0x00007ff9cc5a1000     C:\Windows\SYSTEM32\combase.dll
0x00007ff9c9f20000 - 0x00007ff9ca071000     C:\Windows\system32\GDI32.dll
0x00007ff9c9710000 - 0x00007ff9c9725000     C:\Windows\SYSTEM32\profapi.dll
0x00007ff9c7f70000 - 0x00007ff9c8022000     C:\Windows\SYSTEM32\SHCORE.dll
0x00007ff9ca380000 - 0x00007ff9ca3b6000     C:\Windows\system32\IMM32.DLL
0x00007ff9ca220000 - 0x00007ff9ca372000     C:\Windows\system32\MSCTF.dll
0x00007ff9c74b0000 - 0x00007ff9c772b000     C:\Windows\WinSxS\amd64_microsoft.windows.common-controls_6595b64144ccf1df_6.0.9600.17415_none_6240486fecbd8abb\COMCTL32.dll
0x0000000069630000 - 0x0000000069702000     C:\Progra~1\Java\jre1.8.0_51\bin\msvcr100.dll
0x0000000068da0000 - 0x0000000069623000     C:\Progra~1\Java\jre1.8.0_51\bin\server\jvm.dll
0x00007ff9c39d0000 - 0x00007ff9c39d9000     C:\Windows\SYSTEM32\WSOCK32.dll
0x00007ff9c6780000 - 0x00007ff9c67a2000     C:\Windows\SYSTEM32\WINMM.dll
0x00007ff9c3530000 - 0x00007ff9c353a000     C:\Windows\SYSTEM32\VERSION.dll
0x00007ff9ca3d0000 - 0x00007ff9ca3d7000     C:\Windows\system32\PSAPI.DLL
0x00007ff9cbf60000 - 0x00007ff9cbfba000     C:\Windows\system32\WS2_32.dll
0x00007ff9c29e0000 - 0x00007ff9c2a0a000     C:\Windows\SYSTEM32\WINMMBASE.dll
0x00007ff9cc5b0000 - 0x00007ff9cc5b9000     C:\Windows\system32\NSI.dll
0x00007ff9c9890000 - 0x00007ff9c98df000     C:\Windows\SYSTEM32\cfgmgr32.dll
0x00007ff9c8570000 - 0x00007ff9c8598000     C:\Windows\SYSTEM32\DEVOBJ.dll
0x0000000068d90000 - 0x0000000068d9f000     C:\Progra~1\Java\jre1.8.0_51\bin\verify.dll
0x0000000068d60000 - 0x0000000068d89000     C:\Progra~1\Java\jre1.8.0_51\bin\java.dll
0x0000000068d40000 - 0x0000000068d56000     C:\Progra~1\Java\jre1.8.0_51\bin\zip.dll
0x00007ff9c8f80000 - 0x00007ff9c8fa0000     C:\Windows\SYSTEM32\CRYPTSP.dll
0x00007ff9c8bc0000 - 0x00007ff9c8bf6000     C:\Windows\system32\rsaenh.dll
0x00007ff9c91d0000 - 0x00007ff9c91f6000     C:\Windows\SYSTEM32\bcrypt.dll
0x00007ff9c9510000 - 0x00007ff9c9573000     C:\Windows\system32\bcryptprimitives.dll
0x00007ff9c9580000 - 0x00007ff9c958b000     C:\Windows\SYSTEM32\CRYPTBASE.dll
0x0000000068d20000 - 0x0000000068d3a000     C:\Program Files\Java\jre1.8.0_51\bin\net.dll
0x00007ff9c8f20000 - 0x00007ff9c8f79000     C:\Windows\system32\mswsock.dll
0x00007ff9c66b0000 - 0x00007ff9c66da000     C:\Windows\SYSTEM32\IPHLPAPI.DLL
0x00007ff9c6f20000 - 0x00007ff9c6f2a000     C:\Windows\SYSTEM32\WINNSI.DLL
0x00007ff9c6310000 - 0x00007ff9c6326000     C:\Windows\SYSTEM32\dhcpcsvc6.DLL
0x00007ff9c5e60000 - 0x00007ff9c5e7a000     C:\Windows\SYSTEM32\dhcpcsvc.DLL
0x0000000068d00000 - 0x0000000068d11000     C:\Program Files\Java\jre1.8.0_51\bin\nio.dll
0x00007ff9c4ed0000 - 0x00007ff9c4ee5000     C:\Windows\system32\napinsp.dll
0x00007ff9c7430000 - 0x00007ff9c744b000     C:\Windows\system32\NLAapi.dll
0x00007ff9c8d20000 - 0x00007ff9c8dc4000     C:\Windows\SYSTEM32\DNSAPI.dll
0x00007ff9c4f30000 - 0x00007ff9c4f3d000     C:\Windows\System32\winrnr.dll
0x00007ff9c4f40000 - 0x00007ff9c4f4a000     C:\Windows\System32\rasadhlp.dll
0x00007ff9c6520000 - 0x00007ff9c658b000     C:\Windows\System32\fwpuclnt.dll
0x000000006e4c0000 - 0x000000006e4df000     D:\debugnet\logstash-1.5.3\vendor\jruby\lib\jni\x86_64-Windows\jffi-1.2.dll
0x0000000068cd0000 - 0x0000000068cf4000     C:\Program Files\Java\jre1.8.0_51\bin\sunec.dll

VM Arguments:
jvm_args: -Djdk.home=C:\Progra~1\Java\jre1.8.0_51 -Djruby.home=D:\debugnet\logstash-1.5.3\vendor\jruby -Djruby.script=jruby -Djruby.shell=cmd.exe -Djffi.boot.library.path=D:\debugnet\logstash-1.5.3\vendor\jruby\lib\jni;D:\debugnet\logstash-1.5.3\vendor\jruby\lib\jni\i386-Windows;D:\debugnet\logstash-1.5.3\vendor\jruby\lib\jni\x86_64-Windows -Xss2048k -Xbootclasspath/a:D:\debugnet\logstash-1.5.3\vendor\jruby\lib\jruby.jar -Xms256m -Xmx1g -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+CMSParallelRemarkEnabled -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=1 -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitiatingOccupancyOnly -XX:+HeapDumpOnOutOfMemoryError 
java_command: org/jruby/Main D:\debugnet\logstash-1.5.3\lib\bootstrap\environment.rb logstash\runner.rb agent -f perfmon.conf
java_class_path (initial): <not set>
Launcher Type: SUN_STANDARD

Environment Variables:
JAVA_HOME=C:\Progra~1\Java\jre1.8.0_51\
PATH=D:/debugnet/logstash-1.5.3/vendor/bundle/jruby/1.9/bin;C:\ProgramData\Oracle\Java\javapath;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\
USERNAME=Monitoring
OS=Windows_NT
PROCESSOR_IDENTIFIER=Intel64 Family 6 Model 63 Stepping 2, GenuineIntel

---------------  S Y S T E M  ---------------

OS: Windows Server 2012 R2 , 64 bit Build 9600 (6.3.9600.17415)

CPU:total 6 (8 cores per cpu, 1 threads per core) family 6 model 63 stepping 2, cmov, cx8, fxsr, mmx, sse, sse2, sse3, ssse3, sse4.1, sse4.2, popcnt, avx, avx2, clmul, erms, lzcnt, tsc, bmi1, bmi2

Memory: 4k page, physical 4193844k(50848k free), swap 8388148k(3608k free)

vm_info: Java HotSpot(TM) 64-Bit Server VM (25.51-b03) for windows-amd64 JRE (1.8.0_51-b16), built on Jun  8 2015 18:03:07 by "java_re" with MS VC++ 10.0 (VS2010)

time: Fri Aug 07 00:00:27 2015
elapsed time: 54582 seconds (0d 15h 9m 42s)
michaellandi commented 9 years ago

I'm also having a problem with logstash 1.5.4 on Windows Server (2008 and 2012). Memory usage of "java.exe" just continues to grow until all available memory is consumed. Any update on this?

ph commented 9 years ago

@michaellandi we have found the issue, it's a jruby bug we are waiting for an upstream fix to release a new version of logstash.

For more info see this issue https://github.com/jruby/jruby/issues/3446

michaellandi commented 9 years ago

Thanks for the update, I am going to force logstash to restart several times a day in the meantime.

gzpbx commented 9 years ago

@michaellandi I have the same issue.

michaellandi commented 9 years ago

@gzpbx until the jruby issue is resolved I've taken a few countermeasures.

For starters, forcing java to start with lower memory to begin with by setting the LS_MEM_MAX and LS_MEM_MIN variables to 128m and 256m respectively. This stops the process from claiming the 1GB up front, making it take longer to grow the memory.

Then twice a day recycling the logstash instances (mine are setup as windows services using NSSM). I simply set up a scheduled task to run the following .bat script:

net stop logstash
net start logstash
exit /B
JaminVP commented 9 years ago

I have 7 servers running Logstash with two of them experiencing the same memory leak issues. I found out that only those two have the wildcard symbol * in the input filepath. Removing the wildcard solved the issue for one of my servers (because it has autorolling for the logs), but the other has daterelated log files which need the wildcard.

Try removing the wildcard if it's possible.

michaellandi commented 9 years ago

@JaminVP interesting find. All of my servers have wildcards in the input filepath (i'm pulling in IIS logs which are dated in my case, and not autorolling).

JaminVP commented 9 years ago

After a small week I noticed that the memory leak is still there even when using absolute filepaths, although it's heavily reduced. I switched back to 1.50rc until this issue is fixed.

michaellandi commented 9 years ago

jruby 1.7.23 was released today, and fixes the memory leak using File::Stat. Any idea when this will be incorporated into a logstash build?

jordansissel commented 9 years ago

Soon. Bad timing that Logstash 2.1.0 was released today. We can do a minor release with JRuby 1.7.23 soon.

michaellandi commented 9 years ago

Awesome, thanks! I have several servers which I can test on.

kryten68 commented 9 years ago

I know its only been a couple of days, but is there any view on when this fix might be available? We have a large number of machines seeing this problem and a fix cannot come soon enough. Thanks.

colinsurprenant commented 9 years ago

We will be releasing a bug fix version 2.1.1 early next week for this.

colinsurprenant commented 9 years ago

in the mean time you could try & validate the fix which is available in the latest 2.1 branch snapshot in https://s3-eu-west-1.amazonaws.com/build-eu.elasticsearch.org/logstash/2.1/nightly/JDK8/logstash-latest-SNAPSHOT.zip - (also .tar.gz if preferred)

rurku commented 9 years ago

I'm also having the memory leak issue so I tried the latest version from your link and for me it's crashing in file input:

NotImplementedError: major device unsupported or native support failed to load
       dev_major at org/jruby/RubyFileStat.java:205
           inode at C:/Home/Pulpit/logstash-setup/logstash/vendor/bundle/jruby/1.9/gems/filewatch-0.6.6/lib/filewatch/watch.rb:48
  _discover_file at C:/Home/Pulpit/logstash-setup/logstash/vendor/bundle/jruby/1.9/gems/filewatch-0.6.6/lib/filewatch/watch.rb:155
            each at org/jruby/RubyArray.java:1613
  _discover_file at C:/Home/Pulpit/logstash-setup/logstash/vendor/bundle/jruby/1.9/gems/filewatch-0.6.6/lib/filewatch/watch.rb:137
           watch at C:/Home/Pulpit/logstash-setup/logstash/vendor/bundle/jruby/1.9/gems/filewatch-0.6.6/lib/filewatch/watch.rb:38
            tail at C:/Home/Pulpit/logstash-setup/logstash/vendor/bundle/jruby/1.9/gems/filewatch-0.6.6/lib/filewatch/tail.rb:69
             run at C:/Home/Pulpit/logstash-setup/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-file-2.0.3/lib/logstash/inputs/file.rb:192
            each at org/jruby/RubyArray.java:1613
             run at C:/Home/Pulpit/logstash-setup/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-file-2.0.3/lib/logstash/inputs/file.rb:192
     inputworker at C:/Home/Pulpit/logstash-setup/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.1.0-java/lib/logstash/pipeline.rb:205
     start_input at C:/Home/Pulpit/logstash-setup/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.1.0-java/lib/logstash/pipeline.rb:198

My config:

input {
    file {
        path => "D:\Logs\folder1\Debug.log"
        sincedb_path => "D:\logs\logstash_sincedb"
        start_position => "beginning"
    }
}

filter {
    grok {
        match => {"message" => "%{WORD:level} +%{TIMESTAMP_ISO8601:logtimestamp} %{NOTSPACE:logger} - %{GREEDYDATA:bare_message}\r" }
    }
}

output {
  file {
    path => "d:\logs\logstash-output.txt"
  }
}

What's even more interesting, if I remove the grok filter leaving filter section empty then logstash shuts down immediately without showing any error.

io/console not supported; tty will not be manipulated
Settings: Default filter workers: 2
Registering file input {:path=>["D:\\Logs\\folder1\\Debug.log"], :level=>:info}
Pipeline started {:level=>:info}
Logstash startup completed
Pipeline shutdown complete. {:level=>:info}
Logstash shutdown completed

Does this mean the fix makes things even worse or am I doing something wrong?

kryten68 commented 9 years ago

Hi Colin

I tried the beta you suggested. I'm afraid its not quite there yet. When I try to run it on one of our machines here is what I get:-

io/console not supported; tty will not be manipulated
Settings: Default filter workers: 1
NotImplementedError: major device unsupported or native support failed to load
   dev_major at org/jruby/RubyFileStat.java:205
       inode at E:/CopyCo/logstash-2.1.0/vendor/bundle/jruby/1.9/gems/filewat
ch-0.6.6/lib/filewatch/watch.rb:48
  _discover_file at E:/CopyC/logstash-2.1.0/vendor/bundle/jruby/1.9/gems/filewat
ch-0.6.6/lib/filewatch/watch.rb:155
        each at org/jruby/RubyArray.java:1613
  _discover_file at E:/CopyC/logstash-2.1.0/vendor/bundle/jruby/1.9/gems/filewat
ch-0.6.6/lib/filewatch/watch.rb:137
       watch at E:/CopyC/logstash-2.1.0/vendor/bundle/jruby/1.9/gems/filewat
ch-0.6.6/lib/filewatch/watch.rb:38
        tail at E:/CopyC/logstash-2.1.0/vendor/bundle/jruby/1.9/gems/filewat
ch-0.6.6/lib/filewatch/tail.rb:69
         run at E:/CopyC/logstash-2.1.0/vendor/bundle/jruby/1.9/gems/logstas
h-input-file-2.0.3/lib/logstash/inputs/file.rb:192
        each at org/jruby/RubyArray.java:1613
         run at E:/CopyC/logstash-2.1.0/vendor/bundle/jruby/1.9/gems/logstas
h-input-file-2.0.3/lib/logstash/inputs/file.rb:192
 inputworker at E:/CopyC/logstash-2.1.0/vendor/bundle/jruby/1.9/gems/logstas
h-core-2.1.0-java/lib/logstash/pipeline.rb:205
 start_input at E:/CopyC/logstash-2.1.0/vendor/bundle/jruby/1.9/gems/logstas
h-core-2.1.0-java/lib/logstash/pipeline.rb:198

So, its a non starter at the moment. Would appreciate any thoughts or suggestions.

jsvd commented 9 years ago

This seems related to https://github.com/elastic/logstash/pull/4284 can you confirm @kryten68 ?

kryten68 commented 9 years ago

Unfortunately I'm not (yet) familiar enough with Logstash to be able to offer much insight beyond trying things and reporting what happens. Apologies.

jsvd commented 9 years ago

Sorry I linked the wrong issue, I meant https://github.com/elastic/logstash/issues/3127#issuecomment-101068714

This seems to be a deficiency in symlinking of libcrypt on Ubuntu + Oracle's Java (not OpenJDK) Can you confirm this is also your environment?

kryten68 commented 8 years ago

Hi, I'm certainly using Oracle Java, but the servers in question are Windows Server 2008 R2.

Is there any update on this issue, does anyone know? Will there still be a LS 2.1.1 release with the fix? That snapshot version I downloaded and tried won't even run. We have now had to turn Logstash off on most of our machines so confidence is a little low. Really need a solid LS release soon .. please!

Please let me know if there is anything I can do to assist.

untergeek commented 8 years ago

Yes, @kryten68, we will be releasing 2.1.1 later this week. We have to let the changes bake in our continuous integration testing before we release.

colinsurprenant commented 8 years ago

@jsvd has just confirmed a regression in JRuby 1.7.23 which explains the problem you are experiencing kryten68 - the JRuby team will do a new release shortly to fix this and we will in turn release a new version to include the fix. As soon as we have a build ready we will followup here. Thanks for your patience.

kryten68 commented 8 years ago

Gentlemen. Thank you so much. Your efforts are very much appreciated.

kryten68 commented 8 years ago

Any updates on this? Desperate to get our Logstash up and running again...

untergeek commented 8 years ago

@kryten68 sorry for the delay. We are catching and fixing things for the 2.1.1 release, and it is targeted for early next week.

wyardley commented 8 years ago

I'm still seeing a memory leak in 2.1.2.

suyograo commented 8 years ago

Fixed in https://github.com/jruby/jruby/issues/3446. Please open a new issue if you are seeing this again.