src/Pure/General/timing.scala
author wenzelm
Mon, 09 Sep 2024 21:32:11 +0200
changeset 80829 bdae6195a287
parent 77368 7c57d9586f4c
permissions -rw-r--r--
clarified Pretty.markup_block: use value-oriented YXML.output_markup, with final re-interpretation via print_mode in output_tree; clarified Pretty.symbolic: always use YXML.output_markup;
Ignore whitespace changes - Everywhere: Within whitespace: At end of lines:
40393
2bb7ec08574a somewhat more uniform timing in ML vs. Scala;
wenzelm
parents:
diff changeset
     1
/*  Title:      Pure/General/timing.scala
2bb7ec08574a somewhat more uniform timing in ML vs. Scala;
wenzelm
parents:
diff changeset
     2
    Author:     Makarius
2bb7ec08574a somewhat more uniform timing in ML vs. Scala;
wenzelm
parents:
diff changeset
     3
65920
9e65c03e94da clarified signature;
wenzelm
parents: 65617
diff changeset
     4
Support for time measurement.
40393
2bb7ec08574a somewhat more uniform timing in ML vs. Scala;
wenzelm
parents:
diff changeset
     5
*/
2bb7ec08574a somewhat more uniform timing in ML vs. Scala;
wenzelm
parents:
diff changeset
     6
2bb7ec08574a somewhat more uniform timing in ML vs. Scala;
wenzelm
parents:
diff changeset
     7
package isabelle
2bb7ec08574a somewhat more uniform timing in ML vs. Scala;
wenzelm
parents:
diff changeset
     8
45664
ac6e704dcd12 tuned signature (according to ML version);
wenzelm
parents: 45249
diff changeset
     9
62571
2fd90993a928 print timing like lib/scripts/timestop.bash;
wenzelm
parents: 57912
diff changeset
    10
import java.util.Locale
2fd90993a928 print timing like lib/scripts/timestop.bash;
wenzelm
parents: 57912
diff changeset
    11
2fd90993a928 print timing like lib/scripts/timestop.bash;
wenzelm
parents: 57912
diff changeset
    12
75393
87ebf5a50283 clarified formatting, for the sake of scala3;
wenzelm
parents: 72015
diff changeset
    13
object Timing {
65920
9e65c03e94da clarified signature;
wenzelm
parents: 65617
diff changeset
    14
  val zero: Timing = Timing(Time.zero, Time.zero, Time.zero)
51587
7050c4656fd8 more operations on Time, Timing;
wenzelm
parents: 47653
diff changeset
    15
76593
badb5264f7b9 clarified signature: just one level of arguments to avoid type-inference problems;
wenzelm
parents: 76592
diff changeset
    16
  def timeit[A](body: => A,
76592
ec8bf1268f45 tuned signature: more operations;
wenzelm
parents: 75393
diff changeset
    17
    message: Exn.Result[A] => String = null,
65920
9e65c03e94da clarified signature;
wenzelm
parents: 65617
diff changeset
    18
    enabled: Boolean = true,
75393
87ebf5a50283 clarified formatting, for the sake of scala3;
wenzelm
parents: 72015
diff changeset
    19
    output: String => Unit = Output.warning(_)
76593
badb5264f7b9 clarified signature: just one level of arguments to avoid type-inference problems;
wenzelm
parents: 76592
diff changeset
    20
  ): A = {
47653
4605d4341b8b some builtin session timing;
wenzelm
parents: 46768
diff changeset
    21
    if (enabled) {
56691
ad5d7461b370 tuned signature, in accordance to ML version;
wenzelm
parents: 55618
diff changeset
    22
      val start = Time.now()
76593
badb5264f7b9 clarified signature: just one level of arguments to avoid type-inference problems;
wenzelm
parents: 76592
diff changeset
    23
      val result = Exn.capture(body)
56691
ad5d7461b370 tuned signature, in accordance to ML version;
wenzelm
parents: 55618
diff changeset
    24
      val stop = Time.now()
46768
46acd255810d relevant timing as in ML;
wenzelm
parents: 45674
diff changeset
    25
56691
ad5d7461b370 tuned signature, in accordance to ML version;
wenzelm
parents: 55618
diff changeset
    26
      val timing = stop - start
65920
9e65c03e94da clarified signature;
wenzelm
parents: 65617
diff changeset
    27
      if (timing.is_relevant) {
76592
ec8bf1268f45 tuned signature: more operations;
wenzelm
parents: 75393
diff changeset
    28
        val msg = if (message == null) null else message(result)
77368
wenzelm
parents: 76595
diff changeset
    29
        output(if_proper(msg, msg + ": ") + timing.message + " elapsed time")
65920
9e65c03e94da clarified signature;
wenzelm
parents: 65617
diff changeset
    30
      }
46768
46acd255810d relevant timing as in ML;
wenzelm
parents: 45674
diff changeset
    31
47653
4605d4341b8b some builtin session timing;
wenzelm
parents: 46768
diff changeset
    32
      Exn.release(result)
4605d4341b8b some builtin session timing;
wenzelm
parents: 46768
diff changeset
    33
    }
76593
badb5264f7b9 clarified signature: just one level of arguments to avoid type-inference problems;
wenzelm
parents: 76592
diff changeset
    34
    else body
65920
9e65c03e94da clarified signature;
wenzelm
parents: 65617
diff changeset
    35
  }
72015
6c6609fd898c more accurate message;
wenzelm
parents: 71785
diff changeset
    36
6c6609fd898c more accurate message;
wenzelm
parents: 71785
diff changeset
    37
  def factor_format(f: Double): String =
6c6609fd898c more accurate message;
wenzelm
parents: 71785
diff changeset
    38
    String.format(Locale.ROOT, ", factor %.2f", java.lang.Double.valueOf(f))
45664
ac6e704dcd12 tuned signature (according to ML version);
wenzelm
parents: 45249
diff changeset
    39
}
ac6e704dcd12 tuned signature (according to ML version);
wenzelm
parents: 45249
diff changeset
    40
75393
87ebf5a50283 clarified formatting, for the sake of scala3;
wenzelm
parents: 72015
diff changeset
    41
sealed case class Timing(elapsed: Time, cpu: Time, gc: Time) {
64089
10d719dbb3ee more permissive timing data;
wenzelm
parents: 64084
diff changeset
    42
  def is_zero: Boolean = elapsed.is_zero && cpu.is_zero && gc.is_zero
46768
46acd255810d relevant timing as in ML;
wenzelm
parents: 45674
diff changeset
    43
  def is_relevant: Boolean = elapsed.is_relevant || cpu.is_relevant || gc.is_relevant
46acd255810d relevant timing as in ML;
wenzelm
parents: 45674
diff changeset
    44
64084
bca58a11efde more operations;
wenzelm
parents: 62587
diff changeset
    45
  def resources: Time = cpu + gc
bca58a11efde more operations;
wenzelm
parents: 62587
diff changeset
    46
75393
87ebf5a50283 clarified formatting, for the sake of scala3;
wenzelm
parents: 72015
diff changeset
    47
  def factor: Option[Double] = {
64084
bca58a11efde more operations;
wenzelm
parents: 62587
diff changeset
    48
    val t1 = elapsed.seconds
bca58a11efde more operations;
wenzelm
parents: 62587
diff changeset
    49
    val t2 = resources.seconds
bca58a11efde more operations;
wenzelm
parents: 62587
diff changeset
    50
    if (t1 >= 3.0 && t2 >= 3.0) Some(t2 / t1) else None
bca58a11efde more operations;
wenzelm
parents: 62587
diff changeset
    51
  }
bca58a11efde more operations;
wenzelm
parents: 62587
diff changeset
    52
51587
7050c4656fd8 more operations on Time, Timing;
wenzelm
parents: 47653
diff changeset
    53
  def + (t: Timing): Timing = Timing(elapsed + t.elapsed, cpu + t.cpu, gc + t.gc)
7050c4656fd8 more operations on Time, Timing;
wenzelm
parents: 47653
diff changeset
    54
62587
e31bf8ed5397 clarified messages, notably on Windows where CPU time of poly.exe is not measured;
wenzelm
parents: 62571
diff changeset
    55
  def message: String =
e31bf8ed5397 clarified messages, notably on Windows where CPU time of poly.exe is not measured;
wenzelm
parents: 62571
diff changeset
    56
    elapsed.message + " elapsed time, " + cpu.message + " cpu time, " + gc.message + " GC time"
e31bf8ed5397 clarified messages, notably on Windows where CPU time of poly.exe is not measured;
wenzelm
parents: 62571
diff changeset
    57
72015
6c6609fd898c more accurate message;
wenzelm
parents: 71785
diff changeset
    58
  def message_factor: String =
6c6609fd898c more accurate message;
wenzelm
parents: 71785
diff changeset
    59
    elapsed.message + " elapsed time, " + cpu.message + " cpu time, " + gc.message + " GC time" +
6c6609fd898c more accurate message;
wenzelm
parents: 71785
diff changeset
    60
      Timing.factor_format(cpu.seconds / elapsed.seconds)
6c6609fd898c more accurate message;
wenzelm
parents: 71785
diff changeset
    61
75393
87ebf5a50283 clarified formatting, for the sake of scala3;
wenzelm
parents: 72015
diff changeset
    62
  def message_resources: String = {
64084
bca58a11efde more operations;
wenzelm
parents: 62587
diff changeset
    63
    val factor_text =
bca58a11efde more operations;
wenzelm
parents: 62587
diff changeset
    64
      factor match {
72015
6c6609fd898c more accurate message;
wenzelm
parents: 71785
diff changeset
    65
        case Some(f) => Timing.factor_format(f)
64084
bca58a11efde more operations;
wenzelm
parents: 62587
diff changeset
    66
        case None => ""
bca58a11efde more operations;
wenzelm
parents: 62587
diff changeset
    67
      }
76595
wenzelm
parents: 76593
diff changeset
    68
    if (resources.seconds >= 3.0) {
64084
bca58a11efde more operations;
wenzelm
parents: 62587
diff changeset
    69
      elapsed.message_hms + " elapsed time, " + resources.message_hms + " cpu time" + factor_text
76595
wenzelm
parents: 76593
diff changeset
    70
    }
wenzelm
parents: 76593
diff changeset
    71
    else {
64084
bca58a11efde more operations;
wenzelm
parents: 62587
diff changeset
    72
      elapsed.message_hms + " elapsed time" + factor_text
76595
wenzelm
parents: 76593
diff changeset
    73
    }
62571
2fd90993a928 print timing like lib/scripts/timestop.bash;
wenzelm
parents: 57912
diff changeset
    74
  }
2fd90993a928 print timing like lib/scripts/timestop.bash;
wenzelm
parents: 57912
diff changeset
    75
57912
wenzelm
parents: 56782
diff changeset
    76
  override def toString: String = message
67858
cba5c5657378 more informative JSON results;
wenzelm
parents: 65920
diff changeset
    77
cba5c5657378 more informative JSON results;
wenzelm
parents: 65920
diff changeset
    78
  def json: JSON.Object.T =
cba5c5657378 more informative JSON results;
wenzelm
parents: 65920
diff changeset
    79
    JSON.Object("elapsed" -> elapsed.seconds, "cpu" -> cpu.seconds, "gc" -> gc.seconds)
40848
8662b9b1f123 more abstract/uniform handling of time, preferring seconds as Double;
wenzelm
parents: 40393
diff changeset
    80
}