same event with two stamps

[prad18]

Hi,

sample.log

13 Aug 2013 11:28:30,414 [WebContainer : 6] ERROR - An Error has occured for com.framework.core.exception.MarshException: Your session has timed out.
13 Aug 2013 11:28:30,414 [WebContainer : 6] ERROR - handleException():com.framework.core.exception.MarshException: Your session has timed out.
at com.csa.serviceagreement.CSAAbstractStrutsAction.prepareUserContext(CSAAbstractStrutsAction.java(Compiled Code))
at com.csa.serviceagreement.CSAAbstractStrutsAction.preexecute(CSAAbstractStrutsAction.java(Compiled Code))
at com.csa.serviceagreement.CSAAbstractStrutsAction.execute(CSAAbstractStrutsAction.java(Compiled Code))
at org.apache.struts.action.RequestProcessor.processActionPerform(RequestProcessor.java(Inlined Compiled Code))
at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java(Compiled Code))
at org.apache.struts.action.ActionServlet.process(ActionServlet.java(Inlined Compiled Code))
at org.apache.struts.action.ActionServlet.doPost(ActionServlet.java(Compiled Code))
at javax.servlet.http.HttpServlet.service(HttpServlet.java(Compiled Code))
at javax.servlet.http.HttpServlet.service(HttpServlet.java(Compiled Code))
at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java(Compiled Code))

You can see the above two entries of log have same stamps both are one event. After loading these in splunk they're now two separate events.

1. How can make them as one event in splunk? is it possible after loading(I mean considering them as one while searching)?
2. Or is there way to make one event out of these two log entries while loading them in splunk?(I mean any particular configuration)I'm manually loading the logs in splunk.

Pradi

[kristian_kolb · Accepted solution]

Hi there, I honestly think that you have two separate log messages, both relating to the same event (with the meaning of 'something happening'). Looking at this particular sample of log, the first message is pretty much useless, as all information is also provided in the second message.

Without any specific configuration, Splunk will break a log file into separate messages wherever it finds a timestamp. This is generally A Good Thing. Best option for you is probably to try to get this to work for you.

Second best; if you really want to, you can maybe find a regex pattern to break the log file between "Compiled code))" and the timestamp on the following line. However, if this is going to work for you, is very much dependent on how the messages look. If your patterns vary a lot, the regex will be messy and inefficient.

Have you looked at the props.conf configuration options? Something like this might work;

[your sourcetype]
SHOULD_LINEMERGE = false
LINE_BREAKER = (?:Compiled Code\)\))([\r\n]+)(?:\d\d\s[A-Za-z]{3}\s\d{4})

See the docs for more on LINE BREAKING;

http://docs.splunk.com/Documentation/Splunk/latest/Admin/Propsconf

Third best; For a search time 'merging' of the two events, you could try transaction, but this can lead to rather flawed results, since there is no transactionID, sessionID or similar to tie the messages together, there is just _time. Being more specific in the selection of events minimizes the risk getting strange results. Try this out;

index=XXX source=YYY sourcetype=ZZZ host=QQQ | transaction _time

http://docs.splunk.com/Documentation/Splunk/latest/SearchReference/Transaction

Hope this helps,

K

[kristian_kolb]

FYI: The default behaviour is to break when it finds a timestamp. You may need to change this sometimes, e.g. when a multi-line event has the timestamp on line 3.

[prad18]

so wherever splunk finds timestamp, it'll break them as separate events.
I don't think the second options of props.conf will work properly because log messages will be different.
I tried the last transaction option the way you mentioned and it is combining those two events with same timestamps.
Thank you kristian

[chimbudp]

Have you tried to parse the log with Timestamp with nanoseconds ? where there might be difference in nano seconds in creating logs also..

strftime(_time, "%d/%m/%Y %I:%M:%S %p")