Unable to get the parse value out of multi-line logs in logstash
Asked Answered
P

1

0

I am using Logstash to output JSON message to an API. On Simple Log lines, my grok pattern and configurations are working absolutely fine, But I am unable to get the values dynamically out during exceptions and stacktraces.

Log File :

TID: [-1234] [] [2016-06-07 12:52:59,862]  INFO {org.apache.synapse.core.axis2.ProxyService} -  Successfully created the Axis2 service for Proxy service : TestServiceHttp {org.apache.synapse.core.axis2.ProxyService}
TID: [-1234] [] [2016-06-07 12:59:04,893]  INFO {org.apache.synapse.mediators.builtin.LogMediator} -  To: /services/TestServiceHttp.TestServiceHttpHttpSoap12Endpoint********* Sending Message to the Queue*****WSAction: urn:mediate********* Sending Message to the Queue*****SOAPAction: urn:mediate********* Sending Message to the Queue*****MessageID: urn:uuid:d1bbe24a-2ce3-497f-8224-d260b0632506********* Sending Message to the Queue*****Direction: request********* Sending Message to the Queue*****Envelope: <?xml version='1.0' encoding='utf-8'?><soapenv:Envelope xmlns:soapenv="http://www.w3.org/2003/05/soap-envelope"><soapenv:Body><name> Omer</name></soapenv:Body></soapenv:Envelope> {org.apache.synapse.mediators.builtin.LogMediator}
TID: [-1234] [] [2016-06-07 12:59:04,925]  INFO {org.apache.synapse.core.axis2.TimeoutHandler} -  This engine will expire all callbacks after : 120 seconds, irrespective of the timeout action, after the specified or optional timeout {org.apache.synapse.core.axis2.TimeoutHandler}
TID: [-1234] [] [2016-06-07 12:59:04,933] ERROR {org.apache.axis2.description.ClientUtils} -  The system cannot infer the transport information from the jms:/Customer.01.Request.Queue.01?transport.jms.ConnectionFactoryJNDIName=QueueConnectionFactory&java.naming.factory.initial=org.apache.activemq.jndi.ActiveMQInitialContextFactory&java.naming.provider.url=tcp://localhost:61616&transport.jms.DestinationType=queue URL. {org.apache.axis2.description.ClientUtils}
TID: [-1234] [] [2016-06-07 12:59:04,949] ERROR {org.apache.synapse.core.axis2.Axis2Sender} -  Unexpected error during sending message out {org.apache.synapse.core.axis2.Axis2Sender}
org.apache.axis2.AxisFault: The system cannot infer the transport information from the jms:/Customer.01.Request.Queue.01?transport.jms.ConnectionFactoryJNDIName=QueueConnectionFactory&java.naming.factory.initial=org.apache.activemq.jndi.ActiveMQInitialContextFactory&java.naming.provider.url=tcp://localhost:61616&transport.jms.DestinationType=queue URL.
    at org.apache.axis2.description.ClientUtils.inferOutTransport(ClientUtils.java:81)
    at org.apache.axis2.client.OperationClient.prepareMessageContext(OperationClient.java:288)
    at org.apache.axis2.description.OutOnlyAxisOperationClient.executeImpl(OutOnlyAxisOperation.java:249)
    at org.apache.axis2.client.OperationClient.execute(OperationClient.java:149)
    at org.apache.synapse.core.axis2.Axis2FlexibleMEPClient.send(Axis2FlexibleMEPClient.java:542)
    at org.apache.synapse.core.axis2.Axis2Sender.sendOn(Axis2Sender.java:79)
    at org.apache.synapse.core.axis2.Axis2SynapseEnvironment.send(Axis2SynapseEnvironment.java:461)
    at org.apache.synapse.endpoints.AbstractEndpoint.send(AbstractEndpoint.java:372)
    at org.apache.synapse.endpoints.AddressEndpoint.send(AddressEndpoint.java:65)
    at org.apache.synapse.mediators.builtin.CallMediator.handleNonBlockingCall(CallMediator.java:204)
    at org.apache.synapse.mediators.builtin.CallMediator.mediate(CallMediator.java:87)
    at org.apache.synapse.mediators.AbstractListMediator.mediate(AbstractListMediator.java:81)
    at org.apache.synapse.mediators.AbstractListMediator.mediate(AbstractListMediator.java:48)
    at org.apache.synapse.mediators.base.SequenceMediator.mediate(SequenceMediator.java:149)
    at org.apache.synapse.core.axis2.ProxyServiceMessageReceiver.receive(ProxyServiceMessageReceiver.java:185)
    at org.apache.axis2.engine.AxisEngine.receive(AxisEngine.java:180)
    at org.apache.synapse.transport.passthru.ServerWorker.processEntityEnclosingRequest(ServerWorker.java:395)
    at org.apache.synapse.transport.passthru.ServerWorker.run(ServerWorker.java:142)
    at org.apache.axis2.transport.base.threads.NativeWorkerPool$1.run(NativeWorkerPool.java:172)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
TID: [-1234] [] [2016-06-07 12:59:05,009]  INFO {org.apache.synapse.mediators.builtin.LogMediator} -  To: /services/TestServiceHttp.TestServiceHttpHttpSoap12Endpoint, WSAction: urn:mediate, SOAPAction: urn:mediate, MessageID: urn:uuid:d1bbe24a-2ce3-497f-8224-d260b0632506, Direction: request, MESSAGE = Executing default 'fault' sequence, ERROR_CODE = 0, ERROR_MESSAGE = Unexpected error during sending message out, Envelope: <?xml version='1.0' encoding='utf-8'?><soapenv:Envelope xmlns:soapenv="http://www.w3.org/2003/05/soap-envelope"><soapenv:Body><name> Omer</name></soapenv:Body></soapenv:Envelope> {org.apache.synapse.mediators.builtin.LogMediator}
TID: [-1234] [] [2016-06-07 13:00:04,890]  INFO {org.apache.axis2.transport.http.HTTPSender} -  Unable to sendViaPost to url[http://Omer-PC:8280/services/TestServiceHttp.TestServiceHttpHttpSoap12Endpoint] {org.apache.axis2.transport.http.HTTPSender}
java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
    at java.net.SocketInputStream.read(SocketInputStream.java:170)
    at java.net.SocketInputStream.read(SocketInputStream.java:141)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
    at org.apache.commons.httpclient.HttpParser.readRawLine(HttpParser.java:78)
    at org.apache.commons.httpclient.HttpParser.readLine(HttpParser.java:106)
    at org.apache.commons.httpclient.HttpConnection.readLine(HttpConnection.java:1116)
    at org.apache.commons.httpclient.MultiThreadedHttpConnectionManager$HttpConnectionAdapter.readLine(MultiThreadedHttpConnectionManager.java:1413)
    at org.apache.commons.httpclient.HttpMethodBase.readStatusLine(HttpMethodBase.java:1973)
    at org.apache.commons.httpclient.HttpMethodBase.readResponse(HttpMethodBase.java:1735)
    at org.apache.commons.httpclient.HttpMethodBase.execute(HttpMethodBase.java:1098)
    at org.apache.commons.httpclient.HttpMethodDirector.executeWithRetry(HttpMethodDirector.java:398)
    at org.apache.commons.httpclient.HttpMethodDirector.executeMethod(HttpMethodDirector.java:171)
    at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:397)
    at org.apache.axis2.transport.http.AbstractHTTPSender.executeMethod(AbstractHTTPSender.java:630)
    at org.apache.axis2.transport.http.HTTPSender.sendViaPost(HTTPSender.java:195)
    at org.apache.axis2.transport.http.HTTPSender.send(HTTPSender.java:77)
    at org.apache.axis2.transport.http.CommonsHTTPTransportSender.writeMessageWithCommons(CommonsHTTPTransportSender.java:451)
    at org.apache.axis2.transport.http.CommonsHTTPTransportSender.invoke(CommonsHTTPTransportSender.java:278)
    at org.apache.axis2.engine.AxisEngine.send(AxisEngine.java:442)
    at org.apache.axis2.description.OutInAxisOperationClient.send(OutInAxisOperation.java:430)
    at org.apache.axis2.description.OutInAxisOperationClient.executeImpl(OutInAxisOperation.java:225)
    at org.apache.axis2.client.OperationClient.execute(OperationClient.java:149)
    at org.apache.axis2.client.ServiceClient.sendReceive(ServiceClient.java:554)
    at org.apache.axis2.client.ServiceClient.sendReceive(ServiceClient.java:530)
    at org.apache.jsp.admin.jsp.WSRequestXSSproxy_005fajaxprocessor_jsp._jspService(WSRequestXSSproxy_005fajaxprocessor_jsp.java:294)
    at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
    at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:432)
    at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:395)
    at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:339)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
    at org.wso2.carbon.ui.JspServlet.service(JspServlet.java:155)
    at org.wso2.carbon.ui.TilesJspServlet.service(TilesJspServlet.java:80)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
    at org.eclipse.equinox.http.helper.ContextPathServletAdaptor.service(ContextPathServletAdaptor.java:37)
    at org.eclipse.equinox.http.servlet.internal.ServletRegistration.service(ServletRegistration.java:61)
    at org.eclipse.equinox.http.servlet.internal.ProxyServlet.processAlias(ProxyServlet.java:128)
    at org.eclipse.equinox.http.servlet.internal.ProxyServlet.service(ProxyServlet.java:68)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
    at org.wso2.carbon.tomcat.ext.servlet.DelegationServlet.service(DelegationServlet.java:68)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.wso2.carbon.tomcat.ext.filter.CharacterSetFilter.doFilter(CharacterSetFilter.java:61)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:504)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
    at org.wso2.carbon.tomcat.ext.valves.CompositeValve.continueInvocation(CompositeValve.java:99)
    at org.wso2.carbon.tomcat.ext.valves.TomcatValveContainer.invokeValves(TomcatValveContainer.java:49)
    at org.wso2.carbon.tomcat.ext.valves.CompositeValve.invoke(CompositeValve.java:62)
    at org.wso2.carbon.tomcat.ext.valves.CarbonStuckThreadDetectionValve.invoke(CarbonStuckThreadDetectionValve.java:159)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950)
    at org.wso2.carbon.tomcat.ext.valves.CarbonContextCreatorValve.invoke(CarbonContextCreatorValve.java:57)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:421)
    at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1074)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1739)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1698)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:745)
TID: [-1234] [] [2016-06-07 13:01:40,447]  INFO {org.wso2.carbon.core.init.CarbonServerManager} -  Shutdown hook triggered.... {org.wso2.carbon.core.init.CarbonServerManager}
TID: [-1234] [] [2016-06-07 13:01:40,464]  INFO {org.wso2.carbon.core.init.CarbonServerManager} -  Gracefully shutting down WSO2 Enterprise Service Bus... {org.wso2.carbon.core.init.CarbonServerManager}
TID: [-1234] [] [2016-06-07 13:01:40,477]  INFO {org.wso2.carbon.core.ServerManagement} -  Starting to switch to maintenance mode... {org.wso2.carbon.core.ServerManagement}
TID: [-1234] [] [2016-06-07 13:01:40,481]  INFO {org.apache.axis2.transport.jms.JMSListener} -  JMS Listener Shutdown {org.apache.axis2.transport.jms.JMSListener}

As you can see in the above logs, that some are successful log entries and some are exceptions. Following is my logstash configuration file:

Configuration File:

input {
 stdin {}

    file {
        path => "C:\WSO2Environment\wso2esb-4.9.0\repository\logs\wso2carbon.log" 
        type => "wso2"
        start_position => "beginning"
        codec => multiline {
        pattern => "TID:%{SPACE}|(^\s*at .+)|(^.+)"
        negate => true
        what => "previous"
    }

    }
}

filter {

    if [type] == "wso2" {
        grok {
            match => [ "message", "TID:%{SPACE}\[%{INT:SourceSystemId}\]%{SPACE}\[%{DATA:ProcessName}\]%{SPACE}\[%{TIMESTAMP_ISO8601:TimeStamp}\]%{SPACE}%{LOGLEVEL:MessageType}%{SPACE}{%{JAVACLASS:MessageTitle}}%{SPACE}-%{SPACE}%{GREEDYDATA:Message}" ]
            add_tag => [ "grokked" ]        
        }
        mutate {
          gsub => [
             "TimeStamp", "\s", "T",
             "TimeStamp", ",", "."
           ]
        }


    }
    if !( "_grokparsefailure" in [tags] ) {
        grok{
              match => [ "message", "%{GREEDYDATA:StackTrace}" ]
              add_tag => [ "grokked" ]  
        }
        date {
                match => [ "timestamp", "yyyy MMM dd HH:mm:ss:SSS" ]
                target => "TimeStamp"
                timezone => "UTC"
            }
    }

    if ( "multiline" in [tags] ) {
        grok {
            match => [ "message", "%{GREEDYDATA:StackTrace}" ]
            add_tag => [ "multiline" ]
            tag_on_failure => [ "multiline" ]       
        }
        date {
                match => [ "timestamp", "yyyy MMM dd HH:mm:ss:SSS" ]
                target => "TimeStamp"

            }
    }

}

output {
    stdout { }
     http {
        url => "http://localhost:8086/messages"
        http_method => "post"
        format => "json"
        mapping => ["TimeStamp","%{TimeStamp}","MessageType","%{MessageType}","MessageTitle","%{MessageTitle}","Message","%{log_EventMessage}","SourceSystemId","%{SourceSystemId}","StackTrace","%{log_StackTrace}"]

    }
}

Note: In case of single line log entries , this configuration is working fine, but In case of above mentioned exception and stack traces in the above log file, it is not working correctly.

Current Output in case of exception:

{
  "TimeStamp": "%{TimeStamp}",
  "MessageType": "%{MessageType}",
  "MessageTitle": "%{MessageTitle}",
  "Message": "%{Message}",
  "SourceSystemId": "%{SourceSystemId}",
  "StackTrace": "%{StackTrace}"

}

Expected Output in case of exception:

{
  "TimeStamp": "2001-12-31T12:00:00",
  "StackTrace": " java.net.SocketTimeoutException: Read timed out
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:170)"

}

Problem Statement:

I want to achieve three things.

  1. First I want that In case of exception all the log entries are sent into stack trace element.
  2. Second, I want that In case of exception, there is no TimeStamp generated in the log file, so I want to map the default "@timestamp" attribute to my TimeStamp field.
  3. Third , is it possible that In case of exception, only the "TimeStamp" and "StackTrace" field is sent towards my api.
Pauper answered 7/6, 2016 at 12:15 Comment(0)
Z
1

Are you sure about your multiline filter? It matches all the lines in your example and since you've got negate => true, no lines will be merged together.

Also you don't have any output format to do what you intend to do. You should add something like :

if ( "multiline" in [tags] ) { 
  http {
    url => "http://localhost:8086/messages"
    http_method => "post"
    format => "json"
    mapping => ["TimeStamp","%{TimeStamp}","StackTrace","%{StackTrace}"]
  }
}
Zeitgeist answered 7/6, 2016 at 15:25 Comment(2)
Thanks for your answer, I tried your way, but it is not allowing me to add two http tags in one configuration file, I can only add this in the output tag of the configuration.Pauper
The code sample in my answer has to be put in the output part of the configuration. It should work that way.Zeitgeist

© 2022 - 2024 — McMap. All rights reserved.