On 2013-03-28 12:10, Richard Stupek wrote:
Ok looking at the log I see quite a few messages taking over a second
to process (samples below):
<s u='20130328155503' m=\temp\1332407477322.msg' s='0' r='0'>
<p s='1172' t='1109' l='72697' d='127'/>
<g o='0' i='12.130.136.172' t='u' c='0.486243' p='-0.625' r='Normal'/>
</s>
Great! Now we're getting somewhere.
It seems likely that your system is bound in 2 ways:
* Allocating RAM
* Reading / writing from the hard drive.
The setup time s='1172' indicates that it took more than a second to
allocate a 72K buffer and read the message. That is the only work done
during setup.
The scan time t='1109' indicates the amount of time it took to complete
the rest of the process. I'm guessing that since the setup took more
than a second that writing the message back with injected headers
probably took a while too.
A scan depth of 127 is nominal.
The data you sent indicates this is a problem when the messages are
fairly large. There is likely a boundary condition between smaller
messages and larger ones that allow the smaller messages to be handled
more efficiently.
Since you are indicating that CPU utilization is high during these
events and since you're not mentioning other performance issues, it
seems likely that RAM fragmentation or RAM starvation might be the
problem here.
During the setup, SNF allocates a buffer large enough for the entire
message and then reads it all at once. This is most efficient because
there is a single system call for each of these events - so the OS has
complete control over the entire step and it only happens once.
After the scanning process is done, SNF will typically allocate another
buffer large enough to include the message and all of it's headers. This
new version of the message is constructed in the buffer and then written
all at once to the file system.
If the problem is RAM fragmentation or starvation then it could be
taking as much as a second for the OS to allocate a 72K buffer ---
that's the kind of thing that should be nearly undetectable, but in
these cases where high CPU loads are reported with this kind of log data
I have seen that happen.
If the problem were simply IO then it is likely that CPU utilization
would be low while the CPUs wait for the IO operations to happen.
Of course it could be a combination of things -- it's hard to tell
what's happening in the internals of the OS.
Hope this helps,
_M
--
Pete McNeil
Chief Scientist
ARM Research Labs, LLC
www.armresearch.com
866-770-1044 x7010
twitter/codedweller
#############################################################
This message is sent to you because you are subscribed to
the mailing list <sniffer@sortmonster.com>.
This list is for discussing Message Sniffer,
Anti-spam, Anti-Malware, and related email topics.
For More information see http://www.armresearch.com
To unsubscribe, E-mail to: <sniffer-...@sortmonster.com>
To switch to the DIGEST mode, E-mail to <sniffer-dig...@sortmonster.com>
To switch to the INDEX mode, E-mail to <sniffer-in...@sortmonster.com>
Send administrative queries to <sniffer-requ...@sortmonster.com>