Merge pull request #233 from ilinum/cache-statistics

Cache statistics

macroAnnotations/src/org/jetbrains/plugins/scala/macroAnnotations/Cached.scala

@@ -6,17 +6,17 @@ import scala.annotation.StaticAnnotation
 import scala.language.experimental.macros
 
 /**
- * If you annotate a function with @Cached annotation, the compiler will generate code to cache it.
- *
- * If an annotated function has parameters, one field will be generated (a HashMap).
- * If an annotated function has no parameters, two fields will be generated: result and modCount
- *
- * CURRENTLY NOT SUPPORTED:
- *   Caching overloaded functions in the same scope will cause a name collision
- *
- * Author: Svyatoslav Ilinskiy
- * Date: 9/18/15.
- */
+  * If you annotate a function with @Cached annotation, the compiler will generate code to cache it.
+  *
+  * If an annotated function has parameters, one field will be generated (a HashMap).
+  * If an annotated function has no parameters, two fields will be generated: result and modCount
+  *
+  * NOTE: function annotated with @Cached must be on top-most level because generated code generates fields
+  * right outside the cached function and if this function is inner it won't work.
+  *
+  * Author: Svyatoslav Ilinskiy
+  * Date: 9/18/15.
+  */
 class Cached(synchronized: Boolean, modificationCount: ModCount, psiManager: Any) extends StaticAnnotation {
   def macroTransform(annottees: Any*) = macro CachedMacro.cachedImpl
 }

macroAnnotations/src/org/jetbrains/plugins/scala/macroAnnotations/CachedInsidePsiElement.scala

@@ -4,11 +4,15 @@ import scala.annotation.StaticAnnotation
 import scala.language.experimental.macros
 
 /**
- * This annotation makes the compiler generate code that calls CachesUtil.get(..,)
- *
- * Author: Svyatoslav Ilinskiy
- * Date: 9/25/15.
- */
+  * This annotation makes the compiler generate code that calls CachesUtil.get(..,)
+  *
+  * NOTE: Annotated function should preferably be top-level or in a static object for better performance.
+  * The field for Key is generated and it is more efficient to just keep it stored in this field, rather than get
+  * it from CachesUtil every time
+  *
+  * Author: Svyatoslav Ilinskiy
+  * Date: 9/25/15.
+  */
 class CachedInsidePsiElement(psiElement: Any, dependencyItem: Object, useOptionalProvider: Boolean = false) extends StaticAnnotation {
   def macroTransform(annottees: Any*) = macro CachedMacro.cachedInsidePsiElementImpl
 }

macroAnnotations/src/org/jetbrains/plugins/scala/macroAnnotations/CachedMacro.scala

@@ -59,6 +59,7 @@ object CachedMacro {
         val cacheStatsName = TermName(c.freshName(name + "cacheStats"))
         val keyId = c.freshName(name.toString + "cacheKey")
         val analyzeCaches = c.settings.contains(ANALYZE_CACHES)
+        val defdefFQN = q"""getClass.getName ++ "." ++ ${name.toString}"""
 
         //DefDef parameters
         val flatParams = paramss.flatten
@@ -67,7 +68,7 @@ object CachedMacro {
 
         val analyzeCachesField =
           if(analyzeCaches) {
-            val cacheDecl = q"private val $cacheStatsName = $cacheStatisticsFQN($keyId, ${name.toString})"
+            val cacheDecl = q"private val $cacheStatsName = $cacheStatisticsFQN($keyId, $defdefFQN)"
             if (hasParameters) { //need to put map in cacheStats, so its size can be measured
               q"""
                 $cacheDecl
@@ -186,7 +187,7 @@ object CachedMacro {
         val keyId = c.freshName(name.toString + "cacheKey")
         val key = TermName(c.freshName(name.toString + "Key"))
         val cacheStatsName = TermName(c.freshName(name + "cacheStats"))
-
+        val defdefFQN = q"""getClass.getName ++ "." ++ ${name.toString}"""
         val analyzeCaches = c.settings.contains(ANALYZE_CACHES)
         //function parameters
         val flatParams = paramss.flatten
@@ -237,7 +238,7 @@ object CachedMacro {
         val updatedDef = DefDef(mods, name, tpParams, paramss, retTp, updatedRhs)
         val res = q"""
           private val $key = $cachesUtilFQN.getOrCreateKey[$mappedKeyTypeFQN[(..$parameterTypes), $retTp]]($keyId)
-          ${if (analyzeCaches) q"private val $cacheStatsName = $cacheStatisticsFQN($keyId, ${name.toString})" else EmptyTree}
+          ${if (analyzeCaches) q"private val $cacheStatsName = $cacheStatisticsFQN($keyId, $defdefFQN)" else EmptyTree}
 
           ..$updatedDef
         """
@@ -283,6 +284,7 @@ object CachedMacro {
         val keyVarName = TermName(c.freshName(name.toString + "Key"))
         val cacheStatsName = TermName(c.freshName("cacheStats"))
         val analyzeCaches = c.settings.contains(ANALYZE_CACHES)
+        val defdefFQN = q"""getClass.getName ++ "." ++ ${name.toString}"""
 
         val provider =
           if (useOptionalProvider) TypeName("MyOptionalProvider")
@@ -317,7 +319,7 @@ object CachedMacro {
         val updatedDef = DefDef(mods, name, tpParams, params, retTp, updatedRhs)
         val res = q"""
           private val $keyVarName = $cachesUtilFQN.getOrCreateKey[$keyFQN[$cachedValueFQN[$retTp]]]($keyId)
-          ${if (analyzeCaches) q"private val $cacheStatsName = $cacheStatisticsFQN($keyId, ${name.toString})" else EmptyTree}
+          ${if (analyzeCaches) q"private val $cacheStatsName = $cacheStatisticsFQN($keyId, $defdefFQN)" else EmptyTree}
 
           ..$updatedDef
           """
@@ -362,11 +364,9 @@ object CachedMacro {
         val keyId = c.freshName(name.toString + "cacheKey")
         val key = TermName(c.freshName(name.toString + "Key"))
         val cacheStatsName = TermName(c.freshName("cacheStats"))
+        val defdefFQN = q"""getClass.getName ++ "." + ${name.toString}"""
 
         val analyzeCaches = c.settings.contains(ANALYZE_CACHES)
-        println(s"analyzeCaches: $analyzeCaches")
-        println(s"compiler flags: ${c.settings}")
-
         val provider =
           if (useOptionalProvider) TypeName("MyOptionalProvider")
           else TypeName("MyProvider")
@@ -396,7 +396,7 @@ object CachedMacro {
         val updatedDef = DefDef(mods, name, tpParams, paramss, retTp, updatedRhs)
         val res = q"""
           private val $key = $cachesUtilFQN.getOrCreateKey[$keyFQN[$cachedValueFQN[$retTp]]]($keyId)
-          ${if (analyzeCaches) q"private val $cacheStatsName = $cacheStatisticsFQN($keyId, ${name.toString})" else EmptyTree}
+          ${if (analyzeCaches) q"private val $cacheStatsName = $cacheStatisticsFQN($keyId, $defdefFQN)" else EmptyTree}
 
           ..$updatedDef
           """

macroAnnotations/src/org/jetbrains/plugins/scala/macroAnnotations/CachedMappedWithRecursionGuard.scala

@@ -4,11 +4,15 @@ import scala.annotation.StaticAnnotation
 import scala.language.experimental.macros
 
 /**
- * This annotation makes the compiler generate code that calls CachesUtil.getMappedWithRecursionPreventingWithRollback
- *
- * Author: Svyatoslav Ilinskiy
- * Date: 9/23/15.
- */
+  * This annotation makes the compiler generate code that calls CachesUtil.getMappedWithRecursionPreventingWithRollback
+  *
+  * NOTE: Annotated function should preferably be top-level or in a static object for better performance.
+  * The field for Key is generated and it is more efficient to just keep it stored in this field, rather than get
+  * it from CachesUtil every time
+  *
+  * Author: Svyatoslav Ilinskiy
+  * Date: 9/23/15.
+  */
 class CachedMappedWithRecursionGuard(psiElement: Any, defaultValue: => Any, dependencyItem: Object) extends StaticAnnotation {
   def macroTransform(annottees: Any*) = macro CachedMacro.cachedMappedWithRecursionGuardImpl
 }

macroAnnotations/src/org/jetbrains/plugins/scala/macroAnnotations/CachedWithRecursionGuard.scala

@@ -4,11 +4,15 @@ import scala.annotation.StaticAnnotation
 import scala.language.experimental.macros
 
 /**
- * This annotation makes the compiler generate code that calls CachesUtil.getWithRecursionPreventingWithRollback
- *
- * Author: Svyatoslav Ilinskiy
- * Date: 9/28/15.
- */
+  * This annotation makes the compiler generate code that calls CachesUtil.getWithRecursionPreventingWithRollback
+  *
+  * NOTE: Annotated function should preferably be top-level or in a static object for better performance.
+  * The field for Key is generated and it is more efficient to just keep it stored in this field, rather than get
+  * it from CachesUtil every time
+  *
+  * Author: Svyatoslav Ilinskiy
+  * Date: 9/28/15.
+  */
 class CachedWithRecursionGuard[T](element: Any,
                                    defaultValue: => Any,
                                    dependecyItem: Object,

src/org/jetbrains/plugins/scala/statistics/CacheStatistics.scala

@@ -2,7 +2,9 @@ package org.jetbrains.plugins.scala.statistics
 
 import java.util.concurrent.ConcurrentHashMap
 
+import com.intellij.openapi.diagnostic.Logger
 import com.intellij.util.containers.ContainerUtil
+import org.apache.log4j.Level
 import org.github.jamm.MemoryMeter
 
 import scala.collection.mutable
@@ -66,34 +68,42 @@ class CacheStatistics private(id: String, name: String) {
 
   //this method may take a while time to run
   def spaceTakenByCache: Long = {
-    try {
+    -1 //turned off counting space taken by cache, it causes errors to happen and doesn't work overall
+    /*try {
       objectsToKeepTrackOfNormalReferences.map(memoryMeter.measureDeep).sum
     } catch {
       case e@(_: AssertionError | _: IllegalStateException) =>
         println(e.getMessage) //message is probably: Instrumentation is not set; Jamm must be set as -javaagent
         print("Not counting size of cache")
         -1
-    }
+    }*/
 
   }
 
   override def toString: String = {
     import scala.collection.JavaConversions._
     val calcTimes: Set[Long] = calculationTimes.toSet //efficient because not conccurent
 
-    val averageTimes =
-      if (calcTimes.nonEmpty) {
-        s"average time to calculate: ${calcTimes.sum.toDouble / calcTimes.size}, maxTime: ${calcTimes.max}, minTime: ${calcTimes.min}"
-      } else ""
+    if (calculationTimes.nonEmpty) {
+      val (maxTime, minTime, averageTime) = (calcTimes.max, calcTimes.min, calcTimes.sum.toDouble / calcTimes.size)
 
-    s"""
+      val timeSaved = hits * averageTime
+      s"""
        |****************************
        |$name
        |hits: $hits, misses: $misses
        |*approximate* spaceTaken: $spaceTakenByCache
-       |$averageTimes
+       |maxTime: $maxTime, minTime: $minTime, averageTime: $averageTime
+       |time saved (hits * averageTime): $timeSaved
        |****************************
      """.stripMargin
+    } else {
+      s"""
+        |**************************
+        |$name not used
+        |**************************
+      """.stripMargin
+    }
   }
 }
 
@@ -103,7 +113,9 @@ object CacheStatistics {
   private val caches = new ConcurrentHashMap[String, CacheStatistics]()
 
   def printStats(): Unit = {
-    caches.values().asScala.foreach (c => println(c.toString))
+    val logger = Logger.getInstance(this.getClass)
+    logger.setLevel(Level.INFO)
+    caches.values().asScala.foreach (c => logger.info(c.toString))
   }
 
   def apply(id: String, name: String) = Option(caches.get(id)) match {