Sharepoint ULS multiline entries

Blu3 · July 13, 2017, 9:39am

Hi

I'm trying to configure Logstash to merge multiline messages into one, but I think this is a little different case than described on https://www.elastic.co/guide/en/logstash/current/multiline.html#_timestamps

SharePoint logs multilines by adding asterisk character after timestamp, duplicating all columns other than message and adding three-dots to the end of first part and at the beginning of second part.
Here are two lines of 1 log entry:

07/13/2017 01:29:18.58 	OWSTIMER.EXE (0x2310)                   	0x1F8C	SharePoint Server Search      	Administration                	agwvm	Medium  	Synchronizing Search Topology for application 'Search Service Application' with active topology 'TopologyId: 3a8f6c3e-745f-49fc-bbbc-7d1d07eefbf2, CreationDate: 5/5/2017 6:44:00 PM, State: Active, Components: ContentProcessingComponent[ContentProcessingComponent1, 7e671ea7-11fe-4aa7-bf6f-36f90a6e2618] part of 3a8f6c3e-745f-49fc-bbbc-7d1d07eefbf2 on SP15DEV19, AnalyticsProcessingComponent[AnalyticsProcessingComponent1, 5e6820a0-5639-4d00-a63d-4ce295f5294d] part of 3a8f6c3e-745f-49fc-bbbc-7d1d07eefbf2 on SP15DEV19, QueryProcessingComponent[QueryProcessingComponent1, 4ddb77c0-7180-492a-8b3c-7dc424f410d4] part of 3a8f6c3e-745f-49fc-bbbc-7d1d07eefbf2 on SP15DEV19, CrawlComponent[CrawlComponent0, bf7d5277-b5bb-4496-b41b-c1f364afaede] part of 3a8f6c3e-745f-49fc-bbbc-7d1d07eefbf2 on SP15DEV19, Adm...	ddd3049e-d9f4-9060-4fc5-d4caea0eea4d
07/13/2017 01:29:18.58*	OWSTIMER.EXE (0x2310)                   	0x1F8C	SharePoint Server Search      	Administration                	agwvm	Medium  	...inComponent[AdminComponent1, 04604950-5e55-46c2-943f-d06dabbfa844] part of 3a8f6c3e-745f-49fc-bbbc-7d1d07eefbf2 on SP15DEV19, IndexComponent[IndexComponent1, 5153351b-c072-45a2-92f5-dbda5c861523] part of 3a8f6c3e-745f-49fc-bbbc-7d1d07eefbf2 on SP15DEV19'	ddd3049e-d9f4-9060-4fc5-d4caea0eea4d

Do you have any idea how to merge second message with asterisk into previous one and get rid of three dots?

guyboertje · July 21, 2017, 8:59am

You can still use that example with the pattern "^%{mm/dd/yyyy hh:MM:ss.SS} " (two spaces at the end) because the second line does not have two spaces.

Then your (very long) line will look like:
07/13/2017 01:29:18.58 OWSTIMER.EXE (0x2310) 0x1F8C SharePoint Server Search Administration agwvm Medium Synchronizing Search Topology for application 'Search Service Application' with active topology 'TopologyId: 3a8f6c3e-745f-49fc-bbbc-7d1d07eefbf2, CreationDate: 5/5/2017 6:44:00 PM, State: Active, Components: ContentProcessingComponent[ContentProcessingComponent1, 7e671ea7-11fe-4aa7-bf6f-36f90a6e2618] part of 3a8f6c3e-745f-49fc-bbbc-7d1d07eefbf2 on SP15DEV19, AnalyticsProcessingComponent[AnalyticsProcessingComponent1, 5e6820a0-5639-4d00-a63d-4ce295f5294d] part of 3a8f6c3e-745f-49fc-bbbc-7d1d07eefbf2 on SP15DEV19, QueryProcessingComponent[QueryProcessingComponent1, 4ddb77c0-7180-492a-8b3c-7dc424f410d4] part of 3a8f6c3e-745f-49fc-bbbc-7d1d07eefbf2 on SP15DEV19, CrawlComponent[CrawlComponent0, bf7d5277-b5bb-4496-b41b-c1f364afaede] part of 3a8f6c3e-745f-49fc-bbbc-7d1d07eefbf2 on SP15DEV19, Adm... ddd3049e-d9f4-9060-4fc5-d4caea0eea4d\n07/13/2017 01:29:18.58* OWSTIMER.EXE (0x2310) 0x1F8C SharePoint Server Search Administration agwvm Medium ...inComponent[AdminComponent1, 04604950-5e55-46c2-943f-d06dabbfa844] part of 3a8f6c3e-745f-49fc-bbbc-7d1d07eefbf2 on SP15DEV19, IndexComponent[IndexComponent1, 5153351b-c072-45a2-92f5-dbda5c861523] part of 3a8f6c3e-745f-49fc-bbbc-7d1d07eefbf2 on SP15DEV19' ddd3049e-d9f4-9060-4fc5-d4caea0eea4d

You can use the gsub feature of the mutate filter to remove everything from the newline to the triple dots.

filter {
  mutate {
    gsub => [
      "message", "\\n.+\.\.\.", ""
    ]
  }
}

Blu3 · July 21, 2017, 11:12am

Hi guyboertje

Thanks for the reply. I've tried to use your pattern but it gave me an error "pattern %{mm/dd/yyyy hh:MM:ss.SS} not defined". So I replaced it with pattern => "^%{DATESTAMP} " (with one space) and now it merges log files with asterisk.

Is there any way to remove duplicated timestamp, process and columns other than message from merged entry to have one long message?

System.UnauthorizedAccessException: Access is denied. (Exception from HRESULT: 0x80070005 (E_ACCESSDENIED)), StackTrace:    at Microsoft.SharePoint.SPUserCollection.InitUsersCore(Boolean fCustomUsers, String[] strIdentifiers, SPUserCollectionFlags ucf)     at Microsoft.SharePoint.SPBaseCollection.GetEnumerator()     at Microsoft.SharePoint.Client.ServerStub.<EnumerateChildItems>d__36.MoveNext()     at Microsoft.SharePoint.Client.ServerStub.WriteAsFeed(Object value, ODataWriter writer, RESTfulQuery query, ProxyContext proxyContext)     at Microsoft.SharePoint.Client.ServerStub.Write(Object value, Uri path, ODataWriter writer, RESTfulQuery query, ProxyContext proxyContext)     at Microsoft.SharePoint.Client.Rest.RestRequestProcessor.Process()     at Microsoft.SharePoint.Client.Rest.RestReque...	fa6c079e-923c-505f-b54c-8f05b04cd766
07/21/2017 03:12:56.93*	w3wp.exe (0x1864)                       	0x2CF4	SharePoint Foundation         	General                       	ai1wu	Medium  	...stProcessor.ProcessRequest()     at Microsoft.SharePoint.Client.Rest.RestService.ProcessQuery(Stream inputStream, IList`1 pendingDisposableContainer)     at Microsoft.SharePoint.Client.ClientRequestService.ProcessRestQuery(Stream inputStream)     at SyncInvokeProcessRestQuery(Object , Object[] , Object[] )     at System.ServiceModel.Dispatcher.SyncMethodInvoker.Invoke(Object instance, Object[] inputs, Object[]& outputs)     at System.ServiceModel.Dispatcher.DispatchOperationRuntime.InvokeBegin(MessageRpc& rpc)     at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage5(MessageRpc& rpc)     at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage31(MessageRpc& rpc)     at System.ServiceModel.Dispatcher.MessageRpc.Process(Boolean isOperationContextSet)    ...	fa6c079e-923c-505f-b54c-8f05b04cd766
07/21/2017 03:12:56.93*	w3wp.exe (0x1864)                       	0x2CF4	SharePoint Foundation         	General                       	ai1wu	Medium  	... at System.ServiceModel.Dispatcher.ChannelHandler.DispatchAndReleasePump(RequestContext request, Boolean cleanThread, OperationContext currentOperationContext)     at System.ServiceModel.Dispatcher.ChannelHandler.HandleRequest(RequestContext request, OperationContext currentOperationContext)     at System.ServiceModel.Dispatcher.ChannelHandler.AsyncMessagePump(IAsyncResult result)     at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)     at System.Runtime.AsyncResult.Complete(Boolean completedSynchronously)     at System.Runtime.InputQueue`1.AsyncQueueReader.Set(Item item)     at System.Runtime.InputQueue`1.EnqueueAndDispatch(Item item, Boolean canDispatchOnThisThread)     at System.Runtime.InputQueue`1.EnqueueAndDispatch(T item, Action dequeuedCallback, Boolean ...	fa6c079e-923c-505f-b54c-8f05b04cd766
07/21/2017 03:12:56.93*	w3wp.exe (0x1864)                       	0x2CF4	SharePoint Foundation         	General                       	ai1wu	Medium  	...canDispatchOnThisThread)     at System.ServiceModel.Channels.SingletonChannelAcceptor`3.Enqueue(QueueItemType item, Action dequeuedCallback, Boolean canDispatchOnThisThread)     at System.ServiceModel.Channels.HttpPipeline.EnqueueMessageAsyncResult.CompleteParseAndEnqueue(IAsyncResult result)     at System.ServiceModel.Channels.HttpPipeline.EnqueueMessageAsyncResult.HandleParseIncomingMessage(IAsyncResult result)     at System.Runtime.AsyncResult.SyncContinue(IAsyncResult result)     at System.ServiceModel.Channels.HttpPipeline.EmptyHttpPipeline.BeginProcessInboundRequest(ReplyChannelAcceptor replyChannelAcceptor, Action dequeuedCallback, AsyncCallback callback, Object state)     at System.ServiceModel.Channels.HttpChannelListener`1.HttpContextReceivedAsyncResult`1.ProcessHttpContextAsync(...	fa6c079e-923c-505f-b54c-8f05b04cd766
07/21/2017 03:12:56.93*	w3wp.exe (0x1864)                       	0x2CF4	SharePoint Foundation         	General                       	ai1wu	Medium  	...)     at System.ServiceModel.Channels.HttpChannelListener`1.BeginHttpContextReceived(HttpRequestContext context, Action acceptorCallback, AsyncCallback callback, Object state)     at System.ServiceModel.Activation.HostedHttpTransportManager.HttpContextReceived(HostedHttpRequestAsyncResult result)     at System.ServiceModel.Activation.HostedHttpRequestAsyncResult.HandleRequest()     at System.ServiceModel.Activation.HostedHttpRequestAsyncResult.BeginRequest()     at System.ServiceModel.Activation.HostedHttpRequestAsyncResult.OnBeginRequest(Object state)     at System.ServiceModel.AspNetPartialTrustHelpers.PartialTrustInvoke(ContextCallback callback, Object state)     at System.ServiceModel.Activation.HostedHttpRequestAsyncResult.OnBeginRequestWithFlow(Object state)     at System.Runtime.IOT...	fa6c079e-923c-505f-b54c-8f05b04cd766
07/21/2017 03:12:56.93*	w3wp.exe (0x1864)                       	0x2CF4	SharePoint Foundation         	General                       	ai1wu	Medium  	...hreadScheduler.ScheduledOverlapped.IOCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* nativeOverlapped)     at System.Runtime.Fx.IOCompletionThunk.UnhandledExceptionFrame(UInt32 error, UInt32 bytesRead, NativeOverlapped* nativeOverlapped)     at System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* pOVERLAP)

guyboertje · July 21, 2017, 2:35pm

Actually you need to replace between the first ... <guid>\n to the second ...

filter {
  mutate {
    gsub => [
      "message", "\.{3}\s+\h{8}-\h{4}-\h{4}-\h{4}-\h{12}\n.+?\.{3}", ""
    ]
  }
}

Blu3 · July 22, 2017, 7:14pm

guyboertje, your answer gave me a hint and here is my working solution

mutate {
    gsub => [
        "message", "\.{3}\s\w{8}-\w{4}-\w{4}-\w{4}-\w{12}", ""
    ]
	gsub => [
		"message", "\d{2}/\d{2}/\d{4}\s\d{2}:\d{2}:\d{2}.\d{2}\*.+?\.{3}", ""
	]
	gsub => [
		"message", "\.{3}", ""
	]
}

the first gsub removes ... {guid}\n (from logs in the middle)
the second gsub removes from the date with an asterisk to first three dots
the third gsub removes all other three dots occurrences

Now message is clear and fully concatenated

Thanks guyboertje, you are awesome!

system · August 19, 2017, 7:15pm

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.