Java Memory Error From a Ruby Script?

Hi Logstash,

I’m running the Logstash 7.7.0 Docker container, spun up on an Ubuntu machine. In my LS filter config, I “bounce” all of my records off an external C program via a TCP socket:

  ruby {
    init => "
      require 'socket'
    "

    code => '
      socket = TCPSocket.new("192.168.3.1", 12345)
      socket.write event.to_hash
      response = socket.recv(10000000)
      event.set("NewData", response)
    '

Fairly simple. The C program takes the entire data record, does some processing, and sends back a single string, which should never be more than 50 bytes long. The C program always sends back a string, even under default conditions.

But I’ve noticed that 33% of the time, I see a “null” value in the “NewData” field. That shouldn’t be. Also, I see a lot of this in the LS log:

[2020-10-09T16:34:10,476][ERROR][logstash.filters.ruby ][main][09de6b10cf3fdaa7a5ae8b4e3fcd73837267db580130edc34de5fc2c7e5e9cb2] Ruby exception occurred: Java heap space

I see this message hundreds of times. I don’t know what it means, but I’m guessing that something in the Ruby code calls Java, Java tries to allocate some memory, and the memory allocation fails. Java throws an exception, which causes Ruby to throw an exception, which causes the above error message. Maybe.

I’ve been rummaging about on the Elastic forum, and it looks like there have been similar-sounding issues to mine, such as this one. But the solution quoted here doesn’t seem to apply.

I’m also wondering if the Docker container might be imposing some limitations here? Perhaps a program within a container is only allowed to allocate so much system memory?

How does one troubleshoot something like this? Any suggestions? Much appreciated!

Does adding

socket.close

after the event.set help?

Ah! Good catch! Thank you!

Unfortunately, modifying the code seems to cause an exception throw on every record. Here's the modified code:

code => '
  socket = TCPSocket.new("192.168.3.1", 37261)
  socket.write "    "+">>>"+(event.to_hash).to_s+"<<<"
  response = socket.recv(10000000)
  socket.close
  event.set("nDPI_Application", response)
'

Did I screw up the close function? Because now I don't see a single data record coming into Elasticsearch. The Logstash log is filled with a lot of these:

[2020-10-09T20:45:12,347][WARN ][logstash.codecs.sflow    ][main][10cc1a8cf743c5f9a679845029ecff7f06da16648567a2d1e9f51ac125c221be] Invalid sflow packet received (End of file reached)
[2020-10-09T20:45:13,348][WARN ][logstash.codecs.sflow    ][main][10cc1a8cf743c5f9a679845029ecff7f06da16648567a2d1e9f51ac125c221be] Invalid sflow packet received (End of file reached)
[2020-10-09T20:45:15,355][WARN ][logstash.codecs.sflow    ][main][10cc1a8cf743c5f9a679845029ecff7f06da16648567a2d1e9f51ac125c221be] Unknown counter_flow record: entreprise 16, format 0
[2020-10-09T20:45:17,345][WARN ][logstash.codecs.sflow    ][main][10cc1a8cf743c5f9a679845029ecff7f06da16648567a2d1e9f51ac125c221be] Unknown counter_flow record: entreprise 0, format 2203

And then hundreds of these:

[2020-10-09T20:46:50,364][ERROR][logstash.filters.ruby    ][main][0778fdc44e50f682f4354179ca25ea3d4ff569db1c408914df2857817ffb24f5] Ruby exception occurred: Java heap space
[2020-10-09T20:46:50,365][ERROR][logstash.filters.ruby    ][main][0778fdc44e50f682f4354179ca25ea3d4ff569db1c408914df2857817ffb24f5] Ruby exception occurred: Java heap space
[2020-10-09T20:46:50,365][ERROR][logstash.filters.ruby    ][main][0778fdc44e50f682f4354179ca25ea3d4ff569db1c408914df2857817ffb24f5] Ruby exception occurred: Java heap space

EDIT: Issue went away upon restart... Now the system works perfectly. Wish I knew why, but I'll take it. If anyone from LS sees this, please consider this issue closed. Thank you.

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.