Opened 5 years ago

Closed 5 years ago

Last modified 5 years ago

#4950 closed defect (fixed)

rmgen / CLogger timestamps

Reported by: elexis Owned by: elexis
Priority: Nice to Have Milestone: Alpha 23
Component: Maps Keywords:
Cc: Patch:

Description

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.

Change History (5)

comment:1 by elexis, 5 years ago

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.

comment:2 by elexis, 5 years ago

Component: Core engineMaps
Milestone: BacklogAlpha 23
Owner: set to elexis
Status: newassigned
Summary: CLogger timestampsrmgen / CLogger timestamps

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.

comment:3 by elexis, 5 years ago

Resolution: fixed
Status: assignedclosed

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.

comment:4 by elexis, 5 years ago

In 21466:

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

comment:5 by elexis, 5 years ago

refs #5263

Note: See TracTickets for help on using tickets.