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>

Reply via email to