Insufficient information about assertion violations

[Francesco Casella]

Apologies, the first issue of this ticket was wrong due to a typo in the code. I have modified it to reflect the actual status with the corrected code.

Please consider the attached test package, which demonstrates how OMC does not provide essential information to the user when handling asserts.

Simulate TestWarningConstant. You get the following warning message:

Warning: Variable x is probably too big

Unfortunately, the message doesn't tell you an essential piece of information, i.e., where in the model M has this error been triggered. Is it m1, m2 or m3? It also doesn't tell when the warning has been triggered

One option is to enhance the error message like this:

The following assertion has been violated at initialization:
m3.x < 5
Warning: Variable x is probably too big

Simulate TestWarningVariable. You get the same message as before

Warning: Variable x is probably too big

you should get something like:

The following assertion has been violated at time = 0.8333
m3.x < 5
Warning: Variable x is probably too big

Simulate TestWarningRecurring. You still get

Warning: Variable x is probably too big

According to the non-normative text of the Modelica Specification, Section 8.3.7, you should get something like

The following assertion has been violated at time = 0.1577
m3.x < 5
Warning: Variable x is probably too big

The following assertion is no longer violated at time = 0.3465
m3.x < 5
Warning: Variable x is probably too big

Simulate TestErrorConstant. Here you should see:

The following assertion has been violated at initialization:
m2.x < 10
Error: Variable x is too big

Simulate TestErrorVariable. The information here is quite confusing. What you should get here is

The following assertion has been violated at time = 0.25
m2.x < 5
Warning: Variable x is probably too big

The following assertion has been violated at time = 0.5
m2.x < 10
Error: Variable x is too big

Incidentally, I think the "Process crashed" final message in the last case is inappropriate. It seem to hint to the fact that some uncontrolled error has taken place, such as a memory access violation in some external function, which is definitely not the case here. Evertything here is under control and we have reported the reason for the simulation to stop. I would suggest to use "Process aborted", which seems more appropriate.

[Francesco Casella]

Library with test cases

[Lennart Ochel]

Willi, you insisted on fixing this by your own. So is there already any progress? I think some of the needed changes are rather easy and would already help a lot (e.g. for #3129).

[Willi Braun]

partially fixed in r24606.
Partially because removeSimpleEquation simplifies constant expressions just to true, then we can't obtain the actual violated expression. I guess we need to avoid such simplifications.

Also I haven't defined a special exit code for assert violation, so that we can distinguish between a "normal" failed simulation and an aborted simulation. I'll do that tomorrow, then we can change failing message in OMEdit, too.

[Martin Sjölund]

Replying to wbraun:

partially fixed in r24606.
Partially because removeSimpleEquation simplifies constant expressions just to true, then we can't obtain the actual violated expression. I guess we need to avoid such simplifications.

It will be in the elementsource. You could point the messages to the equation ID and let the debugger show the full information.

[Martin Sjölund]

Milestone changed to 1.9.3 since 1.9.2 was released.

[Francesco Casella]

This problem is still not solved properly. For example, check

​https://test.openmodelica.org/libraries/ThermoPower/files/ThermoPower.Test.DistributedParameterComponents.TestRefrigerantEvaporator.sim

which I report here:

assert    | error   | Dimension 1 has bounds 1..21, got array subscript 22
assert    | info    | simulation terminated by an assertion at initialization 

How can I possibly locate the source of the error based on this information?

[Martin Sjölund]

By running through OMEdit or using simflags -logFormat=xml (I think).

[Willi Braun]

Replying to casella:

This problem is still not solved properly. For example, check

​https://test.openmodelica.org/libraries/ThermoPower/files/ThermoPower.Test.DistributedParameterComponents.TestRefrigerantEvaporator.sim

which I report here:

assert    | error   | Dimension 1 has bounds 1..21, got array subscript 22
assert    | info    | simulation terminated by an assertion at initialization 

How can I possibly locate the source of the error based on this information?

hm, as far as I see currently not at all.

But perhaps it is worth to create a new ticket, since this kind of asserts are different than the one this ticket is about. The one in this ticket are Modelica assert and here you report an assert that is triggered by one of our low-level runtime functions.

See following model:

model A
  function f
  input Real x[2];
  output Real y[2];
  protected 
    Integer i;
  algorithm 
   i := 1;
   while i <=2 loop
     i := i+1;
     y[i] := 2*x[i];
   end while;
  end f;
  Real x[2];
  Real y1[2],y2[2];
equation 
 x = {sin(time),cos(time)};
 when sample(0,0.2) then
   i = pre(i)+1;
 end when;
 y1 = f(x);
 y2 = 2*{x[i+1],x[i+1]};
end A;

The issue is that we need an array subscript analysis to provide sufficient information and that can be quite hard. At at least the function stack, which was called before the assert was triggered would be helpful to find the issue.

[Martin Sjölund]

Eh, we can put the equations info in the threadData as well, and just put it in there to give a cheap way to get better messages.

[Willi Braun]

yes, but in all of that low-level array functions we have currently threadData not available.

[Francesco Casella]

I am not really into the details of the data structures, so I cannot suggest technical solutions. Anything more than we currently have would be appreciated. I guess the function stack would already be informative.

[Martin Sjölund]

The function call stack can be fetched on Linux; it is very expensive, but only runs when the message is generated. It could also be added explicitly by pushing the function name at the start of each function call (but this is additional overhead for every call).

[Willi Braun]

Perhaps we should update and expand all of this very old and ugly low-level array functions and make equation info available, even when this work is a pain in the ass.

[Francesco Casella]

Replying to sjoelund.se:

The function call ... could also be added explicitly by pushing the function name at the start of each function call (but this is additional overhead for every call).

One option is to have a flag to turn on this feature on demand. The assert message should then contain the suggestion to turn on the flag and re-run the simulation to get more information. This should be easily implemented and cause no overhead during normal simulations.

[Martin Sjölund]

Replying to casella:

One option is to have a flag to turn on this feature on demand. The assert message should then contain the suggestion to turn on the flag and re-run the simulation to get more information. This should be easily implemented and cause no overhead during normal simulations.

Would need to re-compile the generated code and re-run the simulation. Doable although not as fast as the user might like.

[Francesco Casella]

Replying to sjoelund.se:

Replying to casella:

One option is to have a flag to turn on this feature on demand. The assert message should then contain the suggestion to turn on the flag and re-run the simulation to get more information. This should be easily implemented and cause no overhead during normal simulations.

Would need to re-compile the generated code and re-run the simulation. Doable although not as fast as the user might like.

Currently the time for debugging is arbitrarily high, so the time of recompiling twice is definitely way better than we currently have. Not to mention avoiding the sense of frustration felt by the model developer facing such useless error messages. Sorry for being blunt here :)

[Adrian Pop]

It should be technically possible to have proper error messages for this without too much overhead. And I mean line numbers and files.

[Francesco Casella]

Another interesting instance of the above-mentioned problem:

​https://test.openmodelica.org/libraries/ThermoPower_Experimental/files/ThermoPower.Test.DistributedParameterComponents.TestRefrigerantEvaporator.sim

assert  | error | Model error: Argument of log(adelta) was nan should be > 0
assert  | info  | simulation terminated by an assertion at initialization

[Martin Sjölund]

Moved to new milestone 1.9.4

[Martin Sjölund]

Milestone pushed to 1.9.5

[Martin Sjölund]

Milestone renamed

[Martin Sjölund]

Ticket retargeted after milestone closed

[Martin Sjölund]

Milestone moved to 1.12.0 due to 1.11.0 already being released.

[Francesco Casella]

I'll try to assess the situation with the current nightly build compared to the initial report

Simulate TestWarningConstant. You get the following warning message:

Warning: Variable x is probably too big

Unfortunately, the message doesn't tell you an essential piece of information, i.e., where in the model M has this error been triggered. Is it m1, m2 or m3? It also doesn't tell when the warning has been triggered

One option is to enhance the error message like this:

The following assertion has been violated at initialization:
m3.x < 5
Warning: Variable x is probably too big

The situation is a bit controversial here. Now the error message is:

The following assertion has been violated during initialization at time 0.000000
false
Variable x is probably too big

In fact, using the debugger reveals that "false" was originally m3.x < 5.0, so it is possible to reconstruct what the original problem was, though I guess it could be better to avoid doing symbolic substitutions on assert statements, to better preserve the clarity.

Simulate TestWarningVariable. You get the same message as before

Warning: Variable x is probably too big

you should get something like:

The following assertion has been violated at time = 0.8333
m3.x < 5
Warning: Variable x is probably too big

Here I now get the expected message.

Simulate TestWarningRecurring. You still get

Warning: Variable x is probably too big

According to the non-normative text of the Modelica Specification, Section 8.3.7, you should get something like

The following assertion has been violated at time = 0.1577
m3.x < 5
Warning: Variable x is probably too big

This is now obtained as expected.

The following assertion is no longer violated at time = 0.3465
m3.x < 5
Warning: Variable x is probably too big

Unfortunately this one is not.

Simulate TestErrorConstant. Here you should see:

The following assertion has been violated at initialization:
m2.x < 10
Error: Variable x is too big

Here we have the same situation of the warning assertion showed above, the condition m2.x < 10 is symbolically turned into false, but at least this is visible in the debugger.

Simulate TestErrorVariable. The information here is quite confusing. What you should get here is

The following assertion has been violated at time = 0.25
m2.x < 5
Warning: Variable x is probably too big

The following assertion has been violated at time = 0.5
m2.x < 10
Error: Variable x is too big

Here we get the expected message.

Incidentally, I think the "Process crashed" final message in the last case is inappropriate. It seem to hint to the fact that some uncontrolled error has taken place, such as a memory access violation in some external function, which is definitely not the case here. Evertything here is under control and we have reported the reason for the simulation to stop. I would suggest to use "Process aborted", which seems more appropriate.

We now get "Simulation process failed. Exited with code -1." which is much better than "Process crashed".