[
https://issues.apache.org/jira/browse/GROOVY-8060?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Paul King updated GROOVY-8060:
------------------------------
Description:
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".
>From cloned issue for an additional case:
{code}
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"
}
}
}
{code}
was:
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}
> @Log annotation does not check logging enablement inside closures which are
> arguments to methods
> ------------------------------------------------------------------------------------------------
>
> Key: GROOVY-8060
> URL: https://issues.apache.org/jira/browse/GROOVY-8060
> Project: Groovy
> Issue Type: Bug
> Components: groovy-runtime
> Affects Versions: 2.3.3, 2.4.8
> Environment: Windows 7, Groovy 2.3.3, JDK 1.8.0_05
> Reporter: Shorn
> Assignee: Paul King
> Priority: Minor
>
> 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".
> From cloned issue for an additional case:
> {code}
> 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"
> }
> }
> }
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
