[erlang-questions] Logger which truncates too big terms

[Robert Raschke]

Hi Jachym,

On Fri, Dec 2, 2011 at 6:30 PM, Jachym Holecek <freza@REDACTED> wrote:

> # Robert Raschke 2011-12-02:
> > Weeell, I think there is good cause for splitting logging into two parts:
> > 1. creating log entries and 2. presenting them for human consumption.
>
> Well, in principle that's a conceivable way to see things, however being
> an old UN*X-head I'm of the firm religious belief that logs should be
> ASCII text files, and I'm sure Operations would share that view. :-)
>

Yeah, I think if our dev had started in unix land, things would be similar.
But stuff grew mostly ad-hoc in the Windows universe. And the operations
people are pretty much all on the applications side of things, not sys
admins.


> > Doing this means that you can forget about any pretty-printing of log
> > messages at the point of their creation. Such, rather heavy, processing
> can
> > be deferred to the point of actually reading the log. The latter usually
> > being done off line anyway.
>
> But how heavy it is remains under your control. Pragmatic approach to
> log layout (when you can afford it) and embracing iolists from the start
> lower the price. You still need to be careful and sometimes move logging
> out of busy path and such, but that's a hard fact of nature the way I see
> it...
>
> Also, I prefer logs to be readily available right after the fact, already
> in their final shape, and inspectable with standard tools (as imperfect as
> they might be, I'd personally rather avoid reinventing them -- I miss grep
> especially dearly every time I'm confronted with binary SASL logs).
>

Dumping logs to text is available at any point from the app itself
(regardless of current state of the system, running or not). I have default
batch scripts to do that. Interestingly, since the logging itself is always
at debug level, the dumping to text is where you specify what level of
detail you require. So, very often I'll look at info and error messages
first, before deciding to drill down into the debug level.

Since the logging uses the standard error_logger_mf functionality, I do
sometimes run into the trouble of configuring the right size of the
rotating log. I've had cases where the load was so high that a 200 MB total
log would only hold an hours worth of logging. But then, that was sized
before I knew what would be thrown at the application.


> > I've started doing this by only ever logging lists of terms (using the
> > error_logger), always providing the module that is logging as part of
> this
> > list. I also have a modified rb (report browser) that will call a
> module's
> > format_log/1 function (if it exists) to take the logged list of terms and
> > return a pretty string.
>
> This introduces an opportunity for mismatch between actual log format
> and what the format_log/1 callback thinks, one that will be undetected
> until RB is started, no? Also, doesn't this dictate that logs only be
> analysed wherever you have full code of faulty node available? Such as
> *not* from your laptop in the middle of a business trip without access
> to deployment/development machines? Also, how well does this work with
> gigabytes of logged events when you need to analyze and fix the issue
> ASAP because every minute of downtime/fault is valued at roughly your
> annual salary?
>
> I have no trouble believing logs in some binary format could be a good
> choice for some particular problem domain, but I've never come across
> one of those in practice...
>

The fallback in the RB is to present the log just as it would without the
format_log/1 callback. So, yes, sometimes a change in the logging code will
result in un-pretty log reading output. But that usually only happens
during development, not in production.

For offline viewing, all I need is the ZIPed up log folder (error_logger_mf
logs ZIP up rather dramatically) and a local copy of the app.

I am currently experimenting with further event handlers registered beside
the standard error_logger_mf_dir I am currently using. This allows me to
provide further logs to go elsewhere. Doing this requires a bit of care
though, as I don't want to accidentally introduce a lot of overhead in the
logging phase. I've got a webmachine resource that simply scrolls the log
messages as they come. And I'm pretty sure I'll be looking at the syslog
logger soon, as well as a Windows Event logger (which we already use from
Lua, but not yet from Erlang directly).

Further bits of work are on the RB side, where I am probably looking at
providing some kind of web based viewer. I especially want to expose the RB
grep functionality more.

All this talk about logging, makes me think I should start a blog article.

/Robby
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://erlang.org/pipermail/erlang-questions/attachments/20111205/ac06edaa/attachment.htm>