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

[Mark Thomas]

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