Hi,

I am working on a tool which compares log files from different servers.
The application allows comparision of data from 2 servers at a time. A max
of 120 logs are compared in one go. To make things simpler, I am loading the
data of the servers in 2 huge hash tables and then comparing them. Each file
has a max size of 2.5MB. I am facing an issue with the memory usage of the
application. If I check in task manager, the application uses close to 1 GB
of memory. Even if the data of the 60 files are cached in the RAM, it should
not cross more than 2.5 * 60 = 150 MB.

I am spawning 10 threads to load the files so that the initial load is
faster. Once the load completes, I am deallocating the threads too. I am not
quite sure why the memory usage is extremely high. Can you please provide
some pointers or alternative approaches for the implementation.

Thanks!

[quoted text, click to view]

Well, that depends on how you're storing the data. For a start, if
you're loading the data as text and it's in ASCII to start with, you'll
double the size of the data due to .NET strings being in Unicode.
Beyond that, however, we'll need to know more details.

[quoted text, click to view]

Do you have any evidence that loading the files in parallel is actually
speeding things up? Unless loading the files really eats processor
time, you're likely to be slowing things down by reading several files
at a time. Even if it *does* speed things up, I'd expect the number of
useful threads to be significantly less than 10.

[quoted text, click to view]

How exactly are you trying to "deallocate" the threads?

[quoted text, click to view]

Could you post a short but complete program which demonstrates the
problem?

See http://www.pobox.com/~skeet/csharp/complete.html for details of
what I mean by that.

--
Jon Skeet - <skeet@pobox.com>
http://www.pobox.com/~skeet Blog: http://www.msmvps.com/jon.skeet

[quoted text, click to view]

At least in principle, the OS can optimize simultaneous read requests
to minimize head shuttling. I have no idea if any version of Windows
really does this.

--

..NET 2.0 for Delphi Programmers www.midnightbeach.com/.net

[quoted text, click to view]

Well (again, in principle!) imagine the first file is at track 10, the
second file is at track 10,000, the third file is at track 500, and
the fourth file is at track 25,000. Even ignoring the time to get from
the current location to track 10, it's going to be faster to step the
head from 10 to 500 then to 10,000 and then to 25,000 than it is to go
from 10 to 10,000 then back to 500 and then forward to 50,000. The
extra physical shuttling adds milliseconds to the (essentially fixed)
transfer time.

Of course, as I keep saying this is only theoretical. I see no reason
to doubt Barry's experience ... though perhaps Vista (or some future
server versions) will implement the sort of seek optimizations (that I
seem to remember Unix had in the '80's ....)

--

..NET 2.0 for Delphi Programmers www.midnightbeach.com/.net

[quoted text, click to view]

But is that going to make it any *faster* than reading in a single
thread, assuming that IO is the limiting factor here? I'd at least hope
that either the disk itself or Windows guesses that if I've read the
first 50MB of a file, I might be about to read the next few bytes, so
any time spent processing should be useful in terms of IO.

Unless there's a *lot* of time spent processing, I can't see the
benefit of using multiple threads - and even then, there'd rarely be a
benefit in using 10 threads (unless you have 8 cores...)

--
Jon Skeet - <skeet@pobox.com>
http://www.pobox.com/~skeet Blog: http://www.msmvps.com/jon.skeet

[quoted text, click to view]


Isn't this what technologies such as Command Queueing in SCSI and SATA are
specifically designed to address? On an old IDE system sure, you can only
actually do 1 read at a time.

On a modern drive with Command Queueing, doesn't the O/S say, "I have these
50 read commands, do 'em all as best you can." ? This is also going to be
very depenant upon the driver and a million other variables...

--
Chris Mullins

[quoted text, click to view]

It's been my experience that simultaneous reads slow everything down by
about 100x, if not much more. Windows doesn't appear to be smart about
it, it tries to be fair to each thread / process, but instead of giving
them a decent run (required given the slowness of disk seeks), it slices
them up too finely.

-- Barry

--

[quoted text, click to view]

It could, if the different threads were reading from different drives.
Even then, one could avoid redundant threads if one used asynchronous
stream accesses - BeginRead etc.

-- Barry

--

[quoted text, click to view]

It's not too bad if your reads are sequential and there aren't too many
of them competing. It gets a lot worse when you've got random competing
reads. You can queue up reads at a far faster rate than the disk seeks,
and disk seeks take far longer than sequential reads. The OS is faced
with Hobson's choice: be unfair to processes and starve them, in order
to minimize seeks and maximize sequential reads; or try to be fair, but
incur loads of wasted time in redundant seeks. Whether it's the OS, the
drive or the driver that gets the final say, there's still a tradeoff.
If there's enough competing reads, you can't afford enough cache RAM to
really amortize the seeks using optimistic read-ahead.

So, you either end up with unresponsive applications, or inefficient
thrashing, or some mix between the two. Until we get solid-state hard
drives, I don't think it's going to qualitatively improve. Modern drives
sequentially read well over 100MB/sec as you probably know, it's seeks
that take all the time.

-- Barry

--

[quoted text, click to view]

Hi Jon,

I am just writing the functions I am calling to read files & storing the
Data in to HashTables / Arraylist.

Method 1:

#region setupReaderThreads
/// <summary>
/// Setup the Multi Threaded environment to read the Log files
/// </summary>
private void setupReaderThreads()
{

int fileNameCount = fileNames.Count;

_fileName = new string[_arrayLength];
_logAnalyserBL = new LogAnalyserBL[_arrayLength];
_logAnalyserBLThread = new Thread[_arrayLength];

for(int i=0; i< _arrayLength; i++)
{
//fileNames is an arraylist

_fileName[i] = fileNames[i + _fileCounter].ToString();

if(! File.Exists(_fileName[i]))
{
return;
}
else
{
_logAnalyserBL[i] = new LogAnalyserBL(false);
_logAnalyserBL[i].FileName = _fileName[i];
}

_logAnalyserBLThread[i] = new Thread(new
ThreadStart(_logAnalyserBL[i].DoWork));
_logAnalyserBLThread[i].Name = "Log Reader " + i;

_logAnalyserBLThread[i].Start();

}

}

************************************************

Method 2:

#region SearchTimer_Tick
/// <summary>
/// SearchTimer_Tick
/// </summary>
/// <param name="sender"></param>
/// <param name="e"></param>
private void SearchTimer_Tick(object sender, System.EventArgs e)
{
try
{
SearchTimer.Enabled = false;
//
// Setting up the Multiple Threades to read the log files
//
if (_state == 0)
{
setupReaderThreads();
_state = 1;
}
//
// Checking if the file Reading is finished or it is still going on
//
else if (_state == 1)
{
Cursor = Cursors.WaitCursor;
bool flag = false;

StatusLabel.Text = _logAnalyserBL[0].statusBar;

for(int i=0; i< _arrayLength; i++)
{
if(!_logAnalyserBL[i].isRunning)
flag = true;
else
{
flag = false;
break;
}
}

if(flag)
_state = 2;

}
//
// Adding all the Logfiles Hash Table objects into the arraylist to
prepare the Result Nodes
//
else if (_state == 2)
{
StatusLabel.Text = string.Format("Preparing Results...", _logs.Count);

// Adding all the log file hashtable objects into the
Arraylist "_logs"
for(int i=0; i< _arrayLength; i++)
{
foreach (LogEntryNode n in _logAnalyserBL[i].results)
{
_logs.Add(n);
}

_logAnalyserBL[i] = null;
}

//Logic for Increment the counter to read 12 files at a time
if(_fileCounter < fileNames.Count - fileNames.Count%12)
{
_fileCounter += 12;

_state = 0;

if( _fileCounter == fileNames.Count - fileNames.Count%12)
{
_arrayLength = fileNames.Count%12;

if(_fileCounter == fileNames.Count)
{
_state = 3;
}
}
else if(_fileCounter == fileNames.Count)
{
_state = 3;
}
}
else
_state = 3;
}
//
// Reading the Log arraylist & Creating the corresponding Hashtables
//
else if (_state == 3)
{
_logMatcher = new LogMatcher();
_logMatcher.logs = _logs;

ThreadStart threadStart = new ThreadStart(_logMatcher.DoWork);
Thread logAnalysisThread = new Thread(threadStart);
logAnalysisThread.Name = "Log Analysis";
logAnalysisThread.Start();

_state = 4;
}
//
// Checking the thread is running or not
//
else if (_state == 4)
{
if (!_logMatcher.isRunning)
_state = 5;
else
StatusLabel.Text = _logMatcher.status;
}
//
// Updating the Status
//
else if (_state == 5)
{
this.StatusLabel.Text = "Converting to TreeView...";
_state = 6;
}
//
// Converting the resultant nodes into TreeView form
//
else if (_state == 6)
{
this.StatusLabel.Text = "Converting to TreeView...";
MetaDataTreeView.BeginUpdate();

MetaDataTreeView.Nodes.Add(new TreeNode("QUERY Nodes"));
MetaDataTreeView.Nodes.Add(new TreeNode("SAVE Nodes"));

int userCount = 1;

foreach (string key in _logMatcher.orderedResults)
{

ArrayList logEntryArrayList = (ArrayList) _logMatcher.results[key];

TreeNode tNode = null;
string startTime = string.Empty;
string endTime = string.Empty;
string timeTaken = string.Empty;

if (_logMatcher.methods.ContainsKey(key))
{
LogEntryNode logEntryNode = (LogEntryNode) _logMatcher.methods[key];

startTime = logEntryNode.GetVal("Time");

tNode = new TreeNode(string.Format("{0} {1}", logEntryNode.themethod,
logEntryNode.GetVal("Time")));

// get the user
string user = logEntryNode.GetVal("Original User");
if (user.Length == 0)
{
string refString = logEntryNode.GetVal("Ref");
user = refString.Substring(0, refString.IndexOf("-"));
}

//user += " - Ping";

if (!_users.ContainsKey(user))
_users.Add(user, new LogUserDetails(user, userCount++));

LogUserDetails logUserDetails = (LogUserDetails) _users[user];
tNode.BackColor = logUserDetails.color;
logUserDetails.count++;
}
else
{
tNode = new TreeNode( "Unknown" );
tNode.BackColor = Color.LightCoral;
}

TreeNode keyNode = new
TreeNode(((LogEntryNode)logEntryArrayList[0]).key);
tNode.Nodes.Add(keyNode);

foreach (LogEntryNode n in logEntryArrayList)
{
tNode.Nodes.Add(n);

if( n.Text.IndexOf(": Completed") > 0)
{
endTime = n.GetVal("Time");
if( startTime != string.Empty && endTime != string.Empty )
{
timeTaken = Convert.ToString( Convert.ToDateTime(endTime) -
Convert.ToDateTime(startTime));
}
}
}

TreeNode timeTakenNode = new TreeNode("Time Taken: " + timeTaken );
timeTakenNode.BackColor = Color.Red;
timeTakenNode.ForeColor = Color.White;

tNode.Nodes.Add(timeTakenNode);

// Distinguishing the Log entries on the Basis of the query & Save
if(tNode.Text.IndexOf("Query") == 0)
{
MetaDataTreeView.Nodes[0].Nodes.Add(tNode);
}
else
{
MetaDataTreeView.Nodes[1].Nodes.Add(tNode);
}
}

MetaDataTreeView.EndUpdate();

_logMatcherHash.Clear();

_logMatcherHash.Add("SEARCH_LOG", _logMatcher);

[quoted text, click to view]

Why, when I specifically asked for a complete program? I can't run the
code you've given, so I can't verify whether or not it has the same
problem on my box.

I'll have a look at it, but it would have been a lot quicker if you'd
posted a complete program.

--
Jon Skeet - <skeet@pobox.com>
http://www.pobox.com/~skeet Blog: http://www.msmvps.com/jon.skeet

[quoted text, click to view]

You're assuming that the files are not fragmented. In reality, if multiple
logfiles are being written simultaneously (I'm thinking logs for different
IIS websites on the same machine, for example), they are likely to have
interleaved fragments, and a good elevator sort will improve throughput
considerably.


[quoted text, click to view]

Elevator sort is best implemented on the drive interface electronics, not
the OS btw, because the OS can have no knowledge of actual disk layout as
determined by number of platters, hardware striping, etc. In contrast
read-ahead caching is best implemented by the OS (or better yet application)
which knows which data is related.

[quoted text, click to view]

At which step are you looking at the memory usage. A TreeView has a lot of
overhead. I also see nowhere that the ArrayList or Hashtable gets freed for
garbage collection. So you probably have three copies of your data, in
Unicode, plus TreeView overhead, of a 150 MB dataset, hence >900MB.

It doesn't help that you have multiple methods named DoWork... you shouldn't
have any actually, it's a horrible name. You gain nothing by starting
multiple threads to write to the same Hashtable.

I'd bring all the data processing back to one worker thread, using
overlapped I/O and completion callbacks (WaitForSingleObjectEx, let the
single object be a cancel event set from the GUI thread). Forget ReadLine,
reading a one-page chunk (usually 4k) will be much faster. There's no need
to save up the entire block before adding to the Hashtable either, once
you've read the key, add the pair (key, new StringBuilder()) and then start
appending data to the StringBuilder (or whatever object). And set the
hashtable to null after you add the nodes to the treeview (either remove
each element as you put in into the treeview, or dereference the entire
hashtable at the end).