be4b8bd2d9e6 — Chris Cannam 3 years ago
Add timedToBudget; docs
2 files changed, 71 insertions(+), 22 deletions(-)

M timing.sig
M timing.sml
M timing.sig +24 -1
@@ 1,12 1,35 @@ 
 
+(** Call a function and log how long it takes. Remembers the timings
+    to report on in an aggregated summary, and can optionally also log
+    immediately on function return.
+*)
 signature TIMING = sig
 
+    (** Label for a specific function invocation point.
+     *)
     type tag = string
-                   
+
+    (** Call the given function, time how long it takes, and record
+        the time against the given tag. The time is also logged
+        immediately if DEBUG log level is active.
+     *)
     val timed : tag -> (unit -> 'a) -> 'a
 
+    (** Call the given function, time how long it takes, and record
+        the time against the given tag. The time is also logged
+        immediately if DEBUG log level is active. If the time taken
+        exceeds the given budget, log immediately with the WARN log
+        level.
+     *)
+    val timedToBudget : tag * Time.time -> (unit -> 'a) -> 'a
+
+    (** Associate the given time with the given tag, as if we had just
+        timed an invocation of it.
+     *)
     val record : tag -> Time.time -> unit
 
+    (** Output a summary of recorded timings to the given log level.
+     *)
     val summarise : Log.level -> unit
                                            
 end

          
M timing.sml +47 -21
@@ 50,27 50,7 @@ structure Timing : TIMING = struct
 
     val mu = implode [chr 0xCE, chr 0xBC]
     fun toUsReal t = Time.toReal t * 1000000.0
-                                         
-    fun timed tag f =
-        let open Log
-            val start = Time.now ()
-            val result = f ()
-            val finish = Time.now ()
-            val elapsed = Time.- (finish, start)
-            val () = record tag elapsed
-            val usElapsed = toUsReal elapsed
-            val () = Log.debug
-                         (fn () =>
-                             ["%1: %2%3s (%4/s)",
-                              tag,
-                              N usElapsed, mu,
-                              if usElapsed > 0.0
-                              then N (1000000.0 / usElapsed)
-                              else "-"
-                         ])
-        in
-            result
-        end
+    fun usPerSecStr u = if u > 0.0 then Log.N (1000000.0 / u) else "-"
 
     fun summarise level =
         let open Log

          
@@ 101,5 81,51 @@ structure Timing : TIMING = struct
             (log level (fn () => ["Aggregate times in order of appearance:"]);
              List.app summariseOne (rev (!recordOrder)))
         end
+                                                                       
+    fun timed tag f =
+        let open Log
+            val start = Time.now ()
+            val result = f ()
+            val finish = Time.now ()
+            val elapsed = Time.- (finish, start)
+            val () = record tag elapsed
+            val usElapsed = toUsReal elapsed
+            val () = Log.debug
+                         (fn () =>
+                             ["%1: %2%3s (%4/s)",
+                              tag,
+                              N usElapsed, mu, usPerSecStr usElapsed
+                         ])
+        in
+            result
+        end
+                                         
+    fun timedToBudget (tag, budget) f =
+        let open Log
+            val start = Time.now ()
+            val result = f ()
+            val finish = Time.now ()
+            val elapsed = Time.- (finish, start)
+            val () = record tag elapsed
+            val usElapsed = toUsReal elapsed
+            val () = Log.debug
+                         (fn () =>
+                             ["%1: %2%3s (%4/s)",
+                              tag,
+                              N usElapsed, mu, usPerSecStr usElapsed
+                         ])
+            val usBudget = toUsReal budget
+            val () = if Time.> (elapsed, budget)
+                     then Log.warn
+                              (fn () =>
+                                  ["%1: exceeded budget of %2%3s with elapsed time of %4%5s (%6/s)",
+                                   tag,
+                                   N usBudget, mu,
+                                   N usElapsed, mu, usPerSecStr usElapsed
+                              ])
+                     else ()
+        in
+            result
+        end
             
 end