Skip to content
This repository was archived by the owner on Mar 24, 2025. It is now read-only.

Commit fe8b981

Browse files
committed
fix @elapsed
1 parent 5dab022 commit fe8b981

File tree

4 files changed

+71
-96
lines changed

4 files changed

+71
-96
lines changed

smt-annotations/src/main/scala/org/bitlap/tools/elapsed.scala

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -25,20 +25,19 @@ import org.bitlap.tools.LogLevel.LogLevel
2525
import org.bitlap.tools.macros.elapsedMacro.ElapsedProcessor
2626

2727
import scala.annotation.{ compileTimeOnly, StaticAnnotation }
28-
import scala.concurrent.duration.Duration
2928

3029
/** annotation to record method cost time.
3130
*
3231
* @author
3332
* 梦境迷离
3433
* @param limit
35-
* Time consuming condition to trigger log.
34+
* Time consuming condition to trigger log. milliseconds
3635
* @param logLevel
3736
* Log Level.
3837
* @since 2021/8/7
3938
* @version 1.0
4039
*/
4140
@compileTimeOnly("enable macro to expand macro annotations")
42-
final class elapsed(limit: Duration, logLevel: LogLevel) extends StaticAnnotation {
41+
final class elapsed(limit: Int, logLevel: LogLevel) extends StaticAnnotation {
4342
def macroTransform(annottees: Any*): Any = macro ElapsedProcessor.impl
4443
}

smt-annotations/src/main/scala/org/bitlap/tools/macros/elapsedMacro.scala

Lines changed: 11 additions & 57 deletions
Original file line numberDiff line numberDiff line change
@@ -24,13 +24,14 @@ package org.bitlap.tools.macros
2424
import org.bitlap.tools.LogLevel.LogLevel
2525
import org.bitlap.tools.{ LogLevel, PACKAGE }
2626

27-
import scala.concurrent.duration._
2827
import scala.reflect.macros.whitebox
2928

3029
/**
31-
* 1. This annotation only support use on non-abstract method. 2. For methods that are not future, `try finally` is
32-
* used to implement the timing of the method. 3. For methods that are Futures, `Future map` is used to implement
33-
* the timing of the method.
30+
* 1. This annotation only support use on non-abstract method.
31+
*
32+
* 2. For methods that are not future, `try finally` is used to implement the timing of the method.
33+
*
34+
* 3. For methods that are Futures, `Future onComplete` is used to implement the timing of the method.
3435
*
3536
* @author
3637
* 梦境迷离
@@ -53,25 +54,20 @@ object elapsedMacro {
5354
LogLevel.getLogLevel(logLevel.toString())
5455
}
5556

56-
private val extractOptions: (Duration, LogLevel) = c.prefix.tree match {
57+
private val extractOptions: (Int, LogLevel) = c.prefix.tree match {
5758
case q"new elapsed(limit=$limit, logLevel=$logLevel)" =>
5859
(evalTree(limit.asInstanceOf[Tree]), getLogLevel(logLevel.asInstanceOf[Tree]))
5960
case _ => c.abort(c.enclosingPosition, ErrorMessage.UNEXPECTED_PATTERN)
6061
}
6162

6263
private def getStartExpr: c.universe.Tree =
63-
q"""val $start = _root_.scala.concurrent.duration.Duration.fromNanos(System.nanoTime())"""
64+
q"""val $start = System.currentTimeMillis()"""
6465

65-
private def getLog(classNameAndMethodName: String, logBy: Tree): c.universe.Tree = {
66-
// CI will fail when use lambda.
67-
implicit val durationApply: c.universe.Liftable[Duration] = new Liftable[Duration] {
68-
override def apply(value: Duration): c.universe.Tree = q"${value._1}"
69-
}
66+
private def getLog(classNameAndMethodName: String, logBy: Tree): c.universe.Tree =
7067
q"""
71-
val $valDef = _root_.scala.concurrent.duration.Duration.fromNanos(System.nanoTime()) - $start
72-
if ($valDef._1 >= ${extractOptions._1}) $logBy(StringContext("slow invoked method: [", "] elapsed [", " ms]").s($classNameAndMethodName, $valDef.toMillis))
68+
val $valDef = System.currentTimeMillis() - $start
69+
if ($valDef >= ${extractOptions._1}) $logBy(StringContext("slow invoked method: [", "] elapsed [", " ms]").s($classNameAndMethodName, $valDef))
7370
"""
74-
}
7571

7672
private def getPrintlnLog(classNameAndMethodName: String): c.universe.Tree = {
7773
val log = findValDefInEnclosingClass(TypeName("org.slf4j.Logger"))
@@ -104,53 +100,11 @@ object elapsedMacro {
104100
defDef => q"""
105101
$getStartExpr
106102
val resFuture = ${defDef.rhs}
107-
resFuture.onComplete { case _ => ..${getIdentNam(defDef.name)} }(_root_.scala.concurrent.ExecutionContext.Implicits.global)
103+
resFuture.onComplete { case _ => ..${getPrintlnLog(getIdentNam(defDef.name))} }(_root_.scala.concurrent.ExecutionContext.Implicits.global)
108104
resFuture
109105
"""
110106
)
111107

112-
// There may be a half-way exit, rather than the one whose last expression is exit.
113-
// Unreliable function!!!
114-
// private def returnEarly(defDef: DefDef, trees: Tree*): List[Tree] = {
115-
// val ifElseMatch = (f: If) => {
116-
// if (f.elsep.nonEmpty) {
117-
// if (f.elsep.children.nonEmpty && f.elsep.children.size > 1) {
118-
// If(f.cond, f.thenp, q"..${returnEarly(defDef, f.elsep.children: _*)}")
119-
// } else {
120-
// If(f.cond, f.thenp, q"..${returnEarly(defDef, f.elsep)}")
121-
// }
122-
// } else {
123-
// f //no test
124-
// }
125-
// }
126-
// if (trees.isEmpty) return Nil
127-
// trees.map {
128-
// case r: Return =>
129-
// q"""
130-
// ..${getPrintlnLog(defDef.name)}
131-
// $r
132-
// """
133-
// case f: If => //support if return
134-
// c.info(c.enclosingPosition, s"returnEarly: thenp: ${f.thenp}, children: ${f.thenp.children}, cond: ${f.cond}", force = true)
135-
// c.info(c.enclosingPosition, s"returnEarly: elsep: ${f.elsep}, children: ${f.elsep.children}, cond: ${f.cond}", force = true)
136-
// if (f.thenp.nonEmpty) {
137-
// if (f.thenp.children.nonEmpty && f.thenp.children.size > 1) {
138-
// val ifTree = If(f.cond, q"..${returnEarly(defDef, f.thenp.children: _*)}", f.elsep)
139-
// ifElseMatch(ifTree)
140-
// } else {
141-
// val ifTree = If(f.cond, q"..${returnEarly(defDef, f.thenp)}", f.elsep)
142-
// ifElseMatch(ifTree)
143-
// }
144-
// } else {
145-
// ifElseMatch(f) //no test
146-
// }
147-
// case t =>
148-
// // TODO support for/while/switch
149-
// c.info(c.enclosingPosition, s"returnEarly: not support expr: $t", force = true)
150-
// t
151-
// }.toList
152-
// }
153-
154108
private def getIdentNam(method: Name): String =
155109
s"${c.enclosingClass match {
156110
case ClassDef(_, name, _, Template(_, _, _)) => name

smt-annotations/src/test/scala/org/bitlap/tools/ElapsedTest.scala

Lines changed: 37 additions & 36 deletions
Original file line numberDiff line numberDiff line change
@@ -24,6 +24,9 @@ package org.bitlap.tools
2424
import org.scalatest.flatspec.AnyFlatSpec
2525
import org.scalatest.matchers.should.Matchers
2626

27+
import scala.concurrent.Await
28+
import scala.concurrent.duration.Duration
29+
2730
import scala.concurrent.Future
2831

2932
/** @author
@@ -37,22 +40,22 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
3740
// Duration and TimeUnit must Full class name
3841
"""
3942
| class A {
40-
| @elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS), logLevel = org.bitlap.tools.LogLevel.INFO)
43+
| @elapsed(limit = 1, logLevel = org.bitlap.tools.LogLevel.INFO)
4144
| def i = ???
4245
| }
4346
|
4447
| class B {
45-
| @elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS), logLevel = org.bitlap.tools.LogLevel.WARN)
48+
| @elapsed(limit = 1, logLevel = org.bitlap.tools.LogLevel.WARN)
4649
| def j = ???
4750
| }
4851
|
4952
| class C {
50-
| @elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS), logLevel = org.bitlap.tools.LogLevel.DEBUG)
53+
| @elapsed(limit = 1, logLevel = org.bitlap.tools.LogLevel.DEBUG)
5154
| def j = ???
5255
| }
5356
|
5457
| class D {
55-
| @elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS), logLevel = org.bitlap.tools.LogLevel.INFO)
58+
| @elapsed(limit = 1, logLevel = org.bitlap.tools.LogLevel.INFO)
5659
| def i:String = ???
5760
| }
5861
| val a = new A()
@@ -66,13 +69,13 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
6669
// Duration and TimeUnit must Full class name
6770
"""
6871
|class A {
69-
| @elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.NANOSECONDS), logLevel = org.bitlap.tools.LogLevel.INFO)
72+
| @elapsed(limit = 1, logLevel = org.bitlap.tools.LogLevel.INFO)
7073
| def helloWorld: String = {
7174
| println("hello world")
7275
| "hello"
7376
| }
7477
|
75-
| @elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS), logLevel = org.bitlap.tools.LogLevel.INFO)
78+
| @elapsed(limit = 1, logLevel = org.bitlap.tools.LogLevel.INFO)
7679
| def helloScala: String = {
7780
| Thread.sleep(2000)
7881
| println("hello world")
@@ -89,18 +92,18 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
8992
// Duration and TimeUnit must Full class name
9093
"""
9194
| class A {
92-
| @elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.NANOSECONDS), logLevel = org.bitlap.tools.LogLevel.INFO)
95+
| @elapsed(limit = 1, logLevel = org.bitlap.tools.LogLevel.INFO)
9396
| def helloWorld: String = {
9497
| println("") ; println(""); ""
9598
| }
9699
|
97-
| @elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS), logLevel = org.bitlap.tools.LogLevel.INFO)
100+
| @elapsed(limit = 1, logLevel = org.bitlap.tools.LogLevel.INFO)
98101
| def helloScala1: String = { println("") ; println(""); ""}
99102
|
100-
| @elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS), logLevel = org.bitlap.tools.LogLevel.INFO)
103+
| @elapsed(limit = 1, logLevel = org.bitlap.tools.LogLevel.INFO)
101104
| def helloScala2: String = { println("") ; println(""); "" }
102105
|
103-
| @elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS), logLevel = org.bitlap.tools.LogLevel.INFO)
106+
| @elapsed(limit = 1, logLevel = org.bitlap.tools.LogLevel.INFO)
104107
| def helloScala3: String = {
105108
| val s = "hello"
106109
| val x = "world"
@@ -115,7 +118,7 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
115118
// Duration and TimeUnit must Full class name
116119
"""
117120
| class A {
118-
| @elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS), logLevel = org.bitlap.tools.LogLevel.INFO)
121+
| @elapsed(limit = 1, logLevel = org.bitlap.tools.LogLevel.INFO)
119122
| def helloScala1: String = {
120123
| val s = "hello"
121124
| if (s == "hello") {
@@ -130,7 +133,7 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
130133
| a.helloScala1
131134
|
132135
| class B {
133-
| @elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS), logLevel = org.bitlap.tools.LogLevel.INFO)
136+
| @elapsed(limit = 1, logLevel = org.bitlap.tools.LogLevel.INFO)
134137
| def helloScala11: String = {
135138
| val s = "hello"
136139
| if (s == "hello") {
@@ -151,7 +154,7 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
151154
private final val log3: org.slf4j.Logger = org.slf4j.LoggerFactory.getLogger(classOf[A])
152155

153156
@elapsed(
154-
limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS),
157+
limit = 1,
155158
logLevel = org.bitlap.tools.LogLevel.INFO
156159
)
157160
def helloScala1: Future[String] = {
@@ -160,7 +163,7 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
160163
}
161164

162165
@elapsed(
163-
limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS),
166+
limit = 1,
164167
logLevel = org.bitlap.tools.LogLevel.DEBUG
165168
)
166169
def helloScala2: Future[String] = {
@@ -171,7 +174,7 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
171174
}
172175

173176
@elapsed(
174-
limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS),
177+
limit = 1,
175178
logLevel = org.bitlap.tools.LogLevel.WARN
176179
)
177180
def helloScala3: Future[String] = Future {
@@ -182,25 +185,21 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
182185

183186
"elapsed6" should "failed, not support when only has one expr" in {
184187
class B {
185-
186-
import scala.concurrent.Await
187-
import scala.concurrent.duration.Duration
188-
189188
@elapsed(
190-
limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS),
189+
limit = 1,
191190
logLevel = org.bitlap.tools.LogLevel.WARN
192191
)
193192
def helloScala(t: String): Future[String] =
194193
Future(t)(scala.concurrent.ExecutionContext.Implicits.global)
195194

196195
@elapsed(
197-
limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS),
196+
limit = 1,
198197
logLevel = org.bitlap.tools.LogLevel.WARN
199198
)
200199
def helloScala11(t: String): Future[String] = Future(t)(scala.concurrent.ExecutionContext.Implicits.global)
201200

202201
@elapsed(
203-
limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS),
202+
limit = 1,
204203
logLevel = org.bitlap.tools.LogLevel.INFO
205204
)
206205
def helloScala2: String = {
@@ -215,21 +214,21 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
215214
| object A {
216215
| private final val log1: org.slf4j.Logger = org.slf4j.LoggerFactory.getLogger(A.getClass)
217216
|
218-
| @elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS), logLevel = org.bitlap.tools.LogLevel.INFO)
217+
| @elapsed(limit = 1, logLevel = org.bitlap.tools.LogLevel.INFO)
219218
| def helloScala1: Future[String] = {
220219
| Thread.sleep(1000)
221220
| Future.successful("hello world")
222221
| }
223222
|
224-
| @elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS), logLevel = org.bitlap.tools.LogLevel.DEBUG)
223+
| @elapsed(limit = 1, logLevel = org.bitlap.tools.LogLevel.DEBUG)
225224
| def helloScala2: Future[String] = {
226225
| Thread.sleep(2000)
227226
| Future {
228227
| "hello world"
229228
| }(scala.concurrent.ExecutionContext.Implicits.global)
230229
| }
231230
|
232-
| @elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS), logLevel = org.bitlap.tools.LogLevel.WARN)
231+
| @elapsed(limit = 1, logLevel = org.bitlap.tools.LogLevel.WARN)
233232
| def helloScala3: Future[String] = Future {
234233
| "hello world"
235234
| }(scala.concurrent.ExecutionContext.Implicits.global)
@@ -239,35 +238,38 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
239238

240239
"elapsed8" should "ok at input args" in {
241240
@elapsed(
242-
limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS),
241+
limit = 1,
243242
logLevel = LogLevel.WARN
244243
)
245244
def helloScala1: String = {
246245
println("")
247246
println("")
248247
"hello"
249248
}
250-
@elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS), logLevel = WARN)
249+
@elapsed(limit = 1, logLevel = LogLevel.INFO)
251250
def helloScala2: String = {
252251
println("")
253252
println("")
254253
"hello"
255254
}
256255

257256
@elapsed(
258-
limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS),
257+
limit = 1,
259258
logLevel = org.bitlap.tools.LogLevel.WARN
260259
)
261260
def helloScala3: String = {
262261
println("")
263-
println("")
262+
Thread.sleep(10)
264263
"hello"
265264
}
265+
266+
helloScala3
267+
266268
}
267269

268270
"elapsed9" should "failed at input args" in {
269271
"""
270-
|@elapsed(logLevel = org.bitlap.tools.LogLevel.WARN, limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS))
272+
|@elapsed(logLevel = org.bitlap.tools.LogLevel.WARN, limit = 1)
271273
| def helloScala1: String = {
272274
| println("")
273275
| println("")
@@ -279,7 +281,7 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
279281
class A {
280282

281283
@elapsed(
282-
limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS),
284+
limit = 1,
283285
logLevel = org.bitlap.tools.LogLevel.INFO
284286
)
285287
def j: Int = {
@@ -302,7 +304,7 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
302304
}
303305

304306
@elapsed(
305-
limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS),
307+
limit = 1,
306308
logLevel = org.bitlap.tools.LogLevel.INFO
307309
)
308310
def k: Unit = {
@@ -337,7 +339,7 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
337339
}
338340

339341
@elapsed(
340-
limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS),
342+
limit = 1,
341343
logLevel = org.bitlap.tools.LogLevel.INFO
342344
)
343345
def l: Int = {
@@ -350,7 +352,7 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
350352
}
351353

352354
@elapsed(
353-
limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS),
355+
limit = 1,
354356
logLevel = org.bitlap.tools.LogLevel.INFO
355357
)
356358
def m: Int = {
@@ -366,7 +368,6 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
366368
val u = 0
367369
return 0
368370
}
369-
370371
1
371372
}
372373

@@ -376,7 +377,7 @@ class ElapsedTest extends AnyFlatSpec with Matchers {
376377
"elapsed11" should "failed at abstract method" in {
377378
"""
378379
|abstract class A {
379-
| @elapsed(limit = scala.concurrent.duration.Duration(1, java.util.concurrent.TimeUnit.SECONDS), logLevel = org.bitlap.tools.LogLevel.WARN)
380+
| @elapsed(limit = 1, logLevel = org.bitlap.tools.LogLevel.WARN)
380381
| def hello:String
381382
| }
382383
|""".stripMargin shouldNot compile

0 commit comments

Comments
 (0)