[Rails] Musings about Rails and Logging and philosophy

Jay Levitt
2006-07-01T14:28:00Z

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 Levitt