Please check out OurPlace MUD !

Member Discussions

terms



[Previous] [Next] [Post] [Reply] [Topics] [Summary] [Search]


Pages: 1 | 2

1. RFC: new logging facility Sun Jul 18, 2004 [3:01 AM]
muir
Email not supplied
member since: Sep 14, 2003
Reply
Requesting commentary on a logging facility I wrote for the Mesh Project.

It's in C++ and a work in process (and somewhat of a proof of concept), but the basic functionality is present. You can browse the source online on the Mesh Project repository viewer here. See the Mesh Wiki for information on accessing the repository using the Subversion version control system or you can just click on the tar file in the parent directory (opens with winRAR on Windows).

Multiple files that are not a part of the logger proper are provided as required files: eventually these will be abstracted to separate modules.

A minimal test program is is included. The code has been tested with g++ (GCC 3.2) on Linux and Visual C++ 6, MinGW (GCC 3.2) on Windows.

There should not be any bugs present albeit a few sections are lacking input validation (to be added) and other finer details. If you notice anything, please let me know.

....

So what's special about it?

Well, at the moment it only supports writing the log to any object that defines an operator<< -the default is std::cout. The output can be formatted to user specification (which can be changed runtime) and it supports variable-length argument lists and direct input of various datatypes (strings, ints, etc.). The main thing, though, is that it simplifies debugging: a given log message can be either evaluated or ignored based on a user-given logging level. In the following example we print out some information that really is negligible, so it may not be desirable to be printed in a production setting (normally the #ifdef NDEBUG directives are used for this effect). Ignore the syntax for now, it'll be explained later.

my_log(my_log.DEBUG) << "Server::NewUser" << "Greet" << "Unable to greet socket " << newsock.id() << ctl::END;

// Alternative syntax, calls are equivalent
my_log.debug() << "Server::NewUser" << "Greet" << "Unable to greet socket " << newsock.id() << ctl::END;

Now, based on the logging level the user has given my_log, the message will either be output normally (if the log level is equal or higher (=more important) than 'DEBUG') or ignored completely otherwise (yes, completely, not a microsecond spent on it).

A word about the design: the logger is modular, consisting of the following parts: InputModel (methods of taking in messages), ProcessingModel (any processing/formatting done to the given messages) and OutputModel (where/how to output the messages) and each can in theory be substituted by any other class that adheres to the Model specification (so Models are essentially Policies) -i.e. a class that implements the needed member functions and defines the needed datatypes. The complete logger is built using compile-time polymorphism, essentially by inheriting template parameters. So InputModel is defined something like this:

template <class ProcessingModel>
class InputModel: public ProcessingModel
...

This way we avoid the overhead of virtual member functions. At the moment only a singlethreaded version exists (InputModel is called single_queue), but a multithreaded one could be easily established by writing a class to replace single_queue.

A log object requires no parameters for initialization although a name can be given (for example, you can name one log 'information' whereas another is called 'error').

#include "default_log.h"

// Creating a default log object
st_log_type my_log("info");

// Creating a critical-messages-only log object
// 'log' is the facade for the entire collection of Models,
// 'single_queue' is InputModel, 'direct' is OutputModel,
// 'formatting' is ProcessingModel, 'log_base' is BaseModel
// and ctl::CRITICAL defines the minimum priority level.
mesh::elflog::log<single_queue<direct<formatting<log_base<> > >, ctl::CRITICAL> > c_log("critical");

'direct', the OutputModel, by default outputs to std::cout, but you can change the stream with the ::channel member function -for example,
my_log.channel(std::cerr);

Note that if you use anything that's not a std::ostream, you will need to supply a template parameter to 'direct'.

You can also format output to your liking. The default output looks something like this:
<< Inform  >>   11:51:34 28.07.03  [Network::Server .:. TCPIPModel::Constructor]
                -- The protocol model has been initialized. This text is here just
                   to show how the text can (and will) be formatted. As you may
                   notice, the idea is to have a line length and an offset from
                   the beginning of the line.

This format is automatically selected. If you want to give a different format, you can do so by supplying a string to the member function 'format()'. For example, the following will just print 3 arguments without any formatting (except spaces inbetween each):
// &e3;     -- Maximum of 3 arguments (any extra ones appended to 3rd)
// &a0..2;  -- Put argument number 0, 1, 2 here
// &k ;     -- A 'konstant', a single space character  
my_log.format("&e3;&a0;&k ;&a1;&k ;&a2;");

Full formatting options can be found in the logprocessingmodels.template file.

As I said earlier, you can supply an arbitrary amount of arguments of various types (basically anything that std::cout would accept). Depending on the selected format these arguments may be treated each separately or bunched all together. You can do things like
// my_log.debug() invokes the logger
// Arguments are passed like to std::cout with op<<
// ctl::END means the end of the message, flush the buffer (like std::endl)
my_log.debug() << "Your hp: " << char.hp() << ctl::END;

easily. If you have a user-defined structure you want to pass in, you will need to overload an operator but that's for later.

About the priority levels: there are 8 defined, here in ascending order of importance: FULL_DEBUG, DEBUG, NEGLIGIBLE, USEFUL, INFO, NORMAL, IMPORTANT and CRITICAL. Using them is simple: if you have a log object that is defined for NORMAL, it means that only messages of NORMAL or higher importance are to be printed. The importance of a given message is signalled in the log invocation:
// This message is 'NEGLIGIBLE' (notice the function is lowercase)
my_log.negligible() << "Blah blah blah...

// So is this (notice the parm is uppercase)
my_log(my_log.NEGLIGIBLE) << "Blah blah blah...

The level that the given log object needs is defined as a template parameter as you saw a few lines above -the default is obviously NORMAL.

----

Hopefully that wasn't too confusing. Please post any questions/comments here. Take a look at the test.cc file, it's pretty simple but it should give you an idea how things work. If you stick to the st_log_type (NORMAL priority, output to a std::ostream) and the default format you can get using it right away.

Future: the interface will probably change a bit (changing the my_log(my_log.NORMAL) call to my_log.log(my_log.NORMAL) or something, for example), I'll try to fix and refine it and I'll add some more Model implementations for greater variance. And I'll write some docs, too :)

.


2. RE: RFC: new logging facility Sun Jul 18, 2004 [3:52 AM]
eiz
eiz@nospam_codealchemy.org
member since: Dec 24, 2002
In Reply To
Reply
I...

...

...man.

You can over-complicate anything, can't you? I'm not even sure where to start, but one phrase really caught my eye:

This way we avoid the overhead of virtual member functions.

How this could possibly matter in a logging system, under any circumstances, is absolutely beyond me. Attempts to reconcile this statement with any sort of known reality have resulted in a massive headache.

I think there are smaller and simpler syslog daemons.


3. RE: RFC: new logging facility Sun Jul 18, 2004 [5:24 AM]
scandum
Email not supplied
member since: Aug 30, 2002
In Reply To
Reply
It's of the greatest importance to log it when the log function itself is called. Imagine, and this is very well possible, that the log function would ever access invalid memory resulting in a segmentation fault. You would turn on the highest priority of logging, and still not find a thing!

Hence I would suggest adding in the logging routine:

system("echo Log function called! >> my_log.txt");

And at the end of the routine:

system("echo Log function exited! >> my_log.txt");

Now what is so wonderful about this: whenever things go wrong, first check my_log.txt, which should have 'Log function exited!' as the last line. If that's the case, you can proceed, confident that your logging fascility wasn't the evil do-er! :)
http://tintin.sf.net - Kickin It Old Skool since 1992


4. RE: RFC: new logging facility Sun Jul 18, 2004 [2:57 PM]
muir
Email not supplied
member since: Sep 14, 2003
In Reply To
Reply
Eiz:
You can over-complicate anything, can't you?

Yep, I'm very proud of it :)

This way we avoid the overhead of virtual member functions.

How this could possibly matter in a logging system, under any circumstances, is absolutely beyond me.

Avoiding the overhead is a general quality of compile-time polymorphism. It's not really required here nor does it make a huge difference, but it's not a detriment either.

The end-user should not have to deal with much of the complexity, though.

Oh, and there are functions present for internal informational and error messages.

.


5. RE: RFC: new logging facility Sun Jul 18, 2004 [4:04 PM]
eiz
eiz@nospam_codealchemy.org
member since: Dec 24, 2002
In Reply To
Reply
Yep, I'm very proud of it :)

That's sick. =(

Avoiding the overhead is a general quality of compile-time polymorphism. It's not really required here nor does it make a huge difference, but it's not a detriment either.

Yes, I'm aware that it's a general quality of compile time polymorphism. But is the ghastly, creeping complexity introduced by your template magic really worth it? Think of the children!

Deus had a pretty simple logging object, you would just do something like dlog("nonsense") << "badgers!" << ends; and it wasn't 6 billion lines of code to do something trivial. These days we just send our messages to std::cout. :P

I don't know, maybe I've just read too much Chuck Moore propaganda, but the fact that I've written entire MUD servers (not in C++ of course) that were vastly smaller than your logger just disturbs me on some level.

The actual feature set seems pretty nice, though, on the condition that you add all sorts of insane logging output models at some point.


6. RE: RFC: new logging facility Sun Jul 18, 2004 [4:09 PM]
lindahlb
Email not supplied
member since: Mar 2, 2001
In Reply To
Reply
The complexity of the compile time by using a templated inhertance system over a typical virtual inheritance system. IMO, wouldn't be worth the small amount of gain you'll get at run time with removing the usage of virtual functions. A virtual function call overhead is incredibly minimal compared to output to a file or the screen, as well as moving buffered character data round.


7. RE: RFC: new logging facility Sun Jul 18, 2004 [4:50 PM]
muir
Email not supplied
member since: Sep 14, 2003
In Reply To
Reply
I'm just kidding about the complexity factor (but if you want to cringe, take a look at the metamagic loginputmodels.h) :)

This is, partly, a proof-of-concept implementation so it tends to be a bit complex for the developer. I'll probably get it simplified, eventually. For this first operational version the goal was just, well, the 'operational' part and primarily simplicity for the end-user -which I think was attained:
// Bring into view
#include "default_log.h"
...

// Create a log object
st_log_type logger("info");
...

// Use it
logger.negligible() << "Network::Server"
                    << "TCPIPServer::Shutdown"
                    << "The server exploded! Approximately "
                    << CalculateCasualties(sys::EXPLOSION)
                    << " dead or injured!"
                    <<ctl::END
...

The added bonus is that that particular message won't be displayed unless 'logger' is defined to NEGLIGIBLE or lower priority -and the message itself can stay in place, unchanged, only the typedef for the type of the logger (here st_log_type) needs to be changed.

I'll heartily agree that this implementation doesn't subscribe to XP: there's vast infrastructure in place to facilitate nearly anything one can think of. A good thing to compare this to -as Tyche pointed out to me- is the Apache Foundation's log4j and its other-language counterparts.

The actual feature set seems pretty nice, though, on the condition that you add all sorts of insane logging output models at some point.

And not only me! The actual interfaces for the Models are very simple: the OutputModel, for example, is only expected to provide three types: streamtype, stringtype and threading model (which may be removed in the future) and a method called output that takes a streamtype as a parameter.

I'll probably change the templating around a little bit for greater independence of each Model -and I disagree that it introduces much complexity: in order to attain the same functionality with 'traditional' means would require having base classes for each Model and each Model to manage an object of those classes rather than inheriting from them directly.

.




8. RE: RFC: new logging facility Sun Jul 18, 2004 [5:16 PM]
lindahlb
Email not supplied
member since: Mar 2, 2001
In Reply To
Reply
The complexity I was talking about was time complexity for compiling. Considering how often a MUD is compiled, a policy-dynamic logging system would be better implemented using virtual functions than template parameters. Like I mentioned before, the overhead of virtual functions is minimal compared to logging information to disk, screen, or even a buffer. So what do you have to gain from using a templated-style? Virtual functions do the same thing - you CAN introduce multiple inheritance.


9. RE: RFC: new logging facility Sun Jul 18, 2004 [8:54 PM]
eiz
eiz@nospam_codealchemy.org
member since: Dec 24, 2002
In Reply To
Reply
Alright, here is my idea of a "simple" logger. It doesn't have nearly as many features (because I wrote it just for this post), but it should demonstrate the basic idea. An example usage:


logger l;
l.add_output(new ostream_output());
l.add_output(new filter_output(ERROR,
new ostream_output(new default_format("%{0} --> %{1}"))));
l << "abc" << "def" << logger::end; // written as rubbish
l(ERROR) << "Not enough templates!" << logger::end; // error


Will produce:


[Sun Jul 18 20:53:49 2004 RUBBISH] abcdef
[Sun Jul 18 20:53:49 2004 ERROR] Not enough templates!
ERROR --> Not enough templates!


Again, it's not nearly as featureful as yours but it's reasonably powerful (more than I'd ever need) and it doesn't need any voodoo, which I feel is a big plus.

Apologies if the formatting on this post is broken.


(Comment added by eiz on Sun Jul 18 22:33:38 2004)

Oh yeah and, log4j needs to die almost 37% as much as commons-logging.


10. RE: RFC: new logging facility Sun Jul 18, 2004 [10:12 PM]
muir
Email not supplied
member since: Sep 14, 2003
In Reply To
Reply
And a good logger it is. It seems to work fine and does what is required of it. But what about multithreading? File output? Debugging? Wide-character locales?

Yeah, you can add that stuff but if you don't design for it, you'll end up with a mess -given that one may end up with a mess even when having designed for it. And that, I suppose, was the point. Some of the files -etime, wordlist and meta-common- also work for other things.

I don't mean to sound too defensive -there're certainly aspects that need improvement. Someone mentioned that the general unfamiliarity of developers with template coding might be a detriment. Would you consider that to be a problem rather than the templating itself?

I don't consider the template compilation overhead to be a hurdle of any sort (cl compiles and links the files in about 8 seconds on my 650MHz/128MB).

.

(Comment added by muir on Sun Jul 18 23:16:19 2004)

Oh, and most of the 'voodoo' is to enable the debug-environment behaviour (which was the concept I was trying to prove -you could do nearly the same using the preprocessor): the compiler will completely optimize away any log invocations that are below the defined logging level, which I consider to be a really nice feature for debugging.


11. RE: RFC: new logging facility Sun Jul 18, 2004 [10:35 PM]
Razzer_9
Email not supplied
member since: Mar 5, 2001
In Reply To
Reply
Well, first I want to say the idea is interesting. Better logging routines is always needed.

But, personally, I think the implementation is more complex than it needs to be. Not only do I gripe at the mass amount of templates (all C++ programmers should know about templates and compiler errors/warnings), I also look and wonder if all the templates are that necessary. I'm all in favor of extensible designs, but it seems rather overkill on the programmer. I look at your code and I wonder just about how much I would actually ever extend your code.

On top of all that, I think the overall design is a bit complex and away from might be really useful. Personally, I like the Boost Test libraries. The logging routines in the test framework library, I think, are ideal. The only problem with them is the design aim of the library, so I end up rewriting a lot of it anyway :=/.

I guess I just wonder about the overall design. It looks like a logger, it acts like a logger, but the code makes me wonder if the logger's design has a bit more functionability that is really worthwhile to the common programmer.

(Comment added by Razzer_9 on Mon Jul 19 10:20:12 2004)

Of course, that should say: "than is really worthwhile..."


12. RE: RFC: new logging facility Sun Jul 18, 2004 [10:38 PM]
eiz
eiz@nospam_codealchemy.org
member since: Dec 24, 2002
In Reply To
Reply
Yeah, you can add that stuff but if you don't design for it, you'll end up with a mess -given that one may end up with a mess even when having designed for it. And that, I suppose, was the point. Some of the files -etime, wordlist and meta-common- also work for other things.

And if you overdesign, you still have a mess. File output? Well, ostream_output can output to any ostream. Using the ufxlib network routines I could add network logging in about 30 lines of code. Debugging? Debugging of what? The logger? My solution is to pray it doesn't have bugs (it does). My solution to errors in usage is to throw an exception. Threading? I hate pre-emptive concurrency (go coroutines!), so I rarely think about it, but I don't think making it thread safe would be a huge problem. And it was designed to be easily extensible, I simply haven't put the time into fleshing it out. None of this stuff would result in a program comparable in size to the template-based one.

I don't mean to sound too defensive -there're certainly aspects that need improvement. Someone mentioned that the general unfamiliarity of developers with template coding might be a detriment. Would you consider that to be a problem rather than the templating itself?

It's not a problem for me personally, but it is a concern for many, yes. And I don't have a fast computer, highly templated code really takes a toll. Not to mention, I'm used to programming in languages that compile so much faster than C++ that I sometimes write code in them while waiting for my C++ to compile... no sense in making it worse =)

As for defensiveness: the only problem I have with the logger is that oversized code really irks me; there are a lot of excellent libraries that I don't like using just because they're too large. Also, there are elements of the logging configuration that I would like to be able to change at runtime (loaded from a configuration file for example).

Oh, and most of the 'voodoo' is to enable the debug-environment behaviour (which was the concept I was trying to prove -you could do nearly the same using the preprocessor): the compiler will completely optimize away any log invocations that are below the defined logging level, which I consider to be a really nice feature for debugging.

I consider template metaprogramming to be voodoo in that the vast majority of C++ programmers I've encountered simply do not understand it at all. Granted, there's not any truly magical stuff in your logger, but the overly verbose style necessesitated by the techniques is still present.

Anyhow, it basically boils down to preference. I go for small whenever possible. =)

(Comment added by eiz on Mon Jul 19 4:41:09 2004)

Okay so it's a boring night and I've got nothing better to do, so I went ahead and added threading support. Not really what I would classify as much of a mess--actually it simplified the interface: no more error-prone logger::end! Thank you bizzaro C++ temporary scoping. I always forget about those stupid terminator tokens.

I'll leave you alone now =)

(Comment added by eiz on Mon Jul 19 16:21:55 2004)

Oh yes, one more thing I didn't see any way to accomplish with elflog: sending output from one logger to multiple destinations. This is pretty much a requirement for me, e.g. to log errors to a file as well as sending them to logged in administrators, writing all messages to stdout during debugging but writing only the infos and higher to the log file (so as to not flood them with debug info)... you get the idea. Am I missing something? Something like this:

struct point {
  point(int a_x, int a_y): x(a_x), y(a_y) {}
  int x;
  int y;
};

ostream &operator<<(ostream &lhs, const point &rhs) {
  lhs << "(" << rhs.x << ", " << rhs.y << ")";
  return lhs;
}

int main(int argc, char **argv) {
  logger<> global_log;
  ofstream outfile("my_log.txt", ios::app);
  // All messages get sent to stdout
  global_log.add_output(new ostream_output());
  // Info and higher gets sent to my_log.txt
  global_log.add_output(new filter_output(logger_base::INFO,
                        new ostream_output(new default_format(), outfile)));
  // Errors get sent to localhost:10000. We initialize this one last
  // so we have somewhere to send the error
  try {
    global_log.add_output(new filter_output(logger_base::ERROR,
                          new network_output("localhost", 10000)));
  } catch (ufx::networkConnectionError &e) {
    global_log(logger_base::ERROR) << "Can't connect to logging host.";
  }
  global_log() << "This text is completely superfluous"; // defaulted
  global_log(logger_base::ERROR) << "Network logging for errors";
  global_log(logger_base::INFO) << "This is some information. Yeah.";
  // Also defaulted
  global_log << "to_str uses ostringstream. Observe: " << point(3,2) << ".";
  { // We can accumulate the long way
    log_accum a(global_log, logger_base::INFO);
    a << "Foo ";
    a << "Bar ";
    a << "Baz ";
  }
}


13. RE: RFC: new logging facility Sun Jul 18, 2004 [10:44 PM]
Razzer_9
Email not supplied
member since: Mar 5, 2001
In Reply To
Reply
multithreading?

That is the one thing that kills about this logger. While it is of some convience, I almost wonder if that is streching the purpose of a logger.

File output?

Well, seeing as both your and eiz's libraries use std::ostream, both easily support file output.

Debugging?

I thought that was a feature of a typical logging mechanism?

Wide-character locales?

Too bad the C++ standard is too silent on this to really make it a major feature of your codebase. While I noticed it browsing through your code and I applaud your effort, wide-character in C++ mean different things on different implementations, so it really doesn't put a lot of portability in my book :(. If you were to design a portable Unicode class, I think that might be interesting to include in the logger.

the compiler will completely optimize away any log invocations that are below the defined logging level, which I consider to be a really nice feature for debugging.

Really? Out of curiosity, did you intentionally design this, or is this a compiler trick?


14. RE: RFC: new logging facility Mon Jul 19, 2004 [6:59 PM]
Tyche
Email not supplied
member since: Apr 4, 2000
In Reply To
Reply

Muir
>> I don't mean to sound too defensive -there're certainly aspects that need improvement. Someone mentioned that the general unfamiliarity of developers with template coding might be a detriment. Would you consider that to be a problem rather than the templating itself?

Eiz
> It's not a problem for me personally, but it is a concern for many, yes. And I don't have a fast computer, highly templated code really takes a toll. Not to mention, I'm used to programming in languages that compile so much faster than C++ that I sometimes write code in them while waiting for my C++ to compile... no sense in making it worse =)
...

Muir
>> Oh, and most of the 'voodoo' is to enable the debug-environment behaviour (which was the concept I was trying to prove -you could do nearly the same using the preprocessor): the compiler will completely optimize away any log invocations that are below the defined logging level, which I consider to be a really nice feature for debugging.

Eiz
> I consider template metaprogramming to be voodoo in that the vast majority of C++ programmers I've encountered simply do not understand it at all. Granted, there's not any truly magical stuff in your logger, but the overly verbose style necessesitated by the techniques is still present.


I guess my view of C++ templates is that they are really esoteric features of C++. Most C++ programmers I know are comfortable using the STL, using templates to parameterize types and constructing function objects. However beyond that I know very few C++ programmers that go into the abstractions of concepts, modeling and refinement. I think these are so far divorced from the language itself that the distance between design discussion and the actual implementation is not something easily bridged. What's missing is the act of iteration or visualizing the iteration that occurred, must occur, to even get to a usable model.

Honestly, it's way too much thinking for me. It has never failed to surprise me at how people approach solving problems though. Sometimes it's a eureka kind of moment, many times not. I used to be one of those you-got-a-nail-I-got-a-hammer-for-it object-oriented holy roller. I have to laugh at many of my old posts on the topic. I've mellowed out on that quite a bit into a whatever floats your boat sort. Now that happened to a lot of us reformed procedural programmers in an annoying sort of way not unlike reformed smokers. Heh. That might be another interesting discussion. How people really approach solving problems.
The Sourcery - http://sourcery.dyndns.org
TeensyMud - http://teensymud.kicks-ass.org
"A man can receive nothing, except it be given him from heaven."


15. RE: RFC: new logging facility Mon Jul 19, 2004 [10:29 PM]
muir
Email not supplied
member since: Sep 14, 2003
In Reply To
Reply
(Responding to all posters on this one for space -gotta save it somewhere:)

Raz:
Not only do I gripe at the mass amount of templates (all C++ programmers should know about templates and compiler errors/warnings), --

Agreed. A single error message may take quite a few lines to decipher for the sheer volume of text; I parse compilation output through a small Ruby script that strips the extra stuff away if need be. I think GDB also has an extension that makes it easier to access breakpoints but I don't really use it that much.

Raz:
I guess I just wonder about the overall design. It looks like a logger, it acts like a logger, but the code makes me wonder if the logger's design has a bit more functionability that is really worthwhile to the common programmer.

It probably does (well, will) have more functionality than necessary: aim is to provide enough for everyone and the ability to 'turn off' what's not needed. Hopefully it'll work that way.

eiz:
Using the ufxlib network routines I could add network logging in about 30 lines of code.

I was actually going to point this out earlier. Rhetorically (since I know the file sizes) -how much will ufxlib add? Or ufxstring, to that?

eiz:
As for defensiveness: the only problem I have with the logger is that oversized code really irks me; there are a lot of excellent libraries that I don't like using just because they're too large.

I agree, although when using library code I usually judge the 'size' by how large the interface is and how much junk that A) I can't turn off and B) I don't need it comes with. A minimal interface is worth the struggle.

eiz:
Oh yes, one more thing I didn't see any way to accomplish with elflog: sending output from one logger to multiple destinations.

Well, that's why it's the 'direct' output model; it produces direct output. The interface for adding a combinatory/arbitrary model is simple: a method that takes a streamtype as a parameter (I decided I'll lump up all the stuff up under log, it'll be closer to a traditional policy-based design that way).

Raz:
multithreading?

That is the one thing that kills about this logger. While it is of some convience, I almost wonder if that is streching the purpose of a logger.

I think toggleable multithreading support is imperative for a general-purpose library (think of a webserver, for example). The idea behind the InputModel and log_streams is that a single log object can return an arbitrary amount of log_streams so multiple threads can output at the same time.

Raz:
the compiler will completely optimize away any log invocations that are below the defined logging level, which I consider to be a really nice feature for debugging.

Really? Out of curiosity, did you intentionally design this, or is this a compiler trick?

That was the entire premise for building the logger (the other parts came in sort of as afterthoughts): I wanted to put log statements in the code and not worry about #ifdef DEBUG statements or having to comment them out for production use. If you run the test script you'll see that the runtime for 10000 loops of output below the desired priority level is exactly 0 seconds.

Tyche:
I guess my view of C++ templates is that they are really esoteric features of C++. Most C++ programmers I know are comfortable using the STL, using templates to parameterize types and constructing function objects. However beyond that I know very few C++ programmers that go into the abstractions of concepts, modeling and refinement.

I think that's a tremendous loss: C++ templates are by far one of the most exciting programming language features to me, right up there with Ruby blocks, lazy evaluation, first-order functions, currying and lambda stuff.

Tyche:
That might be another interesting discussion. How people really approach solving problems.

And how they see problems where none exist :)

.




16. RE: RFC: new logging facility Mon Jul 19, 2004 [11:50 PM]
eiz
eiz@nospam_codealchemy.org
member since: Dec 24, 2002
In Reply To
Reply
I was actually going to point this out earlier. Rhetorically (since I know the file sizes) -how much will ufxlib add? Or ufxstring, to that?

I used something like 4 lines of code from ufxstring because I was too lazy to write the to_str template myself. The full size of ufxlib is somewhat hard to judge because there's no single version of it which contains everything, but the individual modules are, for the most part, very small. Aetas contains about 1700 lines of ufxlib code, total. That is networking, string handling, text layout, configuration, portable directory and time handling. Our old Deus code has maybe 3000 lines worth.

BTW, network logging turned out to be 27 lines. I was close.

I agree, although when using library code I usually judge the 'size' by how large the interface is and how much junk that A) I can't turn off and B) I don't need it comes with. A minimal interface is worth the struggle.

I judge the size of a library by the amount of code I have to read, and if I'm expected to extend something, that means "the whole thing". The amount of code to use the standard logger may be small, but to fully untangle all of the various components means wading through 4700 lines of massive templates. As I demonstrated, a minimal interface does not require a big library.


Well, that's why it's the 'direct' output model; it produces direct output. The interface for adding a combinatory/arbitrary model is simple: a method that takes a streamtype as a parameter (I decided I'll lump up all the stuff up under log, it'll be closer to a traditional policy-based design that way).

Setting up multiple output models using compile time polymorphism (just in case you're wondering, I did not mean output to multiple streams, I meant output to multiple models) would be an excruciating exercise in Alexandrescuism, and I'm not sure how you would do it with traditional methods in your framework, because everything is resolved at compile time. Please enlighten me.

That was the entire premise for building the logger (the other parts came in sort of as afterthoughts): I wanted to put log statements in the code and not worry about #ifdef DEBUG statements or having to comment them out for production use. If you run the test script you'll see that the runtime for 10000 loops of output below the desired priority level is exactly 0 seconds.

There is no way in hell I would leave a log message in a performance critical loop after I was done debugging it; it would render DEBUG-level logging useless for any other purpose, by sheer volume alone. Furthermore, it is not "completely" optimized away -- the log arguments are still evaluated, even if the actual logging is optimized out. What if my log output includes the result of an expensive function call? Now I'm worrying again. I was looking for a real life example of a function like this and I came up with:


std::string trace() {
void *funcs[1024];
std::string result;
char **res_c;
int i;
i = backtrace(funcs, 1024);
res_c = backtrace_symbols(funcs, i);
if (res_c == NULL)
return "<BACKTRACE UNAVAILABLE>";
for (int j = 0; j < i; ++j) {
result.append(res_c[j]);
result.append("\n");
}
free(res_c);
return result;
}


Now this is not really a very expensive function, so I wasn't going to use it as an example, but I tried plugging it into your logger and the formatter hung, used all my memory and crashed. When I put it in my logger, it worked fine, so I think you may have a problem. Example output:


./a.out(_ZStlsISt11char_traitsIcEERSt13basic_ostreamIcT_ES5_c+0x164) [0x804a564]
./a.out(strftime+0xb30) [0x804ac20]
/lib/tls/i686/cmov/libc.so.6(__libc_start_main+0xfa) [0x401237da]


So you might want to check that out.

I think that's a tremendous loss: C++ templates are by far one of the most exciting programming language features to me, right up there with Ruby blocks, lazy evaluation, first-order functions, currying and lambda stuff.


I am a huge fan of various obscure programming languages and metaprogramming, especially in Lisp. Nonetheless, I find this sort of template (ab)use horrifying: the benefits just are not worth the cost at this point, to me. That they obfuscate code is nearly undeniable.

And how they see problems where none exist :)

What is and is not a problem is frequently a matter of taste.

P.S. Those logging terminators really are a menace.

(Comment added by eiz on Tue Jul 20 0:55:09 2004)

Sorry, when I say "templates obfuscate code", read "template metaprogramming obfuscates code". I don't have anything against templates in general.


17. RE: RFC: new logging facility Sat Jul 24, 2004 [2:45 PM]
muir
Email not supplied
member since: Sep 14, 2003
In Reply To
Reply
Sorry. I need to get a job that pays one of these days :)

eiz:
Setting up multiple output models using compile time polymorphism (just in case you're wondering, I did not mean output to multiple streams, I meant output to multiple models) would be an excruciating exercise in Alexandrescuism, and I'm not sure how you would do it with traditional methods in your framework, because everything is resolved at compile time. Please enlighten me.

Everything doesn't have to be resolved compile-time. Outputting to multiple models is simple; just create a new model that can aggregate an arbitrary amount of simple models and iterate.

Furthermore, it is not "completely" optimized away -- the log arguments are still evaluated, even if the actual logging is optimized out.

Not necessarily; even the argument evaluation can be optimized out -even a function, particularly if it only uses local variables and returns a value.

Granted, generally I wouldn't put a log statement in a performance-critical section either (more likely just before and after).

Now this is not really a very expensive function, so I wasn't going to use it as an example, but I tried plugging it into your logger and the formatter hung, used all my memory and crashed.

Where did you plug it in? Did you just run it as a part of a statement or did you put it in the internals? I'll certainly check it out.

That [templates] obfuscate code is nearly undeniable.

I'd like to deny that. The only obfuscation, when templates are being used properly, comes from unfamiliarity.

.


18. RE: RFC: new logging facility Sat Jul 24, 2004 [5:48 PM]
eiz
eiz@nospam_codealchemy.org
member since: Dec 24, 2002
In Reply To
Reply
Everything doesn't have to be resolved compile-time. Outputting to multiple models is simple; just create a new model that can aggregate an arbitrary amount of simple models and iterate.

The problem is that your models are not polymorphic at runtime.

Not necessarily; even the argument evaluation can be optimized out -even a function, particularly if it only uses local variables and returns a value.

Yes, it can be, but in most cases it is not.

Where did you plug it in? Did you just run it as a part of a statement or did you put it in the internals? I'll certainly check it out.

In a log statement. Just "./" also did the trick. Actually, a . followed by any non-valid_eol character seems to do it. It was the paragraph-formatted argument. Also, you might want to consider not using a ^ delimiter internally - or at least document it =)

I'd like to deny that. The only obfuscation, when templates are being used properly, comes from unfamiliarity.

I corrected myself below. Not all templates obfuscate code, but many template techniques do. "Used properly?" Well, that's pretty subjective. Policy classes are one thing that I really don't like, not because it's a bad idea but because C++ doesn't provide adequate facilities for expressing their relations and ensuring their correctness. ML-style module signatures and type equations would be a nice start. There has been work on so-called concept checking in C++, but the current solutions are still just band-aids.

I've got one more question about your code: is single_queue supposed to be thread safe or not? If not, why does _queue_mutex exist? If so, forgetting the ctl::END token will result in the mutex never being unlocked, which of course will create interesting bugs at essentially arbitrary locations.


19. RE: RFC: new logging facility Sun Jul 25, 2004 [1:06 AM]
Tyche
Email not supplied
member since: Apr 4, 2000
In Reply To
Reply
Tyche:
I guess my view of C++ templates is that they are really esoteric features of C++. Most C++ programmers I know are comfortable using the STL, using templates to parameterize types and constructing function objects. However beyond that I know very few C++ programmers that go into the abstractions of concepts, modeling and refinement.


I think that's a tremendous loss: C++ templates are by far one of the most exciting programming language features to me, right up there with Ruby blocks, lazy evaluation, first-order functions, currying and lambda stuff.


It may be a loss, but maybe one day C++ will have features that allow concepts and requirements to be defined directly in the language. It's not beyond the realm of possibilty as it has been suggested. I suppose until then one necessarily restricts their audience. My pragmatism tells me that the gee whiz factor doesn't buy you anything. Remember KISS? ;-)


The Sourcery - http://sourcery.dyndns.org
TeensyMud - http://teensymud.kicks-ass.org
"A man can receive nothing, except it be given him from heaven."


20. RE: RFC: new logging facility Sun Jul 25, 2004 [4:54 PM]
muir
Email not supplied
member since: Sep 14, 2003
In Reply To
Reply
The problem is that your models are not polymorphic at runtime.


There's no need for them to be polymorphic.

In a log statement. Just "./" also did the trick. Actually, a . followed by any non-valid_eol character seems to do it. It was the paragraph-formatted argument. Also, you might want to consider not using a ^ delimiter internally - or at least document it =)

Ah yes. I meant to change the delimiter to a user-defined one or a nonprintable character but forgot about it, thanks. I'll take a look at the paragraph parser.

Policy classes are one thing that I really don't like, not because it's a bad idea but because C++ doesn't provide adequate facilities for expressing their relations and ensuring their correctness.

I don't see how you can justify that statement since all template constructs are checked for correctness at compile time. Any other errors are the exact same in nontemplate code. Relations are expressed just the same as any other relations in C++; inheritance, composition or aggregation.

-- is single_queue supposed to be thread safe or not? If not, why does _queue_mutex exist? If so, forgetting the ctl::END token will result in the mutex never being unlocked, which of course will create interesting bugs at essentially arbitrary locations.

Not strictly at arbitrary locations. It won't work, of course. The reason for the mutex --and actually ctl::END was to support a certain messaging idiom whereby statements such as message concatenation, partial and delayed output and such were possible. Didn't end up taking that route but the relics remained.

.


21. RE: RFC: new logging facility Sun Jul 25, 2004 [6:00 PM]
eiz
eiz@nospam_codealchemy.org
member since: Dec 24, 2002
In Reply To
Reply
There's no need for them to be polymorphic.

There is if you're going to aggregate arbitrary, heterogenous models at runtime.

I don't see how you can justify that statement since all template constructs are checked for correctness at compile time. Any other errors are the exact same in nontemplate code. Relations are expressed just the same as any other relations in C++; inheritance, composition or aggregation.

C++ does not provide adequate facilities for expressing these relations to the programmer. Inheritance through a template parameter, for example, provides no information on the expected signature of said parameter. At best it provides an argument with a similar name to the concept you're supposed to implement. This slows down comprehension as the reader has to go on a scavenger hunt either through the documentation (if you're lucky, it will exist, and if you're super lucky, it might even be accurate!) or the source code. Furthermore, this sort of inheritance often completely breaks the normal is-a relationship normally associated with inheritance.

Not strictly at arbitrary locations. It won't work, of course. The reason for the mutex --and actually ctl::END was to support a certain messaging idiom whereby statements such as message concatenation, partial and delayed output and such were possible. Didn't end up taking that route but the relics remained.

Essentially arbitrary locations. Obviously it will only occur the next time the logger is called, but that could be anywhere in a multithreaded system.


22. RE: RFC: new logging facility Sun Jul 25, 2004 [8:29 PM]
muir
Email not supplied
member since: Sep 14, 2003
In Reply To
Reply
There is if you're going to aggregate arbitrary, heterogenous models at runtime.

There's need for polymorphism, yes, but the models need not exhibit such so long as the combining container does. A naive implementation would simply have a PolymorphicOutputFunctor class subclassed for each type (which should be simple since the interface needs to be the same).

C++ does not provide adequate facilities for expressing these relations to the programmer. Inheritance through a template parameter, for example, provides no information on the expected signature of said parameter.


Compare it to a loosely-/non-typed language or inheriting from 'Object'.

Furthermore, this sort of inheritance often completely breaks the normal is-a relationship normally associated with inheritance.

Bad or unconventional design is not the fault of the paradigm and indeed there is nothing that encourages such design inherent about template metaprogramming. Furthermore Policy-based design in particular (as it was the topic) discourages unconventional inheritance -obviously in the aggregation-style policies (memory_policy_type * mempolicy;) but also in the traditional derivation-style (class pointer: public memory_policy_type).

Obviously it will only occur the next time the logger is called, but that could be anywhere in a multithreaded system.

Right, it doesn't even pretend to support multithreading -as you may witness with the lack of a Thread implementation bar the dummy.

.


23. RE: RFC: new logging facility Sun Jul 25, 2004 [10:27 PM]
eiz
eiz@nospam_codealchemy.org
member since: Dec 24, 2002
In Reply To
Reply
There's need for polymorphism, yes, but the models need not exhibit such so long as the combining container does. A naive implementation would simply have a PolymorphicOutputFunctor class subclassed for each type (which should be simple since the interface needs to be the same).

There is absolutely nothing "simple" about that. Try it out sometime. If it's more than 0 lines of code, it's not simple, because it should be completely unnecessary.

Compare it to a loosely-/non-typed language or inheriting from 'Object'.

Loosely typed and untyped languages don't generally have this sort of subtyping problem, for reasons which should be painfully obvious. Inheritance from Object is completely unrelated and I have no idea why you brought it up. When I compare parametric polymorphism, the standard is ML or Eiffel. C++ falls short of both in this respect.

Bad or unconventional design is not the fault of the paradigm and indeed there is nothing that encourages such design inherent about template metaprogramming. Furthermore Policy-based design in particular (as it was the topic) discourages unconventional inheritance -obviously in the aggregation-style policies (memory_policy_type * mempolicy;) but also in the traditional derivation-style (class pointer: public memory_policy_type).

I said "often". Policy inheritance tends to produce unconventional inheritance. Put simply, it is "backwards". Saying that some type is a subtype of every type (which is basically what you're doing when you inherit from an unconstrained template parameter) is, well, unconventional. And wrong (as your compiler will tell you very verbosely if instantiated with an incompatible type).

What is your reasoning behind policy-based design discouraging unusual inheritance? Your own logger design is a pretty solid example of the exact opposite.

Right, it doesn't even pretend to support multithreading -as you may witness with the lack of a Thread implementation bar the dummy.

Thank you for clarifying - I wasn't sure because of the presence of the mutex.


24. RE: Object-oriented design Mon Jul 26, 2004 [10:34 PM]
muir
Email not supplied
member since: Sep 14, 2003
In Reply To
Reply
There's need for polymorphism, yes, but the models need not exhibit such so long as the combining container does. A naive implementation would simply have a PolymorphicOutputFunctor class subclassed for each type (which should be simple since the interface needs to be the same).

There is absolutely nothing "simple" about that. Try it out sometime. If it's more than 0 lines of code, it's not simple, because it should be completely unnecessary.

I don't see why this is any less simple than your inheritance/polymorphism. A CompoundOutputModel takes any (other OutputModel) type as a parameter for aggregating other OutputModels; from it, a subclass of POFunctor is created and an instance created for storing insinde the COModel. Then when output is desired, the virtual execution will cause the right type of action to take place on each of the contained OutputModels.

Loosely typed and untyped languages don't generally have this sort of subtyping problem, for reasons which should be painfully obvious. Inheritance from Object is completely unrelated and I have no idea why you brought it up.

I think using templates is closer to 'true' object-orientation. Rather than enforcing rigid guidelines, the Caller simply assumes that the Receiver can handle what is tossed to it and will quickly learn if this is not the case -with templates, this occurs not runtime but compile-time.

Policy inheritance tends to produce unconventional inheritance. Put simply, it is "backwards". Saying that some type is a subtype of every type (which is basically what you're doing when you inherit from an unconstrained template parameter) is, well, unconventional. And wrong (as your compiler will tell you very verbosely if instantiated with an incompatible type).

I don't see how that's wrong. Take a SmartPointer class -in a completely nontemplate implementation, the SP will manage its memory, have a given ownership policy &c. No, it is not a OwnershipPolicy but it is an entity that provides OwnershipPolicy -so think of it as an Owner. Therefore, it's fully reasonable to expect that a policy-based implementation will also be an Owner and a Manager.

What is your reasoning behind policy-based design discouraging unusual inheritance? Your own logger design is a pretty solid example of the exact opposite.

Strict policy-based design requires rigorous discipline -orthogonality is key. If all policy guidelines are followed, the design will be good. No, it doesn't automatically make the code better -the implementer need spare some effort, too- but then again, mundane pointers can get you in a heap of trouble, too.

My particular design was not policy-based, but model-based as I pointed out in the first post (I think); it's more of a pragmatic than dogmatic implementation. Presently I am converting it to a traditional policy implementation which should be simpler to understand. Alternately I'm considering composing the object of Policy objects and may yet implement it that way if that fancy strikes.

.


25. RE: Object-oriented design Tue Jul 27, 2004 [2:17 AM]
eiz
eiz@nospam_codealchemy.org
member since: Dec 24, 2002
In Reply To
Reply

I don't see why this is any less simple than your inheritance/polymorphism. A CompoundOutputModel takes any (other OutputModel) type as a parameter for aggregating other OutputModels; from it, a subclass of POFunctor is created and an instance created for storing insinde the COModel. Then when output is desired, the virtual execution will cause the right type of action to take place on each of the contained OutputModels.


I dunno, it sounds more complicated than

class output_base {
public:
  virtual bool write_output(logger_base::log_level level,
                            logger_base::arg_list &args) = 0;
  virtual ~output_base() {}
};  


Maybe it's just me. Maybe it's that POFunctor subclassing deal.

I think using templates is closer to 'true' object-orientation.

I don't believe there's any such thing as 'true' object orientation, but I'm not going to dispute you either. My favorite object system so far is called Cecil, and it's nothing like C++-style OO.

I don't see how that's wrong. Take a SmartPointer class -in a completely nontemplate implementation, the SP will manage its memory, have a given ownership policy &c. No, it is not a OwnershipPolicy but it is an entity that provides OwnershipPolicy -so think of it as an Owner. Therefore, it's fully reasonable to expect that a policy-based implementation will also be an Owner and a Manager.

It's not wrong, just weird. Normally, subtyping is an is-a relationship. I should be able to use the subtype in place of the supertype. This is not the case with classes that inherit policies.

Strict policy-based design requires rigorous discipline -orthogonality is key. If all policy guidelines are followed, the design will be good.

Something can be unusual and still good. In this case, I don't feel the added complexity is worth it, but for smart pointers for example I believe it is (not that I use smart pointers... modern C++ programmers are such wusses!) I don't think you can produce a good design by just "following guidelines", either. A design can be as orthogonal and flexible and adherent to Best Practices(TM) and whatever as you want, and still be a horrible, horrible train wreck. Just look at Java.

My particular design was not policy-based...

Be that as it may, it's still unconventional (and I think my original problem was with unconstrained inheritance through a template parameter, not policy based design... but whatever). Have fun. You have weird template mania; I have Forth. I don't think we're going to reach a conclusion here.


Pages: 1 | 2



[Previous] [Next] [Post] [Reply] [Topics] [Summary] [Search]