1076770 - Profile the log parser to see if performance can be improved

Status: RESOLVED INCOMPLETE

(Tree Management :: Treeherder: Data Ingestion, defect, P4)

Description

[Ed Morley [:emorley]]

Broken out of bug 1074927.

There might be some further perf improvements we can make.

It would also be interesting to know how much slower each additional regex makes it, and as such, whether it's worth spending time trying to figure out if any are no longer used.

Comment 1

[Ed Morley [:emorley]]

I know in many places we've intentionally used .match() instead of .search(), since if you're matching from start of string, it's faster.

However there are places where we've added a '.*' to the start of the regex just so we can use .match() - but interestingly this seems to actually be slower than using .search()

eg: (from bug 1121670)

>>> print timeit.timeit(stmt="r.match(s)",
...     setup="import re; s = 'TEST-UNEXPECTED-FAIL | leakcheck | tab process: 42114 bytes leaked (AsyncLatencyLogger, AsyncTransactionTrackersHolder, AudioOutputObserver, BufferRecycleBin, CipherSuiteChangeObserver, ...)'; r = re.compile(r'.*\d+ bytes leaked \((.+)\)$')",
...     number = 10000000)
43.355268762

>>> print timeit.timeit(stmt="r.search(s)",
...     setup="import re; s = 'TEST-UNEXPECTED-FAIL | leakcheck | tab process: 42114 bytes leaked (AsyncLatencyLogger, AsyncTransactionTrackersHolder, AudioOutputObserver, BufferRecycleBin, CipherSuiteChangeObserver, ...)'; r = re.compile(r'\d+ bytes leaked \((.+)\)$')",
...     number = 10000000)
18.8647965157

-> So just over twice as fast to use .search() and drop the '.*' (using Python 2.7.9)

Using .+ doesn't seem to be a

Comment 2

[Ed Morley [:emorley]]

Bah didn't mean to submit.

I was going to say using .+ doesn't seem to be as bad, however it turns out what helped was adding a space between the '.*' or '.+' and the '\d+'. eg:

>>> print timeit.timeit(stmt="r.match(s)",
...     setup="import re; s = 'TEST-UNEXPECTED-FAIL | leakcheck | tab process: 42114 bytes leaked (AsyncLatencyLogger, AsyncTransactionTrackersHolder, AudioOutputObserver, BufferRecycleBin, CipherSuiteChangeObserver, ...)'; r = re.compile(r'.* \d+ bytes leaked \((.+)\)$')",
...     number = 10000000)
19.0460573373

Anyway guess this shows we need to profile and not assume - and significant speedups are possible.

Comment 3

[Ed Morley [:emorley]]

Using the New Relic thread profiler:

https://rpm.newrelic.com/accounts/677903/applications/5585473/profiles/1671082

Comment 4

[Ed Morley [:emorley]]

Lets not worry about this unless we start getting backlogs, or log parsing tasks start appearing in the slow transaction traces in New Relic.