Files
@ r27832:3318d468dd1d
Branch filter:
Location: cpp/openttd-patchpack/source/docs/logging_and_performance_metrics.md - annotation
r27832:3318d468dd1d
7.3 KiB
text/x-markdown
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 | r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r23924:4d6b1b24e250 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 r24069:49625df81342 | # Logging, frame rate and performance metrics
## 1.0) Logging of potentially dangerous actions
OpenTTD is a complex program, and together with NewGRF, it may show a buggy
behaviour. But not only bugs in code can cause problems. There are several
ways to affect game state possibly resulting in program crash or multiplayer
desyncs.
Easier way would be to forbid all these unsafe actions, but that would affect
game usability for many players. We certainly do not want that.
However, we receive bug reports because of this. To reduce time spent with
solving these problems, these potentially unsafe actions are logged in
the savegame (including crash.sav). Log is stored in crash logs, too.
Information logged:
- Adding / removing / changing order of NewGRFs
- Changing NewGRF parameters, loading compatible NewGRF
- Changing game mode (scenario editor <-> normal game)
- Loading game saved in a different OpenTTD / TTDPatch / Transport Tycoon Deluxe /
original Transport Tycoon version
- Running a modified OpenTTD build
- Changing settings affecting NewGRF behaviour (non-network-safe settings)
- Triggering NewGRF bugs
No personal information is stored.
You can show the game log by typing 'gamelog' in the console or by running
OpenTTD in debug mode.
## 2.0) Frame rate and performance metrics
The Help menu in-game has a function to open the Frame rate window. This
window shows various real-time performance statistics, measuring what parts
of the game require the most processing power currently.
A summary of the statistics can also be retrieved from the console with the
`fps` command. This is especially useful on dedicated servers, where the
administrator might want to determine what's limiting performance in a slow
game.
The frame rate is given as two figures, the simulation rate and the graphics
frame rate. Usually these are identical, as the screen is rendered exactly
once per simulated tick, but in the future there might be support for graphics
and simulation running at different rates. When the game is paused, the
simulation rate drops to zero.
In addition to the simulation rate, a game speed factor is also calculated.
This is based on the target simulation speed, which is 30 milliseconds per
game tick. At that speed, the expected frame rate is 33.33 frames/second, and
the game speed factor is how close to that target the actual rate is. When
the game is in fast forward mode, the game speed factor shows how much
speed up is achieved.
The lower part of the window shows timing statistics for individual parts of
the game. The times shown are short-term and long-term averages of how long
it takes to process one tick of game time, all figures are in milliseconds.
Clicking a line in the lower part of the window opens a graph window, giving
detailed readings on each tick simulated by the game.
The following is an explanation of the different statistics:
- *Game loop* - Total processing time used per simulated "tick" in the game.
This includes all pathfinding, world updates, and economy handling.
- *Cargo handling* - Time spent loading/unloading cargo at stations, and
industries and towns sending/retrieving cargo from stations.
- *Train ticks*, *Road vehicle ticks*, *Ship ticks*, *Aircraft ticks* -
Time spent on pathfinding and other processing for each player vehicle type.
- *World ticks* - Time spent on other world/landscape processing. This
includes towns growing, building animations, updates of farmland and trees,
and station rating updates.
- *GS/AI total*, *Game script*, and *AI players* - Time spent running logic
for game scripts and AI players. The total may show as less than the current
sum of the individual scripts, this is because AI players at lower
difficulty settings do not run every game tick, and hence contribute less
to the average across all ticks. Keep in mind that the "Current" figure is
also an average, just only over short term.
- *Link graph delay* - Time overruns of the cargo distribution link graph
update thread. Usually the link graph is updated in a background thread,
but these updates need to synchronise with the main game loop occasionally,
if the time spent on link graph updates is longer than the time taken to
otherwise simulate the game while it was updating, these delays are counted
in this figure.
- *Graphics rendering* - Total time spent rendering all graphics, including
both GUI and world viewports. This typically spikes when panning the view
around, and when more things are happening on screen at once.
- *World viewport rendering* - Isolated time spent rendering just world
viewports. If this figure is significantly lower than the total graphics
rendering time, most time is spent rendering GUI than rendering world.
- *Video output* - Speed of copying the rendered graphics to the display
adapter. Usually this should be very fast (in the range of 0-3 ms), large
values for this can indicate a graphics driver problem.
- *Sound mixing* - Speed of mixing active audio samples together. Usually
this should be very fast (in the range of 0-3 ms), if it is slow, consider
switching to the NoSound set.
If the frame rate window is shaded, the title bar will instead show just the
current simulation rate and the game speed factor.
## 3.0) NewGRF callback profiling
NewGRF developers can profile callback chains via the `newgrf_profile`
console command. The command controls a profiling mode where every sprite
request is measured and logged, and written to a CSV file in the end.
The NewGRF developer tools need to be enabled for the command to function.
View the syntax for the command in-game with the console command
`help newgrf_profile`.
Profiling only works during game or in the editor, it's not possible to
profile across the main menu, world generation, or loading savegames.
The CSV files contain one line per sprite request during the profiling.
They can get very large, especially on large games with many objects from
the GRF. Start profiling short periods such as 3 or 7 days, and watch the
file sizes.
The produced CSV file contains the following fields:
- *Tick* - Game tick counter, this may wrap to zero during recording.
Mainly useful to distinguish events from separate ticks.
- *Sprite* - Index of the root Action 2 sprite in the GRF file. This is
the sprite group being resolved.
- *Feature* - NewGRF feature number the sprite group is being resolved for.
This will be 0xFF for AI purchase selection and ambient sound callbacks.
- *Item* - The id of the item within the GRF. For cargotypes, railtypes,
roadtypes, and tramtypes, this is the integer representation of the label.
- *CallbackID* - The type of callback being resolved. ID 0 is regular graphics
lookup. See the `newgrf_callbacks.h` file in the OpenTTD source code for the
full list of callback IDs.
- *Microseconds* - Total time spent to resolve the Action 2, in microseconds.
- *Depth* - Number of recursive Action 2 lookups were made during resolution.
Value zero means the sprite group resolved directly.
- *Result* - Result of the callback resolution. For lookups that result in
a sprite, this is the index of the base action 2 in the GRF file. For
callbacks that give a numeric result, this is the callback result value.
For lookups that result in an industry production or tilelayout, this
is the sprite index of the action 2 defining the production/tilelayout.
|