On Fri, Dec 19, 2014 at 9:36 PM, Andres Freund <
andres@2ndquadrant.com> wrote:
>
> Hi,
>
> When debugging lwlock issues I found PRINT_LWDEBUG/LOG_LWDEBUG rather
> painful to use because of the amount of elog contexts/statements
> emitted. Given the number of lwlock acquirations that's just not doable.
>
> To solve that during development I've solved that by basically
> replacing:
> if (Trace_lwlocks)
> elog(LOG, "%s(%s %d): %s", where, name, index, msg);
>
> with something like
>
> if (Trace_lwlocks)
> {
> ErrorContextCallback *old_error_context_stack;
> ...
> old_error_context_stack = error_context_stack;
> error_context_stack = NULL;
> ereport(LOG,
> (errhidestmt(true),
> errmsg("%s(%s %d): %s", where, T_NAME(lock),
> T_ID(lock), msg)));
>
> I think it'd generally be useful to have something like errhidecontext()
> akin to errhidestatement() to avoid things like the above.
>
Under this proposal, do you want to suppress the context/statement
unconditionally or via some hook/variable, because it might be useful to
print the contexts/statements in certain cases where there is complex
application and we don't know which part of application code causes
problem.
> The usecases wher eI see this as being useful is high volume debug
> logging, not normal messages...
>
I think usecase is valid, it is really difficult to dig such a log especially
when statement size is big. Also I think even with above, the number
of logs generated are high for any statement which could still make
debugging difficult, do you think it would be helpful if PRINT_LWDEBUG
and LOG_LWDEBUG are used with separate defines (LOCK_DEBUG and
LOCK_BLOCK_DEBUG) as in certain cases we might want to print info
about locks which are acquired after waiting or in other words that gets
blocked.
