Not transferring Multiline messages


(Gary Keller) #1

It seems my multiline filter in Filebeat is not working I was
looking at the log file for the multiline messages and found that they
were not being transferred to Elastisearch. My config file is

filebeat:
  # List of prospectors to fetch data.
  prospectors:
    # Each - is a prospector. Below are the prospector specific configurations
    -
      paths:
        - /local/gstapps/development/jboss/domain/servers/axeda68dev/log/server.log
        - /local/gstapps/development/jboss/domain/servers/axeda68dev/log/customobjects.log
      input_type: log
      exclude_lines: ["^$"]
      multiline:
        pattern: '^[[:space:]]+|^Caused by:'
        negate: false
        match: after
      close_older: 15m
output:
  ### Elasticsearch as output
  elasticsearch:
    hosts: ["3.28.180.76:9200"]
    index: "filebeat-jboss-dev"

A sample from the server.log file is, where the message at 15:20 is tranferred but the message at 15:22 is not.

15:20:30,233 ERROR [com.axeda.drm.config.validation.AbstractCacheClusterValidator] (EHCACHE ClusterValidator Thread) Found cache key 3.20.244.80-e555b44:157c4a58579:-8000:3.20.244.82--8bae67c:157c4a880e3:-8000 when it should have been deleted (invalidated) for validatorType=EHCACHE nodeId='3.20.244.80-e555b44:157c4a58579:-8000'
15:22:47,141 ERROR [com.axeda.drm.services.eventsubscription.AMQServer] (ESS-Periodic-Reaper-%d thread-1) Error acquiring MBean server connection, username: GEHC, password: gehcManager, jmxUri: service:jmx:rmi:///jndi/rmi://usmkersvpvmd2l.am.health.ge.com:3099/jmxrmi,service:jmx:rmi:///jndi/rmi://usmkersvpvmd3l.am.health.ge.com:3099/jmxrmi,service:jmx:rmi:///jndi/rmi://usmkersvpvmd4l.am.health.ge.com:3099/jmxrmi: java.io.IOException: Failed to retrieve RMIServer stub: javax.naming.NameNotFoundException: jmxrmi,service:jmx:rmi:///jndi/rmi://usmkersvpvmd3l.am.health.ge.com:3099/jmxrmi,service:jmx:rmi:///jndi/rmi://usmkersvpvmd4l.am.health.ge.com:3099/jmxrmi
    at javax.management.remote.rmi.RMIConnector.connect(RMIConnector.java:369) [rt.jar:1.7.0_75]
    at javax.management.remote.rmi.RMIConnector.connect(RMIConnector.java:249) [rt.jar:1.7.0_75]
    at com.axeda.drm.services.eventsubscription.AMQServer.getMBeanServerConnection(AMQServer.java:164)
    at com.axeda.drm.services.eventsubscription.AMQHelper.getBrokerViewMbean(AMQHelper.java:98)
    at com.axeda.drm.services.eventsubscription.QueueManagerImpl.getSamePrefixQueues(QueueManagerImpl.java:222)
    at com.axeda.drm.services.eventsubscription.AMQConnectionMonitor.reapQueues(AMQConnectionMonitor.java:159)
    at com.axeda.drm.services.eventsubscription.PeriodicReaperRunnable.run(PeriodicReaperRunnable.java:50)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_75]
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304) [rt.jar:1.7.0_75]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178) [rt.jar:1.7.0_75]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [rt.jar:1.7.0_75]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_75]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_75]
    at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_75]
Caused by: javax.naming.NameNotFoundException: jmxrmi,service:jmx:rmi:///jndi/rmi://usmkersvpvmd3l.am.health.ge.com:3099/jmxrmi,service:jmx:rmi:///jndi/rmi://usmkersvpvmd4l.am.health.ge.com:3099/jmxrmi
    at com.sun.jndi.rmi.registry.RegistryContext.lookup(RegistryContext.java:116) [rt.jar:1.7.0_75]
    at com.sun.jndi.toolkit.url.GenericURLContext.lookup(GenericURLContext.java:203) [rt.jar:1.7.0_75]
    at javax.naming.InitialContext.lookup(InitialContext.java:411) [rt.jar:1.7.0_75]
    at javax.management.remote.rmi.RMIConnector.findRMIServerJNDI(RMIConnector.java:1929) [rt.jar:1.7.0_75]
    at javax.management.remote.rmi.RMIConnector.findRMIServer(RMIConnector.java:1896) [rt.jar:1.7.0_75]
    at javax.management.remote.rmi.RMIConnector.connect(RMIConnector.java:286) [rt.jar:1.7.0_75]
    ... 13 more

(Steffen Siering) #2

any message right after the message from 15:22 ? The event is still actively processed by the multiline filter. It can not detect multiline being over without seen the next log line starting with a timestamp. By default multiline filter has a timeout of 5 seconds. That is, latest on timeout or after timeout the event should be pushed.

P.S.: Please format logs and config files with </> button or three back-ticks to make your post more readable.


(Gary Keller) #3

Steffen,

Thanks for the reply and the tip on formatting the messages. Are you suggesting that I increase that value to more than the default of 5 seconds? There were several messages after the 15:22 message that are withing the 5 second time period.


(Steffen Siering) #4

the messages after the multiline one have been send? You have a more complete log for testing?


(Gary Keller) #5

Steffen,

Yes, I have a more complete log for testing. Can you direct me to documentation on how to send the file. When I tried to upload one before it complained about the file type.


(Gary Keller) #6

Steffen,

I have found the problem, but not the solution. The problem is in the line pattern: '^[[:space:]]+|^Caused by:'. When I remove the Caused by: following the pipe, it will add the "\n\tat " lines to the error message and will create a separate entry for the Caused by: entries.

I have tried several different options to add the additional pattern to the string, and even tried two separate pattern entries, but none of my attempts have worked. Any suggestions?


(Gary Keller) #7

Steffen,

I found the option of using Multiline as an array, so I tried that. The configuration I am using is

  multiline:
    patterns:
      -
        pattern: '^[[:space:]]+'
        negate: false
        match: after
      -
        pattern: '^Caused by:'
        negate: false
        match: after

But this is giving me the error of "ERR Stop Harvesting. Unexpected encoding line reader error: unknown matcher type:"

Is this not supported in Filebeat v 1,3?


(Steffen Siering) #8

The multi-pattern-multiline feature is not implemented in any beat. It has been discussed early on, but not being implemented. I think the implementation originally intended would not be usable the way you expect here, though.

The pattern works for me: https://play.golang.org/p/4DJ8Nlqvq4
But mileage might vary, as I copied logs from your post.

Here is a multiline test by some community member: https://github.com/hartfordfive/filebeat-multiline-tester

The Caused by: should be no problem. I wonder about when/how the next log line after a stack trace is printed. Sometimes buffering in application logger (not writing content to file) can block the multiline matcher.


(Gary Keller) #9

Steffen,

Here is the abbreviated log file that I am using in my local testing along with the yml file.

Gary D Keller
GE Healthcare, consultant

Office: 262-548-2470 (42470)
Cell: 262-497-6264


(Gary Keller) #10

Steffen,

I found my problem in the filebeat config. I was trying to bypass blank log file lines and it was causing it to discard the complete multiline message. I deleted the exclude_lines: ["^$"] statement and am now able to correctly record the multiline message in the elasticsearch index. I found this out by using the -d "*" option while running filebeat with my abbreviated test file.

Will have to experiment with how to bypass blank lines in my testing.

Thanks for all of your help.


(system) #11

This topic was automatically closed after 21 days. New replies are no longer allowed.