rmgen / CLogger timestamps

[elexis]

In Caledonian Meadows and Wild Lake there is/was some code to compute timestamps for the different steps of map generation.

This serves the general use case of debugging why some parts of the map generation code are much slower than others.

Instead of repeating Date calculations in every random map script, it should become a universal feature with the same string format in each string.

The log() function called by RMS is registered in ScriptInterface.cpp and is just a proxy to a non-rendered WriteMessage in CLogger.cpp that writes to mainlog.html.

A current example is:

<p>Loading simulation script 'simulation/components/VisionSharing.js'</p>
<p>Loading simulation script 'simulation/components/WallPiece.js'</p>
<p>Loading simulation script 'simulation/components/WallSet.js'</p>
<p>Loading simulation script 'simulation/components/Wonder.js'</p>
<p>'art/terrains/terrains.xml' does not exist. Using previous properties.</p>
<p>Loading RMS 'maps/random/volcanic_lands.js'</p>
<p>Loading map generator script 'maps/random/rmgen/area.js'</p>
<p>Loading map generator script 'maps/random/rmgen/constraint.js'</p>
<p>Loading map generator script 'maps/random/rmgen/entity.js'</p>
...
<p>Loading map generator script 'maps/random/rmgen/terrain.js'</p>
<p>Loading map generator script 'maps/random/rmgen/tileclass.js'</p>
<p>Loading map generator script 'maps/random/rmgen/wall_builder.js'</p>
<p>Creating new map...</p>
<p>Creating volcano</p>
<p>Creating hills...</p>
<p>Creating forests...</p>
<p>Creating dirt patches...</p>
<p>Creating stone mines...</p>
<p>Creating small stone mines...</p>
<p>Creating metal mines...</p>
<p>Creating small decorative rocks...</p>
<p>Creating large decorative rocks...</p>
<p>Creating straggler trees...</p>
<p>Determine starting units...</p>
<p>Ensure resources for a civic center...</p>
<p>Placing player units...</p>
<p>Determine starting units...</p>
<p>Ensure resources for a civic center...</p>
<p>Placing player units...</p>
<p>Determine starting units...</p>
<p>Ensure resources for a civic center...</p>
<p>Placing player units...</p>
<p>Saving map...</p>
<p>Number of entities: 380</p>
<p>CSkeletonAnimManager::GetAnimation(art/animation/biped/new/fem_idle_long.dae): Loaded successfully</p>
<p>CSkeletonAnimManager::GetAnimation(art/animation/biped/new/fem_idle_short.dae): Loaded successfully</p>
<p>CSkeletonAnimManager::GetAnimation(art/animation/biped/new/fem_idle_relax.dae): Loaded successfully</p>
<p>CSkeletonAnimManager::GetAnimation(art/animation/biped/new/fem_idle_relax_b.dae): Loaded successfully</p>

The timestamp could be the time since launch of the game or since start of the map generator:

<p>[1324] Creating volcano</p>
<p>[1325] Creating hills...</p>
<p>[1642] Creating forests...</p>

The timestamp could become a feature of the CLogger rather than only adding it to the random map generation code.

[elexis]

In 20853:

Remove random map script log entries that measured the time.
The mechanism should work for all random map script log entries, if the timestamps are not added to the CLogger directly, refs #4950.

[elexis]

Reducing the problem to rmgen/. For the simulation we already have two timers. Using JS rather than C++ for flexibility and simplicity.

We can cut the map gen time in half on many maps by removing the workarounds mentioned in #4695.

[elexis]

In 21073:

Implement rmgen JS logger that measures the time for each procedure and prints logmessages to stdout, fixes #4950.
Allows to identify performance bottlenecks quickly and provides a better sense of progress when viewing stdout.

[elexis]

In 21466:

Fix the two incorrect replacements in rP21434, refs #4950.

[elexis]

refs #5263