Re: logging full queries separately

From: Charles Sprickman <spork(at)biglist(dot)com>
To: John Rouillard <rouilj(at)renesys(dot)com>
Cc: pgsql-admin(at)postgresql(dot)org
Subject: Re: logging full queries separately
Date: 2013-02-27 10:52:49
Message-ID: 2D6ECD19-EFF2-4BBC-BB6D-FE7E56DA78EA@biglist.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-admin

On Feb 25, 2013, at 9:59 AM, John Rouillard wrote:

> On Sat, Feb 23, 2013 at 12:55:07AM -0500, Charles Sprickman wrote:
>> [...]
>> The one huge downside to this is that the logs are so noisy, it's
>> hard to track down errors and stats real-time since the query logging
>> is so noisy.
>> [...]
>> Right now I'm considering just switching to syslog-ng or rsyslog
>> and seeing if there's a way I can parse the non-query messages
>> out and dump them in another logfile… Any pointers on that?
>
> I use SEC for log analysis and I identify query logs by looking for
> the duration entry in the first line. Then pull the triplet of:
>
> hostname, pid and log line id (the 5 in [5-2], [5-3] etc.)
>
> and find all the rest of the lines by matching that triplet.

I'm having sort of the opposite problem - for pgbadger, I simply log
everything and that's easy enough.

For real-time human consumption, I want to filter out all the
statements so I'm just left with errors, periodic stats, notices of
temporary tables being created, etc. But what really screws me up
on that match is the multi-line output:

Feb 19 05:06:16 j15 postgres[32818]: [28-2] db=collects,user=collects STATEMENT: select count(distinct s.sub_id) as subscribers, count(distinct ls.id) as subscriptions
Feb 19 05:06:16 j15 postgres[32818]: [28-3] from list l
Feb 19 05:06:16 j15 postgres[32818]: [28-4] join list_sub ls on (l.list_id = ls.list_id)

First line, easy enough, if I see "STATEMENT", throw it away.

It's those next two lines. And rsyslog is doing line-by-line
processing on filters.

I suppose my other option is to find every possible prefix
(STATEMENT, LOG, ERROR, and who knows how many others) and do a
positive match for all of those rather than trying to negate the
statements.

Does any of that make sense?

Here's a rough example in rsyslog's config format:

} else if $fromhost-ip == '10.99.88.22' then {
local0.* /var/log/j15/pgsql-full
if not $msg contains 'STATEMENT' then /var/log/j15/pgsql-brief
}

I suspect I'm going to have to instead explicitly match everything
that's not a "STATEMENT". Just need to figure out what the full
list is. I think that part of the log line corresponds to "%i" in
log_line_prefix.

Thanks,

Charles

>
>> Without breaking compatibility with pgbadger, what
>> log_line_prefix might make it easier to pick out
>> statements (even when they span multiple lines)?
>
> Just for reference I use:
>
> '%t %u(at)%d(%p): '
>
> --
> -- rouilj
>
> John Rouillard System Administrator
> Renesys Corporation 603-244-9084 (cell) 603-643-9300 x 111
>
>
> --
> Sent via pgsql-admin mailing list (pgsql-admin(at)postgresql(dot)org)
> To make changes to your subscription:
> http://www.postgresql.org/mailpref/pgsql-admin

In response to

Responses

Browse pgsql-admin by date

  From Date Subject
Next Message John Rouillard 2013-02-27 16:08:40 Re: logging full queries separately
Previous Message Albe Laurenz 2013-02-27 08:58:45 Re: Postgres point-in-time recovery failure