REPOST: Musings on Rails and logging philosophies

[OK, since I stupidly posted this over the July 4th week[end] and got no
responses, let’s try it again…]

As a perpetual Rails dabbler, I make an awful lot of typical beginner
mistakes. And the logs are always either too verbose or too sparse to
help
me. And it started me thinking.

I came from one of the largest production OLTP systems in the world, and
the one thing that helped us manage troubleshooting in both development
and
production was extensive, obsessive, flexible logging. Every operation
was
logged. Every OS call was followed by an error check and a log message

and I mean EVERY call. On Stratus computers, s$sleep returns an error
code. In ten years, I never saw it return anything but zero, but you’d
better believe that every single s$sleep call was accompanied by a
conditional call to our log system.

Now, with Ruby’s support for exceptions, such paranoia may not seem
warranted. After all, if something wild happens, a subroutine can raise
an
exception, and it will get propagated back to something that logs it.
And
it’s true; the need for logging errors is strongly satisfied by
exceptions.

But errors are only one category of log messages. Warnings are an
excellent way to troubleshoot. For any error, I’d usually find four or
five related warnings that told me why the error occurred. And for
“stepping through” code after the fact, info and debug messages are
invaluable. Exceptions can’t help you here.

Obviously, you don’t want to pollute the log files with hundreds of
messages per second. So following such a “log everything” philosophy
requires a powerful log filtering system. It needs to handle multiple
source categories - exceptions, debug statements, database queries,
controller/action invocation. It needs to understand severity levels.
It
needs to allow flexible, conditional routing of these messages to a
database, log file, live output, or simply its own circular buffer. And
it
needs a good interface to manage that routing.

I think Rick Olsen’s ExceptionLogger is a great step toward such a
filtering system, and I’ve volunteered to contribute. But I realized
that
such an “ActiveLogging” engine would only solve part of the problem.
The
bigger problem, if you see it as a problem, is that Rails and its
applications would need to start logging many more operations. And that
would create a dependency on a plugin that’s not likely to become part
of
core, at least in its current database-dependent state.

I think it’s worth the time to create a core ActiveLogger plugin that
will
handle the message routing, with the defaults set to the existing log
files
at first. Then plugins, generators or engines could handle things like
database output (Rick’s plugin), e-mail notifications (Jamis’s), etc. A
bunch of non-invasive, logging-only patches could add the desired
logging
points to the Rails core.

I’d be willing to put in a few hours a day on this. As a Rails novice,
I
actually have a better feel for what log messages are missing from
Rails,
because at least once an hour I’m running into something that could use
them!

But maybe I’m thinking too hard. I have yet to run a true Rails
production
application, so I don’t know the true needs there. Maybe logging is
old-school, and YAGNI. I’ll post this on rails-core if there’s a
consensus, but I wanted to get some input first before I start tilting
at,
well, logging mills.

What do folks think?

Jay L.

Like you, I’m a rails dabbler with large systems experience.

You have my support on this. I find rails current logging to be
generally unhelpful. Better logging with plain language messages would
be nice. A good logging engine like you suggest is a good start.

I agree. Rails logging is very basic. It would be nice to have a
better system.

Richard
RogueWaveMarine.com

But maybe I’m thinking too hard. I have yet to run a true Rails production
application, so I don’t know the true needs there. Maybe logging is
old-school, and YAGNI. I’ll post this on rails-core if there’s a
consensus, but I wanted to get some input first before I start tilting at,
well, logging mills.

What do folks think?

Jay L.

+1

But if you do need it, by all means work on it. For what it’s worth,
you might look at the syslog logger that robot coop did. It may give
you some ideas on how to provide extended logging capabilities as an
addon: http://dev.robotcoop.com/Tools/

On Fri, 7 Jul 2006 22:01:13 -0500, Rick O. wrote:

But if you do need it, by all means work on it. For what it’s worth,
you might look at the syslog logger that robot coop did. It may give
you some ideas on how to provide extended logging capabilities as an
addon: http://dev.robotcoop.com/Tools/

Rick,

Thanks for the semi-encouragement :slight_smile: The big problem, I think, is that
for
such an extension to be useful and widely used, Rails itself needs a lot
more logging. I could do a proof-of-concept version that overrides some
key Rails routines to wrap them in log messages, but this doesn’t start
to
get really interesting until it’s actually into core, which is why I was
sending up a trial balloon.

I’m actually more interested to hear your (and similar) viewpoints than
those who agree with me - what facets of Rails do you feel have
eliminated
the need for such verbose logging?

Jay

What about log4r? It seems to be a framework ready to solve all of the
problems you mentioned…

Yes, if log4r is half as flexible as log4j, it should be flexible enough
for what the OP is describing.

Ken

On Wed, 12 Jul 2006 10:03:39 +0200, Kenneth L. wrote:

Yes, if log4r is half as flexible as log4j, it should be flexible enough
for what the OP is describing.

Ken

Robert J. wrote:

What about log4r? It seems to be a framework ready to solve all of the
problems you mentioned…

logr4 is wonderful! I don’t know how I missed it.

I think my ideal solution would be to:

  • Redirect Rails Logger into log4r
  • Create a web admin page for log4r like Rick’s exception logger
  • Wrap it all up into a plugin or engine.

Once I do that, then I will come back and take up the cause of how to
get
better logging rolled into the core itself - I don’t feel that this
should
stay in a plugin forever, for both technical and, er, “moral” reasons,
but
I realize that creating even an optional dependency on log4r could be
problematic for Rails.

If anyone’s interested in collaborating with me, drop me a line at “jay
at
jay dot eff-emm”.

Jay L.