[jira] [Comment Edited] (GROOVY-6932) @Log annotation does not check logging enablement inside closures

["Michael Kohout (JIRA)" <ji...@apache.org>]

    [ https://issues.apache.org/jira/browse/GROOVY-6932?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15830298#comment-15830298 ] 

Michael Kohout edited comment on GROOVY-6932 at 1/19/17 5:33 PM:
-----------------------------------------------------------------

I'm still not seeing this issue fixed-it still evaluates the strings in the levels not enabled.  Here's a Spock test that duplicates this issue.

This is with the just released Groovy 2.4.8 and slf4j 1.7.21.

Is there something I don't understand about how Groovy should build GroovyStrings?

See my attached Spec.


was (Author: mwkohout):
I'm still not seeing this issue fixed-it still evaluates the strings in the levels not enabled.  Here's a Spock test that duplicates this issue.

This is with the just released Groovy 2.4.8 and slf4j 1.7.21.

Is there something I don't understand about how Groovy should build GroovyStrings?


import groovy.util.logging.Slf4j
import spock.lang.Specification

@Slf4j
class LoggingSpec extends Specification {


    def "makes sure groovy isn't building the string inside inactive log levels"() {
        assert log.isDebugEnabled() == false, "set the log level for this class to INFO to see the horror"
        assert log.isInfoEnabled() == true, "set the log level for this class to INFO to see the horror"

        CountingDoIt counter = new CountingDoIt()

        //http://docs.groovy-lang.org/docs/groovy-2.4.5/html/documentation/#_logging_improvements
        when: "we shouldn't evaluate"
        log.debug("this shouldn't happen ${counter.call()}".toString())
        then:
        counter.count == 0

        when: "we should evaluate"
        counter = new CountingDoIt()
        log.info("this should happen ${counter.call()}".toString())
        then:
        counter.count == 1

        when: "we're inside a closure and groovy is failing..so beware"
        counter = new CountingDoIt()
        1.times({ ignore ->
            log.debug(counter.call())
        })
        then:
        counter.count == 0    //debug isn't enabled so this string should never be evaluated but it is

        when: "we're inside a closure that calls a method.  it's OK"
        counter = new CountingDoIt()

        1.times({ ignore ->
            log.debug("this shouldn't happen ${doIt(counter)}".toString())
        })
        then:
        counter.count == 0

    }


    String doIt(CountingDoIt countingDoIt) {
        log.debug("this shouldn't happen ${countingDoIt.call()}".toString())
        "blah"

    }

    static class CountingDoIt {
        int count = 0

        String call() {
            count = count + 1
            "doneDidIt"
        }
    }
}

> @Log annotation does not check logging enablement inside closures
> -----------------------------------------------------------------
>
>                 Key: GROOVY-6932
>                 URL: https://issues.apache.org/jira/browse/GROOVY-6932
>             Project: Groovy
>          Issue Type: Bug
>          Components: groovy-runtime
>    Affects Versions: 2.2.0, 2.3.3
>         Environment: Windows 7, Groovy 2.3.3, JDK 1.8.0_05
>            Reporter: Shorn
>            Assignee: Paul King
>            Priority: Minor
>             Fix For: 2.4.8
>
>         Attachments: LogAstProblem.groovy, LoggingSpec.groovy
>
>
> Groovy doesn't do a check for whether the log level is enabled when the log statement is made from inside a closure.
> I believe the attached script should not print "called with 3".
> Result on my machine is:
> Groovy version: 2.3.3
> Java version: 1.8.0_05-b13
> OS: Windows 7
> called with 1
> 12:03:30.119 [main] INFO  TestCode - blah: 1
> called with 3
> Script:
> {code}
> @Grapes([
>   @Grab(group='org.slf4j', module='slf4j-api', version='1.7+'),
>   @Grab(group='ch.qos.logback', module='logback-classic', version='1.+')])
> import groovy.util.logging.Slf4j
> new TestCode().doSomethingThatLogs()
> @Slf4j
> class TestCode {
>   void doSomethingThatLogs(){
>     println "Groovy version: ${GroovySystem.version}"
>     println "Java version: ${System.properties["java.runtime.version"]}"
>     println "OS: ${System.properties["os.name"]}"
>     println ""
>     log.info createLogString(1)
>     log.trace createLogString(2)
>     Closure c = { log.trace createLogString(3) }
>     c()
>   }
>   String createLogString(int p){
>     println "called with $p"
>     return "blah: $p"
>   }
> }
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)