Dymola provides a means to measure where the CPU time is being spent in the model code execution. This feature is known as profiling. Profiling is described in Section 5.7.5 of the Dymola User Manual Volume 1. This blog article supplies further information.
Profiling is implemented by inserting timers into the dsmodel.c code so that the amount of time spent computing different sections of the code can be recorded. To enable profiling in Dymola set either of these flags from the Dymola Command line:
Advanced.GenerateBlockTimers=true; Advanced.GenerateTimers=true;
When Advanced.GenerateBlockTimers=true a few timers are inserted in the code when Advanced.GenerateTimers =true a large number of timers are inserted and this allows finer analysis of the code’s performance.
An example of the profiling information that is returned when a model is simulated is in Figure 1. These results were generated by simulating the Modelica.Magnetic.FluxTubes.Examples.SaturatedInductor model for 10 seconds using DASSL and with Advanced.GenerateBlockTimers=true.
Figure 1. Profiling information for model
The 1st column in Figure 1 gives the name of the timing block. For further information about the different types of timing blocks refer to Table 1 found at the end of this blog post.
The Block number (column 2 in Figure 1) makes it easy to find where the timers have been inserted into the dsmodel.c code. To find the start of the timer search for DymolaStartTimer(#) and to search for the end of the timer search for DymolaEndTimerName(#), where # is the Block number.
Columns 3 to 6 contains timing information, from the results in Figure 1 most of the CPU time is spent calculating the simulation.nonlinear[1] system.
How often a section of code is called (i.e. column 7 of Figure 1) is important as improving the performance of the code with the largest number of calls will give a large performance improvement. A basic flow diagram of how a time step calculation is performed is in Figure 2, this diagram helps explain why different code sections are called a different number of times.
Figure 2. Simple flow diagram of how the model code in dsmodel.c is called when solving a time step calculation. The blue blocks are model code, red blocks are controlling code and yellow blocks are comments. The flow diagram was created using code2flow.com.
The flow diagram in Figure 2 is of the control of the calls to the model code. The controlling code will call the InitialSection, the OutputSection, the DynamicsSection, the AccpetedSection1 and the AcceptedSection2 code of dsmodel.c.
If initialisation fails the first time then the homotopy method is used and the InitialSection code will be called multiple times as the homotopy’s lambda value is increased to 1. Once the model has been initialised successfully then the IntialSection code is not called again.
When an inline solver is used then the states are updated within the dsmodel code, in this case there is no DynamicsSection and only the OutputSection code. If an inline Runge Kutta method is used then the OutputSection code will be called multiple times depending on the order of the Runge Kutta.
When the DASSL solver is used the DynamicsSection code is called multiple times until the solution calculated by the solver satisfies the solver’s requirements.
In some cases the controlling code can detect that the states are non-changing for that time step, in this case there will be no call to the OutputSection and the DynamicsSection code and the states will remain unchanged.
The AcceptedSection1 code contains code that does not directly affect the derivatives of the states, however, the past values of this code may affect the derivatives. An example of code that may be found here is the pre() functions used in logic expressions. The AcceptedSection2 code contains equations for calculating model variables that are dependent on the states of the model.
There are many possible locations in a time step calculation where the code may fail, these failures have not been included in the flow diagram in Figure 2 to keep the flow diagram as simple as possible.
———————————————————————————————————————————————————————————-
| Name of block timer | Comment |
|---|---|
| AcceptedSection1 | Code for which past values effects the OutputSection and DynamicSection equations. For example the pre() equations. |
| AcceptedSection2 | Typically auxiliary variables that are not required by the OutputSection or DynamicsSection |
| Asserts | Calls to the assert() function |
| Auxiliary code | Calculates variables that are not directty required by state update process |
| Code for h fixed | Code specific for a fixed time step, typically used with fixed step solvers to solve the first time step |
| Code for h variable | Code specific for a range of times steps, typically used with a fixed step solver |
| Crossing code | Used for detecting events |
| DynamicsSection | Equations to calculate the derivatives of states used by solver to update states |
| Dynamics code | Code part of the dynamics section |
| Empty timer | Used to calculate how long the timer code takes |
| Entire model | Total time for all evaluations |
| Event handling | The total time for model evaluations during event handling. |
| Initial # eq | A system of # equations in the initial section |
| InitialSection | Initialisation code |
| initialization.linear[#] | Initialisation code for linear system # |
| initialization.nonlinear[#] | Intialisation code for nonlinear system # |
| Inline Update | Meant to calculate the how long the code used to control the inline solver takes, however it is calculated in a questionable way |
| Inlined sys | System of equations that are a result of inlining |
| Lin sys Jac | Jacobian used by linear system of equations |
| Lin sys solve | Calls to linear system solving functions such as SolveLinearSystemOfEquations(J, b, y, 1); and similar equations, inside Lin sys total |
| Lin sys torn | Linear system torn section, inside Linear system total, inside Lin sys total |
| Lin sys total | Linear system |
| Mixed sys | Mixed system of equations, equations involving Boolean and Real equations |
| Nonlinear residue | Time taken to calculate residues |
| Output # eq | Output code for a system of # equations |
| Output code | This code includes the assert calls, and can include when equations and more. Code to update the internal states of an inlined solver |
| OutputSection | Section of all the output code |
| Outside of model | The total time spent outside of the model code |
| Parameter code | Assigning parameters, includes reading variables from files, string variables etc. |
| simulation.linear[#] | Linear system number # in the simulation section. Only equations that have been expanded out are labelled with the simulation.linear[#] method |
| simulation.nonlinear[#] | Nonlinear system number # in the simulation section |
| Structured Jacobian | Calculation of structured Jacobian |
| Structured residual | Calculation of residual of structured Jacobian |
Table 1. Explanation of some of the timer block names
Written by: Garron Fish – Chief Engineer