Write the log in XML format suitable for VisualVM 'UI Actions' (#4110)

Start `project-manager` with following options to provide first 20s of the startup sequence:
```
$ project-manager --profiling-events-log-path=start.log --profiling-path=start.npss --profiling-time=20
```
once the `start.log` and `start.npss` files are generated (next to each other), open them in GraalVM's VisualVM:
```
$ graalvm/bin/jvisualvm --openfile start.npss
```
analyze.

CHANGELOG.md

@@ -554,6 +554,7 @@
 - [Optimize Atom storage layouts][3862]
 - [Make instance methods callable like statics for builtin types][4077]
 - [Convert large longs to doubles, safely, for host calls][4099]
+- [Profile engine startup][4110]
 
 [3227]: https://github.com/enso-org/enso/pull/3227
 [3248]: https://github.com/enso-org/enso/pull/3248
@@ -644,6 +645,7 @@
 [4056]: https://github.com/enso-org/enso/pull/4056
 [4077]: https://github.com/enso-org/enso/pull/4077
 [4099]: https://github.com/enso-org/enso/pull/4099
+[4110]: https://github.com/enso-org/enso/pull/4110
 
 # Enso 2.0.0-alpha.18 (2021-10-12)
 

docs/profiler/engine-startup.md

@@ -0,0 +1,42 @@
+# Summary
+
+One of the main objectives to deliver satisfactory user experience when using
+Enso is to be fast when getting ready to work. This requires the engine to
+initialize all services the IDE needs in proper order and to make sure the
+essential ones are ready as quickly as possible. In short - to **start fast**.
+This document describes how to measure, record and analyze the startup of the
+Enso engine.
+
+## Collecting the data
+
+Start `project-manager` with following options to record first 20s of the Enso
+engine startup sequence:
+
+```
+$ project-manager --profiling-events-log-path=start.log --profiling-path=start.npss --profiling-time=20
+```
+
+Let the IDE connect to just launched `project-manager` - e.g. start the IDE with
+`--no-backed` option. Once the `start.log` and `start.npss` files are generated
+(next to each other), open them in GraalVM's VisualVM:
+
+```
+$ graalvm/bin/jvisualvm --openfile start.npss
+```
+
+Use VisualVM to analyze to recorded data.
+
+### Interactively Analyze
+
+VisualVM offers two timelines. A "stackdepth" one and also _"UI Actions"_ line.
+Hovering over boxes in _"UI Actions"_ shows the messages describing what happens
+in the engine - what has been logged into `start.log`. One can then select an
+interval and get profiling information for that interval:
+
+![VisualVM](https://user-images.githubusercontent.com/26887752/216099011-33866c1d-06ab-48dc-936d-b9190e80b9fb.png)
+
+This picture shows that 2.7s is spend in `EnsoCompiledJob` task. Overall the
+goal is to log enough information to help us navigate thru the long startup
+sequence. Select appropriate interval based on the displayed _UI Actions_ - e.g.
+logged events - and analyze what has happened there based on the sampling of JVM
+stack traces.

docs/profiler/profiling.md

@@ -49,7 +49,8 @@ performing **objective**s.
 
 - **Project startup**  
   Time from selecting a project from the Hello Screen to a working graph view of
-  the project. Sub-processes:
+  the project. See also [engine startup](engine-startup.md) for non-IDE details
+  on a similar topic. Sub-processes:
 
   - **Graph Editor initialization**  
     Time needed to display fully-functional graph editor (not colored).

engine/language-server/src/main/scala/org/enso/languageserver/runtime/ApiEventsMonitor.scala

@@ -7,16 +7,28 @@ import org.enso.polyglot.runtime.Runtime.Api
 import java.nio.charset.StandardCharsets
 import java.nio.file.{Files, Path, StandardOpenOption}
 import java.time.Clock
+import java.util.logging.XMLFormatter
 
 import scala.util.Try
+import java.util.logging.LogRecord
+import java.util.logging.Level
 
 /** Gather messages between the language server and the runtime and write them
-  * to the provided file in CSV format.
+  * to the provided file in XML format.
   *
   * @param path the path where to write the events
   * @param clock the system clock
   */
 final class ApiEventsMonitor(path: Path, clock: Clock) extends EventsMonitor {
+  private lazy val fmt = {
+    Files.write(
+      path,
+      "<?xml version='1.0'?>\n<records>".getBytes(StandardCharsets.UTF_8),
+      StandardOpenOption.APPEND,
+      StandardOpenOption.SYNC
+    )
+    new XMLFormatter()
+  }
 
   import ApiEventsMonitor.Direction
 
@@ -57,8 +69,10 @@ final class ApiEventsMonitor(path: Path, clock: Clock) extends EventsMonitor {
     val requestIdEntry = requestId.fold("")(_.toString)
     val payloadEntry   = payload.getSimpleName
     val timeEntry      = clock.instant()
-    s"$timeEntry,$direction,$requestIdEntry,$payloadEntry${System.lineSeparator()}"
-      .getBytes(StandardCharsets.UTF_8)
+    val msg            = s"$direction,$requestIdEntry,$payloadEntry"
+    val record         = new LogRecord(Level.INFO, msg)
+    record.setInstant(timeEntry)
+    fmt.format(record).getBytes(StandardCharsets.UTF_8)
   }
 }
 object ApiEventsMonitor {