5. Debugging models

The JModelica.org compilers can generate debugging information in order to facilitate localization of errors. There are three mechanisms for generating such diagnostics: dumping of debug information to the system output, generation of HTML code that can be viewed with a standard web browser or logs in XML format from the non-linear solver.

5.1. Compiler logging

The amount of logging that should be output by the compiler can be set with the argument compiler_log_level to the compile-functions (compile_fmu, compile_jmu and also transfer_optimization_problem). The available log levels are 'warning' (default), 'error', 'info' and 'debug' which can also be written as 'w', 'e', 'i' and 'd' respectively. The following example demonstrates setting the log level to 'info':

# Set compiler log level to 'info'
compile_fmu('myModel', 'myModels.mo', compiler_log_level='info')

The log is printed to the standard output, normally the terminal window from which the compiler is invoked.

The log can also be written to file by appending the log level flag with a colon and file name. This is shown in the following example:

# Set compiler log level to info and write the log to a file log.txt
compile_fmu('myModel', 'myModels.mo', compiler_log_level='i:log.txt')

It is possible to specify several log outputs by separating the list with a comma. The following example writes log warnings and errors (log level 'warning' or 'w') to the standard output and a more verbose logging to file (log level 'info' or 'i'):

# Write warnings and errors to standard output and the log with log level info to log.txt
compile_fmu('myModel', 'myModels.mo', compiler_log_level= 'w,i:log.txt')

5.2. Runtime logging

5.2.1. Setting log level

Many events that occur inside of an FMU can generate log messages. The log messages from the runtime are saved in a file with the default name <FMU name>_log.txt. A log file name can also be supplied when loading an FMU, this is shown in the example below:

# Load model
model = load_fmu(fmu_name, log_file_name='MyLog.txt')

How much information that is output to the log file can be controlled by setting the log_level argument to load_fmu. log_level can be any number between 0 and 7, where 0 means no logging and 7 means the most verbose logging. The log level can also be changed after the FMU has been loaded with the function set_log_level(level). Setting the log_level is demonstrated in the following example:

# Load model and set log level to 5
model = load_fmu(fmu_name, log_level=5)

# Change log level to 7
model.set_log_level(7)

If the loaded FMU is an FMU exported by JModelica.org, the amount of logging produced by the FMU can also be altered. This is done by setting the parameter _log_level in the FMU. This log level ranges from 0 to 6 where 0 represents the least verbose logging and 6 the most verbose. The following example demonstrates this:

# Load model (with default log level)
model = load_fmu(fmu_name)

# Set amount of logging produced to the most verbose
model.set('_log_level', 6)

# Change log level to 7 to be able to see everything that is being produced
model.set_log_level(7)

5.2.2. Interpreting logs from JModelica.org

In JModelica.org, information is logged in XML format, which ends up mixed with FMI Library output in the resulting log file. Example: (the following examples are based on the example pyjmi.examples.logger_example.)

...
FMIL: module = FMICAPI, log level = 5: Calling fmiInitialize
FMIL: module = Model, log level = 4: [INFO][FMU status:OK] <EquationSolve>Model equations evaluation invoked at<value name="t">        0.0000000000000000E+00</value>
FMIL: module = Model, log level = 4: [INFO][FMU status:OK]   <BlockEventIterations>Starting block (local) event iteration at<value name="t">        0.0000000000000000E+00</value>in<value name="block">0</value>
FMIL: module = Model, log level = 4: [INFO][FMU status:OK]     <vector name="ivs">        0.0000000000000000E+00,         0.0000000000000000E+00,         0.0000000000000000E+00</vector>
FMIL: module = Model, log level = 4: [INFO][FMU status:OK]     <vector name="switches">        0.0000000000000000E+00,         0.0000000000000000E+00,         0.0000000000000000E+00,         0.0000000000000000E+00</vector>
FMIL: module = Model, log level = 4: [INFO][FMU status:OK]     <vector name="booleans"></vector>
FMIL: module = Model, log level = 4: [INFO][FMU status:OK]     <BlockIteration>Local iteration<value name="iter">1</value>at<value name="t">        0.0000000000000000E+00</value>
FMIL: module = Model, log level = 4: [INFO][FMU status:OK]       <JacobianUpdated><value name="block">0</value>
FMIL: module = Model, log level = 4: [INFO][FMU status:OK]         <matrix name="jacobian">
FMIL: module = Model, log level = 4: [INFO][FMU status:OK]                  -1.0000000000000000E+00,         4.0000000000000000E+00,         0.0000000000000000E+00;
FMIL: module = Model, log level = 4: [INFO][FMU status:OK]                  -1.0000000000000000E+00,        -1.0000000000000000E+00,        -1.0000000000000000E+00;
FMIL: module = Model, log level = 4: [INFO][FMU status:OK]                  -1.0000000000000000E+00,         1.0000000000000000E+00,        -1.0000000000000000E+00;
FMIL: module = Model, log level = 4: [INFO][FMU status:OK]         </matrix>
FMIL: module = Model, log level = 4: [INFO][FMU status:OK]       </JacobianUpdated>
...

The log can be inspected manually, using general purpose XML tools, or parsed using the tools in pyjmi.log. A pure XML file that can be read by XML tools can be extracted with

# Extract the log file XML contents into a pure XML file
pyjmi.log.extract_jmi_log(dest_xml_file_name, log_file_name)

The XML contents in the log file can also be parsed directly:

# Parse the entire XML log
log = pyjmi.log.parse_jmi_log(log_file_name)

log will correspond to the top level log node, containing all other nodes. Log nodes have two kinds of children: named (with a name attribute in the XML file) and unnamed (without).

  • Named children are accessed by indexing with a string: node['t'], or simply dot notation: node.t.

  • Unnamed children are accessed as a list node.nodes, or by iterating over the node.

There is also a convenience function gather_solves to extract common information about equation solves in the log. This function collects nodes of certain types from the log and annotates some of them with additional named children. The following example is from pyjmi.examples.logger_example:

# Parse the entire XML log
log = pyjmi.log.parse_jmi_log(log_file_name)
# Gather information pertaining to equation solves
solves = pyjmi.log.gather_solves(log)

print
print 'Number of solver invocations:',                      len(solves)
print 'Time of first solve:',                               solves[0].t
print 'Number of block solves in first solver invocation:', len(solves[0].block_solves)
print 'Names of iteration variables in first block solve:', solves[0].block_solves[0].variables
print 'Min bounds in first block solve:',                   solves[0].block_solves[0].min
print 'Max bounds in first block solve:',                   solves[0].block_solves[0].max
print 'Initial residual scaling in first block solve:',     solves[0].block_solves[0].initial_residual_scaling
print 'Number of iterations in first block solve:',         len(solves[0].block_solves[0].iterations)
print
print 'First iteration in first block solve: '
print '  Iteration variables:',              solves[0].block_solves[0].iterations[0].ivs
print '  Scaled residuals:',                 solves[0].block_solves[0].iterations[0].residuals
print '  Jacobian:\n',                       solves[0].block_solves[0].iterations[0].jacobian
print '  Jacobian updated in iteration:',    solves[0].block_solves[0].iterations[0].jacobian_updated
print '  Residual scaling factors:',         solves[0].block_solves[0].iterations[0].residual_scaling
print '  Residual scaling factors_updated:', solves[0].block_solves[0].iterations[0].residual_scaling_updated
print '  Scaled residual norm:',             solves[0].block_solves[0].iterations[0].scaled_residual_norm

5.3. Getting HTML diagnostics

By setting the compiler option generate_html_diagnostics to true, a number of HTML pages containing similar diagnostics is generated. The HTML files are generated in the directory Model_Name_diagnostics, where Model_Name is the name of the compiled model. As compared to the diagnostics generated by the compiler_log_level argument, the HTML diagnostics contains only the most important information, but it also provides a better overview. Opening the file Model_Name_diagnostics/index.html in a web browser, results in a page similar to the one shown below.

Modelica.Mechanics.Rotational.Examples.First

Problems:
0 errors, 0 compliance errors, 1 warnings

Model before transformation

Number of independent constants:              1
  Number of Real independent constants:       1
  Number of Integer independent constants:    0
  Number of Enum independent constants:       0
  Number of Boolean independent constants:    0
  Number of String independent constants:     0
Number of dependent constants:                0
  Number of Real dependent constants:         0
  Number of Integer dependent constants:      0
  Number of Enum dependent constants:         0
  Number of Boolean dependent constants:      0
  Number of String dependent constants:       0
Number of independent parameters:             20
  Number of Real independent parameters:      14
  Number of Integer independent parameters:   0
  Number of Enum independent parameters:      4
  Number of Boolean independent parameters:   2
  Number of String independent parameters:    0
Number of dependent parameters:               6
  Number of Real dependent parameters:        6
  Number of Integer dependent parameters:     0
  Number of Enum dependent parameters:        0
  Number of Boolean dependent parameters:     0
  Number of String dependent parameters:      0
Number of variables :                         53
  Number of Real variables:                   53
  Number of Integer variables:                0
  Number of Enum variables:                   0
  Number of Boolean variables:                0
  Number of String variables:                 0
Number of Real differentiated variables:      8
Number of Real derivative variables:          0
Number of Real algebraic variables:           45
Number of inputs:                             0
  Number of Real inputs:                      0
  Number of Integer inputs:                   0
  Number of Enum inputs:                      0
  Number of Boolean inputs:                   0
  Number of String inputs:                    0
Number of discrete variables :                0
  Number of Real discrete variables:          0
  Number of Integer discrete variables:       0
  Number of Enum discrete variables:          0
  Number of Boolean discrete variables:       0
  Number of String discrete variables:        0
Number of equations:                          51
Number of variables with binding expression:  4
  Number of Real variables with binding exp:  4
  Number of Integer variables binding exp:    0
  Number of Enum variables binding exp:       0
  Number of Boolean variables binding exp:    0
  Number of String variables binding exp:     0
Total number of equations:                    55
Number of initial equations:                  0
Number of relational exps in equations:       1
Number of relational exps in init equations:  0
Flattened model

Connection sets

Model after transformation

Number of independent constants:              1
  Number of Real independent constants:       1
  Number of Integer independent constants:    0
  Number of Enum independent constants:       0
  Number of Boolean independent constants:    0
  Number of String independent constants:     0
Number of dependent constants:                0
  Number of Real dependent constants:         0
  Number of Integer dependent constants:      0
  Number of Enum dependent constants:         0
  Number of Boolean dependent constants:      0
  Number of String dependent constants:       0
Number of independent parameters:             34
  Number of Real independent parameters:      19
  Number of Integer independent parameters:   2
  Number of Enum independent parameters:      4
  Number of Boolean independent parameters:   9
  Number of String independent parameters:    0
Number of dependent parameters:               6
  Number of Real dependent parameters:        6
  Number of Integer dependent parameters:     0
  Number of Enum dependent parameters:        0
  Number of Boolean dependent parameters:     0
  Number of String dependent parameters:      0
Number of variables :                         28
  Number of Real variables:                   28
  Number of Integer variables:                0
  Number of Enum variables:                   0
  Number of Boolean variables:                0
  Number of String variables:                 0
Number of Real differentiated variables:      4
Number of Real derivative variables:          4
Number of Real algebraic variables:           20
Number of inputs:                             0
  Number of Real inputs:                      0
  Number of Integer inputs:                   0
  Number of Enum inputs:                      0
  Number of Boolean inputs:                   0
  Number of String inputs:                    0
Number of discrete variables :                0
  Number of Real discrete variables:          0
  Number of Integer discrete variables:       0
  Number of Enum discrete variables:          0
  Number of Boolean discrete variables:       0
  Number of String discrete variables:        0
Number of equations:                          24
Number of variables with binding expression:  0
  Number of Real variables with binding exp:  0
  Number of Integer variables binding exp:    0
  Number of Enum variables binding exp:       0
  Number of Boolean variables binding exp:    0
  Number of String variables binding exp:     0
Total number of equations:                    24
Number of initial equations:                  4
Number of relational exps in equations:       1
Number of relational exps in init equations:  0
Transformed model

Alias sets (13 sets, 40 eliminated variables)

BLT diagnostics
BLT diagnostics table

Number of unsolved equation blocks in DAE initialization system: 1: {4}
Number of unsolved equation blocks in DAE system: 1: {4}

Number of unsolved equation blocks in DAE initialization system after tearing: 1: {1}
Number of unsolved equation blocks in DAE system after tearing: 1: {1}

Note that some of the entries, including Problems, Flattened model, Connection sets, Transformed model, Alias sets, BLT diagnostics table and BLT diagnostics are links to sub pages containing additional information. For example, the BLT diagnostics page contains information about individual systems of equations:

...

--- Block 7 ---
Solved block of 1 variables:
Computed variable:
  inertia2.flange_b.tau
Solution:
   - (  - ( damper.flange_b.tau ) ) - (  - ( spring.flange_b.tau ) ) + 0

--- Block 8 (Unsolvable block 0) ---
Non-solved linear block of 4 variables:
Coefficient variability: Parameter
Unknown variables:
  inertia2.a
  idealGear.flange_b.tau
  idealGear.flange_a.tau
  inertia1.a
Equations:
  inertia1.a = ( idealGear.ratio ) * ( inertia2.a )
  ( inertia2.J ) * ( inertia2.a ) =  - ( idealGear.flange_b.tau ) + inertia2.flange_b.tau
  0 = ( idealGear.ratio ) * ( idealGear.flange_a.tau ) + idealGear.flange_b.tau
  ( inertia1.J ) * ( inertia1.a ) =  - ( torque.flange.tau ) - ( idealGear.flange_a.tau )

...

Additionally there is a table view of the BLT. It can be found on the BLT diagnostics table page. It provides a graphical representation of the BLT. The view is limited to 300 equations due to the complexity of the graph.