24
\$\begingroup\$

I'm trying to speed up a Python script that reads a large log file (JSON lines, 50gb+) and filter out results that match 1 of 2000 CIDR ranges.

Logfile

20 million lines

{"ip":"xxx.xxx.xxx.xxx","timestamp":"2017-05-27T04:00:35-04:00","data":{},"error":"EOF","error_component":"banner"}
{"ip":"xxx.xxx.xxx.xxx","timestamp":"2017-05-27T04:00:35-04:00","data":{"banner":"xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx","ehlo":"xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx","starttls":"500 Unknown command\r\n"},"error":"Bad return code for STARTTLS","error_component":"starttls"}
{"ip":"xxx.xxx.xxx.xxx","timestamp":"2017-05-27T04:00:35-04:00","data":{},"error":"EOF","error_component":"banner"}
{"ip":"xxx.xxx.xxx.xxx","timestamp":"2017-05-27T04:00:35-04:00","data":{"banner":"xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx","ehlo":"xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx","starttls":"502 No such command\r\n"},"error":"Bad return code for STARTTLS","error_component":"starttls"}

CIDR file

2,000 lines

86.80.0.0/12
77.160.0.0/12
188.200.0.0/13
178.224.0.0/13
84.24.0.0/13

Script

import sys
import json
from netaddr import *

reload(sys)
sys.setdefaultencoding('utf-8')

filename = 'results.json'
filename = unicode(filename, 'utf-8')
cidr_filename = 'cidr.txt'

rowcount = 0
count = 0

# Load CIDR ranges
with open(cidr_filename, 'r') as f:
    cidr = [line.strip() for line in f]

# Load JSON line by line
with open(filename) as f:
    for line in f:
        output = json.loads(line)
        rowcount += 1

        # Match if IP is in CIDR ranges
        if all_matching_cidrs(output['ip'], cidr):
            if 'banner' in output['data']:
                print(output['ip'] + '\t' + output['data']['banner'])
                count += 1

print('---------------------------------------')
print('LINES:   {rowcount}')
print('RESULTS: {count}')
print('---------------------------------------')

Current results

Parsing an example set of 100,000 rows takes now 8 minutes using:

  • Pypy
  • MacBook Pro with 2.8 GHz Intel Core i7, 16Gb RAM, SSD

Parsing the complete set of 20,000,000 rows would take a staggering 26 hours.

---------------------------------------
LINES:   100000
RESULTS: 1243
---------------------------------------

real    7m57.739s
user    7m52.127s
sys     0m4.177s

The bottleneck is the number of CIDR ranges to search within, when I run an example set of 100,000 row against 1 CIDR range it takes only 1.2 seconds.

---------------------------------------
LINES:   100000
RESULTS: 4
---------------------------------------

real    0m1.201s
user    0m1.095s
sys     0m0.090s

Is there a faster way of accomplishing this? Would Multithreading/Multiprocessing speed things up? Any help or other feedback would be much appreciated!

Things I've done:

  • Using Pypy, this is 9x(!) faster than Python 2.7 for this job.
  • Tried using Tim Bray's Widefinder but couldn't make it work as it focuses on regex searches IMHO.

UPDATE

rolfl's solution brought my times to parse 20,344,457 rows from ±26 hours to 4.5 minutes!

---------------------------------------
LINES:   20344457
RESULTS: 130863
---------------------------------------

real    4m27.661s 
user    3m55.171s 
sys     0m26.793s

TemporalWolf's advice to cProfile my code showed that indeed json.loads() was a bottleneck:

ncalls    tottime  percall  cumtime  percall filename:lineno(function)
16607394  131.960    0.000  131.960    0.000 {_pypyjson.loads}

Following his advice to slice the IP address natively instead of loading each line as JSON it was 2.5x times faster!

---------------------------------------
LINES:   20344457
RESULTS: 130863
---------------------------------------

real    1m40.548s
user    1m13.885s
sys     0m22.664s
\$\endgroup\$
  • 1
    \$\begingroup\$ what does all_matching_cidrs(output['ip'], cidr): do? \$\endgroup\$ – Maarten Fabré Jun 14 '17 at 14:00
  • 1
    \$\begingroup\$ If I look at the code of that method, that is not an efficient method to use to check whether 20 million lines match 2000 CIDR's. It returns all matches, so it checks 400E9 times, even when it matches on the first CIDR. I think you will need to implement your own lookup \$\endgroup\$ – Maarten Fabré Jun 14 '17 at 14:53
  • 2
    \$\begingroup\$ A sort-of-similar question that I asked a while back. It's about parsing string IP addresses into a binary format to use in a Trie data structure, which is specifically geared toward matching the longest prefix, which seems to be what you are trying to do with CIDR. Tries work really well for this task, and it's more or less what rolfl did in his improvement to your code. It may be useful to learn that data structure if you do things like this often! \$\endgroup\$ – Chris Cirefice Jun 14 '17 at 16:00
  • 1
    \$\begingroup\$ 50GB ... JSON ... dear god... \$\endgroup\$ – Alexander Jun 14 '17 at 22:09
  • 2
    \$\begingroup\$ You should profile your code, for example with cProfile => if you notice json.loads() takes a significant amount of time and most lines don't match your cidr list, naively slicing for IP addresses (and processsing for shorter than max length) takes about 1/20th the time of json.loads(), which you only need to do for lines you are processing... a 95% reduction in cost for lines which are skipped. Is that significant? You won't know until you profile. \$\endgroup\$ – TemporalWolf Jun 14 '17 at 23:01
32
\$\begingroup\$

Is there a faster way of accomplishing this? Would Multithreading/Multiprocessing speed things up? Any help or other feedback would be much appreciated!

No, for the most part, multi-threading will make no difference for you. At some point the bottleneck should be the IO speed of reading 50GB of file content, and not the speed of the processing. You also need to read the file sequentially (I presume) to get the output in the same order as the input.

But, fundamentally, the solution should not need to have multi-threaded execution in order to improve the performance.

Learning how to measure performance of various parts of your code is an important skill. For the moment, it may be as simple as timing this code:

# Load JSON line by line
with open(filename) as f:
    for line in f:
        output = json.loads(line)
        rowcount+=1

i.e. convert each line from JSON, and count the lines.... how fast is that? I would expect that the whole program should be just as fast when the IP CIDR lookups work fast too.

Your performance issue is almost certainly related to this line here:

if all_matching_cidrs(output['ip'], cidr):

Your timings already support this.... it takes 1 second to search all records in 1 CIRD, but significantly longer for 2000 CIDRs...

So, you have a performance problem in the order of \$O(mn)\$ where \$m\$ is the number of rows in the file, and \$n\$ is the number of CIDRs.

You can't improve the performance related to the number of rows in the files, but you can improve the cost of the CIDR lookups. What if it was a fixed-cost to check all CIDR matches? Then your overall performance becomes \$O(m)\$ and does not depend on the number of CIDR records.

You can do this by preprocessing the CIDR data in to a structure that allows a fixed-cost lookup.

The structure I would use is a binary tree consisting of nodes representing each bit in the CIDR specs. Each leaf node represents a CIDR to include. I.e. you preprocess the CIDRs in to the tree that at most has 32 levels (for a /32 CIDR).

Then, for the lookup, you take your IP from the JSON, convert it in to an integer, and start shifting bits from the most significant. For each bit, you start descending the CIDR tree, and if you can descend the tree until you hit a leaf node, then you have found a matching CIDR. At most, this will be 32 iterations down the tree, but for the most part, CIDR's seldom are that specific. So, let's assume at most a /24 CIDR, meaning that you reduce your lookups to at most 24 descents, instead of as many as 2000 complete checks.

It comes down to the algorithm.

Update - example lookup

Note, I hacked together this tree for supporting faster lookups of IPs in a number of CIDR ranges. Python is not my primary language, so inspect it carefully, and adjust as needed. Specifically, I have used some naive mecheanisms for parsing IP addresses in to integers. Use dedicated libraries to do that instead.

You can see it running on ideone: https://ideone.com/cd0O2I

def parseIPPart(ipx, shift):
    try:
        return int(ipx) << shift
    except TypeError:
        return 0

def parseIP(ipString):
    ips_shifts = zip(ipString.split("."), range(24, -1, -8))

    addr = [parseIPPart(ip, shift) for ip, shift in ips_shifts]
    return sum(addr)


def parseCIDR(cidr):
    addrString, bitsString = cidr.split('/')
    try:
        bits = int(bitsString)
    except TypeError:
        bits = 32
    addr = parseIP(addrString)
    return addr, bits


class CIDRTree:
    class CIDRNode:
        def __init__(self, depth):
            self.depth = depth
            self.isset = None
            self.unset = None
            self.leaf = False

    def __init__(self):
        self.root = CIDRTree.CIDRNode(-1)

    def addCIDR(self, cidr):
        ip, bits = parseCIDR(cidr)
        node = self.root
        for b in range(bits):
            if node.leaf:
                # Previous bigger CIDR Covers this subnet
                return
            mask = 1 << (31 - b)

            if (ip & mask) != 0:
                if node.isset is None:
                    node.isset = CIDRTree.CIDRNode(b)
                kid = node.isset
            else:
                if node.unset is None:
                    node.unset = CIDRTree.CIDRNode(b)
                kid = node.unset
            node = kid
        # node is now a representation of the leaf that comes from this CIDR.
        # Clear out any more specific CIDRs that are no longer relevant (this CIDR includes a previous CIDR)
        node.isset = None
        node.unset = None
        node.leaf = True
        #print("Added CIDR ", ip, " and bits ", bits)

    def matches(self, ipString):

        ip = parseIP(ipString)
        node = self.root
        shift = 0
        while node is not None and not node.leaf:
            shift += 1
            mask = 1 << (32 - shift)
            val = (ip & mask) != 0
            node = node.isset if val else node.unset

        return node is not None and node.leaf

if __name__ == "__main__":
    cidrTree = CIDRTree()
    cidrTree.addCIDR("8.0.0.0/8")
    cidrTree.addCIDR("9.8.7.0/24")

    print ("Tree matches 8.8.8.8:", cidrTree.matches("8.8.8.8"))
    print ("Tree matches 9.9.9.9:", cidrTree.matches("9.9.9.9"))
    print ("Tree matches 9.8.7.6:", cidrTree.matches("9.8.7.6"))
\$\endgroup\$
  • 6
    \$\begingroup\$ WOW, many thanks. It is insanely fast, 100,000 rows now take only 1.3 seconds instead of 7 minutes: real 0m1.350s user 0m1.174s sys 0m0.146s \$\endgroup\$ – JMK09 Jun 14 '17 at 14:56
  • 3
    \$\begingroup\$ I've run it on the complete set of 20,344,457 rows: real 4m27.661s user 3m55.171s sys 0m26.793s That's even faster than my initial attempt of 100,000 records :) \$\endgroup\$ – JMK09 Jun 14 '17 at 15:01
  • 3
    \$\begingroup\$ Just FYI, I crunched some numbers, and it's procesing about 75,000 records per second now, or 190MB/s, which I feel is in the right sort of ball-park for your system. SSD should be a bit faster, but there are some overheads, and I expect, that if you had a concurrent IO/processing system now (computing matches in one thread while blocking on IO in another), that you could reduce the time a bit.... but it's probably not worth it. There's still room for improvement, but it will be hard work.... \$\endgroup\$ – rolfl Jun 14 '17 at 19:35
  • 1
    \$\begingroup\$ Nitpick for the explanation: A binary search tree reduces complexity to O(log n), so the end complexity would be O(m log n). \$\endgroup\$ – TemporalWolf Jun 14 '17 at 20:42
  • 1
    \$\begingroup\$ @TemporalWolf - that's not strictly accurate. The reality is that the n in the log n is a constant, 32 (the number of bits in an IP address), not the number of CIDRs, so, being a constant the complexity is just \$O(m)\$ \$\endgroup\$ – rolfl Jun 14 '17 at 21:51
2
\$\begingroup\$

I do not see the reason behind using sys.setdefaultencoding() regarding the log and CIDR files you are dealing with.

You may be interested in reading:

\$\endgroup\$
  • \$\begingroup\$ I run into some encoding issues when parsing (I believe it was) Japanese characters. I removed these 2 lines and run the script again, it didn't had any performance improvements. real 7m17.190s user 7m14.737s sys 0m1.853s \$\endgroup\$ – JMK09 Jun 14 '17 at 12:56
1
\$\begingroup\$

First and foremost, Phyton is not my language of choice (or in other words, I don't know it at all), so I'm just trying to add something regardless of the language.

Yes, you would benefit a lot from multithreading here, it's quite a basic case. I give for granted that Phyton does nothing to complicate using of multiple thread, obviously, because doing multithreading itself is cheese task even when using the basic OS APIs. As a general rule of thumb, unless you are dealing with a really fast computation where the additional overhead added by threading will worsen the performances, there is no point in not using parallelism everywhere. It's one of the easiest things to do in computer programming, and it allows you to "choke" the hardware to the point that no matter what, you are granted to be going as fast as the PC allows.


So, one of the thing here is that the CPU is waiting for your hard disk to provide data, and then the hard disk is waiting for the CPU to ask for something.

The first and more obvious point is that accessing disk to get a few bytes each time is terribly inefficient: disks (HDD or SDD is the same, in this case) are best for sustained reading. The OS cache will help you so that it will read a bunch of data ahead for every request you make, but you know you are going through the entire file so you shouldn't rely on the cache and try to be as efficient as possible in your code.

In fact, as rolfl points out

At some point the bottleneck should be the IO speed of reading 50GB of file content

And one of the comments to his answer shows that it's exactly what is happening:

I crunched some numbers, and it's procesing about 75,000 records per second now, or 190MB/s

190 MB/s is ridiculously low for an hard disk, unless is a 5-8 years old cheap model; right now even an SD card can be faster than that, sometime. From a decent SSD I'd expect at least twice that speed, and today even SSD in the range of 100$ can easily saturate the SATA interface.

That is, you want to read big chunks of data every time; no matter what, don't read a line at time. There is no magic number, but unless the computer has serious memory issues 100 megabyte each time should be more than good.

Now, problem is, while waiting for data the CPU is sitting idle doing nothing. Then, while the CPU is crunching your data, the disk is sitting idle waiting for something to do: needless to say this is time for some free multithreading.

Deciding what to implement is a bit complicate without knowing the exact details and limits of the project, because you can simply have a number of threads equal to the number of cores, each one working onto an equal part of the file (easily doable in an hour total), or going to write a central dispatcher that read chunks of the file, create threads up to a certain limit (maybe doing some throttling), and collecting the results (and this can take up to a day of work). It all depends on money and time you have available to do this but, yeah, go for it.

\$\endgroup\$

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.