Multiline problem


#1

Hello Logstash community,

I have a problem with the multiline filter.

I have a multiline logfile which is very huge and which will be devided into two parts.

This is my multiline log: (just as info: please replace the "," with "|". This logfile is just a copy of a further version!

Error,10,MyMetroController,pvm0ec2b5r1ugwahun055mo3,de,,,Error getting session data for user WoytonGmbH,"System.ServiceModel.EndpointNotFoundException: There was no endpoint listening at http://id-pp.metrogroup-networking.com/ecommerce/myMetro/webService/ManageUserAccount.asmx that could accept the message. This is often caused by an incorrect address or SOAP action. See InnerException, if present, for more details. ---> System.Net.WebException: Unable to connect to the remote server ---> System.Net.Sockets.SocketException: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 10.16.207.143:80
   at System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
   at System.Net.Sockets.Socket.InternalConnect(EndPoint remoteEP)
   at System.Net.ServicePoint.ConnectSocketInternal(Boolean connectFailure, Socket s4, Socket s6, Socket& socket, IPAddress& address, ConnectSocketState state, IAsyncResult asyncResult, Exception& exception)
   --- End of inner exception stack trace ---
   at System.Net.HttpWebRequest.GetRequestStream(TransportContext& context)
   at System.Net.HttpWebRequest.GetRequestStream()
   at System.ServiceModel.Channels.HttpOutput.WebRequestHttpOutput.GetOutputStream()
   --- End of inner exception stack trace ---

Server stack trace: 
   at System.ServiceModel.Channels.HttpOutput.WebRequestHttpOutput.GetOutputStream()
   at System.ServiceModel.Channels.HttpOutput.Send(TimeSpan timeout)
   at System.ServiceModel.Channels.HttpChannelFactory`1.HttpRequestChannel.HttpChannelRequest.SendRequest(Message message, TimeSpan timeout)
   at System.ServiceModel.Channels.RequestChannel.Request(Message message, TimeSpan timeout)
   at System.ServiceModel.Dispatcher.RequestChannelBinder.Request(Message message, TimeSpan timeout)
  at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs)
   at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation)
   at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)

Exception rethrown at [0]: 
   at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
   at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
   at metrosystems.mcrm.data.DataProvider.Webservice.ManageUserAccount.ManageUserAccountSoap.getAccountByUPN(String UPN)
   at metrosystems.mcrm.data.DataProvider.Webservice.LDAPWebserviceDataProvider.GetAccountByUPN(String loginName) in d:\TeamCity\buildAgent\work\e9218e867e0db194\metrosystems.mcrm.data\DataProvider\Webservice\LDAPWebserviceDataProvider.cs:line 55
   at metrosystems.mcrm.data.Repository.LDAPRepository.GetCardholderByLogin(String loginName) in d:\TeamCity\buildAgent\work\e9218e867e0db194\metrosystems.mcrm.data\Repository\LDAPRepository.cs:line 80
   at metrosystems.mcrm.oo2.Controllers.MyMetroController.Login(LoginModel loginModel) in d:\TeamCity\buildAgent\work\e9218e867e0db194\metrosystems.mcrm.oo2\Controllers\MyMetroController.cs:line 213
System.Net.WebException: Unable to connect to the remote server ---> System.Net.Sockets.SocketException: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 10.16.207.143:80
   at System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
   at System.Net.Sockets.Socket.InternalConnect(EndPoint remoteEP)
   at System.Net.ServicePoint.ConnectSocketInternal(Boolean connectFailure, Socket s4, Socket s6, Socket& socket, IPAddress& address, ConnectSocketState state, IAsyncResult asyncResult, Exception& exception)
   --- End of inner exception stack trace ---
   at System.Net.HttpWebRequest.GetRequestStream(TransportContext& context)
   at System.Net.HttpWebRequest.GetRequestStream()
   at System.ServiceModel.Channels.HttpOutput.WebRequestHttpOutput.GetOutputStream()
System.Net.Sockets.SocketException (0x80004005): A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 10.16.207.143:80
   at System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
   at System.Net.Sockets.Socket.InternalConnect(EndPoint remoteEP)
   at System.Net.ServicePoint.ConnectSocketInternal(Boolean connectFailure, Socket s4, Socket s6, Socket& socket, IPAddress& address, ConnectSocketState state, IAsyncResult asyncResult, Exception& exception)",MyMetroController,LogEntry

So what happen when this multiline will be parse.

The logfile entry will be cut in to parts:

First part 1:

Error,10,MyMetroController,pvm0ec2b5r1ugwahun055mo3,de,,,Error getting session data for user WoytonGmbH,"System.ServiceModel.EndpointNotFoundException: There was no endpoint listening at http://id-pp.metrogroup-networking.com/ecommerce/myMetro/webService/ManageUserAccount.asmx that could accept the message. This is often caused by an incorrect address or SOAP action. See InnerException, if present, for more details. ---> System.Net.WebException: Unable to connect to the remote server ---> System.Net.Sockets.SocketException: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 10.16.207.143:80
   at System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
   at System.Net.Sockets.Socket.InternalConnect(EndPoint remoteEP)
   at System.Net.ServicePoint.ConnectSocketInternal(Boolean connectFailure, Socket s4, Socket s6, Socket& socket, IPAddress& address, ConnectSocketState state, IAsyncResult asyncResult, Exception& exception)
   --- End of inner exception stack trace ---
   at System.Net.HttpWebRequest.GetRequestStream(TransportContext& context)
   at System.Net.HttpWebRequest.GetRequestStream()
   at System.ServiceModel.Channels.HttpOutput.WebRequestHttpOutput.GetOutputStream()
   --- End of inner exception stack trace ---

Server stack trace: 
   at System.ServiceModel.Channels.HttpOutput.WebRequestHttpOutput.GetOutputStream()
   at System.ServiceModel.Channels.HttpOutput.Send(TimeSpan timeout)
   at System.ServiceModel.Channels.HttpChannelFactory`1.HttpRequestChannel.HttpChannelRequest.SendRequest(Message message, TimeSpan timeout)
   at System.ServiceModel.Channels.RequestChannel.Request(Message message, TimeSpan timeout)
   at System.ServiceModel.Dispatcher.RequestChannelBinder.Request(Message message, TimeSpan timeout)
  at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs)
   at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation)
   at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)

And the second part appear only when a new line will be written to the logfile appended to the new logfile entry. The Part For example:

<187>Jul 24 09:41:49 FFM30WEBZST0031 DEVTEST2-OO-Logs: Error|19|metrosystems.mcrm.oo2.Controllers.ErrorController||de|||User was redirected to Maintenance Page!||ErrorController|LogEntry
Exception rethrown at [0]: 
   at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
   at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
   at metrosystems.mcrm.data.DataProvider.Webservice.ManageUserAccount.ManageUserAccountSoap.getAccountByUPN(String UPN)
   at metrosystems.mcrm.data.DataProvider.Webservice.LDAPWebserviceDataProvider.GetAccountByUPN(String loginName) in d:\TeamCity\buildAgent\work\e9218e867e0db194\metrosystems.mcrm.data\DataProvider\Webservice\LDAPWebserviceDataProvider.cs:line 55
   at metrosystems.mcrm.data.Repository.LDAPRepository.GetCardholderByLogin(String loginName) in d:\TeamCity\buildAgent\work\e9218e867e0db194\metrosystems.mcrm.data\Repository\LDAPRepository.cs:line 80
   at metrosystems.mcrm.oo2.Controllers.MyMetroController.Login(LoginModel loginModel) in d:\TeamCity\buildAgent\work\e9218e867e0db194\metrosystems.mcrm.oo2\Controllers\MyMetroController.cs:line 213
System.Net.WebException: Unable to connect to the remote server ---> System.Net.Sockets.SocketException: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 10.16.207.143:80
   at System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
   at System.Net.Sockets.Socket.InternalConnect(EndPoint remoteEP)
   at System.Net.ServicePoint.ConnectSocketInternal(Boolean connectFailure, Socket s4, Socket s6, Socket& socket, IPAddress& address, ConnectSocketState state, IAsyncResult asyncResult, Exception& exception)
   --- End of inner exception stack trace ---
   at System.Net.HttpWebRequest.GetRequestStream(TransportContext& context)
   at System.Net.HttpWebRequest.GetRequestStream()
   at System.ServiceModel.Channels.HttpOutput.WebRequestHttpOutput.GetOutputStream()
System.Net.Sockets.SocketException (0x80004005): A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 10.16.207.143:80
   at System.Net.ServicePoint.ConnectSocketInternal(Boolean connectFailure, Socket s4, Socket s6, Socket& socket, IPAddress& address, ConnectSocketState state, IAsyncResult asyncResult, Exception& exception)"|MyMetroController|LogEntry

As you can see the new line look like:

<187>Jul 24 09:41:49 FFM30WEBZST0031 DEVTEST2-OO-Logs: Error|19|metrosystems.mcrm.oo2.Controllers.ErrorController||de|||User was redirected to Maintenance Page!||ErrorController|LogEntry

The other part normaly belongs to the logmessage before.

Why this happens and how can I fix it? Does anybody had this issue, too?

Greetz,
ABecker


Yet another multiline plea for help please
#2

Is there a limit how long an logfile entry can be?

Maybe also for the grok filter?


#3

just an additional information. My filter look like:

filter {
        if [type] == "online_ordering" {
                multiline {
                        stream_identity => "%{@source}.%{@type}"
                        pattern => "^<%{BASE10NUM}>"
                        what => "previous"
                        negate => true
                }

                if "_grokparsefailure" not in [tags] {
                        grok {
                                match => [ "message", "<%{BASE10NUM}>%{MONTH:month}%{SPACE}%{MONTHDAY:day}%{SPACE}%{TIME:time}%{SPACE}%{HOSTNAME:server}%{SPACE}%{DATA:logfile}:%{SPACE}%{GREEDYDATA:mesag}" ]
                                remove_field => [ "host" ]
                        }
                        csv {
                                columns => ["level","severity", "logger", "aspnet-sessionid", "organisation", "correlationState", "user", "msg", "exception", "method", "messageType"]
                                separator => "|"
                                source => "mesag"
                                remove_field => [ "severity" ]
                        }
                }
        }
}

(Asaf Yigal) #4

Can you please explain the problem further?

The multi-line works in a way that it collects all the lines given the condition you have. So it will always wait at the end of the last log message for the new log message so it can know that the previous one ended - hope that makes sense.

-- Asaf.


#5

Hello asafyigal,

thank you for your hints. I were able to solve this problem.

I have changed the input configuration. Not it looks like:

input {
        tcp {
                type => "online_ordering"
                port => 5547
                codec =>  multiline {
                                pattern => "^<%{BASE10NUM}>"
                                what => "previous"
                                negate => true
                }
        }
}

Now the whole multiline log will be stored within message. But an other error appeared.

When multiline logs will be received this match does not work correctly.

                        grok {
                                match => [ "message", "<%{BASE10NUM}>%{MONTH:month}%{SPACE}%{MONTHDAY:day}%{SPACE}%{TIME:time}%{SPACE}%{HOSTNAME:server}%{SPACE}%{DATA:logfile}:%{SPACE}%{GREEDYDATA:mesag}" ]
                                remove_field => [ "host" ]
                        }

The last match for GREEDYDATA:mesag only captures till the first line end and not till the end of the message. Does somebody have an idea why this happen?

I will post an example of what I mean:

origin message:

<187>Jul 27 15:14:16 FFM30WEBZST0031 DEVTEST2-OO-Logs: Error|7|MyMetroController|bberzpqvbyvkj4rshfygqb1z|de|||Error getting session data for user WoytonGmbH|"System.ServiceModel.EndpointNotFoundException: There was no endpoint listening at http://id-pp.metrogroup-networking.com/ecommerce/myMetro/webService/ManageUserAccount.asmx that could accept the message. This is often caused by an incorrect address or SOAP action. See InnerException, if present, for more details. ---> System.Net.WebException: Unable to connect to the remote server ---> System.Net.Sockets.SocketException: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 10.16.207.143:80
   at System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
   at System.Net.Sockets.Socket.InternalConnect(EndPoint remoteEP)
   at System.Net.ServicePoint.ConnectSocketInternal(Boolean connectFailure, Socket s4, Socket s6, Socket& socket, IPAddress& address, ConnectSocketState state, IAsyncResult asyncResult, Exception& exception)
   --- End of inner exception stack trace ---
   at System.Net.HttpWebRequest.GetRequestStream(TransportContext& context)
   at System.Net.HttpWebRequest.GetRequestStream()
   at System.ServiceModel.Channels.HttpOutput.WebRequestHttpOutput.GetOutputStream()
   --- End of inner exception stack trace ---

Server stack trace: 
   at System.ServiceModel.Channels.HttpOutput.WebRequestHttpOutput.GetOutputStream()
   at System.ServiceModel.Channels.HttpOutput.Send(TimeSpan timeout)
   at System.ServiceModel.Channels.HttpChannelFactory`1.HttpRequestChannel.HttpChannelRequest.SendRequest(Message message, TimeSpan timeout)
   at System.ServiceModel.Channels.RequestChannel.Request(Message message, TimeSpan timeout)
   at System.ServiceModel.Dispatcher.RequestChannelBinder.Request(Message message, TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs)
   at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation)
   at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)

Exception rethrown at [0]: 
   at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
   at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
   at metrosystems.mcrm.data.DataProvider.Webservice.ManageUserAccount.ManageUserAccountSoap.getAccountByUPN(String UPN)
   at metrosystems.mcrm.data.DataProvider.Webservice.LDAPWebserviceDataProvider.GetAccountByUPN(String loginName) in d:\TeamCity\buildAgent\work\e9218e867e0db194\metrosystems.mcrm.data\DataProvider\Webservice\LDAPWebserviceDataProvider.cs:line 55
   at metrosystems.mcrm.data.Repository.LDAPRepository.GetCardholderByLogin(String loginName) in d:\TeamCity\buildAgent\work\e9218e867e0db194\metrosystems.mcrm.data\Repository\LDAPRepository.cs:line 80
   at metrosystems.mcrm.oo2.Controllers.MyMetroController.Login(LoginModel loginModel) in d:\TeamCity\buildAgent\work\e9218e867e0db194\metrosystems.mcrm.oo2\Controllers\MyMetroController.cs:line 213
System.Net.WebException: Unable to connect to the remote server ---> System.Net.Sockets.SocketException: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 10.16.207.143:80
   at System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
   at System.Net.Sockets.Socket.InternalConnect(EndPoint remoteEP)
   at System.Net.ServicePoint.ConnectSocketInternal(Boolean connectFailure, Socket s4, Socket s6, Socket& socket, IPAddress& address, ConnectSocketState state, IAsyncResult asyncResult, Exception& exception)
   --- End of inner exception stack trace ---
   at System.Net.HttpWebRequest.GetRequestStream(TransportContext& context)
   at System.Net.HttpWebRequest.GetRequestStream()
   at System.ServiceModel.Channels.HttpOutput.WebRequestHttpOutput.GetOutputStream()
System.Net.Sockets.SocketException (0x80004005): A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 10.16.207.143:80
   at System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
   at System.Net.Sockets.Socket.InternalConnect(EndPoint remoteEP)
   at System.Net.ServicePoint.ConnectSocketInternal(Boolean connectFailure, Socket s4, Socket s6, Socket& socket, IPAddress& address, ConnectSocketState state, IAsyncResult asyncResult, Exception& exception)"|MyMetroController|LogEntry

out of message the GREEDYDATA part mesag:

Error|7|MyMetroController|bberzpqvbyvkj4rshfygqb1z|de|||Error getting session data for user WoytonGmbH|"System.ServiceModel.EndpointNotFoundException: There was no endpoint listening at http://id-pp.metrogroup-networking.com/ecommerce/myMetro/webService/ManageUserAccount.asmx that could accept the message. This is often caused by an incorrect address or SOAP action. See InnerException, if present, for more details. ---> System.Net.WebException: Unable to connect to the remote server ---> System.Net.Sockets.SocketException: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 10.16.207.143:80

This is really strange for me why this happen.


#6

Hello,

the problem is solved now.

No further help is needed. Thanks!

Greetings,

ABecker


(system) #7