Stream Operator Overloading Design Choices

[VirGin]

HiHiHi,

I have a logging class. I want to update it to perform the following
by overloading the insertion operator:
- I want to prepend the time to the stream. Whether I'm writing to a
stringstream, cout, cerr, whatever.
- I want to be able to drop certain lines that might otherwise be
written to the stream. This would allow me to set a logging level when
I start writing to the stream.
- In certain situations, I want to be able to insert the result of
some other operation into the stream. I can do this already.
- I want to put this in a library file that I can link to from
different projects when I need to.

Illustration of the different goals
oLog << "Some Event" << endl;
- Use the default log message level and if the message should be
logged, prepend the time to the message and process it.

oLog(a_message_level) << "Some Other Event" << endl;
oLog(different_level) << "Details regarding Some Other Event" <<
endl;
- Process the two lines based on the logging level. Drop one or both
if they don't meet whatever criteria is set.


class LogIt : public ofstream
{
public:
...
various member definitions
...
template <class T>
friend LogIt & operator<<(LogIt &oObj, const T &xVal);
friend LogIt & operator<<(LogIt &oObj, std:stream &(*el)
(std:stream &));

private:
...
various private member definitions
...
};

template <class T>
LogIt & operator<<(LogIt &oObj, const T &xVal)
{
cout << "Prefix_Rez\t" << xVal;// << endl;
return oObj;
}
LogIt & operator<<(LogIt &oObj, std:stream &(*el)(std:stream &))
{
(*el)(oObj);
return oObj;
}


I'm testing the above with:
oLog01 << "Line One" << 5 << 5.55 << endl;
oLog01 << "Line Two" << endl;
oLog01 << 333 << endl;


As you can probably see, I end up with the "Prefix_Rez" string every
time the insertion operator is called. the second problem is that the
endl isn't ending the line.


I've played with different samples, methods and ideas.
So.
- Design-wise, what is a "good" way to specify different logging
levels for different messages?
- Also design-wise, what is a good way to only process the insertion
operator one time for each message, regardless of the number of times
that the insertion operator might be used while building a given
message?
- What is the correct method of passing endl and ending that line?



Thanx


-V-

 

[kasthurirangan.balaji]

HiHiHi,

        I have a logging class. I want to update it to perform the following
by overloading the insertion operator:
        - I want to prepend the time to the stream. Whether I'm writing to a
stringstream, cout, cerr, whatever.
        - I want to be able to drop certain lines that might otherwise be
written to the stream. This would allow me to set a logging level when
I start writing to the stream.
        - In certain situations, I want to be able to insert the result of
some other operation into the stream. I can do this already.
        - I want to put this in a library file that I can link to from
different projects when I need to.

        Illustration of the different goals
        oLog << "Some Event" << endl;
        - Use the default log message level and if the message should be
logged, prepend the time to the message and process it.

        oLog(a_message_level) << "Some Other Event" << endl;
        oLog(different_level) << "Details regarding Some Other Event" <<
endl;
        - Process the two lines based on the logging level. Drop one or both
if they don't meet whatever criteria is set.

class LogIt : public ofstream
{
public:
        ...
        various member definitions
        ...
        template <class T>
        friend LogIt & operator<<(LogIt &oObj, const T &xVal);
        friend LogIt & operator<<(LogIt &oObj, std:stream &(*el)
(std:stream &));

private:
        ...
        various private member definitions
        ...

};

template <class T>
LogIt & operator<<(LogIt &oObj, const T &xVal)
{
        cout << "Prefix_Rez\t" << xVal;// << endl;
        return oObj;}

LogIt & operator<<(LogIt &oObj, std:stream &(*el)(std:stream &))
{
        (*el)(oObj);
        return oObj;

}

I'm testing the above with:
oLog01 << "Line One" << 5 << 5.55 << endl;
oLog01 << "Line Two" << endl;
oLog01 << 333 << endl;

As you can probably see, I end up with the "Prefix_Rez" string every
time the insertion operator is called. the second problem is that the
endl isn't ending the line.

I've played with different samples, methods and ideas.
So.
        - Design-wise, what is a "good" way to specify different logging
levels for different messages?
        - Also design-wise, what is a good way to only process the insertion
operator one time for each message, regardless of the number of times
that the insertion operator might be used while building a given
message?
        - What is the correct method of passing endl and ending that line?

Thanx

-V-

For different levels, i guess this might be one way
oLog << a_message_level << ...
oLog << different_level << ...

This is similar to standard c++ way of using iomanip facilities like
cout << right << ....

Prefer using '\n' for ending a line rather than endl. Standard c++
streams are buffered. Hence using endl actually doesn't mean writing
to the stream directly. Using '\n' should solve this or endl + flush.

Thanks,
Balaji.

 

[James Kanze]

I have a logging class. I want to update it to perform the following
by overloading the insertion operator:
- I want to prepend the time to the stream. Whether I'm writing to a
stringstream, cout, cerr, whatever.
- I want to be able to drop certain lines that might otherwise be
written to the stream. This would allow me to set a logging level when
I start writing to the stream.
- In certain situations, I want to be able to insert the result of
some other operation into the stream. I can do this already.
- I want to put this in a library file that I can link to from
different projects when I need to.

Illustration of the different goals
oLog << "Some Event" << endl;
- Use the default log message level and if the message should be
logged, prepend the time to the message and process it.

oLog(a_message_level) << "Some Other Event" << endl;
oLog(different_level) << "Details regarding Some Other Event" <<
endl;
- Process the two lines based on the logging level. Drop one or both
if they don't meet whatever criteria is set.

class LogIt : public ofstream
{
public:
...
various member definitions
...
template <class T>
friend LogIt & operator<<(LogIt &oObj, const T &xVal);
friend LogIt & operator<<(
LogIt &oObj,
std:stream &(*el) > (std:stream &));

private:
...
various private member definitions
...
};

I'm not sure you want to derive here. I tend to have an
ostream* member, which I use. Depending on whether output is
desired or not, the oLog function returns an instance of log it
with this pointer set to null, or to a valid output stream. (In
my case, the "valid output stream" uses a filtering streambuf
which can fan the output out to several different destinations,
including special streambuf's to output to syslog or to email,
as well as a file or cerr or cout.)

template <class T>
LogIt & operator<<(LogIt &oObj, const T &xVal)
{
cout << "Prefix_Rez\t" << xVal;// << endl;
return oObj;
}

This *isn't* where you want to put the prefix. The prefix
should be handled by the special streambuf as well. In
particular, the special streambuf has a flag, isStartOfLine,
which is initialized true, and then set as a function of each
character output. Something like the following, for example:

int
LogStreambuf:verflow( int ch )
{
if ( myIsStartOfLine ) {
myDest->sputn( prefix ) ;
}
int result = myDest->sputc( ch ) ;
myIsStartOfLine = (ch == '\n') ;
return result ;
}

LogIt & operator<<(LogIt &oObj, std:stream &(*el)(std:stream &))
{
(*el)(oObj);
return oObj;
}

I'm testing the above with:
oLog01 << "Line One" << 5 << 5.55 << endl;
oLog01 << "Line Two" << endl;
oLog01 << 333 << endl;

As you can probably see, I end up with the "Prefix_Rez" string every
time the insertion operator is called. the second problem is that the
endl isn't ending the line.

The second is curious. You have the special function so that
endl should be called. All endl should do is more or less:

std:stream&
endl( std:stream& dest )
{
dest.put( '\n' ) ;
dest.flush() ;
return dest ;
}

Off hand, I don't see why this wouldn't work with your code.

Except, of course: you derive from an fstream, but your template
<< operator outputs to cout. Whereas the specialization for
endl does output to the base class. Are you sure that you've
opened the file in the base class correctly.

Again, I prefer using a member, with something like:

template< typename T >
LogIt&
operator<<( LogIt& dest, T const& obj )
{
if ( dest.stream != NULL ) {
dest << obj ;
}
return dest ;
}

(Note that this has the added advantage that if logging is
turned off here, you don't convert the obj to text.)

Also, you'll probably want a specialization for std::ios_base&
(*)( std::ios_base& ) as well, for some of the other
manipulators.

I've played with different samples, methods and ideas.
So.
- Design-wise, what is a "good" way to specify different logging
levels for different messages?
- Also design-wise, what is a good way to only process the insertion
operator one time for each message, regardless of the number of times
that the insertion operator might be used while building a given
message?
- What is the correct method of passing endl and ending that line?

In my own code, I actually have different ostream's for
different logging levels, with an array of ostream* indexed by
the logging level (and simply a null pointer if logging is
disactivated for that level). The oLog function returns a
temporary LogIt object, initialized with the corresponding
pointer. In my case, I've gone a step further: my LogIt object
supports copy (necessary if it is to be a return value) in a
special way, with an instance counter, so that the last
destructor of the copy will be recognized. In this way, I can
inform the special streambuf of both the start and the end of
the log record: this allows things like using a different prefix
in follow-up lines in the log, automatically appending a '\n' at
the end of the record if the client forgets it, generating an
explicit flush for streambuf's which need it to ensure atomicity
(e.g. email or syslog), and getting and releasing a mutex lock
in a multi-threaded envirionment.

 

[VirGin]

Hiya Balaji,

For different levels, i guess this might be one way
oLog << a_message_level << ...
oLog << different_level << ...

I was considering something like this. To be honest, I don't have a
preference which framework I use. My concern regarding specifying the
logging level is ease of use and standardization. I tend to create
libraries and dlls that I can use again and again across different
projects.
I ran into some issues with this as I define the logging levels as
integers. Whenever I used the insertion operator with an int that just
happened to have the same value as one of the logging levels (an
enumeration), then the insertion would be processed as if I were
specifying a logging level. Example:
Assume: L2 = LogIt::LEVEL_2 (evaluating to 2);
oLog << L2 << endl;
but if I used:
oLog << SomeVariableWithValueOf2 << endl;
I ended up resetting the logging level to 2. If the variable had a
value of 3, it would reset the logging level to 3, etc.
There's an easy fix for this, but I wasn't sure if I would remember
to use the fix two years from now when I've forgotten how I
implemented the log. Since I freelance, I also have concerns regarding
subsequent developers working on code.
However, as I said, if this turns out to be a better way, then I'll
go with it.

This is similar to standard c++ way of using iomanip facilities like
cout << right << ....

Good point. It works there, I should be able to make it work.

Prefer using '\n' for ending a line rather than endl. Standard c++
streams are buffered. Hence using endl actually doesn't mean writing
to the stream directly. Using '\n' should solve this or endl + flush.

You are correct, using either of those options work. I just happened
to discover that I wasn't handling endl correctly and went about
finding a solution (which I haven't found yet). Until I understand
what the problem is at a low level and fix my code to handle this, I
will probably use a workaround. That workaround being a define inserts
the appropriate ... whatever; ENDL.

Thanks,
Balaji.

heh. Thank *you*. It's good to get constructive (negative or
positive) feedback.


-V-

 

[Boris]

[...]Prefer using '\n' for ending a line rather than endl. Standard c++
streams are buffered. Hence using endl actually doesn't mean writing
to the stream directly. Using '\n' should solve this or endl + flush.

std::endl flushes the stream.

Boris

 

[VirGin]

Hallo James,

Danke für Ihre Antwort.

I'm not sure you want to derive here. I tend to have an
ostream* member, which I use. Depending on whether output is
desired or not, the oLog function returns an instance of log it
with this pointer set to null, or to a valid output stream. (In
my case, the "valid output stream" uses a filtering streambuf
which can fan the output out to several different destinations,
including special streambuf's to output to syslog or to email,
as well as a file or cerr or cout.)

This is a good point. Orginally, the log class only wrote to files
and cout. Part of my goal is to support different destinations.

This *isn't* where you want to put the prefix. The prefix
should be handled by the special streambuf as well. In
particular, the special streambuf has a flag, isStartOfLine,
which is initialized true, and then set as a function of each
character output. Something like the following, for example:

int
LogStreambuf:verflow( int ch )
{
if ( myIsStartOfLine ) {
myDest->sputn( prefix ) ;
}
int result = myDest->sputc( ch ) ;
myIsStartOfLine = (ch == '\n') ;
return result ;
}

Sounds like good advice. In thinking about a flag, it seemed like it
would be overhead that could be avoided.

The second is curious. You have the special function so that
endl should be called. All endl should do is more or less:

std:stream&
endl( std:stream& dest )
{
dest.put( '\n' ) ;
dest.flush() ;
return dest ;
}

Off hand, I don't see why this wouldn't work with your code.

I think it doesn't work right now because of the way that I am using
it. For testing the insertion template, I'm using cout. After reading
your response I think it will be ok when I write to a file.

Except, of course: you derive from an fstream, but your template
<< operator outputs to cout. Whereas the specialization for
endl does output to the base class. Are you sure that you've
opened the file in the base class correctly.

The cout was for testing. I noticed a problem and stripped it to the
most basic form so I could see what the problem was.

Again, I prefer using a member, with something like:

template< typename T >
LogIt&
operator<<( LogIt& dest, T const& obj )
{
if ( dest.stream != NULL ) {
dest << obj ;
}
return dest ;
}

I was toying with using a sstring member to hold the log messages
until they should be flushed or deriving from sstream as well.
However, since I'm changing the goal and capabilities, the class is
no longer an interface to a file. I will update this as well.

(Note that this has the added advantage that if logging is
turned off here, you don't convert the obj to text.)

Also, you'll probably want a specialization for std::ios_base&
(*)( std::ios_base& ) as well, for some of the other
manipulators.

OK. I think you've just saved me some amount of frustation.

In my own code, I actually have different ostream's for
different logging levels, with an array of ostream* indexed by
the logging level (and simply a null pointer if logging is
disactivated for that level). The oLog function returns a
temporary LogIt object, initialized with the corresponding
pointer. In my case, I've gone a step further: my LogIt object
supports copy (necessary if it is to be a return value) in a
special way, with an instance counter, so that the last
destructor of the copy will be recognized. In this way, I can
inform the special streambuf of both the start and the end of
the log record: this allows things like using a different prefix
in follow-up lines in the log, automatically appending a '\n' at
the end of the record if the client forgets it, generating an
explicit flush for streambuf's which need it to ensure atomicity
(e.g. email or syslog), and getting and releasing a mutex lock
in a multi-threaded envirionment.

This sounds like the direction I intend to go.
One of the ways I use the older version of the class is to log
different types of messages to different files. This meant that I
would have several instances of LogIt. There have been projects where
I had the application log to three different files. The reason for
this in that situation was that a script would process one of the logs
and populate a database based on the contents of the log. Also, the
network manager that was managing the application was able to look at
a log that only dealt with application errors.

Than you again.

I really appreciate the time you took to respond. You've given me some
good things to think about.


-V-

 

[James Kanze]

[...]

This is a good point. Orginally, the log class only wrote to files
and cout. Part of my goal is to support different destinations.

The key point in the way I do it is the layering. A lot takes
place in the streambuf, behind the ostream, even. In fact, in
my current implementation, the ostream is created (constructed)
new each time the oLog function is called---only the streambuf's
persist. (This has the advantage that someone outputting in hex
to the log doesn't end up causing all of the following output to
be in hex.)

Sounds like good advice. In thinking about a flag, it seemed like it
would be overhead that could be avoided.

You're outputting. By the time you get here, you're definitly
outputting---you're not in a log which has been disactivated.
Testing or setting a boolean is nothing compared to the rest of
what you're going to be doing. (Don't forget that to be really
useful, you're going to want to flush at the end of the log
record. Otherwise, if the program core dumps, the log will
contain everything except the most interesting part---what
happened immediately before the core dump.)

I was toying with using a sstring member to hold the log
messages until they should be flushed or deriving from sstream
as well.

In practice, the way my front-end streambuf works is to just
stuff the characters into an std::vector<char>. It's only when
it is informed of the end of the record that it passes the data
on to the final targets. In my case, I even use a different
interface from streambuf for these final targets: a single write
of an std::vector<char> which the derived class is supposed to
handle atomically (if that makes sense for the class). One of
the derived classes wraps a streambuf*, calling sputn(), then
sync(), for the write---this class handles std::cout and
std::cerr. Since portability to non-Unix systems hasn't been an
issue to date, I use the low level file functions when writing
to a file---up to a certain size (which is sufficient to cover
most, if not all, log records), write() is guaranteed to be
atomic, and the file can be opened in such a way that writes
always go to the end (again, atomically). These two
characteristics together make it possible for two communicating
processes to log to the same file---very useful when tracking
down errors in the communications. And of course, there are
also derived classes which send the message to an email address,
or put it somewhere where snmp can find it (syslog, etc.).

One of the ways I use the older version of the class is to log
different types of messages to different files.

This meant that I would have several instances of LogIt. There
have been projects where I had the application log to three
different files. The reason for this in that situation was
that a script would process one of the logs and populate a
database based on the contents of the log. Also, the network
manager that was managing the application was able to look at
a log that only dealt with application errors.

In the more elaborate versions I use, logging is controlled by a
configuration file, with a line oriented syntax something like:
<severity> <subsystem> <command>
The severity can be a single number, a range or a comma
separated list. <subsystem> can be a single name, or a comma
separated list of names, and <command> is the rest of the line,
starting with a keyword such as "file", "mail", etc. (Handling
the subsystem parameter is rather complex, and is probably only
necessary for very big systems. Also, some of the systems I've
used this on run 24 hours a day---in such cases, I try to work
something out so that the log can be reconfigured without
shutting the system down. In a multithreaded system, that can
be very non-trivial.)