[netsa-tools-discuss] Any known issues with memory use and python plugins?

Tue Feb 13 13:12:49 EST 2018

Mark:

Thank you for the feedback. The larger buffer sizes make sense re: memory usage. I knew that had come in but had trouble isolating when in the release notes. I probably just rushed over it in my reviews. I'm going to take a closer look at those environment variables and do some tests to see if we can get similar output to our previous runs without too much performance loss.

Before I leave the memory usage topic I did want to bring up one other behavior I've noticed. In my rwuniq runs so far memory use seems to double when running with our python plugin versus without. Do you have a feel for what sort of overhead the use of the python plugins adds in general and if there are ways to reduce memory usage in that model? I'll be digging in the documentation for this, but any hints you have would be welcomed.

Matt
-- 
Matthew Markland | Sr Analyst/Programmer | Information Technology | 507-538-5493 | markland.matthew at mayo.edu
Mayo Clinic | 200 First Street SW | Rochester, MN 55905 | www.mayoclinic.org

On 2/9/18, 4:57 PM, "Mark Thomas" <mthomas at cert.org> wrote:

    Matt-

    One explanation for the larger memory numbers in SiLK 3.16 is that
    our hash table no-longer limits itself to 2GB of RAM on 64-bit
    systems.  That change was introduced in SiLK 3.14.

    Prior to 3.14.0, rwuniq (and rwstats) made use of temporary files
    when the hash table's size approached 2GB.  The tools are still
    capable or using temporary files, but they need to do so less often
    because of the larger memory limit.

    However, that does not explain why your output is malformed.  I will
    investigate and see what I can determine.

    In the meantime, here are two environment variables that may help
    you in debugging this issue.  Setting the second one to "4g" should
    cause rwuniq to behave as it did in SiLK 3.11.

    * SILK_UNIQUE_DEBUG

      When set to 1, the binning engine used by rwuniq prints debugging
      messages to the standard error.  These messages are mostly about
      writing, reading, and merging temporary files.

    * SILK_HASH_MAXMEM

      Specifies the maximum number of bytes in memory a hash table may
      occupy.  This accepts the same sort of argument as the
      --sort-buffer-size switch from rwsort; that is, you may append k,
      m, g, for kilo-, mega-, giga-bytes, respectively.

    Cheers,

    -Mark

    -----Original Message-----
    From: "Markland, Matthew W. (Matt), M.S." <Markland.Matthew at mayo.edu>
    Date: Wed, 7 Feb 2018 21:53:23 +0000
    To: "netsa-tools-discuss at cert.org" <netsa-tools-discuss at cert.org>
    Subject: [netsa-tools-discuss] Any known issues with memory use and python
    	plugins?

    All:

    I'm working on moving a workflow from SiLK 3.11.0.1 to SiLK 3.16 and
    have run into some interesting memory usage numbers. I have a large
    deduped file (1.6Gb compressed) which I'm running rwuniq on with a
    custom python plugin which adds two fields to the output. The python
    plugin is not doing any real computation per se (i.e. no heavy
    math). What caused me to notice something was up is that the output
    from rwuniq when using SiLK 3.16 has entries in it which have
    addresses not in the dedupe file and the entries also appear
    malformed.

    A typical invocation of rwuniq looks like. 

    /usr/bin/time /home/users/software/silk/bin/rwuniq
    --python-file=../scripts/get_mseconds.py
    --values=Records,Packets,Bytes,start_mseconds,end_mseconds
    --fields=1-5,8 --timestamp-format=iso,local --ipv6-policy=asv4
    --delimited=, 2018020214.dedupe > 2018020214.summary

    I'm running on a 16-core machine with plenty of RAM. When I run I see
    the following "Max Resident Memory" numbers as provided by
    /usr/bin/time:

    3.11.0.1:  842700
    3.16:         5577576 

    Seeing this I'm guessing the mangled output is due to hitting some sort of 4Gb limit. If I don't use the python plugin I see this 

    3.16:  2787624

    Which still doesn't seem to be stellar in my mind, but at least it doesn't mangle the output.

    Looking at the config.log file for the 3.16 build I don't see anything
    that would appear to change its behavior like this. It was built with
    gcc 4.8.5 on CentOS (I believe).

    I'm thinking that I may not need the python plugin going forward (more
    experiments to run), but I wanted to see if anyone else has seen
    memory usage like this.

    Thanks for your time!

    Matt

    -- 
    Matthew Markland | Sr Analyst/Programmer | Information Technology | 507-538-5493 | markland.matthew at mayo.edu
    Mayo Clinic | 200 First Street SW | Rochester, MN 55905 | www.mayoclinic.org