src/Pure/Tools/build_log.scala
author wenzelm
Thu Oct 06 11:27:03 2016 +0200 (2016-10-06)
changeset 64063 2c5039363ea3
parent 64062 a7352cbde7d7
child 64079 ff26032b7f2a
permissions -rw-r--r--
tuned signature;
wenzelm@64045
     1
/*  Title:      Pure/Tools/build_log.scala
wenzelm@64045
     2
    Author:     Makarius
wenzelm@64045
     3
wenzelm@64045
     4
Build log parsing for historic versions, back to "build_history_base".
wenzelm@64045
     5
*/
wenzelm@64045
     6
wenzelm@64045
     7
package isabelle
wenzelm@64045
     8
wenzelm@64045
     9
wenzelm@64061
    10
import java.time.ZonedDateTime
wenzelm@64061
    11
import java.time.format.{DateTimeFormatter, DateTimeParseException}
wenzelm@64061
    12
wenzelm@64054
    13
import scala.collection.mutable
wenzelm@64054
    14
import scala.util.matching.Regex
wenzelm@64054
    15
wenzelm@64054
    16
wenzelm@64045
    17
object Build_Log
wenzelm@64045
    18
{
wenzelm@64062
    19
  /** log file **/
wenzelm@64045
    20
wenzelm@64062
    21
  object Log_File
wenzelm@64062
    22
  {
wenzelm@64062
    23
    def apply(name: String, lines: List[String]): Log_File =
wenzelm@64062
    24
      new Log_File(name, lines)
wenzelm@64062
    25
wenzelm@64062
    26
    def apply(name: String, text: String): Log_File =
wenzelm@64063
    27
      Log_File(name, Library.trim_split_lines(text))
wenzelm@64062
    28
  }
wenzelm@64062
    29
wenzelm@64062
    30
  class Log_File private(val name: String, val lines: List[String])
wenzelm@64045
    31
  {
wenzelm@64062
    32
    log_file =>
wenzelm@64062
    33
wenzelm@64062
    34
    override def toString: String = name
wenzelm@64062
    35
wenzelm@64062
    36
    def text: String = cat_lines(lines)
wenzelm@64062
    37
wenzelm@64062
    38
    def err(msg: String): Nothing =
wenzelm@64062
    39
      error("Error in log file " + quote(name) + ": " + msg)
wenzelm@64062
    40
wenzelm@64062
    41
wenzelm@64062
    42
    /* inlined content */
wenzelm@64062
    43
wenzelm@64062
    44
    def find[A](f: String => Option[A]): Option[A] =
wenzelm@64062
    45
      lines.iterator.map(f).find(_.isDefined).map(_.get)
wenzelm@64062
    46
wenzelm@64062
    47
    def find_match(regex: Regex): Option[String] =
wenzelm@64062
    48
      lines.iterator.map(regex.unapplySeq(_)).find(res => res.isDefined && res.get.length == 1).
wenzelm@64062
    49
        map(res => res.get.head)
wenzelm@64062
    50
wenzelm@64062
    51
wenzelm@64062
    52
    /* settings */
wenzelm@64062
    53
wenzelm@64062
    54
    def get_setting(setting: String): String =
wenzelm@64062
    55
      lines.find(_.startsWith(setting + "=")) getOrElse err("missing " + setting)
wenzelm@64045
    56
wenzelm@64062
    57
    def get_settings(settings: List[String]): List[String] =
wenzelm@64062
    58
      settings.map(get_setting(_))
wenzelm@64062
    59
wenzelm@64062
    60
wenzelm@64062
    61
    /* properties (YXML) */
wenzelm@64062
    62
wenzelm@64062
    63
    val xml_cache = new XML.Cache()
wenzelm@64062
    64
wenzelm@64062
    65
    def parse_props(text: String): Properties.T =
wenzelm@64062
    66
      xml_cache.props(XML.Decode.properties(YXML.parse_body(text)))
wenzelm@64062
    67
wenzelm@64062
    68
    def filter_props(prefix: String): List[Properties.T] =
wenzelm@64062
    69
      for (line <- lines; s <- Library.try_unprefix(prefix, line)) yield parse_props(s)
wenzelm@64045
    70
wenzelm@64062
    71
    def find_line(prefix: String): Option[String] =
wenzelm@64062
    72
      find(Library.try_unprefix(prefix, _))
wenzelm@64062
    73
wenzelm@64062
    74
    def find_props(prefix: String): Option[Properties.T] =
wenzelm@64062
    75
      find_line(prefix).map(parse_props(_))
wenzelm@64062
    76
wenzelm@64062
    77
wenzelm@64062
    78
    /* parse various formats */
wenzelm@64062
    79
wenzelm@64062
    80
    def parse_session_info(session_name: String, full: Boolean): Session_Info =
wenzelm@64062
    81
      Build_Log.parse_session_info(log_file, session_name, full)
wenzelm@64062
    82
wenzelm@64062
    83
    def parse_header: Header = Build_Log.parse_header(log_file)
wenzelm@64062
    84
wenzelm@64062
    85
    def parse_info: Info = Build_Log.parse_info(log_file)
wenzelm@64045
    86
  }
wenzelm@64045
    87
wenzelm@64045
    88
wenzelm@64045
    89
  /* session log: produced by "isabelle build" */
wenzelm@64045
    90
wenzelm@64045
    91
  sealed case class Session_Info(
wenzelm@64045
    92
    session_name: String,
wenzelm@64045
    93
    session_timing: Properties.T,
wenzelm@64045
    94
    command_timings: List[Properties.T],
wenzelm@64045
    95
    ml_statistics: List[Properties.T],
wenzelm@64045
    96
    task_statistics: List[Properties.T])
wenzelm@64045
    97
wenzelm@64062
    98
  private def parse_session_info(log_file: Log_File, name0: String, full: Boolean): Session_Info =
wenzelm@64045
    99
  {
wenzelm@64045
   100
    val xml_cache = new XML.Cache()
wenzelm@64045
   101
wenzelm@64045
   102
    val session_name =
wenzelm@64062
   103
      log_file.find_line("\fSession.name = ") match {
wenzelm@64045
   104
        case None => name0
wenzelm@64045
   105
        case Some(name) if name0 == "" || name0 == name => name
wenzelm@64062
   106
        case Some(name) => log_file.err("log from different session " + quote(name))
wenzelm@64045
   107
      }
wenzelm@64062
   108
    val session_timing = log_file.find_props("\fTiming = ") getOrElse Nil
wenzelm@64062
   109
    val command_timings = log_file.filter_props("\fcommand_timing = ")
wenzelm@64062
   110
    val ml_statistics = if (full) log_file.filter_props("\fML_statistics = ") else Nil
wenzelm@64062
   111
    val task_statistics = if (full) log_file.filter_props("\ftask_statistics = ") else Nil
wenzelm@64045
   112
wenzelm@64045
   113
    Session_Info(session_name, session_timing, command_timings, ml_statistics, task_statistics)
wenzelm@64045
   114
  }
wenzelm@64054
   115
wenzelm@64054
   116
wenzelm@64062
   117
  /* header and meta data */
wenzelm@64061
   118
wenzelm@64061
   119
  object Header_Kind extends Enumeration
wenzelm@64061
   120
  {
wenzelm@64061
   121
    val ISATEST = Value("isatest")
wenzelm@64061
   122
    val AFP_TEST = Value("afp-test")
wenzelm@64061
   123
    val JENKINS = Value("jenkins")
wenzelm@64061
   124
  }
wenzelm@64061
   125
wenzelm@64061
   126
  sealed case class Header(kind: Header_Kind.Value, props: Properties.T, settings: List[String])
wenzelm@64061
   127
wenzelm@64061
   128
  object Field
wenzelm@64061
   129
  {
wenzelm@64061
   130
    val build_host = "build_host"
wenzelm@64061
   131
    val build_start = "build_start"
wenzelm@64061
   132
    val build_end = "build_end"
wenzelm@64061
   133
    val isabelle_version = "isabelle_version"
wenzelm@64061
   134
    val afp_version = "afp_version"
wenzelm@64061
   135
  }
wenzelm@64061
   136
wenzelm@64062
   137
  val ml_settings = List("ML_PLATFORM", "ML_HOME", "ML_SYSTEM", "ML_OPTIONS")
wenzelm@64062
   138
wenzelm@64061
   139
  object AFP
wenzelm@64061
   140
  {
wenzelm@64061
   141
    val Date_Format =
wenzelm@64061
   142
      Date.Format.make_patterns(List("EEE MMM d HH:mm:ss VV yyyy", "EEE MMM d HH:mm:ss O yyyy"),
wenzelm@64061
   143
        // workaround for jdk-8u102
wenzelm@64061
   144
        s => Word.implode(Word.explode(s).map({ case "CEST" => "GMT+2" case a => a })))
wenzelm@64062
   145
wenzelm@64061
   146
    val Test_Start = new Regex("""^Start test for .+ at (.+), (\w+)$""")
wenzelm@64061
   147
    val Test_End = new Regex("""^End test on (.+), \w+, elapsed time:.*$""")
wenzelm@64061
   148
    val Isabelle_Version = new Regex("""^Isabelle version: .* -- hg id (\w+)$""")
wenzelm@64061
   149
    val AFP_Version = new Regex("""^AFP version: .* -- hg id (\w+)$""")
wenzelm@64062
   150
    val settings = "ISABELLE_BUILD_OPTIONS" :: ml_settings
wenzelm@64061
   151
  }
wenzelm@64061
   152
wenzelm@64062
   153
  private def parse_header(log_file: Log_File): Header =
wenzelm@64061
   154
  {
wenzelm@64062
   155
    log_file.lines match {
wenzelm@64062
   156
      case AFP.Test_Start(start, hostname) :: _ =>
wenzelm@64062
   157
        (start, log_file.lines.last) match {
wenzelm@64062
   158
          case (AFP.Date_Format(start_date), AFP.Test_End(AFP.Date_Format(end_date))) =>
wenzelm@64062
   159
            val isabelle_version =
wenzelm@64062
   160
              log_file.find_match(AFP.Isabelle_Version) getOrElse
wenzelm@64062
   161
                log_file.err("missing Isabelle version")
wenzelm@64062
   162
            val afp_version =
wenzelm@64062
   163
              log_file.find_match(AFP.AFP_Version) getOrElse
wenzelm@64062
   164
                log_file.err("missing AFP version")
wenzelm@64061
   165
wenzelm@64062
   166
            Header(Header_Kind.AFP_TEST,
wenzelm@64061
   167
              List(
wenzelm@64061
   168
                Field.build_host -> hostname,
wenzelm@64061
   169
                Field.build_start -> start_date.toString,
wenzelm@64062
   170
                Field.build_end -> end_date.toString,
wenzelm@64062
   171
                Field.isabelle_version -> isabelle_version,
wenzelm@64062
   172
                Field.afp_version -> afp_version),
wenzelm@64062
   173
              log_file.get_settings(AFP.settings))
wenzelm@64062
   174
wenzelm@64062
   175
          case _ => log_file.err("cannot detect start/end date in afp-test log")
wenzelm@64061
   176
        }
wenzelm@64062
   177
      case _ => log_file.err("cannot detect log header format")
wenzelm@64061
   178
    }
wenzelm@64061
   179
  }
wenzelm@64061
   180
wenzelm@64061
   181
  object Session_Status extends Enumeration
wenzelm@64061
   182
  {
wenzelm@64061
   183
    val UNKNOWN = Value("unknown")
wenzelm@64061
   184
    val FINISHED = Value("finished")
wenzelm@64061
   185
    val FAILED = Value("failed")
wenzelm@64061
   186
    val CANCELLED = Value("cancelled")
wenzelm@64061
   187
  }
wenzelm@64061
   188
wenzelm@64061
   189
wenzelm@64054
   190
  /* main log: produced by isatest, afp-test, jenkins etc. */
wenzelm@64054
   191
wenzelm@64054
   192
  sealed case class Info(
wenzelm@64054
   193
    ml_options: List[(String, String)],
wenzelm@64054
   194
    finished: Map[String, Timing],
wenzelm@64054
   195
    timing: Map[String, Timing],
wenzelm@64054
   196
    threads: Map[String, Int])
wenzelm@64054
   197
  {
wenzelm@64054
   198
    val sessions: Set[String] = finished.keySet ++ timing.keySet
wenzelm@64054
   199
wenzelm@64054
   200
    override def toString: String =
wenzelm@64054
   201
      sessions.toList.sorted.mkString("Build_Log.Info(", ", ", ")")
wenzelm@64054
   202
  }
wenzelm@64054
   203
wenzelm@64054
   204
  private val Session_Finished1 =
wenzelm@64054
   205
    new Regex("""^Finished (\S+) \((\d+):(\d+):(\d+) elapsed time, (\d+):(\d+):(\d+) cpu time.*$""")
wenzelm@64054
   206
  private val Session_Finished2 =
wenzelm@64054
   207
    new Regex("""^Finished (\S+) \((\d+):(\d+):(\d+) elapsed time.*$""")
wenzelm@64054
   208
  private val Session_Timing =
wenzelm@64054
   209
    new Regex("""^Timing (\S+) \((\d) threads, (\d+\.\d+)s elapsed time, (\d+\.\d+)s cpu time, (\d+\.\d+)s GC time.*$""")
wenzelm@64054
   210
wenzelm@64054
   211
  private object ML_Option
wenzelm@64054
   212
  {
wenzelm@64054
   213
    def unapply(s: String): Option[(String, String)] =
wenzelm@64054
   214
      s.indexOf('=') match {
wenzelm@64054
   215
        case -1 => None
wenzelm@64054
   216
        case i =>
wenzelm@64054
   217
          val a = s.substring(0, i)
wenzelm@64054
   218
          Library.try_unquote(s.substring(i + 1)) match {
wenzelm@64054
   219
            case Some(b) if Build.ml_options.contains(a) => Some((a, b))
wenzelm@64054
   220
            case _ => None
wenzelm@64054
   221
          }
wenzelm@64054
   222
      }
wenzelm@64054
   223
  }
wenzelm@64054
   224
wenzelm@64062
   225
  private def parse_info(log_file: Log_File): Info =
wenzelm@64054
   226
  {
wenzelm@64054
   227
    val ml_options = new mutable.ListBuffer[(String, String)]
wenzelm@64054
   228
    var finished = Map.empty[String, Timing]
wenzelm@64054
   229
    var timing = Map.empty[String, Timing]
wenzelm@64054
   230
    var threads = Map.empty[String, Int]
wenzelm@64054
   231
wenzelm@64062
   232
    for (line <- log_file.lines) {
wenzelm@64054
   233
      line match {
wenzelm@64054
   234
        case Session_Finished1(name,
wenzelm@64054
   235
            Value.Int(e1), Value.Int(e2), Value.Int(e3),
wenzelm@64054
   236
            Value.Int(c1), Value.Int(c2), Value.Int(c3)) =>
wenzelm@64054
   237
          val elapsed = Time.hms(e1, e2, e3)
wenzelm@64054
   238
          val cpu = Time.hms(c1, c2, c3)
wenzelm@64054
   239
          finished += (name -> Timing(elapsed, cpu, Time.zero))
wenzelm@64054
   240
        case Session_Finished2(name,
wenzelm@64054
   241
            Value.Int(e1), Value.Int(e2), Value.Int(e3)) =>
wenzelm@64054
   242
          val elapsed = Time.hms(e1, e2, e3)
wenzelm@64054
   243
          finished += (name -> Timing(elapsed, Time.zero, Time.zero))
wenzelm@64054
   244
        case Session_Timing(name,
wenzelm@64054
   245
            Value.Int(t), Value.Double(e), Value.Double(c), Value.Double(g)) =>
wenzelm@64054
   246
          val elapsed = Time.seconds(e)
wenzelm@64054
   247
          val cpu = Time.seconds(c)
wenzelm@64054
   248
          val gc = Time.seconds(g)
wenzelm@64054
   249
          timing += (name -> Timing(elapsed, cpu, gc))
wenzelm@64054
   250
          threads += (name -> t)
wenzelm@64054
   251
        case ML_Option(a, b) => ml_options += (a -> b)
wenzelm@64054
   252
        case _ =>
wenzelm@64054
   253
      }
wenzelm@64054
   254
    }
wenzelm@64054
   255
wenzelm@64054
   256
    Info(ml_options.toList, finished, timing, threads)
wenzelm@64054
   257
  }
wenzelm@64045
   258
}