背景
刚学 Kotlin , 学到字符串模板的时候有个疑问。
在 Kotlin 中,我们使用 slf4j (或者说logback) 时 应该使用 占位符呢还是Kotlin 的字符串模板。
从语法上来看,我更喜欢使用字符串模板,但是从API 风格上来看应该使用 占位符。
所以我就性能来做了一个小测试。
我这里不表明到底应该用那种方式来输出日志,此测试仅供参考
。
测试结果: Kotlin 的字符串性能更好
, 但是与 slf4j 的占位符性能 相差不大
。
测试代码
// File created at: Wednesday, December 11, 2019
// File encoding : UTF-8
// Line separator : LF
// Tab stop : 4 spaces
// IDE : IntelliJ IDEA community edition
import org.junit.Test
import org.slf4j.LoggerFactory
import java.io.FileOutputStream
import java.io.PrintStream
/**
*
* @author Joel
*/
class LogbackFeture {
companion object {
private const val TIMES = 1000000
}
data class User(
val name: String,
val age: Int,
val gender: String,
val weight: Double,
val height: Double,
val px:Long
)
private fun generateUser(): User? {
val u = User("Joel", 22, "Male", 120.0, 169.0, 13355001)
if (u.age == 100)
return null
return u
}
@Test
fun test01() {
println("############################ 01 ####################################")
val out = System.out
System.setOut(PrintStream(FileOutputStream("/dev/null")))
val logger = LoggerFactory.getLogger("a")
val stopWatch = org.springframework.util.StopWatch()
val u = generateUser()?: return
stopWatch.start("log-template-1")
for (index in 1..TIMES) {
logger.info("user info, name:{}, age:{},gender:{}, weight:{}, height:{}, px:{}",
u.name, u.age, u.gender, u.weight, u.height, u.px)
}
stopWatch.stop()
stopWatch.start("log-kotlin-template-1")
for (index in 1..TIMES)
logger.info("user info, name:${u.name}, age:${u.age},gender:${u.gender}, weight:${u.weight}, height:${u.height}, px:${u.px}")
stopWatch.stop()
System.setOut(out)
println(stopWatch.prettyPrint())
}
@Test
fun test02() {
println("############################ 02 ####################################")
val out = System.out
System.setOut(PrintStream(FileOutputStream("/dev/null")))
val logger = LoggerFactory.getLogger("a")
val stopWatch = org.springframework.util.StopWatch()
val u = generateUser()?: return
stopWatch.start("log-kotlin-template-1")
for (index in 1..TIMES)
logger.info("user info, name:${u.name}, age:${u.age},gender:${u.gender}, weight:${u.weight}, height:${u.height}, px:${u.px}")
stopWatch.stop()
stopWatch.start("log-template-1")
for (index in 1..TIMES) {
logger.info("user info, name:{}, age:{},gender:{}, weight:{}, height:{}, px:{}",
u.name, u.age, u.gender, u.weight, u.height, u.px)
}
stopWatch.stop()
System.setOut(out)
println(stopWatch.prettyPrint())
}
@Test
fun test03() {
println("############################ 03 ####################################")
val out = System.out
System.setOut(PrintStream(FileOutputStream("/dev/null")))
val logger = LoggerFactory.getLogger("a")
val stopWatch = org.springframework.util.StopWatch()
val u = generateUser()?: return
stopWatch.start("log-kotlin-template-1")
for (index in 1..TIMES)
logger.info("user info, name:${u.name}, age:${u.age},gender:${u.gender}, weight:${u.weight}, height:${u.height}, px:${u.px}")
stopWatch.stop()
stopWatch.start("log-template-1")
for (index in 1..TIMES) {
logger.info("user info, name:{}, age:{},gender:{}, weight:{}, height:{}, px:{}",
u.name, u.age, u.gender, u.weight, u.height, u.px)
}
stopWatch.stop()
stopWatch.start("log-kotlin-template-2")
for (index in 1..TIMES)
logger.info("user info, name:${u.name}, age:${u.age},gender:${u.gender}, weight:${u.weight}, height:${u.height}, px:${u.px}")
stopWatch.stop()
stopWatch.start("log-template-2")
for (index in 1..TIMES) {
logger.info("user info, name:{}, age:{},gender:{}, weight:{}, height:{}, px:{}",
u.name, u.age, u.gender, u.weight, u.height, u.px)
}
stopWatch.stop()
System.setOut(out)
println(stopWatch.prettyPrint())
}
@Test
fun test04() {
println("############################ 04 ####################################")
val out = System.out
System.setOut(PrintStream(FileOutputStream("/dev/null")))
val logger = LoggerFactory.getLogger("a")
val stopWatch = org.springframework.util.StopWatch()
val u = generateUser()?: return
stopWatch.start("log-template-1")
for (index in 1..TIMES) {
logger.info("user info, name:{}, age:{},gender:{}, weight:{}, height:{}, px:{}",
u.name, u.age, u.gender, u.weight, u.height, u.px)
}
stopWatch.stop()
stopWatch.start("log-kotlin-template-1")
for (index in 1..TIMES)
logger.info("user info, name:${u.name}, age:${u.age},gender:${u.gender}, weight:${u.weight}, height:${u.height}, px:${u.px}")
stopWatch.stop()
stopWatch.start("log-template-2")
for (index in 1..TIMES) {
logger.info("user info, name:{}, age:{},gender:{}, weight:{}, height:{}, px:{}",
u.name, u.age, u.gender, u.weight, u.height, u.px)
}
stopWatch.stop()
stopWatch.start("log-kotlin-template-2")
for (index in 1..TIMES)
logger.info("user info, name:${u.name}, age:${u.age},gender:${u.gender}, weight:${u.weight}, height:${u.height}, px:${u.px}")
stopWatch.stop()
System.setOut(out)
println(stopWatch.prettyPrint())
}
@Test
fun test05() {
println("############################ 05 ####################################")
val out = System.out
System.setOut(PrintStream(FileOutputStream("/dev/null")))
val logger = LoggerFactory.getLogger("a")
val stopWatch = org.springframework.util.StopWatch()
val u = generateUser()?: return
stopWatch.start("log-template-1")
for (index in 1..TIMES) {
logger.info("user info, name:{}, age:{},gender:{}, weight:{}, height:{}, px:{}",
u.name, u.age, u.gender, u.weight, u.height, u.px)
}
stopWatch.stop()
stopWatch.start("log-template-2")
for (index in 1..TIMES) {
logger.info("user info, name:{}, age:{},gender:{}, weight:{}, height:{}, px:{}",
u.name, u.age, u.gender, u.weight, u.height, u.px)
}
stopWatch.stop()
stopWatch.start("log-kotlin-template-1")
for (index in 1..TIMES)
logger.info("user info, name:${u.name}, age:${u.age},gender:${u.gender}, weight:${u.weight}, height:${u.height}, px:${u.px}")
stopWatch.stop()
stopWatch.start("log-kotlin-template-2")
for (index in 1..TIMES)
logger.info("user info, name:${u.name}, age:${u.age},gender:${u.gender}, weight:${u.weight}, height:${u.height}, px:${u.px}")
stopWatch.stop()
System.setOut(out)
println(stopWatch.prettyPrint())
}
@Test
fun test06() {
println("############################ 05 ####################################")
val out = System.out
System.setOut(PrintStream(FileOutputStream("/dev/null")))
val logger = LoggerFactory.getLogger("a")
val stopWatch = org.springframework.util.StopWatch()
val u = generateUser()?: return
stopWatch.start("log-kotlin-template-1")
for (index in 1..TIMES)
logger.info("user info, name:${u.name}, age:${u.age},gender:${u.gender}, weight:${u.weight}, height:${u.height}, px:${u.px}")
stopWatch.stop()
stopWatch.start("log-kotlin-template-2")
for (index in 1..TIMES)
logger.info("user info, name:${u.name}, age:${u.age},gender:${u.gender}, weight:${u.weight}, height:${u.height}, px:${u.px}")
stopWatch.stop()
stopWatch.start("log-template-1")
for (index in 1..TIMES) {
logger.info("user info, name:{}, age:{},gender:{}, weight:{}, height:{}, px:{}",
u.name, u.age, u.gender, u.weight, u.height, u.px)
}
stopWatch.stop()
stopWatch.start("log-template-2")
for (index in 1..TIMES) {
logger.info("user info, name:{}, age:{},gender:{}, weight:{}, height:{}, px:{}",
u.name, u.age, u.gender, u.weight, u.height, u.px)
}
stopWatch.stop()
System.setOut(out)
println(stopWatch.prettyPrint())
}
}
测试结果输出
############################ 01 ####################################
StopWatch '': running time = 4203358761 ns
---------------------------------------------
ns % Task name
---------------------------------------------
2593452758 062% log-template-1
1609906003 038% log-kotlin-template-1
############################ 02 ####################################
StopWatch '': running time = 3076158731 ns
---------------------------------------------
ns % Task name
---------------------------------------------
1481434004 048% log-kotlin-template-1
1594724727 052% log-template-1
############################ 03 ####################################
StopWatch '': running time = 6204617384 ns
---------------------------------------------
ns % Task name
---------------------------------------------
1525574213 025% log-kotlin-template-1
1619254222 026% log-template-1
1462597118 024% log-kotlin-template-2
1597191831 026% log-template-2
############################ 04 ####################################
StopWatch '': running time = 6127473865 ns
---------------------------------------------
ns % Task name
---------------------------------------------
1621986281 026% log-template-1
1448474874 024% log-kotlin-template-1
1597398202 026% log-template-2
1459614508 024% log-kotlin-template-2
############################ 05 ####################################
StopWatch '': running time = 6146448730 ns
---------------------------------------------
ns % Task name
---------------------------------------------
1628835391 027% log-template-1
1602684003 026% log-template-2
1452516907 024% log-kotlin-template-1
1462412429 024% log-kotlin-template-2
############################ 05 ####################################
StopWatch '': running time = 6186698367 ns
---------------------------------------------
ns % Task name
---------------------------------------------
1478944412 024% log-kotlin-template-1
1505337485 024% log-kotlin-template-2
1599451241 026% log-template-1
1602965229 026% log-template-2