1 /***********************************************************************
2  * Copyright (c) 2013-2024 Commonwealth Computer Research, Inc.
3  * All rights reserved. This program and the accompanying materials
4  * are made available under the terms of the Apache License, Version 2.0
5  * which accompanies this distribution and is available at
6  * http://www.opensource.org/licenses/apache2.0.php.
7  ***********************************************************************/
8 
9 package org.locationtech.geomesa.utils.stats
10 
11 import com.typesafe.scalalogging.LazyLogging
12 
13 import java.util.concurrent.atomic.AtomicLong
14 
15 trait MethodProfiling extends LazyLogging {
16 
17   protected def profile[R](onComplete: Long => Unit)(code: => R): R = {
18     val start = System.currentTimeMillis
19     val result: R = code
20     onComplete(System.currentTimeMillis - start)
21     result
22   }
23 
24   protected def profile[R](onComplete: (R, Long) => Unit)(code: => R): R = {
25     val start = System.currentTimeMillis
26     val result: R = code
27     onComplete(result, System.currentTimeMillis - start)
28     result
29   }
30 
31   protected def profile[R](message: String)(code: => R): R =
32     profile(time => logger.debug(s"$message in ${time}ms"))(code)
33 }
34 
35 /**
36  * Class to hold timing results
37  */
38 class Timing extends Serializable {
39 
40   private var total = 0L
41   private var count = 0L
42 
43   /**
44    * Updates this instance with a new timing
45    *
46    * @param time time in millis
47    * @return
48    */
49   def occurrence(time: Long): Unit = {
50     total += time
51     count += 1
52   }
53 
54   /**
55    * Gets the total time
56    *
57    * @return
58    */
59   def time: Long = total
60 
61   /**
62    * Gets the number of event occurrences
63    *
64    * @return
65    */
66   def occurrences: Long = count
67 
68   /**
69    * Computes the average for this instance
70    *
71    * @return
72    */
73   def average(): Double = total / count.toDouble
74 }
75 
76 trait Timings extends Serializable {
77 
78   /**
79    * Updates the given identifier with a new timing
80    *
81    * @param identifier identifier
82    * @param time time in millis
83    */
84   def occurrence(identifier: String, time: Long): Unit
85 
86   /**
87    * Gets the total time for the given identifier
88    *
89    * @param identifier identifier
90    * @return
91    */
92   def time(identifier: String): Long
93 
94   /**
95    * Gets the total occurrences for the given identifier
96    *
97    * @param identifier identifier
98    * @return
99    */
100   def occurrences(identifier: String): Long
101 
102   /**
103    * Creates a printed string with the computed averages
104    *
105    * @return
106    */
107   def averageOccurrences(): String
108 
109   /**
110    * Creates a printed string with the computed averages
111    *
112    * @return
113    */
114   def averageTimes(): String
115 }
116 
117 /**
118  * Class to hold timing results. Not thread-safe.
119  */
120 class TimingsImpl extends Timings {
121 
122   private val map = scala.collection.mutable.Map.empty[String, Timing]
123 
124   override def occurrence(identifier: String, time: Long): Unit =
125     map.getOrElseUpdate(identifier, new Timing).occurrence(time)
126 
127   override def time(identifier: String): Long = map.getOrElseUpdate(identifier, new Timing).time
128 
129   override def occurrences(identifier: String): Long = map.getOrElseUpdate(identifier, new Timing).occurrences
130 
131   override def averageOccurrences(): String = if (map.isEmpty) {
132     "No occurrences"
133   } else {
134     val entries = map.toList.sortBy(_._1)
135     val total = entries.map(_._2.occurrences).sum
136     val percentOccurrences = entries.map { case (id, timing) =>
137       s"$id: ${(timing.occurrences * 100 / total.toDouble).formatted("%.1f%%")}"
138     }
139     percentOccurrences.mkString(s"Total occurrences: $total. Percent of occurrences - ", ", ", "")
140   }
141 
142   override def averageTimes(): String = if (map.isEmpty) {
143     "No occurrences"
144   } else {
145     val entries = map.toList.sortBy(_._1)
146     val total = entries.map(_._2.time).sum
147     val percentTimes = entries.map { case (id, timing) =>
148       s"$id: ${(timing.time * 100 / total.toDouble).formatted("%.1f%%")}" +
149           s" ${timing.occurrences} times at ${timing.average().formatted("%.4f")} ms avg"
150     }
151     percentTimes.mkString(s"Total time: $total ms. Percent of time - ", ", ", "")
152   }
153 }
154 
155 /**
156  * Class to hold timing results. Thread-safe.
157  */
158 class ThreadSafeTimingsImpl extends Timings {
159 
160   private val map = scala.collection.mutable.Map.empty[String, Timing]
161 
162   override def occurrence(identifier: String, time: Long): Unit = {
163     val timing = map.synchronized(map.getOrElseUpdate(identifier, new Timing))
164     timing.synchronized(timing.occurrence(time))
165   }
166 
167   override def time(identifier: String): Long =
168     map.synchronized(map.getOrElseUpdate(identifier, new Timing)).time
169 
170   override def occurrences(identifier: String): Long =
171     map.synchronized(map.getOrElseUpdate(identifier, new Timing)).occurrences
172 
173   override def averageOccurrences(): String = if (map.isEmpty) {
174     "No occurrences"
175   } else {
176     val entries = map.synchronized(map.toList).sortBy(_._1)
177     val total = entries.map(_._2.occurrences).sum
178     val percentOccurrences = entries.map { case (id, timing) =>
179       s"$id: ${(timing.occurrences * 100 / total.toDouble).formatted("%.1f%%")}"
180     }
181     percentOccurrences.mkString(s"Total occurrences: $total. Percent of occurrences - ", ", ", "")
182   }
183 
184   override def averageTimes(): String = if (map.isEmpty) {
185     "No occurrences"
186   } else {
187     val entries = map.synchronized(map.toList).sortBy(_._1)
188     val total = entries.map(_._2.time).sum
189     val percentTimes = entries.map { case (id, timing) =>
190       timing.synchronized(s"$id: ${(timing.time * 100 / total.toDouble).formatted("%.1f%%")}" +
191           s" ${timing.occurrences} times at ${timing.average().formatted("%.4f")} ms avg")
192     }
193     percentTimes.mkString(s"Total time: $total ms. Percent of time - ", ", ", "")
194   }
195 }
196 
197 /**
198  * Useful for sharing timings between instances of a certain class
199  *
200  * @param moduloToLog how many events to skip between logging
201  */
202 class AutoLoggingTimings(moduloToLog: Int = 1000) extends ThreadSafeTimingsImpl with LazyLogging {
203 
204   val count = new AtomicLong()
205 
206   override def occurrence(identifier: String, time: Long): Unit = {
207     super.occurrence(identifier, time)
208     if (count.incrementAndGet() % moduloToLog == 0) {
209       logger.debug(averageTimes())
210     }
211   }
212 }
213 
214 object NoOpTimings extends Timings {
215 
216   override def occurrence(identifier: String, time: Long): Unit = {}
217 
218   override def occurrences(identifier: String) = 0L
219 
220   override def time(identifier: String) = 0L
221 
222   override def averageTimes() = ""
223 
224   override def averageOccurrences() = ""
225 }