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.