Add clock time (HH:MM) to GC notifications.
authorMatt Birkholz <puck@birchwood-abbey.net>
Wed, 9 Dec 2015 22:53:45 +0000 (15:53 -0700)
committerMatt Birkholz <puck@birchwood-abbey.net>
Sun, 3 Jan 2016 20:06:11 +0000 (13:06 -0700)
This makes it easier to see if a long running program is GCing more than
infrequently.

src/runtime/gcnote.scm
src/runtime/gcstat.scm
src/runtime/runtime.pkg

index e612ae65824c3c9e2a1ba464d23d07ad7dda6d07..30c1dd44a4bec4c8b07762364e4cd6ed74424c8d 100644 (file)
@@ -205,10 +205,22 @@ USA.
                     (round->exact (* (/ gc-length period) 100))
                     #d10))
                "%)")
-              7))))))
-
+              7)))))
+        (uctime-string     ;; E.g. "13:15" for 1:15pm local time
+         (lambda (uctime)
+           (let* ((decoded-time
+                   (universal-time->local-decoded-time uctime))
+                  (hour (decoded-time/hour decoded-time))
+                  (minute (decoded-time/minute decoded-time))
+                  (second (decoded-time/second decoded-time)))
+             (string-append
+              (if (< hour 10) "0" "") (number->string hour)
+              (if (< minute 10) ":0" ":") (number->string minute)
+              (if (< second 10) ":0" ":") (number->string second))))))
     (string-append ";GC #"
                   (number->string (gc-statistic/meter statistic))
+                  " "
+                  (uctime-string (gc-statistic/this-gc-start-uctime statistic))
                   ": took: "
                   (intervals->string
                    (gc-statistic/this-gc-start statistic)
index 532d1113e68f0a19b7ce79d0a5b88dca156ad8e2..46400439c079ec42c7c8139c8dc28180e8435eaf 100644 (file)
@@ -44,6 +44,7 @@ USA.
 
 (define (recorder/gc-start)
   (port/gc-start console-i/o-port)
+  (set! this-gc-start-uctime (get-universal-time))
   (set! this-gc-start-clock (real-time-clock))
   (set! this-gc-start (process-time-clock))
   unspecific)
@@ -55,6 +56,7 @@ USA.
     (increment-non-runtime! (- end-time this-gc-start))
     (statistics-flip this-gc-start end-time
                     space-remaining
+                    this-gc-start-uctime
                     this-gc-start-clock end-time-clock))
   (port/gc-finish console-i/o-port))
 \f
@@ -63,6 +65,7 @@ USA.
 (define last-gc-start)
 (define last-gc-end)
 (define this-gc-start)
+(define this-gc-start-uctime)
 (define this-gc-start-clock)
 (define last-gc-start-clock)
 (define last-gc-end-clock)
@@ -86,17 +89,19 @@ USA.
   (this-gc-end false read-only true)
   (last-gc-start false read-only true)
   (last-gc-end false read-only true)
+  (this-gc-start-uctime false read-only true)
   (this-gc-start-clock false read-only true)
   (this-gc-end-clock false read-only true)
   (last-gc-start-clock false read-only true)
   (last-gc-end-clock false read-only true))
 
-(define (statistics-flip start-time end-time heap-left start-clock end-clock)
+(define (statistics-flip start-time end-time heap-left
+                        start-uctime start-clock end-clock)
   (let ((statistic
         (make-gc-statistic timestamp heap-left
                            start-time end-time
                            last-gc-start last-gc-end
-                           start-clock end-clock
+                           start-uctime start-clock end-clock
                            last-gc-start-clock last-gc-end-clock)))
     (set! timestamp (cons (1+ (car timestamp)) (cdr timestamp)))
     (set! total-gc-time (+ (- end-time start-time) total-gc-time))
index 0a1dc57180e2f0c7f562adc64f71f98ae128388c..87ca7625b6e96a14328946a1b8c0aa88bdf3c48d 100644 (file)
@@ -2053,6 +2053,7 @@ USA.
          gc-statistic/this-gc-start
          gc-statistic/this-gc-end-clock
          gc-statistic/this-gc-start-clock
+         gc-statistic/this-gc-start-uctime
          gc-statistics
          gc-timestamp
          gctime)