Re: quieting DEBUG3

From: Craig Ringer <craig(at)2ndquadrant(dot)com>
To: Robert Haas <robertmhaas(at)gmail(dot)com>, PostgreSQL Hackers <pgsql-hackers(at)postgresql(dot)org>
Subject: Re: quieting DEBUG3
Date: 2015-10-28 00:16:39
Message-ID: CAMsr+YHvpHWXeZcqoLHGoZJhMmDkh_JsU+g2EqeSRvf=yOS4dg@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

On 28 October 2015 at 04:52, Robert Haas <robertmhaas(at)gmail(dot)com> wrote:

> Thoughts?

I agree with you that DEBUG3 is currently impractical. So much so that
when testing/debugging I often change log severities of messages of
interest so they'll show up at DEBUG2 instead, rather than running in
DEBUG3.

Simplifying the StartTransaction log to a single message line is
clearly sensible.

I tend to see a lot of:

DEBUG: StartTransactionCommand
DEBUG: StartTransaction
DEBUG: name: unnamed; blockState: DEFAULT; state: INPROGR,
xid/subid/cid: 0/1/0, nestlvl: 1, children:
DEBUG: ProcessUtility
DEBUG: CommitTransactionCommand
DEBUG: StartTransactionCommand
DEBUG: ProcessQuery
DEBUG: CommitTransactionCommand
DEBUG: StartTransactionCommand
DEBUG: ProcessQuery
DEBUG: CommitTransactionCommand
DEBUG: StartTransactionCommand
DEBUG: ProcessUtility
DEBUG: CommitTransactionCommand
DEBUG: CommitTransaction
DEBUG: name: unnamed; blockState: END; state: INPROGR,
xid/subid/cid: 3778/1/2, nestlvl: 1, children:

It's pretty spammy, and the StartTransactionCommand /
CommitTransactionCommand entries don't seem to add any useful
information.

I'm not so sure about bumping transaction tracing down to DEBUG5,
given that transaction control is pretty important, and can be an
issue when chasing problems with cache accesses, etc. There's a lot of
other output, too, and once simplified to one line I think it's
reasonable to retain at DEBUG3.

I'd be pretty happy to get:

DEBUG: StartTransaction(1): blockState: DEFAULT; state: INPROGR,
xid/subid/cid: 0/1/0
DEBUG: ProcessUtility
DEBUG: ProcessQuery
DEBUG: ProcessQuery
DEBUG: ProcessUtility
DEBUG: CommitTransaction(1): blockState: END; state: INPROGR,
xid/subid/cid: 3778/1/2

instead.

I think it'd be helpful to define some level of policy about what the
debug levels are intended for, so there's some guidance on what level
to emit messages on rather than playing "pick a number". But that
shouldn't hold up the simplifications you propose here, except maybe
the DEBUG3 to DEBUG5 change.

--
Craig Ringer http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

In response to

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Tom Lane 2015-10-28 00:48:17 Re: [COMMITTERS] pgsql: Cleanup commit timestamp module activaction, again
Previous Message Robert Haas 2015-10-28 00:04:12 Re: Parallel Seq Scan