[
https://issues.apache.org/jira/browse/OAK-2302?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14227373#comment-14227373
]
Chetan Mehrotra edited comment on OAK-2302 at 11/27/14 8:15 AM:
----------------------------------------------------------------
Patch which populates the MDC with following variable
* {{oak.query.id}} - Unique incrementing counter for current query being
executed. This can be used to corelate logs for single query statement from
different categories
* {{oak.query.debug}} - Set to true if either of {{explain}} or {{measure}} is
enabled
With above setup and following logback config
{code:xml}
<configuration>
<turboFilter class="ch.qos.logback.classic.turbo.DynamicThresholdFilter">
<Key>oak.query.debug</Key>
<DefaultThreshold>INFO</DefaultThreshold>
<MDCValueLevelPair>
<value>true</value>
<level>TRACE</level>
</MDCValueLevelPair>
</turboFilter>
<appender name="query" class="ch.qos.logback.core.FileAppender">
<file>target/unit-tests-query.log</file>
<encoder>
<pattern>%date{HH:mm:ss.SSS} %-5level %-40([%thread] %F:%L) %marker
%X{oak.query.id} %X{oak.query.debug} %msg%n
</pattern>
</encoder>
</appender>
<logger name="org.apache.jackrabbit.oak.query" level="DEBUG"
additivity="false">
<appender-ref ref="query"/>
</logger>
</configuration>
{code}
It makes use of
[DynamicThresholdFilter|http://logback.qos.ch/apidocs/ch/qos/logback/classic/turbo/DynamicThresholdFilter.html]
to set log level to TRACE if given MDC key value is found to be true
Debug level logs for {{org.apache.jackrabbit.oak.query}} would only be
generated for that thread and code path where the MDC {{oak.query.debug}} is
found to be true.
With this user gets precise logs and system would not be flooded with debug
level logs from all query executions
[~tmueller] Can you have a look. I would like it to be made part of 1.0 branch
to simplify query related debugging while using newer LucenePropertyIndex as it
generates quite a bit of logging
was (Author: chetanm):
Patch which populates the MDC with following variable
* {{oak.query.id}} - Unique incrementing counter for current query being
executed
* {{oak.query.debug}} - Set to true if either of {{explain}} or {{measure}} is
enabled
With above setup and following logback config
{code:xml}
<configuration>
<turboFilter class="ch.qos.logback.classic.turbo.DynamicThresholdFilter">
<Key>oak.query.debug</Key>
<DefaultThreshold>INFO</DefaultThreshold>
<MDCValueLevelPair>
<value>true</value>
<level>TRACE</level>
</MDCValueLevelPair>
</turboFilter>
<appender name="query" class="ch.qos.logback.core.FileAppender">
<file>target/unit-tests-query.log</file>
<encoder>
<pattern>%date{HH:mm:ss.SSS} %-5level %-40([%thread] %F:%L) %marker
%X{oak.query.id} %X{oak.query.debug} %msg%n
</pattern>
</encoder>
</appender>
<logger name="org.apache.jackrabbit.oak.query" level="DEBUG"
additivity="false">
<appender-ref ref="query"/>
</logger>
</configuration>
{code}
Debug level logs for {{org.apache.jackrabbit.oak.query}} would only be
generated for that thread and code path where the MDC {{oak.query.debug}} is
found to be true.
With this user gets precise logs and system would not be flooded with debug
level logs from all query executions
[~tmueller] Can you have a look. I would like it to be made part of 1.0 branch
to simplify query related debugging while using newer LucenePropertyIndex as it
generates quite a bit of logging
> Simplify query debugging with MDC
> ---------------------------------
>
> Key: OAK-2302
> URL: https://issues.apache.org/jira/browse/OAK-2302
> Project: Jackrabbit Oak
> Issue Type: Improvement
> Components: query
> Reporter: Chetan Mehrotra
> Priority: Minor
> Fix For: 1.0.9, 1.2
>
> Attachments: OAK-2302.patch
>
>
> QueryEngine in Oak has support for {{explain}} and {{measure}} to enable a
> user to determine how a query is executed by the engine. Result returned via
> explain call just tell what index would be used to execute the query. However
> often we need to see which all indexes were consulted and what cost were
> obtained from them.
> To get that data one has to enable debug level log for
> {{org.apache.jackrabbit.oak.query}}. Enabling them on a bigger system often
> results in lots of logs due to invocation of queries done by various part.
> Mostly the log is flooded with reference query invoked by authentication
> layer thus making it hard to find out relevant logs.
> To simplify getting only debug level logs for query which had explain enabled
> it would be helpful to provide support via MDC [1] (which is part of Slf4j
> API already being used in Oak)
> (patch and usage details to follow)
> [1] http://logback.qos.ch/manual/mdc.html
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
