Highlighted
Niemand.Richard1 Absent Member.
Absent Member.
698 views

Last line parsing for RegEx flex

Hi All

We are in the process of implementing ArcSight and one of the major deliverables holding us back is the RegEx Flex Folder Follower agent. In our environment we have thousands of log files written by custom services that need to be collected for auditing purposes. The problem comes in when we parse multi line log files (especially the last line of the log); we are able to get almost every line of the log file parsed into the ESM except the last line – I would assume this has something to do with the “multiline.starts.regex” option that we set in the sdkrfilereader.properties file.

Upon this discovery we brought this up with our local ArcSight partner who confirmed that they too were unable to parse the last line of the log file. Next step to follow was to log a call with ArcSight regarding this “bug” asking for a possible work around / fix for the issue, they suggested getting into contact with protect724 while we await a response to see if anyone else has had the same issue.

So here is the full breakdown of the problem we are having, the tests I have done and the configuration files we are using. If anyone has a suggestion on how to include the last line in our parser I would be most grateful for the help.

The Log File..

-------INFO (Wed Oct 13 13:26:23 2010) - 01 Service starting...

-------ERROR (Wed Oct 13 13:26:38 2010) - 02 An exception has occurred:

System.Data.SqlClient.SqlException. A network-related or instance-specific error occurred while establishing a connection to SQL Server. The server was not found or was not accessible. Verify that the instance name is correct and that SQL Server is configured to allow remote connections. (provider: Named Pipes Provider, error: 40 - Could not open a connection to SQL Server)

Additional info : Exception occurred while fetching operator banned list settings.

Location trace :

Void OnError(System.Data.SqlClient.SqlException, Boolean)

-------INFO (Thu Oct 21 07:01:30 2010) 03 CMPPokerGameControllerService::OnConnectFailed - Failed to connect to the Login service at 10.10.10.10:1861. Error Code: 10061, Error Message: Connection refused.

-------INFO (Thu Oct 21 07:01:39 2010) 04 CBaseConnectionManager::ConnectToManagedConnection - Attempting to connect to the Login service (10.10.10.10:1861).

-------INFO (Thu Oct 21 07:01:40 2010) 05 CMPPokerGameControllerService::OnConnectFailed - Failed to connect to the Login service at 10.10.10.10:1861. Error Code: 10061, Error Message: Connection refused.

-------ERROR (Wed Jan 19 16:41:43 2011) 06 CNetworkedService::OnConnectionLost - Connection to network controller has been lost.

-------INFO (Wed Jan 19 16:41:50 2011) 07 CBaseConnectionManager::ConnectToManagedConnection - Attempting to connect to the Network Controller service (127.0.0.1:1867).

-------INFO (Wed Jan 19 16:41:50 2011) 08 CNetworkedService::OnConnectionReady - Connected to the Network Controller Service.

-------WARNING (Wed Jan 19 18:38:48 2011) 09 CLobbyPokerTable::CheckCurrentWaitingPlayers - Removing player 12037 from the "waiting for players" list for table 10046 because (s)he was on there for 87172 milliseconds

-------INFO (Wed Jan 19 19:50:14 2011) 10 CMultiplayerModuleService::OnConnectionLost - Connection to a router service service has been lost. Error Code: 10054, Error Message: Connection reset by peer.

-------INFO (Wed Jan 19 19:50:14 2011) 11 CMultiplayerModuleService::OnConnectionLost - Connection to a router service service has been lost. Error Code: 10054, Error Message: Connection reset by peer.

I started with a basic parser that looked like this.

#::::::::::::::::::::::::::::::::::::::::::::::

# sdk regex properties file

#::::::::::::::::::::::::::::::::::::::::::::::

multiline.starts.regex=-------.*

regex=(.*)

token.count=1

token[0].name=message

token[0].type=String

event.deviceProduct=__stringConstant("Custom_Parser")

event.deviceVendor=__stringConstant("MyCompany")

submessage.token=message

submessage.count=1

submessage[0].pattern.count=1

submessage[0].pattern[0].regex=-------(\\w{1,}) \\(\\w{1,} (\\w{1,} \\d{1,} \\d{1,}:\\d{1,}:\\d{1,} \\d{4})\\)(.*)

submessage[0].pattern[0].fields=event.name,event.endTime,event.message

submessage[0].pattern[0].types=String,TimeStamp,String

submessage[0].pattern[0].formats=null,MMM dd hh:mm:ss yyyy,null

As you can see here we are only getting the first 10 lines from the log file – the last line is ignored.

err_parser_01.png

I have tried modifying the “multiline.starts.regex” option with the following variations (and many more).

  • (-------|$|\Z|\z|^$|^\z|^\Z).*
  • (-------|$).*
  • (-------|\Z|\z).*
  • (-------|$|\Z|\r\n|\r|\n|\z|^$|^\z|^\Z|^\r\n|^\r|^\n)
  • (?mis) (-------|$|\Z|\z|^$|^\z|^\Z).*
  • (?mis) (-------|$).*
  • (?mis) (-------|\Z|\z).*
  • (?mis) (-------|$|\Z|\r\n|\r|\n|\z|^$|^\z|^\Z|^\r\n|^\r|^\n)
  • (-------|).*
  • (-------|\r).*
  • (-------|\n).*

The same goes for the “multiline.ends.regex” option.

Every variation always ends up with the last line being ignored.

err_parser_02.png

Looking through the logs I see no major errors while running the parser.

[2011-05-10 10:37:22,770][INFO ][default.com.arcsight.agent.util.p][processFile] Found file [C:\Logs\test.log] will wait for at least [10000] to start processing.

[2011-05-10 10:37:22,770][INFO ][default.com.arcsight.agent.util.p][run] 0 files processed

[2011-05-10 10:37:23,066][INFO ][default.com.arcsight.agent.loadable._TrafficController][run] Traffic controller cache terminated.

[2011-05-10 10:37:23,070][INFO ][default.com.arcsight.agent.loadable._DeviceEventCounter][processSingleAlert] New device found [ARCLABESM|10.1.5.35|ArcSight|ArcSight]. Starting counters.

[2011-05-10 10:37:27,704][INFO ][default.com.arcsight.agent.transport.m][getAppropriateInputStream] Connection to https://arclabesm.ops.net:8443/arcsight/agent/event supports compression.

[2011-05-10 10:37:27,772][INFO ][default.com.arcsight.agent.util.p][run] 0 files processed

[2011-05-10 10:37:32,772][INFO ][default.com.arcsight.agent.util.p][processFile] Processing file [C:\Logs\test.log]

[2011-05-10 10:37:32,772][INFO ][default.com.arcsight.agent.ih][fileStarted] Started processing file [test.log]

[2011-05-10 10:37:32,776][INFO ][default.com.arcsight.agent.ke.ob$a_][getInputStream] Resource [arcsight\arcsight.link.csv] not found in any of the usual places

[2011-05-10 10:37:32,776][INFO ][default.com.arcsight.agent.ke.ob$a_][getInputStream] Resource [arcsight\arcsight.csv] not found in any of the usual places

[2011-05-10 10:37:32,790][INFO ][default.com.arcsight.agent.baseagents.e.m][createStreams] Created input stream for the file[C:\Logs\test.log] successfully.

[2011-05-10 10:37:32,791][INFO ][default.com.arcsight.agent.baseagents.e.m][createStreams] Created all streams/reas for the file[C:\Logs\test.log] successfully.

[2011-05-10 10:37:32,791][INFO ][default.com.arcsight.agent.baseagents.e.m][FileReaThread] File[C:\Logs\test.log] has an initial size[2300]

[2011-05-10 10:37:32,792][INFO ][default.com.arcsight.agent.baseagents.e.m][startAt] Attempting to start the file rea at byte offset[-1], char offset[-1] with crc32[-1], remnant[null]

[2011-05-10 10:37:32,792][INFO ][default.com.arcsight.agent.baseagents.e.m][start] Successfully started the file rea for the file[C:\Logs\test.log] with startatend[false]

[2011-05-10 10:37:32,799][INFO ][default.com.arcsight.agent.parsers.a.h][setCalendar] Using current year [2011] calendar

[2011-05-10 10:37:32,799][INFO ][default.com.arcsight.agent.parsers.a.h][<init>] Locale is [en_US]

[2011-05-10 10:37:32,810][INFO ][default.com.arcsight.agent.ke.i$a_$b_][<init>] New ThreadLocalWorker [ThreadLocalWorker #1 for Main Flow Batching[3G4Wjui8BABCBXX3ETCu+YA==]] created by thread [FileRea[C:\Logs\test.log]]

[2011-05-10 10:37:32,822][INFO ][default.com.arcsight.agent.ih][fileEnded] Finished processing file [test.log]. Status: success

[2011-05-10 10:37:32,822][INFO ][default.com.arcsight.agent.util.p][run] 1 files processed

[2011-05-10 10:37:32,823][INFO ][default.com.arcsight.agent.util.p][run] 0 files processed

[2011-05-10 10:37:32,832][INFO ][default.com.arcsight.agent.loadable._EventCounter][processSingleAlert] First event from [MyCompany|Custom_Parser||] received.

[2011-05-10 10:37:32,833][INFO ][default.com.arcsight.agent.ke.pb$a_][getInputStream] Resource [mycompany\custom_parser.link.csv] not found in any of the usual places

[2011-05-10 10:37:32,834][INFO ][default.com.arcsight.agent.ke.pb$a_][getInputStream] Resource [mycompany\custom_parser.csv] not found in any of the usual places

[2011-05-10 10:37:32,838][INFO ][default.com.arcsight.agent.ke.nb$b_][getInputStream] Resource [mycompany\custom_parser.link.csv] not found

[2011-05-10 10:37:32,843][INFO ][default.com.arcsight.agent.ke.nb$b_][getInputStream] Resource [mycompany\custom_parser.csv] not found

[2011-05-10 10:37:32,843][WARN ][default.com.arcsight.common.h.a][processSingleAlert] Unable to find categorization file [mycompany\custom_parser.csv]

[2011-05-10 10:37:32,843][INFO ][default.com.arcsight.agent.ke.ob$a_][getInputStream] Resource [mycompany\custom_parser.link.csv] not found in any of the usual places

[2011-05-10 10:37:32,844][INFO ][default.com.arcsight.agent.ke.ob$a_][getInputStream] Resource [mycompany\custom_parser.csv] not found in any of the usual places

[2011-05-10 10:37:32,845][INFO ][default.com.arcsight.agent.ke.i$a_$b_][<init>] New ThreadLocalWorker [ThreadLocalWorker #1 for Post-Aggregation Batching[3G4Wjui8BABCBXX3ETCu+YA==]] created by thread [ThreadLocalWorker #1 for Main Flow Batching[3G4Wjui8BABCBXX3ETCu+YA==]]

[2011-05-10 10:37:32,856][INFO ][default.com.arcsight.agent.ke.i$a_$b_][run] ThreadLocalWorker [ThreadLocalWorker #1 for Main Flow Batching[3G4Wjui8BABCBXX3ETCu+YA==]] self-terminating

[2011-05-10 10:37:32,857][INFO ][default.com.arcsight.agent.loadable._DeviceEventCounter][processSingleAlert] New device found [||MyCompany|Custom_Parser]. Starting counters.

[2011-05-10 10:37:32,867][INFO ][default.com.arcsight.agent.ke.i$a_$b_][run] ThreadLocalWorker [ThreadLocalWorker #1 for Post-Aggregation Batching[3G4Wjui8BABCBXX3ETCu+YA==]] self-terminating

[2011-05-10 10:37:37,823][INFO ][default.com.arcsight.agent.util.p][run] 0 files processed

If anyone could shed some light on this I would be most appreciative.

Thanks

P.S. I have attached all relevant files needed to recreate the parser.

Labels (3)
0 Likes
Reply
2 Replies
Okiok Absent Member.
Absent Member.

Re: Last line parsing for RegEx flex

I had the same issue and thought it was a bug until I observed this behaviour:

Because the Flex Connector waits to match the "multiline.starts.regex", the last line of the log file will not be parsed until another event come to the connector.

In the case of a folder follower (also my case), when a second file will be presented to the connector, the last line of the previous file will be parsed and sent to the configured destinations appropriately.

0 Likes
Reply
Respected Contributor.. jcruz Respected Contributor..
Respected Contributor..

Re: Last line parsing for RegEx flex

Just to complement this bug info...

I've experienced this issue today.

In a multine folder follower, the same file (and same conn configuration) gets all lines parsed fine in Windows environment, but on Unix the last line don't get parsed.

Weird.

0 Likes
Reply
The opinions expressed above are the personal opinions of the authors, not of Micro Focus. By using this site, you accept the Terms of Use and Rules of Participation. Certain versions of content ("Material") accessible here may contain branding from Hewlett-Packard Company (now HP Inc.) and Hewlett Packard Enterprise Company. As of September 1, 2017, the Material is now offered by Micro Focus, a separately owned and operated company. Any reference to the HP and Hewlett Packard Enterprise/HPE marks is historical in nature, and the HP and Hewlett Packard Enterprise/HPE marks are the property of their respective owners.