Design question...

N

Nick Z.

I am writing a reusable class for logging.
My goal is to make it as fast and as robust as possible, while keeping
memory usage to the lowest. All members are static.

For some reason I'm stuck on the following design question.
Obviously you need a stream to write the log file.
Should this stream be created every time the log needs to be written, or
should the stream be a member variable of the logging class and only be
opened and closed once per application lifetime.

Can someone suggest the right way to go here and why?
This seems like a simple question but for some reason I can't decide
which is the right way to do this. Does it even matter?
 
M

Michael C

Nick Z. said:
I am writing a reusable class for logging.
My goal is to make it as fast and as robust as possible, while keeping
memory usage to the lowest. All members are static.

For some reason I'm stuck on the following design question.
Obviously you need a stream to write the log file.
Should this stream be created every time the log needs to be written, or
should the stream be a member variable of the logging class and only be
opened and closed once per application lifetime.

Can someone suggest the right way to go here and why?
This seems like a simple question but for some reason I can't decide which
is the right way to do this. Does it even matter?

For logs I open and close the stream each time. If someone happens to
terminate the app premeturely you need to be able to see the log.

Michael
 
N

Nick Z.

Michael said:
For logs I open and close the stream each time. If someone happens to
terminate the app premeturely you need to be able to see the log.

Michael

Hmmm, true. But what if you force the stream to flush after each write.
I guess I want to know what the overhead is for creating the stream
every time.
 
G

Guest

Hi Nick,
I am sure you have good reason to write your own logging class, but have
you looked at some of the out of the box logging .Net offers you such as a
TextWriterTraceListener, you can then write to log files using the:

System.Diagnostics.Trace or
System.Diagnostics.Debug classes.

Mark
 
N

Nick Z.

Hey Mark,

Thanks for you input. As far as I know using System.Diagnostics only
provides the ability to save event to system's application EventLog, the
one accessible through administrative tools. Or am I wrong? Would I be
able to easily retrieve/collect events generated by my application
specifically on demand? (for error reporting etc.)

The reason I want to implement my own logging class is making the log
file as easy to use and process as possible yet as non intrusive as
possible. I wanted to use xml and basically provide some structure to
the log file making it easier to parse without adversely affecting
performance of the logging class. I want to make it extremely fast so I
don't feel uncomfortable posting events to the log. Would creating a
separate thread to do file access be a smart thing to do or do the
stream writers (XmlTextWriter to be more precise) run asynchronously (in
another thread) anyway?

Thanks,
Nick Z.
 
G

Guest

Hi Nick,
writing logs to the event log is just one of the places you can write the
System.Diagnostics.Trace output to, this would be if you used an
EventLogTraceListener. If you want to output info easily to a file or the
console you can use a TextWriterTraceListener class.

If you are using .Net 2.0 then it has another Trace writer you can use
called an XmlWriterTraceListener which will write your info to an Xml File.

You can very easily add or remove the TraceListeners from your app by
modifying the App.Config file (or Web.Config for the web) and adding a new
trace listener (search Google for more info on how to do this).

You could also write your own custom trace listener by inheriting from
the abstract class System.Diagnostics.TraceListener. For an example see:
http://www.codeproject.com/dotnet/customnettracelisteners.asp

I recently did this to allow me to log trace messages over a network in
real-time using Remoting. I like you, was worried about affecting the
performance of the application by using tracing. What I did was to have a
queue, when the trace event occurs it simply places a message in the queue,
then I have a thread which loops through all the messages in the queue and
processes them, this way there is no performance hit for the app and the
thread can take it's time.


Hope that helps
Mark R Dawson
 
J

jeremiah johnson

I wrote a little test program to find out if opening and closing a file
1000 times introduces any major overhead, or slows down a loop at all.

it does not. well, it does, but not much at all. I have a p4-3ghz,
1.5gb RAM. This is using .NET 2.0 beta2.

test 1 opens a file, logs to it 1000 times, then closes the file.
test 2 opens a file, logts to it, closes it, then does all that 999 more
times.

here are the results:
0ms for the first test.
187ms for the second test.

Here's the source:

using System;
using System.IO;
using System.Collections.Generic;
using System.Text;

namespace fileopenclosetest {
class Program {
static void Main(string[] args) {

DateTime beforeFirst = DateTime.Now;

FileStream fs = new FileStream("test1.txt", FileMode.OpenOrCreate);
StreamWriter sw = new StreamWriter(fs);

for (int i = 0; i < 1000; i++) {
sw.WriteLine("this is a log line. It is logline " + i + ".");
}

sw.Close();
fs.Close();

DateTime afterFirst = DateTime.Now;

TimeSpan ts = afterFirst - beforeFirst;

Console.WriteLine(ts.Milliseconds + "ms for the first test.");

/////////////////////// second test.

DateTime beforeSecond = DateTime.Now;

for (int i = 0; i < 1000; i++) {

FileStream fs2 = new FileStream("test2.txt", FileMode.Append);
StreamWriter sw2 = new StreamWriter(fs2);

sw2.WriteLine("this is a log line. It is logline " + i + ".");
sw2.Close();
fs2.Close();

sw2=null;
fs2=null;

}

DateTime afterSecond = DateTime.Now;

TimeSpan ts2 = afterSecond - beforeSecond;

Console.WriteLine(ts2.Milliseconds + "ms for the second test.");

}
}
}
 
G

Guest

I’ve done something similar to this using a queue to add the messages to log
and let a separate thread do the logging. It works great!
 
N

Nick Z.

Thank you very much for the benchmarks!

187 per 1000 calls will probably be negligible for most applications.

Nick Z.

jeremiah said:
I wrote a little test program to find out if opening and closing a file
1000 times introduces any major overhead, or slows down a loop at all.

it does not. well, it does, but not much at all. I have a p4-3ghz,
1.5gb RAM. This is using .NET 2.0 beta2.

test 1 opens a file, logs to it 1000 times, then closes the file.
test 2 opens a file, logts to it, closes it, then does all that 999 more
times.

here are the results:
0ms for the first test.
187ms for the second test.

Here's the source:

using System;
using System.IO;
using System.Collections.Generic;
using System.Text;

namespace fileopenclosetest {
class Program {
static void Main(string[] args) {

DateTime beforeFirst = DateTime.Now;

FileStream fs = new FileStream("test1.txt", FileMode.OpenOrCreate);
StreamWriter sw = new StreamWriter(fs);

for (int i = 0; i < 1000; i++) {
sw.WriteLine("this is a log line. It is logline " + i + ".");
}

sw.Close();
fs.Close();

DateTime afterFirst = DateTime.Now;

TimeSpan ts = afterFirst - beforeFirst;

Console.WriteLine(ts.Milliseconds + "ms for the first test.");

/////////////////////// second test.

DateTime beforeSecond = DateTime.Now;

for (int i = 0; i < 1000; i++) {

FileStream fs2 = new FileStream("test2.txt", FileMode.Append);
StreamWriter sw2 = new StreamWriter(fs2);

sw2.WriteLine("this is a log line. It is logline " + i + ".");
sw2.Close();
fs2.Close();

sw2=null;
fs2=null;

}

DateTime afterSecond = DateTime.Now;

TimeSpan ts2 = afterSecond - beforeSecond;

Console.WriteLine(ts2.Milliseconds + "ms for the second test.");
}
}
}
Hmmm, true. But what if you force the stream to flush after each write.
I guess I want to know what the overhead is for creating the stream
every time.
 
N

Nick Z.

Mark said:
Hi Nick,
writing logs to the event log is just one of the places you can write the
System.Diagnostics.Trace output to, this would be if you used an
EventLogTraceListener. If you want to output info easily to a file or the
console you can use a TextWriterTraceListener class.

If you are using .Net 2.0 then it has another Trace writer you can use
called an XmlWriterTraceListener which will write your info to an Xml File.

You can very easily add or remove the TraceListeners from your app by
modifying the App.Config file (or Web.Config for the web) and adding a new
trace listener (search Google for more info on how to do this).

You could also write your own custom trace listener by inheriting from
the abstract class System.Diagnostics.TraceListener. For an example see:
http://www.codeproject.com/dotnet/customnettracelisteners.asp

This looks interesting. However, what would be the advantage of
implementing a TraceListener? XmlWriterTraceListener sounds like a great
idea, but its only supported in 2.0. For a class like this I'd rather
have it support all versions of the framework.
I recently did this to allow me to log trace messages over a network in
real-time using Remoting. I like you, was worried about affecting the
performance of the application by using tracing. What I did was to have a
queue, when the trace event occurs it simply places a message in the queue,
then I have a thread which loops through all the messages in the queue and
processes them, this way there is no performance hit for the app and the
thread can take it's time.

I am probably going to do the same. This sounds very efficient.
However, isn't the writing done in a separate thread anyway? So in a
sense aren't you implementing a thread that simply starts another thread
to write the log.

Just out of curiosity, when the thread that is writing the messages runs
out of messages to write, does it terminate or wait for new messages to
come in. If it waits how could that be implemented?
 
N

Nick Z.

Also, doesn't Trace require that the user change something in the config
file? What exactly does this mean?

From the codeproject article: (I believe I saw something similar in the
official docs as well)
"Trace functions can be compiled into a program and shipped to
customers, so in case your users encounter a problem, they can activate
trace by simply editing application configuration file."

Thank you,
Nick Z.
 
G

Guest

Hi Nick,
The advantage of writing a class that Inherits from TraceListener is that
you can write your own custom listener that is not provided as standard by
Microsoft, I did this to send my trace messages over a network using remoting.

One way to achieve asyncronosity is to have the main app thread write data
into the log queue, then a seperate thread sits and waits for the data and
pulls it out of the queue and performs processing. This consumer thread will
loop until it is told to stop, when there is no data it will just wait until
more data is added to the log. In the example below I used an AutoResetEvent
to make the thread wait until the Producer added more data to the queue:


using System;
using System.Threading;
using System.Collections;

namespace ConsoleApplication5
{
class Program
{
static void Main(string[] args)
{
MessageManager mm = new MessageManager();
Random random = new Random();

int numberofMessages = 100;
int count = 0;
while (count++ < numberofMessages)
{
mm.AddMessage("hello: " + count.ToString());
Thread.Sleep((int)(random.NextDouble() * 300));
}
}


}

public class MessageManager
{
private AutoResetEvent _consumerWait;
private Queue _queue;
private Thread _consumer;
private bool _continueProcessing;

public MessageManager()
{
_queue = new Queue();
_consumerWait = new AutoResetEvent(false);
_continueProcessing = true;

_consumer = new Thread(new ThreadStart(ConsumeMessages));
_consumer.IsBackground = true;
_consumer.Start();
}

private void Stop()
{
_continueProcessing = false;
_consumerWait.Set();
}

private void ConsumeMessages()
{
//Loop until we no longer want to process messages
while (_continueProcessing)
{
//process all the current messages
while (_queue.Count > 0)
{
string message = (string)_queue.Dequeue();
Console.WriteLine(message);
}

//wait until there is data to process
_consumerWait.WaitOne();
}
}

public void AddMessage(string message)
{
//Add message to the queue
_queue.Enqueue(message);

//Signal there is more data
_consumerWait.Set();
}
}


Hope that helps
Mark R Dawson
http://www.markdawson.org
 
N

Nick Z.

I looked at log4net, but I think its just too much (bloated) for a
simple logging solution. It has features that I will never use.
 
N

Nick Z.

Thank you very much for the code!
Very clear right to the point. Basically you need some synchronization
object for the thread in your case it was AutoResetEvent, got it.

Thanks,
Nick Z.
Hi Nick,
The advantage of writing a class that Inherits from TraceListener is that
you can write your own custom listener that is not provided as standard by
Microsoft, I did this to send my trace messages over a network using remoting.

One way to achieve asyncronosity is to have the main app thread write data
into the log queue, then a seperate thread sits and waits for the data and
pulls it out of the queue and performs processing. This consumer thread will
loop until it is told to stop, when there is no data it will just wait until
more data is added to the log. In the example below I used an AutoResetEvent
to make the thread wait until the Producer added more data to the queue:


using System;
using System.Threading;
using System.Collections;

namespace ConsoleApplication5
{
class Program
{
static void Main(string[] args)
{
MessageManager mm = new MessageManager();
Random random = new Random();

int numberofMessages = 100;
int count = 0;
while (count++ < numberofMessages)
{
mm.AddMessage("hello: " + count.ToString());
Thread.Sleep((int)(random.NextDouble() * 300));
}
}


}

public class MessageManager
{
private AutoResetEvent _consumerWait;
private Queue _queue;
private Thread _consumer;
private bool _continueProcessing;

public MessageManager()
{
_queue = new Queue();
_consumerWait = new AutoResetEvent(false);
_continueProcessing = true;

_consumer = new Thread(new ThreadStart(ConsumeMessages));
_consumer.IsBackground = true;
_consumer.Start();
}

private void Stop()
{
_continueProcessing = false;
_consumerWait.Set();
}

private void ConsumeMessages()
{
//Loop until we no longer want to process messages
while (_continueProcessing)
{
//process all the current messages
while (_queue.Count > 0)
{
string message = (string)_queue.Dequeue();
Console.WriteLine(message);
}

//wait until there is data to process
_consumerWait.WaitOne();
}
}

public void AddMessage(string message)
{
//Add message to the queue
_queue.Enqueue(message);

//Signal there is more data
_consumerWait.Set();
}
}


Hope that helps
Mark R Dawson
http://www.markdawson.org



Nick Z. said:
This looks interesting. However, what would be the advantage of
implementing a TraceListener? XmlWriterTraceListener sounds like a great
idea, but its only supported in 2.0. For a class like this I'd rather
have it support all versions of the framework.


I am probably going to do the same. This sounds very efficient.
However, isn't the writing done in a separate thread anyway? So in a
sense aren't you implementing a thread that simply starts another thread
to write the log.

Just out of curiosity, when the thread that is writing the messages runs
out of messages to write, does it terminate or wait for new messages to
come in. If it waits how could that be implemented?
 
J

jeremiah johnson

Nick said:
Thank you very much for the benchmarks!

187 per 1000 calls will probably be negligible for most applications.

Nick Z.

That's 187 Milliseconds - less than a fifth of a second for all 1000
opens and all 1000 closes.

jeremiah
 
N

Nick Z.

jeremiah said:
That's 187 Milliseconds - less than a fifth of a second for all 1000
opens and all 1000 closes.

jeremiah


Yeah, thats what I meant, skipped a word, oops.
 
N

Nick Z.

When opening a XmlTextWriter along with a stream and writing 1000 times
it takes 1400-1600 ms, you still think its a good idea to open/close
every time?

If I keep the stream open throughout the lifetime of the class it takes
10-80 ms to write 1000 times.

Is it bad design to have a static resource open throughout a lifetime of
a class with all static members? I mean it sure seems "nicer"
opening/closing every time, but its just that much slower and I dont
want to ever think about performance of that class again. I just want to
make it as fast as reliable as possible the first time. However, I
dont'n want to get used to bad design practices. So my question is why
is keeping the stream open a bad idea?

Thanks,
Nick Z.
 

Ask a Question

Want to reply to this thread or ask your own question?

You'll need to choose a username for the site, which only take a couple of moments. After that, you can post your question and our members will help you out.

Ask a Question

Top