src/Pure/Tools/build_log.scala
author wenzelm
Fri Oct 07 17:41:19 2016 +0200 (2016-10-07)
changeset 64086 ac7ae5067783
parent 64085 1c451e5c145f
child 64087 a77c57235bae
permissions -rw-r--r--
clarified status: started sessions may bomb without explicit FAILED or CANCELLED (cf. in afp-test-devel-2016-01-03.log);
     1 /*  Title:      Pure/Tools/build_log.scala
     2     Author:     Makarius
     3 
     4 Build log parsing for historic versions, back to "build_history_base".
     5 */
     6 
     7 package isabelle
     8 
     9 
    10 import java.time.ZonedDateTime
    11 import java.time.format.{DateTimeFormatter, DateTimeParseException}
    12 
    13 import scala.collection.mutable
    14 import scala.util.matching.Regex
    15 
    16 
    17 object Build_Log
    18 {
    19   /** settings **/
    20 
    21   object Settings
    22   {
    23     val build_settings = List("ISABELLE_BUILD_OPTIONS")
    24     val ml_settings = List("ML_PLATFORM", "ML_HOME", "ML_SYSTEM", "ML_OPTIONS")
    25     val all_settings = build_settings ::: ml_settings
    26 
    27     type Entry = (String, String)
    28     type T = List[Entry]
    29 
    30     object Entry
    31     {
    32       def unapply(s: String): Option[Entry] =
    33         s.indexOf('=') match {
    34           case -1 => None
    35           case i =>
    36             val a = s.substring(0, i)
    37             val b = Library.perhaps_unquote(s.substring(i + 1))
    38             Some((a, b))
    39         }
    40       def apply(a: String, b: String): String = a + "=" + quote(b)
    41       def getenv(a: String): String = apply(a, Isabelle_System.getenv(a))
    42     }
    43 
    44     def show(): String =
    45       cat_lines(
    46         build_settings.map(Entry.getenv(_)) ::: List("") ::: ml_settings.map(Entry.getenv(_)))
    47   }
    48 
    49 
    50   /** log file **/
    51 
    52   object Log_File
    53   {
    54     def apply(path: Path): Log_File =
    55     {
    56       val (path_name, ext) = path.expand.split_ext
    57       val text =
    58         if (ext == "gz") File.read_gzip(path)
    59         else if (ext == "xz") File.read_xz(path)
    60         else File.read(path)
    61       apply(path_name.base.implode, text)
    62     }
    63 
    64     def apply(name: String, lines: List[String]): Log_File =
    65       new Log_File(name, lines)
    66 
    67     def apply(name: String, text: String): Log_File =
    68       Log_File(name, Library.trim_split_lines(text))
    69   }
    70 
    71   class Log_File private(val name: String, val lines: List[String])
    72   {
    73     log_file =>
    74 
    75     override def toString: String = name
    76 
    77     def text: String = cat_lines(lines)
    78 
    79     def err(msg: String): Nothing =
    80       error("Error in log file " + quote(name) + ": " + msg)
    81 
    82 
    83     /* inlined content */
    84 
    85     def find[A](f: String => Option[A]): Option[A] =
    86       lines.iterator.map(f).find(_.isDefined).map(_.get)
    87 
    88     def find_match(regex: Regex): Option[String] =
    89       lines.iterator.map(regex.unapplySeq(_)).find(res => res.isDefined && res.get.length == 1).
    90         map(res => res.get.head)
    91 
    92 
    93     /* settings */
    94 
    95     def get_setting(a: String): Settings.Entry =
    96       Settings.Entry.unapply(
    97         lines.find(_.startsWith(a + "=")) getOrElse err("missing " + a)).get
    98 
    99     def get_settings(as: List[String]): Settings.T = as.map(get_setting(_))
   100 
   101 
   102     /* properties (YXML) */
   103 
   104     val xml_cache = new XML.Cache()
   105 
   106     def parse_props(text: String): Properties.T =
   107       xml_cache.props(XML.Decode.properties(YXML.parse_body(text)))
   108 
   109     def filter_props(prefix: String): List[Properties.T] =
   110       for (line <- lines; s <- Library.try_unprefix(prefix, line)) yield parse_props(s)
   111 
   112     def find_line(prefix: String): Option[String] =
   113       find(Library.try_unprefix(prefix, _))
   114 
   115     def find_props(prefix: String): Option[Properties.T] =
   116       find_line(prefix).map(parse_props(_))
   117 
   118 
   119     /* parse various formats */
   120 
   121     def parse_session_info(
   122         default_name: String = "",
   123         command_timings: Boolean = false,
   124         ml_statistics: Boolean = false,
   125         task_statistics: Boolean = false): Session_Info =
   126       Build_Log.parse_session_info(
   127         log_file, default_name, command_timings, ml_statistics, task_statistics)
   128 
   129     def parse_header(): Header = Build_Log.parse_header(log_file)
   130 
   131     def parse_build_info(): Build_Info = Build_Log.parse_build_info(log_file)
   132   }
   133 
   134 
   135   /* session log: produced by "isabelle build" */
   136 
   137   sealed case class Session_Info(
   138     session_name: String,
   139     session_timing: Properties.T,
   140     command_timings: List[Properties.T],
   141     ml_statistics: List[Properties.T],
   142     task_statistics: List[Properties.T])
   143 
   144   private def parse_session_info(
   145     log_file: Log_File,
   146     default_name: String,
   147     command_timings: Boolean,
   148     ml_statistics: Boolean,
   149     task_statistics: Boolean): Session_Info =
   150   {
   151     val xml_cache = new XML.Cache()
   152 
   153     val session_name =
   154       log_file.find_line("\fSession.name = ") match {
   155         case None => default_name
   156         case Some(name) if default_name == "" || default_name == name => name
   157         case Some(name) => log_file.err("log from different session " + quote(name))
   158       }
   159     val session_timing = log_file.find_props("\fTiming = ") getOrElse Nil
   160     val command_timings_ =
   161       if (command_timings) log_file.filter_props("\fcommand_timing = ") else Nil
   162     val ml_statistics_ =
   163       if (ml_statistics) log_file.filter_props("\fML_statistics = ") else Nil
   164     val task_statistics_ =
   165       if (task_statistics) log_file.filter_props("\ftask_statistics = ") else Nil
   166 
   167     Session_Info(session_name, session_timing, command_timings_, ml_statistics_, task_statistics_)
   168   }
   169 
   170 
   171   /* header and meta data */
   172 
   173   object Header_Kind extends Enumeration
   174   {
   175     val ISATEST = Value("isatest")
   176     val AFP_TEST = Value("afp-test")
   177     val JENKINS = Value("jenkins")
   178   }
   179 
   180   sealed case class Header(
   181     kind: Header_Kind.Value, props: Properties.T, settings: List[(String, String)])
   182 
   183   object Field
   184   {
   185     val build_host = "build_host"
   186     val build_start = "build_start"
   187     val build_end = "build_end"
   188     val isabelle_version = "isabelle_version"
   189     val afp_version = "afp_version"
   190   }
   191 
   192   object AFP
   193   {
   194     val Date_Format =
   195       Date.Format.make_patterns(List("EEE MMM d HH:mm:ss VV yyyy", "EEE MMM d HH:mm:ss O yyyy"),
   196         // workaround for jdk-8u102
   197         s => Word.implode(Word.explode(s).map({ case "CEST" => "GMT+2" case a => a })))
   198 
   199     val Test_Start = new Regex("""^Start test for .+ at (.+), (\w+)$""")
   200     val Test_End = new Regex("""^End test on (.+), \w+, elapsed time:.*$""")
   201     val Isabelle_Version = new Regex("""^Isabelle version: .* -- hg id (\w+)$""")
   202     val AFP_Version = new Regex("""^AFP version: .* -- hg id (\w+)$""")
   203   }
   204 
   205   private def parse_header(log_file: Log_File): Header =
   206   {
   207     log_file.lines match {
   208       case AFP.Test_Start(start, hostname) :: _ =>
   209         (start, log_file.lines.last) match {
   210           case (AFP.Date_Format(start_date), AFP.Test_End(AFP.Date_Format(end_date))) =>
   211             val isabelle_version =
   212               log_file.find_match(AFP.Isabelle_Version) getOrElse
   213                 log_file.err("missing Isabelle version")
   214             val afp_version =
   215               log_file.find_match(AFP.AFP_Version) getOrElse
   216                 log_file.err("missing AFP version")
   217 
   218             Header(Header_Kind.AFP_TEST,
   219               List(
   220                 Field.build_host -> hostname,
   221                 Field.build_start -> start_date.toString,
   222                 Field.build_end -> end_date.toString,
   223                 Field.isabelle_version -> isabelle_version,
   224                 Field.afp_version -> afp_version),
   225               log_file.get_settings(Settings.all_settings))
   226 
   227           case _ => log_file.err("cannot detect start/end date in afp-test log")
   228         }
   229       case _ => log_file.err("cannot detect log header format")
   230     }
   231   }
   232 
   233 
   234   /* build info: produced by isabelle build */
   235 
   236   object Session_Status extends Enumeration
   237   {
   238     val EXISTING = Value("existing")
   239     val FINISHED = Value("finished")
   240     val FAILED = Value("failed")
   241     val CANCELLED = Value("cancelled")
   242   }
   243 
   244   sealed case class Session_Entry(
   245     chapter: String,
   246     groups: List[String],
   247     threads: Option[Int],
   248     timing: Option[Timing],
   249     ml_timing: Option[Timing],
   250     status: Session_Status.Value)
   251   {
   252     def finished: Boolean = status == Session_Status.FINISHED
   253   }
   254 
   255   sealed case class Build_Info(sessions: Map[String, Session_Entry])
   256   {
   257     def session(name: String): Session_Entry = sessions(name)
   258     def get_session(name: String): Option[Session_Entry] = sessions.get(name)
   259 
   260     def finished(name: String): Boolean =
   261       get_session(name) match {
   262         case Some(entry) => entry.finished
   263         case None => false
   264       }
   265 
   266     def timing(name: String): Timing =
   267       (for (entry <- get_session(name); t <- entry.timing) yield t) getOrElse Timing.zero
   268 
   269     def ml_timing(name: String): Timing =
   270       (for (entry <- get_session(name); t <- entry.ml_timing) yield t) getOrElse Timing.zero
   271   }
   272 
   273   private def parse_build_info(log_file: Log_File): Build_Info =
   274   {
   275     object Chapter_Name
   276     {
   277       def unapply(s: String): Some[(String, String)] =
   278         space_explode('/', s) match {
   279           case List(chapter, name) => Some((chapter, name))
   280           case _ => Some(("", s))
   281         }
   282     }
   283 
   284     val Session_No_Groups = new Regex("""^Session (\S+)$""")
   285     val Session_Groups = new Regex("""^Session (\S+) \((.*)\)$""")
   286     val Session_Finished1 =
   287       new Regex("""^Finished (\S+) \((\d+):(\d+):(\d+) elapsed time, (\d+):(\d+):(\d+) cpu time.*$""")
   288     val Session_Finished2 =
   289       new Regex("""^Finished (\S+) \((\d+):(\d+):(\d+) elapsed time.*$""")
   290     val Session_Timing =
   291       new Regex("""^Timing (\S+) \((\d) threads, (\d+\.\d+)s elapsed time, (\d+\.\d+)s cpu time, (\d+\.\d+)s GC time.*$""")
   292     val Session_Started = new Regex("""^(?:Running|Building) (\S+) \.\.\.$""")
   293     val Session_Failed = new Regex("""^(\S+) FAILED""")
   294     val Session_Cancelled = new Regex("""^(\S+) CANCELLED""")
   295 
   296     var chapter = Map.empty[String, String]
   297     var groups = Map.empty[String, List[String]]
   298     var threads = Map.empty[String, Int]
   299     var timing = Map.empty[String, Timing]
   300     var ml_timing = Map.empty[String, Timing]
   301     var started = Set.empty[String]
   302     var failed = Set.empty[String]
   303     var cancelled = Set.empty[String]
   304     def all_sessions: Set[String] =
   305       chapter.keySet ++ groups.keySet ++ threads.keySet ++
   306       timing.keySet ++ ml_timing.keySet ++ failed ++ cancelled ++ started
   307 
   308 
   309     for (line <- log_file.lines) {
   310       line match {
   311         case Session_No_Groups(Chapter_Name(chapt, name)) =>
   312           chapter += (name -> chapt)
   313           groups += (name -> Nil)
   314         case Session_Groups(Chapter_Name(chapt, name), grps) =>
   315           chapter += (name -> chapt)
   316           groups += (name -> Word.explode(grps))
   317         case Session_Started(name) =>
   318           started += name
   319         case Session_Finished1(name,
   320             Value.Int(e1), Value.Int(e2), Value.Int(e3),
   321             Value.Int(c1), Value.Int(c2), Value.Int(c3)) =>
   322           val elapsed = Time.hms(e1, e2, e3)
   323           val cpu = Time.hms(c1, c2, c3)
   324           timing += (name -> Timing(elapsed, cpu, Time.zero))
   325         case Session_Finished2(name,
   326             Value.Int(e1), Value.Int(e2), Value.Int(e3)) =>
   327           val elapsed = Time.hms(e1, e2, e3)
   328           timing += (name -> Timing(elapsed, Time.zero, Time.zero))
   329         case Session_Timing(name,
   330             Value.Int(t), Value.Double(e), Value.Double(c), Value.Double(g)) =>
   331           val elapsed = Time.seconds(e)
   332           val cpu = Time.seconds(c)
   333           val gc = Time.seconds(g)
   334           ml_timing += (name -> Timing(elapsed, cpu, gc))
   335           threads += (name -> t)
   336         case _ =>
   337       }
   338     }
   339 
   340     val sessions =
   341       Map(
   342         (for (name <- all_sessions.toList) yield {
   343           val status =
   344             if (failed(name)) Session_Status.FAILED
   345             else if (cancelled(name)) Session_Status.CANCELLED
   346             else if (timing.isDefinedAt(name) || ml_timing.isDefinedAt(name))
   347               Session_Status.FINISHED
   348             else if (started(name)) Session_Status.FAILED
   349             else Session_Status.EXISTING
   350           val entry =
   351             Session_Entry(
   352               chapter.getOrElse(name, ""),
   353               groups.getOrElse(name, Nil),
   354               threads.get(name),
   355               timing.get(name),
   356               ml_timing.get(name),
   357               status)
   358           (name -> entry)
   359         }):_*)
   360     Build_Info(sessions)
   361   }
   362 }