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

Fri Feb 16 18:16:49 EST 2018

Matt-

I found the bug and have fixed it in the SiLK 3.16.1 Release that
is now available.

As far as Python memory usage goes, recent releases of Python have
increased the memory debugging tools available:

* Python 3.4 added the tracemalloc module.
  https://docs.python.org/3/library/tracemalloc.html

* Python 3.6 allow run-time selection of Python's internal allocator
  via the PYTHONMALLOC environment variable, and PYTHONMALLOCSTATS
  now works in release mode.

The tracemalloc module shows the size before any data was processed
at 3,770,209 bytes.  After processing 15.7 million records, the size
was 3,779,599 bytes.

My simple script is attached.

-Mark

-----Original Message-----
From: "Markland, Matthew W. (Matt), M.S." <Markland.Matthew at mayo.edu>
Date: Tue, 13 Feb 2018 18:12:49 +0000
To: Mark Thomas <mthomas at cert.org>
Cc: "netsa-tools-discuss at cert.org" <netsa-tools-discuss at cert.org>
Subject: Re: [netsa-tools-discuss] Any known issues with memory use and python
 plugins?

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

-------------- next part --------------
A non-text attachment was scrubbed...
Name: msec-2.py.txt
Type: application/octet-stream
Size: 923 bytes
Desc: not available
URL: <http://lists.sei.cmu.edu/pipermail/netsa-tools-discuss/attachments/20180216/0d43c689/attachment.obj>