Skip to content

Instantly share code, notes, and snippets.

@tgsoverly
Last active August 29, 2015 14:03
Show Gist options
  • Save tgsoverly/34f9a56287291297777b to your computer and use it in GitHub Desktop.
Save tgsoverly/34f9a56287291297777b to your computer and use it in GitHub Desktop.
A test to check about logging performance
package com.spidasoftware.interchange.util
import groovy.util.logging.Log4j
import org.apache.log4j.Logger
import spock.lang.Specification
/**
* Created by toverly on 6/27/14.
*/
class LogPerformanceSpec extends Specification {
def final log = Logger.getLogger(LogPerformanceSpec.class)
def expando
def callCount
def runs = 10000
def setup() {
expando = new Expando()
expando.slow = {
Thread.sleep(1)
callCount++
}
}
def "logging just a string should not call method in string"() {
when:
callCount = 0
def begin = System.currentTimeMillis()
for (i in 1..runs) {
log.debug("Just a plain string")
}
def end = System.currentTimeMillis()
then:
println("Time consumed string: ${(end - begin) / 1000} s")
end - begin < 1000
callCount == 0
}
def "with a GString should not call method if not logged"() {
when:
callCount = 0
def begin = System.currentTimeMillis()
for (i in 1..runs) {
log.debug "String in with method ${expando.slow()}"
}
def end = System.currentTimeMillis()
then:
println("Time consumed gstring: ${(end - begin) / 1000} s")
end - begin < 1000
callCount == 0
}
def "with if should not call method in string"() {
when:
callCount = 0
def begin = System.currentTimeMillis()
for (i in 1..runs) {
if (log.isDebugEnabled()) {
log.debug "String in with method ${expando.slow()}"
}
}
def end = System.currentTimeMillis()
then:
println("Time consumed if gstring: ${(end - begin) / 1000} s")
end - begin < 1000
callCount == 0
}
def "with closure should not call method in string"() {
when:
log.metaClass.debug = { Closure c ->
if (delegate.debugEnabled) {
delegate.debug c.call().toString()
}
}
callCount = 0
def begin = System.currentTimeMillis()
for (i in 1..runs) {
log.debug { "String in with method closure ${expando.slow()}" }
}
def end = System.currentTimeMillis()
then:
println("Time consumed closure: ${(end - begin) / 1000} s")
end - begin < 1000
callCount == 0
}
}
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment