logback source code analysis-2, appender parsing

Posted by kumaran on Fri, 10 May 2019 09:24:03 +0200

Source code based on logback 1.1.2

The logback.xml file is as follows

<?xml version="1.0"?>
<configuration scan="true" scanPeriod="30 seconds">
    <property name="fileDir" value="/export/log/ingoreTest"/>
    <appender name="debugFile" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${fileDir}/debug.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <FileNamePattern>${fileDir}/debug.%d{yyyy-MM-dd}.log</FileNamePattern>
            <MaxHistory>30</MaxHistory>
        </rollingPolicy>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>DEBUG</level>
            <onMatch>NEUTRAL</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
        <filter class="com.example.IgnoreFilter">
            <ignorePolicy class="com.example.IgnorePolicy">
                <methodPrefix class="com.example.MethodPrefix">
                    <array class="com.example.Array">
                        <value>1</value>
                        <value>2</value>
                        <value>3</value>
                    </array>
                </methodPrefix>
            </ignorePolicy>
        </filter>
        
        <encoder>
            <pattern>%date [%thread] %-5level %logger{80} - %msg%n</pattern>
        </encoder>
    </appender>

    <root>
        <level value="DEBUG"/>
        <appender-ref ref="debugFile"/>
    </root>
</configuration>

Here's how loaback parses appender:

1. When the appender tag is parsed, trigger the appender's startEvent, and finally call the begin method of the corresponding AppenderAction of [configuration][appender]:

public void begin(InterpretationContext ec, String localName,
      Attributes attributes) throws ActionException {
    // We are just beginning, reset variables
    appender = null;
    inError = false;
    //Get the type of appender, such as ch.qos.logback.core.rolling.RollingFileAppender 
    String className = attributes.getValue(CLASS_ATTRIBUTE);
    if (OptionHelper.isEmpty(className)) {
      addError("Missing class name for appender. Near [" + localName
          + "] line " + getLineNumber(ec));
      inError = true;
      return;
    }

    try {
      addInfo("About to instantiate appender of type [" + className + "]");
      //Initialize an appender instance based on appender's className
      appender = (Appender<E>) OptionHelper.instantiateByClassName(className,
          ch.qos.logback.core.Appender.class, context);

      appender.setContext(context);
       //Get the appender tag name attribute 
      String appenderName = ec.subst(attributes.getValue(NAME_ATTRIBUTE));

      if (OptionHelper.isEmpty(appenderName)) {
        addWarn("No appender name given for appender of type " + className
            + "].");
      } else {
        //Setting the name variable of the appender instance
        appender.setName(appenderName);
        addInfo("Naming appender as [" + appenderName + "]");
      }

      // The execution context contains a bag which contains the appenders
      // created thus far.
      //The appender instances created are later maintained in appenderBag of ec's objectMap 
      HashMap<String, Appender<E>> appenderBag = (HashMap<String, Appender<E>>) ec.getObjectMap().get(
          ActionConst.APPENDER_BAG);

      // add the appender just created to the appender bag.
      appenderBag.put(appenderName, appender);
      //Push the appender instance into ec's objectStack 
      ec.pushObject(appender);
    } catch (Exception oops) {
      inError = true;
      addError("Could not create an Appender of type [" + className + "].",
          oops);
      throw new ActionException(oops);
    }
  }

2.[configuration][appender]startEvent is the startEvent of [configuration][appender][file], but [configuration][appender][file] has no corresponding action. According to previous rules, file has no embedded elements and uses implicit action: Nested Basic Property IA. But the begin of Nested Basic Property IA is empty, that is, it does not do any processing.  
3.[configuration][appender][file] after the start Event, should be [configuration][appender][file] of the body Event, eventually will call the NestedBasicProperty IA body method:

public void body(InterpretationContext ec, String body) {
    //Get the body of the file, that is, ${fileDir}/debug.log
    String finalBody = ec.subst(body);
    // get the action data object pushed in isApplicable() method call
    //actionData maintains three properties: 
    //1.parentBean: Attributes associated with parent element instances, where the file parent is an appender instance 
    //2.aggregationType: The action type of the element path, and the action of [configuration][appender][file] belongs to 
      AS_BASIC_PROPERTY type 
    //3.propertyName: A name that acts as a parent instance property or can be converted into a setXX form. Here is the file. The appender instance has an attribute called file. 
      //Or the setFile approach 
    //This action data is pushed into action DataStack when finding the corresponding action and deciding that the action of the mapping is implicit action. 
    IADataForBasicProperty actionData = (IADataForBasicProperty) actionDataStack.peek();
    switch (actionData.aggregationType) {
    case AS_BASIC_PROPERTY:
      //Setting the attribute value of the parent label instance with reflection, in this case fileName is set by calling the setFile method of the appender instance 
      actionData.parentBean.setProperty(actionData.propertyName, finalBody);
      break;
    case AS_BASIC_PROPERTY_COLLECTION:
      actionData.parentBean
          .addBasicProperty(actionData.propertyName, finalBody);
    }

4.[configuration][appender][file] bodyEvent is the endEvent of [configuration][appender][file], which eventually calls the end method of NestedBasicPropertyIA:

public void end(InterpretationContext ec, String tagName) {
    // pop the action data object pushed in isApplicable() method call
    //The above comment is clear, popping up the action data pushed in when looking for the corresponding action 
    actionDataStack.pop();
  }

5. The end Event of [configuration] [appender] [file] is the start Event of [configuration] [appender] [rolling policy]. The corresponding action of [configuration] [appender] [rolling policy] is NestedComplexPropertyIA. Let's look at NestedComplexPropertyIA's begin method.

public void begin(InterpretationContext ec, String localName,
      Attributes attributes) {
    // LogLog.debug("in NestComponentIA begin method");
    // get the action data object pushed in isApplicable() method call
    //actionData maintains four main attributes: 
    //1.parentBean: Attributes related to parent element instances, where rolling Policy parent is appender instance 
    //2.aggregationType: the action type of the element path, the action genus of [configuration] [appender] [rolling policy] 
      //Type AS_COMPLEX_PROPERTY 
    //3.propertyName: As the name of the parent instance property, here is rollingPolicy. The appender instance has an attribute called rollingPolicy. 
    //4. nested ComplexProperty: Object instantiated according to class attribute, here is TimeBasedRollingPolicy instance object 
    IADataForComplexProperty actionData = (IADataForComplexProperty) actionDataStack
        .peek();
    //Get the class attribute value, which is ch. qos. logback. core. rolling. TimeBasedRolling Policy 
    String className = attributes.getValue(CLASS_ATTRIBUTE);
    // perform variable name substitution
    className = ec.subst(className);

    Class<?> componentClass = null;
    try {

      if (!OptionHelper.isEmpty(className)) { 
        //Instantiate TimeBasedRolling Policy
        componentClass = Loader.loadClass(className, context);
      } else {
        // guess class name via implicit rules
        PropertySetter parentBean = actionData.parentBean;
        componentClass = parentBean.getClassNameViaImplicitRules(actionData
            .getComplexPropertyName(), actionData.getAggregationType(), ec
            .getDefaultNestedComponentRegistry());
      }

      if (componentClass == null) {
        actionData.inError = true;
        String errMsg = "Could not find an appropriate class for property ["
            + localName + "]";
        addError(errMsg);
        return;
      }

      if (OptionHelper.isEmpty(className)) {
        addInfo("Assuming default type [" + componentClass.getName()
            + "] for [" + localName + "] property");
      }
      //Store the TimeBasedRollingPolicy instance object in the nestedComplexProperty attribute of actionData 
      actionData.setNestedComplexProperty(componentClass.newInstance());

      // pass along the repository
      if (actionData.getNestedComplexProperty() instanceof ContextAware) {
        ((ContextAware) actionData.getNestedComplexProperty())
            .setContext(this.context);
      }
      //addInfo("Pushing component [" + localName
      //    + "] on top of the object stack.");
      //Push the TimeBasedRollingPolicy instance object into the objectStack of ec.
      ec.pushObject(actionData.getNestedComplexProperty());

    } catch (Exception oops) {
      actionData.inError = true;
      String msg = "Could not create component [" + localName + "] of type ["
          + className + "]";
      addError(msg, oops);
    }

  }

6. [configuration] [appender] [rolling policy] is the startEvent of [configuration] [appender] [rolling policy] [fileNamePattern], which eventually calls the NestedBasicPropertyIA's start method, which is empty.  
7. [configuration] [appender] [rolling policy] [fileNamePattern] is the body Event of [configuration] [appender] [rolling policy] [fileNamePattern], which eventually calls the body method of NestedBasicPropertyIA. According to step 3 above, the body method of NestedBasicPropertyIA mainly takes out the value of the current element and sets it to an attribute of the parent element. The current element name is fileNamePattern, and the parent element is rolling Policy. setFileNamePattern, which invokes the instance of the parent element by reflection, passes in the value of fileNamePattern.  
8. [configuration] [appender] [rolling policy] [fileNamePattern] bodyEvent is the endEvent of [configuration] [appender] [rolling policy] [fileNamePattern], which eventually calls the end method of NestedBasic Property IA, which simply pops up the actionData corresponding to the element path.  
9. Next comes [configuration] [appender] [rolling policy] [maxHistory]. The logic is basically the same as fileName Patterns, and readers can debug it themselves.  
10. [configuration] [appender] [rolling Policy] after the embedded elements are processed, it triggers its endEvent method, and eventually calls the end method of NestedComplexPropertyIA:

 public void end(InterpretationContext ec, String tagName) {

    // pop the action data object pushed in isApplicable() method call
    // we assume that each this begin
    IADataForComplexProperty actionData = (IADataForComplexProperty) actionDataStack
        .pop();

    if (actionData.inError) {
      return;
    }
    //Building nested Bean of rolling Policy 
    PropertySetter nestedBean = new PropertySetter(actionData
        .getNestedComplexProperty());
    nestedBean.setContext(context);

    // have the nested element point to its parent if possible
    //If there are attributes within the instance of the embedded element pointing to its parent element, the parent attribute of the instance corresponding to the embedded element needs to be set to the instance of the parent element. 
    //The embedded element instance here is TimeBasedRollingPolicy, setting the parent value of TimeBasedRollingPolicy to RollingFileAppender 
      //Example
    if (nestedBean.computeAggregationType("parent") == AggregationType.AS_COMPLEX_PROPERTY) {
      nestedBean.setComplexProperty("parent", actionData.parentBean.getObj());
    }

    // start the nested complex property if it implements LifeCycle and is not
    // marked with a @NoAutoStart annotation
    //Get an instance of TimeBasedRollingPolicy from actionData and call its start method 
    Object nestedComplexProperty = actionData.getNestedComplexProperty();
    if (nestedComplexProperty instanceof LifeCycle
        && NoAutoStartUtil.notMarkedWithNoAutoStart(nestedComplexProperty)) {
      ((LifeCycle) nestedComplexProperty).start();
    }

    Object o = ec.peekObject();

    if (o != actionData.getNestedComplexProperty()) {
      addError("The object on the top the of the stack is not the component pushed earlier.");
    } else {
      ec.popObject();
      // Now let us attach the component
      switch (actionData.aggregationType) {
      case AS_COMPLEX_PROPERTY:
        //The set${TagName} method calling the parent element instance of the element stores the corresponding instance of the current element into the parent element instance. 
        //Here is the RollingFileAppender instance that calls the setRollingPolicy method to pass in the TimeBasedRollingPolicy instance 
        actionData.parentBean.setComplexProperty(tagName, actionData
            .getNestedComplexProperty());

        break;
      case AS_COMPLEX_PROPERTY_COLLECTION:
        actionData.parentBean.addComplexProperty(tagName, actionData
            .getNestedComplexProperty());

        break;
      }
    }
  }

11. [configuration] [appender] [rolling policy] ends with LevelFilter, the first filter of [configuration][appender][filter], which has no specified action and is judged to be NestedComplex Property IA. The processing method is consistent with the previous rolling policy.

12. After the LevelFilter parsing is completed, it is the [configuration][appender][filter] IgnoreFilter. This element has no specified action, and eventually calls the begin method of NestedComplexPropertyIA.

13. Parse [configuration][appender][filter][IgnorePolicy], this element does not specify an action, and eventually calls NestedComplexPropertyIA's begin method

14. Resolve [configuration][appender][filter][IgnorePolicy][methodPrefix], which has no specified action, and eventually invoke NestedComplexPropertyIA's begin method

14. Resolve [configuration][appender][filter][IgnorePolicy][methodPrefix][array], which has no specified action and eventually calls the begin method of NestedComplexPropertyIA

15. Resolve [configuration][appender][filter][IgnorePolicy][methodPrefix][array][value]. This element has no specified action, and eventually calls the body method of NestedBasic Property IA, which is AS_BASIC_PROPERTY_COLLECTION according to aggregationType.

public void body(InterpretationContext ec, String body) {

    String finalBody = ec.subst(body);
    // get the action data object pushed in isApplicable() method call
    IADataForBasicProperty actionData = (IADataForBasicProperty) actionDataStack.peek();
    switch (actionData.aggregationType) {
    case AS_BASIC_PROPERTY:
      actionData.parentBean.setProperty(actionData.propertyName, finalBody);
      break;
    //Enter when multiple values are encountered
    case AS_BASIC_PROPERTY_COLLECTION:
      actionData.parentBean
          .addBasicProperty(actionData.propertyName, finalBody);
    }
  }

How do I determine aggregationType types here? From NestedBasic Property IA's isApplicable method

public boolean isApplicable(ElementPath elementPath, Attributes attributes,
      InterpretationContext ec) {
    // System.out.println("in NestedSimplePropertyIA.isApplicable [" + pattern +
    // "]");
    String nestedElementTagName = elementPath.peekLast();

    // no point in attempting if there is no parent object
    if (ec.isEmpty()) {
      return false;
    }

    Object o = ec.peekObject();
    PropertySetter parentBean = new PropertySetter(o);
    parentBean.setContext(context);
    //Computing aggregationType 
    AggregationType aggregationType = parentBean
        .computeAggregationType(nestedElementTagName);

    switch (aggregationType) {
    case NOT_FOUND:
    case AS_COMPLEX_PROPERTY:
    case AS_COMPLEX_PROPERTY_COLLECTION:
      return false;

    case AS_BASIC_PROPERTY:
    case AS_BASIC_PROPERTY_COLLECTION:
      IADataForBasicProperty ad = new IADataForBasicProperty(parentBean,
          aggregationType, nestedElementTagName);
      actionDataStack.push(ad);
      // addInfo("NestedSimplePropertyIA deemed applicable [" + pattern + "]");
      return true;
    default:
      addError("PropertySetter.canContainComponent returned " + aggregationType);
      return false;
    }
  }

computeAggregationType() is to compute aggregationType.

parentBean is the parent element <array class="com.example.Array"> </array> class com.example.Array

16. Resolve [configuration][appender][filter][IgnorePolicy] [method Prefix] [array] [value], [configuration][appender][filter][IgnorePolicy] [method Prefix] [array], [configuration][appender][filter][IgnorePolicy] [method Prefix], [configuration][appender][filter][IgnorePolicy] [method Prefix], [configuration][appender][filter][IgnorePolicy] and [configuration][appender][filter] respectively.

17.[configuration][appender][filter] ends with [configuration][appender][encoder], mainly setting the log output format.

18. Finally, the endEvent of [configuration][appender] will call the end method of AppenderAction:
 

  /**
   * Once the children elements are also parsed, now is the time to activate the
   * appender options.
   */
  //It's time to activate appender's end operation when the child elements are parsed. 
  public void end(InterpretationContext ec, String name) {
    if (inError) {
      return;
    }

    if (appender instanceof LifeCycle) {
      //start method to trigger appender: Open the output Stream of the output log file and set it to encoder. Later log records are delegated to encoder for processing. 
      ((LifeCycle) appender).start();
    }
    //First, take out the appender instance of objectStack in ec to judge whether it pops up prematurely and then it really pops up.
    Object o = ec.peekObject();

    if (o != appender) {
      addWarn("The object at the of the stack is not the appender named ["
          + appender.getName() + "] pushed earlier.");
    } else {
      ec.popObject();
    }
  }

Topics: Programming Attribute xml