Uploaded image for project: 'logback'
  1. logback
  2. LOGBACK-1118

logback.groovy/Gaffer variable scope is broken

    XMLWordPrintable

Details

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: Major Major
    • 1.5.12
    • 1.1.3
    • logback-classic
    • None

    Description

      The normal variable scope as expected in Groovy scripts does not work properly in logback.groovy. Declared variables are accessible in all parts of the script, whereas fields (using @Field annotation) and undeclared variables are only accessible in the top-level code and not in any pre-defined closures.

      The following sample logback.groovy shows this behaviour:

      import groovy.transform.Field
      
      // declared variable, will go into run method of compiled script class
      def PATH1 = "dir1"
      // declared field, will become a field of compiled script class
      @Field
      def PATH2 = "dir2"
      // undeclared variable, will go into script binding
      PATH3 = "dir3"
      
      appender("FILE", FileAppender) {
        file = "/${PATH1}/${PATH2}/${PATH3}/mylog.log"
        encoder(PatternLayoutEncoder) {
          pattern = "%msg%n"
        }
      }
      root(DEBUG, ["FILE"])
      

      The expected file path would be /dir1/dir2/dir3/mylog.log, but instead it is set to /dir1/null/null/mylog.log

      The following sample is a normal groovy script that shows scoping rules:

      import groovy.transform.Field
      
      def PATH1 = "dir1"
      @Field
      def PATH2 = "dir2"
      PATH3 = "dir3"
      
      String method1(Closure clos) {
      	println "Inside method1"
      	println "/<not in scope>/${PATH2}/${PATH3}/mylog.log"
      	clos()
      }
      
      clos1 = {clos ->
      	println "Inside clos1"
      	println "/${PATH1}/${PATH2}/${PATH3}/mylog.log"
      	clos()
      }
      	
      println "Script top-level code"
      	println "/${PATH1}/${PATH2}/${PATH3}/mylog.log"
      
      method1({
      	println "Closure passed into method1"
      	println "/${PATH1}/${PATH2}/${PATH3}/mylog.log"
      	})
      
      clos1({
      	println "Closure passed into clos1"
      	println "/${PATH1}/${PATH2}/${PATH3}/mylog.log"
      	})
      
      

      All printed paths show up as /dir1/dir2/dir3/mylog.log (expect for the println in method1 as PATH1 is not in scope as local variable of the script run method). This means that the different types of variables can be resolved, whether they are used in a closure passed into a method or into another closure.

      I found that the cause of this is in the ComponentDelegate class. All logback configuration components are represented as closures and the ComponentDelegate class is set as delegate of each component. The delegation strategy is changed to DELEGATE_FIRST, so that component specific fields and methods can be handled by ComponentDelegate via the missingMethod and missingProperty methods. However, when a property or method is found to be component specific , the code logs an error and simply returns. Choosing strategy DELEGATE_FIRST, would mean that if the delegate cannot find the method/field, the owner should be checked next. This is not done, because of the return. Instead, ComponentDelegate should throw a MissingMethodException/MissingPropertyException. This signals to the Closure (class) code that it should continue looking for the missing method/field. And this is where the field or undeclared variable are then found.

      Note that the strange behaviour for the hostname variable (a binding variable) as described in the documentation and also in LOGBACK-488 is caused by this as well. After applying the above fix, hostname simply resolves even when it is used in a closure.

      I have made a fix where both return statements are replaced with throwing mentioned exceptions. As the 2 error logs are no longer necessarily applicable, I have removed them (gave too much clutter in my opinion). Instead, for the MissingPropertyException, the same string as for the error log is used and eventually, if the property is never found, the same message comes out as an exception. The MissingMethodException has a fixed constructor signature, therefore this is followed. If a method is used, that is not found as part of the component (e.g. appender, encoder, etc) and not present in the script, then the not-found method comes out as an exception.
      In the same fix, I have updated 2 unit test input files as they referred to an unknown variable p. Before this would print out null, now it gives an exception back. Instead, I opted to print out the hostname variable instead.
      Also, I have updated the site documentation by removing the extra HOSTNAME workaround and by adding a section that explains about variable scope.

      Attachments

        Activity

          People

            logback-dev Logback dev list
            forsel Frans Orsel
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

              Created:
              Updated: