RAMSES Documentation  27.0.130
Information for RAMSES users and developers
Performance and profiling

Overview

There are multiple ways to find bottlenecks in your assets, your code using Ramses, or Ramses itself.

Inspecting the contents of your scene and optimizing it

The first source of performance problems in a 3D application is usually the content. Having large textures or geometry, heavy shaders, or simply rendering suboptimally - those are all things that can be easily solved in the content/scene directly by a skilled technical artist.

Ramses provides a tool to perform such analysis, called the ramses scene viewer (see its documentation in ramses-scene-viewer).

Looking at the Ramses periodic performance logs

A great source of information about what's going on in the Ramses threads (specifically when having network involved) are the ramses periodic logs (RPER). See below how to read and use these logs.

General periodic logs

Any Ramses application (regardless if it has a client, a renderer, or both) has a periodic log whichs looks like this: 

20210212-16:33:50.770 | Info  | RPER | Version: 27.0.6 Hash:cca2a0b60f Commit:28143 Type:Release Env:(unknown) SyncT:1613144030770ms (dtSteady:2023 - dtSync:2023 -> 0) PUp:31679 RUp:31575 RInit:1 RParallel:1
20210212-16:33:50.775 | Info  | RPER | Connected Participant(s): 00000000-0000-0000-0000-000000000003, 00000000-0000-0000-0000-000000000004, 00000000-0000-0000-0000-000000000002, 00000000-0000-0000-0000-000000000005
20210212-16:33:50.775 | Info  | RPER | Dcsm(7AB1-B4A4D03AA15F) C LP:false LC:false CP[] C[]

First line:

  • Ramses version, commithash, commit no, build type
  • RInit: 1 instance of ramses initialized (framework)
  • RParallel: 1 instance of ramses running now

Second line: Participants connected to this instance of ramses

Third line: Dcsm related stats

Client periodic logs

A Ramses client typically reports logs like this: 

20210212-16:33:50.778 | Info  | RPER | Client: 1 scene(s): 123 Subscribed
20210212-16:33:50.778 | Info  | RPER | msgIn (0) msgO (0) res+ (27/32/29) res- (0) resNr (218/245/231) resF (0) resFS (0)
20210212-16:33:50.782 | Info  | RPER | scene: 123 flush (60/61/60) obj+ (50/75/62) obj- (0) objNr (2670/2720/2695) actG (1560/1671/1615) actGS (30988/33020/32004) actO (1560/1671/1615) actSkp (0) ar# (173/197/185) aras (53460/54325/53892) arms (408272) er# (11) eras (1241) erms (2388) tr# (19/20/19) tras (1099739/1114657/1107198) trms (2097144)

The client-side periodic logger collects the stats values (flush, obj+, etc) every second. However the time interval for logging output is configurable and by default set to 2 seconds.

The collected values are printed in two fashions depending on the stat value:

  • suX lists the largest collected values of the last logging period (value1, value2, ..., valueN)
  • For all other stats there are typically 3 values printed (min/max/avg): -* min: the smallest value that was collected since the last log output -* max: the largest value that was collected since the last log output -* avg: the average of all collected values since the last log output: ((value1 + value2 + ..valueN) / n)

If the smallest and the largest value are equal (min == max), only 1 value will be printed: (value)

Examples:

  • Time interval is set to 4 seconds. The logger collected 4 values: 20, 25, 21, 55; Logs will print: (20/55/30)
  • Time interval is set to 2 seconds, the logger collected 2 values: 42, 42; Logs will print (42)

The logs explained line by line:

First line:

  • Client participant id
  • List of scenes owned by the client and their status

Second line (General client performance stats):

  • msgIn: Number of messages received
  • msgO: Number of message sent
  • res+: Client Resources created
  • res-: Client Resources destroyed
  • resNr: Client Resource Count
  • resF: Number of Client Resources loaded from File
  • resFS: Size of Client Resources loaded from file

Third line and over (Scene related stats):

  • scene: scene id
  • flush: Number of flushes triggered per second
  • obj+: Number of scene objects created (ramses::SceneObject) per second
  • obj-: Number of scene objects destroyed (ramses::SceneObject) per second
  • objNr: Number of currently existing scene objects (ramses::SceneObject)
  • actG: Number of scene actions generated per second
  • actGS: Size of scene actions generated per second
  • actO: Number of scene actions sent to renderer(s) per second (will be counted for each scene subscriber)
  • actSkp: Number of skipped scene actions per second (usually an optimization to avoid empty updates)
  • suG: Scene updates generated per second. Number of scene update packages generated for network send (might be more than # of sceneupdates)
  • suGS: Scene update generated size per second. Accumulated size of scene update packages generated for network send
  • suX: The size of the largest scene update package within 1 second
  • ar#: Number of currently used array resources
  • aras: Average size of a single array resource ((totalSize of currently used array resources) / ar#)
  • arms: Largest currently used array resource
  • er#: Number of currently used Effects
  • eras: Average size of a single effect resource ((totalSize of currently used effects) / er#)
  • erms: Largest currently used effect resource
  • tr#: Number of currently used texture resources
  • tras: Average size of a single texture resource ((totalSize of currently used textures) / tr#)
  • trms: Largest currently used texture resource

Caveats:

Some stats describe changes/deltas to the scene: flush, obj+, obj-, act*, su* - others describe a snapshot of the current scene state: objNr, ar*, er* tr* Resource stats (ar*,er*, tr*) are only logged if there was a flush during the logging interval

Renderer periodic logs

A Ramses application which also contains a renderer component has periodic logs which look like this: 

20210212-16:33:48.791 | Info  | RPER | Renderer: 1 scene(s): 123 Rendered
Avg framerate: 52.63158 FPS [minFrameTime 381us, maxFrameTime 59404us], drawcallsPerFrame 35, numFrames 107, resUploaded 128 (13207530 B)
FB0: 92
Scene 123: rendered 92, framesFArrived 92, framesFApplied 92, framesFBlocked 0, maxFramesWithNoFApplied 3, maxFramesFBlocked 0, FArrived 1397, FApplied 1397, actions/F (10/215/20.180386), dt/F (1/21295/34.343594), RC+/F (0/28/0.09234073), RC-/F (0/28/0.09520401), RS/F (0/0/0)
Time budgets: sceneResourceUpload 315360000000000us resourceUpload 315360000000000us obRender 315360000000000us
Longest frame(us)[avg]:59190 RendererCommands:749 [387] UpdateClientResources:32 [372] ApplySceneActions:7841 [2781] UpdateSceneResources:159 [114] UpdateEmbeddedCompositingResources:14 [8] UpdateStreamTextures:10 [5] UpdateScenesToBeMapped:13 [8] UpdateResourceCache:1039 [3234] UpdateAnimations:8 [5] UpdateTransformations:290 [138] UpdateDataLinks:44 [26] HandleDisplayEvents:34 [316] DrawScenes:1908 [1393] SwapBuffersNotifyClients:47049 [6854] MaxFramerateSleep:0 [2870]

Read these logs like this:

First line:

  • Renderer participant id
  • List of scenes known to renderer and status

Second line (General renderer performance stats):

  • Number of frames per second
  • minimal and maximal frame time within time period
  • drawcalls per frame
  • Number of frames rendered in time period
  • resources uploaded in time period

Third line and over(scene related stats):

  • Scene id
  • rendered: Number of frames rendered
  • FrameFArrived: Number of frames where flushes arrived
  • FramesFApplied: Number of frames where flushes applied
  • FrameFBlocked: Number of frames where applying a flush was blocked
  • maxFramesWithNoFApplied: How many consecutive frame there was no flush applied
  • maxFramesFBlocked: How many consecutive frames flushes were blocked from applying
  • FArrived: Number of flushes arrived
  • FApplied: Number of flushes applied
  • actions/F: number of scene actions per flush
  • dt/F: flush latency
  • RC+/F RC-/F: Number of client resources added/removed per flush
  • RS/F: Number of scene resource actions per flush
  • RSUploaded: Size of scene resources uploaded

Time budgets: Information about how much time per frame an action may take as a maximum, set by application

Advanced stats:

  • Longest Frame: How long did the longest frame take to render alltogether
  • Rest: Advanced stats for profiling renderer which need internal understanding of the Ramses renderer.

Using specialized tools

If the above methods didn't yield the results you expected, or you still think your application can perform better, you can also use some of the professional tools for profiling:

  • NVidia NSight - a great tool by NVidia which can analyze any OpenGL-based application. Limitation: requires an NVidia graphics card.
  • Standard profilers like the MSVC Profiler or gprof - great for finding CPU bottlenecks or memory attrition issues.
  • Android Profiler - a great all-round tool for finding issues, also in native libs such as Ramses. Works only on Android.
Generated by doxygen 1.9.1