Getting Data In

Merge Multiline Java Stack trace via syslog

Explorer

I'm having a heck of a time figuring out the best way to get splunk to show these multiline events in one event. Any help would be appreciated.

Each event is broken up by the line that looks like this:

2011-03-22 18:43:58 -04:00 info critical_en8.web: 22 Mar 2011 18:43:58,906 [ERROR] [crm] [Misc] misc

OR

2011-03-22 18:44:00 -04:00 info critical_en8.web: 22 Mar 2011 18:44:00,061 [ERROR] [crm] [Misc] misc

Example log:

2011-03-22 18:43:58 -04:00 info critical_en8.web: 22 Mar 2011 18:43:58,906 [ERROR] [crm] [Misc] misc
2011-03-22 18:43:58 -04:00 info critical_en8.web: [ERROR] [crm] javax.servlet.ServletException: 
com.infusion.util.db.LoadingException: Couldn't find the record with primary key 0 in Contact
2011-03-22 18:43:58 -04:00 info critical_en8.web: [ERROR] [crm]         at org.apache.jasper.runtime.PageContextImpl.doHandlePageException(PageContextImpl.java:862)
2011-03-22 18:43:58 -04:00 info critical_en8.web: [ERROR] [crm]         at org.apache.jasper.runtime.PageContextImpl.handlePageException(PageContextImpl.java:791)
2011-03-22 18:43:58 -04:00 info critical_en8.web: [ERROR] [crm]         at org.apache.jsp.Contact.tab.address_jsp._jspService(address_jsp.java:130)
2011-03-22 18:43:58 -04:00 info critical_en8.web: [ERROR] [crm]         at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
2011-03-22 18:43:58 -04:00 info critical_en8.web: [ERROR] [crm]         at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
2011-03-22 18:43:58 -04:00 info critical_en8.web: [ERROR] [crm]         at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:377)
2011-03-22 18:43:58 -04:00 info critical_en8.web: [ERROR] [crm]         at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:313)
2011-03-22 18:43:58 -04:00 info critical_en8.web: [ERROR] [crm] Caused by: com.infusion.util.db.LoadingException: Couldn't find the record with primary key 0 in Contact
2011-03-22 18:43:58 -04:00 info critical_en8.web: [ERROR] [crm]         at com.infusion.crm.db.DatabaseObject.loadFromDatabase(DatabaseObject.java:1700)
2011-03-22 18:43:58 -04:00 info critical_en8.web: [ERROR] [crm]         at com.infusion.crm.db.DatabaseObject.loadFromDatabase(DatabaseObject.java:1675)
2011-03-22 18:44:00 -04:00 info critical_en8.web: 22 Mar 2011 18:44:00,061 [ERROR] [crm] [Misc] misc
2011-03-22 18:44:00 -04:00 info critical_en8.web: [ERROR] [crm] javax.servlet.ServletException: com.infusion.util.db.LoadingException: No primary key defined to load Contact
2011-03-22 18:44:00 -04:00 info critical_en8.web: [ERROR] [crm]         at org.apache.jasper.runtime.PageContextImpl.doHandlePageException(PageContextImpl.java:862)
2011-03-22 18:44:00 -04:00 info critical_en8.web: [ERROR] [crm]         at org.apache.jasper.runtime.PageContextImpl.handlePageException(PageContextImpl.java:791)
2011-03-22 18:44:00 -04:00 info critical_en8.web: [ERROR] [crm]         at org.apache.jsp.Contact.tab.filebox_jsp._jspService(filebox_jsp.java:281)
2011-03-22 18:44:00 -04:00 info critical_en8.web: [ERROR] [crm]         at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
2011-03-22 18:44:00 -04:00 info critical_en8.web: [ERROR] [crm]         at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
2011-03-22 18:44:00 -04:00 info critical_en8.web: [ERROR] [crm]         at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:377)
2011-03-22 18:44:00 -04:00 info critical_en8.web: [ERROR] [crm]         at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:313)
Tags (1)

Splunk Employee
Splunk Employee

I would simply use:

[java_over_syslog]
SHOULD_LINEMERGE = false
TRUNCATE = 9999999
LINE_BREAKER = ([\r\n]+)(?=(\S+\s*){5}\:\d{1,2}\s+\w\s+\d{4}\s+\d{1,2}:\d{2}:\d{2},\d{4}\D)
TIME_PREFIX = ^(\S+\s*){5}\:\s+
TIME_FORMAT = %d %b %Y %H:%M:%S,%3N

Which pretty much means, "break when you see the next line has the base syslog headers (which are 5 "words") followed by something that looks like the Java timestamp".

This is what I'd do with non-syslog Java as well, except that you have to account for the forced syslog timestamp before the java timestamp. I've taken the liberty of setting the time via the Java timestamp, since it is more likely to be correct and it has milliseconds.

Explorer

Actually this might be ok. Splunk is combining separate events into one but they are the same error just happening in succession. It does seem to be splitting everything else. Thanks for the help!

0 Karma

Explorer

This did not:
2011-03-24 13:12:52 -04:00 info critical_ft3both.web: 24 Mar 2011 13:12:52,854 [ERROR] [valueone] [Database] database
2011-03-24 13:12:52 -04:00 info critical_ft3both.web: [ERROR] [valueone] com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Unknown database 'valueone'
2011-03-24 13:12:52 -04:00 info critical_ft3both.web: 24 Mar 2011 13:12:52,855 [ERROR] [valueone] [Database] database
2011-03-24 13:12:52 -04:00 info critical_ft3both.web: [ERROR] [valueone] at com.infusion.databridge.DatabridgeConnectionImpl.prepareForRetry(DatabridgeConnectionImpl.java:726)

0 Karma

Explorer

This worked:
2011-03-24 13:12:54 -04:00 info critical_mn31.web: 24 Mar 2011 13:12:54,904 [ERROR] [iu] [User] Could not load user with Id: 2
2011-03-24 13:12:54 -04:00 info critical_mn31.web:Caused by: java.lang.Exception: Couldn't find the record with primary key 2 in User
2011-03-24 13:12:54 -04:00 info critical_mn31.web: [ERROR] [iu] at com.infusion.crm.db.DatabaseObject.loadFromDatabase(DatabaseObject.java:1697)
2011-03-24 13:12:54 -04:00 info critical_mn31.web: [ERROR] [iu] ... 64 more

0 Karma

Explorer

This seems to get close. However, now it's combining some events into one that should not.

0 Karma

Splunk Employee
Splunk Employee

Although what I'd really use is a Splunk forwarder instead of syslog. In addition to the advantages dwaddle cites, you will also be able to tell apart different files using a forwarder, which isn't that easy with syslog, since everything gets merged into a single stream and may even have multiple files interleaved.

SplunkTrust
SplunkTrust

My first thought is "can you use a forwarder instead of syslog?"

You may be able to get syslog to work, but Splunk has a default setting in props.conf of "BREAK_ONLY_BEFORE_DATE=true". Meaning that, on most inputs, the datestamp on each line will make it treat each line as a new event and not merge them.

You can reconfigure to avoid this, but it may be easier in the long run to configure a forwarder reading this log file directly. Forwarders also have an advantage over syslog-via-UDP in that TCP is more reliable in the event of packet loss.

Don’t Miss Global Splunk
User Groups Week!

Free LIVE events worldwide 2/8-2/12
Connect, learn, and collect rad prizes
and swag!