Uploaded image for project: 'Solr'
  1. Solr
  2. SOLR-12344

SolrSlf4jReporter doesn't set MDC context

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 7.5
    • Component/s: metrics
    • Labels:
      None

      Description

      I setup a slf4j reporter like this on master

      solr.xml

      <metrics>
        <reporter name="log_update_stats" group="core" class="org.apache.solr.metrics.reporters.SolrSlf4jReporter">
          <int name="period">1</int>
          <str name="filter">UPDATE./update.requestTimes</str>
          <str name="logger">update_logger</str>
        </reporter>
      </metrics>

      log4j2.xml

      <?xml version="1.0" encoding="UTF-8"?>
      <!--
        Licensed to the Apache Software Foundation (ASF) under one or more
        contributor license agreements.  See the NOTICE file distributed with
        this work for additional information regarding copyright ownership.
        The ASF licenses this file to You under the Apache License, Version 2.0
        (the "License"); you may not use this file except in compliance with
        the License.  You may obtain a copy of the License at
      
            http://www.apache.org/licenses/LICENSE-2.0
      
        Unless required by applicable law or agreed to in writing, software
        distributed under the License is distributed on an "AS IS" BASIS,
        WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
        See the License for the specific language governing permissions and
        limitations under the License.
        -->
      
      <Configuration>
        <Appenders>
          <Console name="STDOUT" target="SYSTEM_OUT">
            <PatternLayout>
              <Pattern>
                %-4r [%t] %-5p %c %x [%X{collection} %X{shard} %X{replica} %X{core}] %c; %m%n
              </Pattern>
            </PatternLayout>
          </Console>
          <RollingFile
              name="RollingFile"
              fileName="${sys:solr.log.dir}/solr.log"
              filePattern="${sys:solr.log.dir}/solr.log.%i" >
            <PatternLayout>
              <Pattern>
                %-5p - %d{yyyy-MM-dd HH:mm:ss.SSS}; [%X{collection} %X{shard} %X{replica} %X{core}] %c; %m%n
              </Pattern>
            </PatternLayout>
            <Policies>
              <OnStartupTriggeringPolicy />
              <SizeBasedTriggeringPolicy size="32 MB"/>
            </Policies>
            <DefaultRolloverStrategy max="10"/>
          </RollingFile>
          <RollingFile
              name="RollingMetricFile"
              fileName="${sys:solr.log.dir}/solr_metric.log"
              filePattern="${sys:solr.log.dir}/solr_metric.log.%i" >
            <PatternLayout>
              <Pattern>
                %-5p - %d{yyyy-MM-dd HH:mm:ss.SSS}; [%X{collection} %X{shard} %X{replica} %X{core}] %c; %m%n
              </Pattern>
            </PatternLayout>
            <Policies>
              <OnStartupTriggeringPolicy />
              <SizeBasedTriggeringPolicy size="32 MB"/>
            </Policies>
            <DefaultRolloverStrategy max="10"/>
          </RollingFile>
        </Appenders>
        <Loggers>
          <Logger name="org.apache.hadoop" level="warn"/>
          <Logger name="org.apache.solr.update.LoggingInfoStream" level="off"/>
          <Logger name="org.apache.zookeeper" level="warn"/>
      
          <Logger name="update_logger" level="info" additivity="false">
            <AppenderRef ref="RollingMetricFile"/>
          </Logger>
      
          <Root level="info">
            <AppenderRef ref="RollingFile"/>
            <AppenderRef ref="STDOUT"/>
          </Root>
        </Loggers>
      </Configuration>
      

      The output I get from the solr_metric.log file is like this

      INFO  - 2018-05-11 15:31:16.009; [   ] update_logger; type=TIMER, name=UPDATE./update.requestTimes, count=0, min=0.0, max=0.0, mean=0.0, stddev=0.0, median=0.0, p75=0.0, p95=0.0, p98=0.0, p99=0.0, p999=0.0, mean_rate=0.0, m1=0.0, m5=0.0, m15=0.0, rate_unit=events/second, duration_unit=milliseconds
      
      INFO  - 2018-05-11 15:31:17.010; [   ] update_logger; type=TIMER, name=UPDATE./update.requestTimes, count=0, min=0.0, max=0.0, mean=0.0, stddev=0.0, median=0.0, p75=0.0, p95=0.0, p98=0.0, p99=0.0, p999=0.0, mean_rate=0.0, m1=0.0, m5=0.0, m15=0.0, rate_unit=events/second, duration_unit=milliseconds
      
      INFO  - 2018-05-11 15:31:18.010; [   ] update_logger; type=TIMER, name=UPDATE./update.requestTimes, count=0, min=0.0, max=0.0, mean=0.0, stddev=0.0, median=0.0, p75=0.0, p95=0.0, p98=0.0, p99=0.0, p999=0.0, mean_rate=0.0, m1=0.0, m5=0.0, m15=0.0, rate_unit=events/second, duration_unit=milliseconds

      On a JVM which has multiple cores, this will become impossible to tell where it's coming from if MDC context is not set

        Attachments

        1. SOLR-12344.patch
          8 kB
          Andrzej Bialecki

          Activity

            People

            • Assignee:
              ab Andrzej Bialecki
              Reporter:
              varunthacker Varun Thacker
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: