Skip to content

Commit

Permalink
- change debug output for solver, event and zero crossings
Browse files Browse the repository at this point in the history 
git-svn-id: https://openmodelica.org/svn/OpenModelica/trunk@13607 f25d12d1-65f4-0310-ae8a-bbce733d8d8e
  • Loading branch information
Willi Braun committed Oct 24, 2012
1 parent 834c214 commit 9e432d4
Show file tree
Hide file tree
Showing 9 changed files with 216 additions and 258 deletions.
14 changes: 10 additions & 4 deletions Compiler/Template/CodegenC.tpl
View file
Expand Up @@ -1082,9 +1082,7 @@ template functionWhenReinitStatementThen(list<WhenOperator> reinits, Text &varDe
else
'<%cref(stateVar)%> = <%val%>;'
<<
if (DEBUG_FLAG(LOG_EVENTS)) {
INFO1("reinit <%cref(stateVar)%> = %f", <%val%>);
}
DEBUG_INFO_AL1(LOG_EVENTS,"| | reinit <%cref(stateVar)%> = %f", <%val%>);
<%preExp%>
<%lhs%>
data->simulationInfo.needToIterate = 1;
Expand Down Expand Up @@ -1312,7 +1310,15 @@ template functionZeroCrossing(list<ZeroCrossing> zeroCrossings) "template functi
let &varDecls = buffer "" /*BUFD*/
let zeroCrossingsCode = zeroCrossingsTpl(zeroCrossings, &varDecls /*BUFD*/)

let resDesc = (zeroCrossings |> ZERO_CROSSING(__) => '"<%ExpressionDump.printExpStr(relation_)%>", '
;separator="\n")

<<
const char *zeroCrossingDescription[] =
{
<%resDesc%>
};

int function_ZeroCrossings(DATA *data, double *gout, double *t)
{
state mem_state;
Expand Down Expand Up @@ -1377,7 +1383,7 @@ template functionCheckForDiscreteChanges(list<ComponentRef> discreteModelVars) "
match var
case CREF_QUAL(__)
case CREF_IDENT(__) then
'if(<%cref(var)%> != $P$PRE<%cref(var)%>) { DEBUG_INFO2(LOG_EVENTS, "Discrete Var <%crefStr(var)%> : <%crefToPrintfArg(var)%> to <%crefToPrintfArg(var)%>", $P$PRE<%cref(var)%>, <%cref(var)%>); needToIterate=1; }'
'if(<%cref(var)%> != $P$PRE<%cref(var)%>) { DEBUG_INFO_AL2(LOG_EVENTS, "| events | | Discrete Var <%crefStr(var)%> changed: <%crefToPrintfArg(var)%> to <%crefToPrintfArg(var)%>", $P$PRE<%cref(var)%>, <%cref(var)%>); needToIterate=1; }'
;separator="\n")

<<
Expand Down
8 changes: 4 additions & 4 deletions SimulationRuntime/c/math-support/nonlinearSolverHybrd.c
View file
Expand Up @@ -183,7 +183,7 @@ int solveHybrd(DATA *data, int sysNumber) {
if (DEBUG_FLAG(LOG_NONLIN_SYS)) {
for (i = 0; i < solverData->n; i++) {
INFO_AL1("\t%d:", i);
INFO_AL2("\tx-scale = %e\tx = %e",
INFO_AL2("\tx-scale = %e\tx = %.15e",
systemData->nlsxScaling[i], systemData->nlsx[i]);
INFO_AL2("\tnlsxOld = %e\tExtrapolation = %e",
systemData->nlsxOld[i], systemData->nlsxExtrapolation[i]);
Expand Down Expand Up @@ -265,13 +265,13 @@ int solveHybrd(DATA *data, int sysNumber) {
INFO_AL("### System solved! ###");
INFO_AL2("\tSolution after:\t%d retries\t%d restarts", retries,
retries2+retries3);
INFO_AL3("\tnfunc = %d\terror = %e\terror_scaled = %e", nfunc_evals, xerror, xerror_scaled );
INFO_AL3("\tnfunc = %d\terror = %.15e\terror_scaled = %.15e", nfunc_evals, xerror, xerror_scaled );
if (DEBUG_FLAG(LOG_NONLIN_SYS)) {
for (i = 0; i < solverData->n; i++) {
INFO_AL1("\t%d:", i);
INFO_AL2("\tdiag = %e\tx = %e",
INFO_AL2("\tdiag = %e\tx = %.15e",
solverData->diag[i], solverData->x[i]);
INFO_AL2("\tresidual Scale = %e\tresidual = %e",
INFO_AL2("\tresidual Scale = %e\tresidual = %.15e",
solverData->resScaling[i], solverData->fvec[i]);
}
}
Expand Down
6 changes: 6 additions & 0 deletions SimulationRuntime/c/openmodelica_func.h
View file
Expand Up @@ -156,6 +156,12 @@ extern int function_ZeroCrossings(DATA *data, double* gout, double* t);
extern int function_updateSample(DATA *data);
extern int checkForDiscreteChanges(DATA *data);

/*! \var zeroCrossingDescription
*
* This variable contains a description string for zero crossing condition
*/
extern const char *zeroCrossingDescription[];

/* function for initializing time instants when sample() is activated */
extern void function_sampleInit(DATA *data);
extern void function_initMemoryState(void);
Expand Down
50 changes: 14 additions & 36 deletions SimulationRuntime/c/simulation/simulation_runtime.cpp
View file
Expand Up @@ -346,7 +346,7 @@ int startNonInteractiveSimulation(int argc, char**argv, DATA* data)
string* method = (string*) getFlagValue("s", argc, argv);
if(!(method == NULL)){
data->simulationInfo.solverMethod = method->c_str();
DEBUG_INFO_AL1(LOG_SOLVER, "| overwrite solver method: %s [from command line]", data->simulationInfo.solverMethod);
DEBUG_INFO_AL1(LOG_SOLVER, " | overwrite solver method: %s [from command line]", data->simulationInfo.solverMethod);
}
}

Expand Down Expand Up @@ -435,26 +435,16 @@ int callSolver(DATA* simData, string result_file_cstr, string init_initMethod,
cerr << "Unknown output format: " << simData->simulationInfo.outputFormat << endl;
return 1;
}
if (DEBUG_FLAG(LOG_SOLVER)) {
cout << "Allocated simulation result data storage for method '"
<< sim_result->result_type() << "' and file='" << result_file_cstr
<< "'" << endl; fflush(NULL);
}
DEBUG_INFO2(LOG_SOLVER,"Allocated simulation result data storage for method '%s' and file='%s'", sim_result->result_type(), result_file_cstr.c_str());

if (simData->simulationInfo.solverMethod == std::string("")) {
if (DEBUG_FLAG(LOG_SOLVER)) {
cout << "No solver is set, using dassl." << endl; fflush(NULL);
}
DEBUG_INFO(LOG_SOLVER, " | No solver is set, using dassl.");
retVal = solver_main(simData, init_initMethod.c_str(), init_optiMethod.c_str(), init_file.c_str(), init_time, 3, outVars);
} else if (simData->simulationInfo.solverMethod == std::string("euler")) {
if (DEBUG_FLAG(LOG_SOLVER)) {
cout << "Recognized solver: " << simData->simulationInfo.solverMethod << "." << endl; fflush(NULL);
}
DEBUG_INFO1(LOG_SOLVER, " | Recognized solver: %s.", simData->simulationInfo.solverMethod);
retVal = solver_main(simData, init_initMethod.c_str(), init_optiMethod.c_str(), init_file.c_str(), init_time, 1, outVars);
} else if (simData->simulationInfo.solverMethod == std::string("rungekutta")) {
if (DEBUG_FLAG(LOG_SOLVER)) {
cout << "Recognized solver: " << simData->simulationInfo.solverMethod << "." << endl; fflush(NULL);
}
DEBUG_INFO1(LOG_SOLVER, " | Recognized solver: %s.", simData->simulationInfo.solverMethod);
retVal = solver_main(simData, init_initMethod.c_str(), init_optiMethod.c_str(), init_file.c_str(), init_time, 2, outVars);
} else if (simData->simulationInfo.solverMethod == std::string("dassl") ||
simData->simulationInfo.solverMethod == std::string("dasslwort") ||
Expand All @@ -463,47 +453,35 @@ int callSolver(DATA* simData, string result_file_cstr, string init_initMethod,
simData->simulationInfo.solverMethod == std::string("dasslNumJac") ||
simData->simulationInfo.solverMethod == std::string("dasslColorSymJac") ||
simData->simulationInfo.solverMethod == std::string("dasslColorNumJac")) {
if (DEBUG_FLAG(LOG_SOLVER)) {
cout << "Recognized solver: " << simData->simulationInfo.solverMethod << "." << endl; fflush(NULL);
}

DEBUG_INFO1(LOG_SOLVER, " | Recognized solver: %s.", simData->simulationInfo.solverMethod);
retVal = solver_main(simData, init_initMethod.c_str(), init_optiMethod.c_str(), init_file.c_str(), init_time, 3, outVars);
} else if (simData->simulationInfo.solverMethod == std::string("inline-euler")) {
if (!_omc_force_solver || std::string(_omc_force_solver) != std::string("inline-euler")) {
cout << "Recognized solver: " << simData->simulationInfo.solverMethod
<< ", but the executable was not compiled with support for it. Compile with -D_OMC_INLINE_EULER."
<< endl; fflush(NULL);
DEBUG_INFO1(LOG_SOLVER, " | Recognized solver: %s, but the executable was not compiled with support for it. Compile with -D_OMC_INLINE_EULER.", simData->simulationInfo.solverMethod);
retVal = 1;
} else {
if (DEBUG_FLAG(LOG_SOLVER)) {
cout << "Recognized solver: " << simData->simulationInfo.solverMethod << "." << endl; fflush(NULL);
}
DEBUG_INFO1(LOG_SOLVER, " | Recognized solver: %s.", simData->simulationInfo.solverMethod);
retVal = solver_main(simData, init_initMethod.c_str(), init_optiMethod.c_str(), init_file.c_str(), init_time, 4, outVars);
}
} else if (simData->simulationInfo.solverMethod == std::string("inline-rungekutta")) {
if (!_omc_force_solver || std::string(_omc_force_solver) != std::string("inline-rungekutta")) {
cout << "Recognized solver: " << simData->simulationInfo.solverMethod
<< ", but the executable was not compiled with support for it. Compile with -D_OMC_INLINE_RK."
<< endl; fflush(NULL);
DEBUG_INFO1(LOG_SOLVER, " | Recognized solver: %s, but the executable was not compiled with support for it. Compile with -D_OMC_INLINE_RK.", simData->simulationInfo.solverMethod);
retVal = 1;
} else {
if (DEBUG_FLAG(LOG_SOLVER)) {
cout << "Recognized solver: " << simData->simulationInfo.solverMethod << "." << endl; fflush(NULL);
}
DEBUG_INFO1(LOG_SOLVER, " | Recognized solver: %s.", simData->simulationInfo.solverMethod);
retVal = solver_main(simData, init_initMethod.c_str(), init_optiMethod.c_str(), init_file.c_str(), init_time, 4, outVars);
}
#ifdef _OMC_QSS_LIB
} else if (simData->simulationInfo.solverMethod == std::string("qss")) {
if (DEBUG_FLAG(LOG_SOLVER)) {
cout << "Recognized solver: " << simData->simulationInfo.solverMethod << "." << endl; fflush(NULL);
}
DEBUG_INFO1(LOG_SOLVER, " | Recognized solver: %s.", simData->simulationInfo.solverMethod);
retVal = qss_main(argc, argv, simData->simulationInfo.startTime,
simData->simulationInfo.stopTime, simData->simulationInfo.stepSize,
simData->simulationInfo.numSteps, simData->simulationInfo.tolerance, 3);
#endif
} else {
cout << "Unrecognized solver: " << simData->simulationInfo.solverMethod
<< "; valid solvers are dassl, euler, rungekutta, inline-euler, inline-rungekutta, dasslwort, dasslSymJac, dasslNumJac, dasslColorSymJac, dasslColorNumJac, qss."
<< endl; fflush(NULL);
DEBUG_INFO1(LOG_SOLVER, " | Unrecognized solver: %s.", simData->simulationInfo.solverMethod);
DEBUG_INFO(LOG_SOLVER, " | valid solvers are: dassl, euler, rungekutta, inline-euler, inline-rungekutta, dasslwort, dasslSymJac, dasslNumJac, dasslColorSymJac, dasslColorNumJac, qss.");
retVal = 1;
}

Expand Down
81 changes: 29 additions & 52 deletions SimulationRuntime/c/simulation/solver/dassl.c
View file
Expand Up @@ -138,7 +138,7 @@ dasrt_initial(DATA* simData, SOLVER_INFO* solverInfo, DASSL_DATA *dasslData){
WARNING_AL2(" %-15s [%s]", dasslMethodStr[i], dasslMethodStrDescStr[i]);
THROW("see last warning");
}else{
DEBUG_INFO2(LOG_SOLVER,"Use solver method: %s\t%s",dasslMethodStr[dasslData->dasslMethod],dasslMethodStrDescStr[dasslData->dasslMethod]);
DEBUG_INFO2(LOG_SOLVER,"| solver | Use solver method: %s\t%s",dasslMethodStr[dasslData->dasslMethod],dasslMethodStrDescStr[dasslData->dasslMethod]);
}


Expand Down Expand Up @@ -183,7 +183,7 @@ dasrt_initial(DATA* simData, SOLVER_INFO* solverInfo, DASSL_DATA *dasslData){
dasslData->dasslMethod == DASSL_COLOREDNUMJAC ||
dasslData->dasslMethod == DASSL_TEST){
if (initialAnalyticJacobianA(simData)){
DEBUG_INFO(LOG_SOLVER,"Jacobian or SparsePattern is not generated or failed to initialize! Switch back to normal.");
DEBUG_INFO(LOG_SOLVER,"| solver | Jacobian or SparsePattern is not generated or failed to initialize! Switch back to normal.");
dasslData->dasslMethod = DASSL_RT;
}else{
dasslData->info[4] = 1; /* use sub-routine JAC */
Expand Down Expand Up @@ -237,12 +237,12 @@ int dasrt_step(DATA* simData, SOLVER_INFO* solverInfo)
DASSL_DATA *dasslData = (DASSL_DATA*) solverInfo->solverData;
modelica_real* stateDer = sDataOld->realVars + simData->modelData.nStates;
dasslData->rpar = (double*) (void*) simData;
ASSERT(dasslData->rpar, "simDat could not passed to DASSL");
ASSERT(dasslData->rpar, "| DDASRT | could not passed to DDASRT");

/* If an event is triggered and processed restart dassl. */
if (solverInfo->didEventStep)
{
DEBUG_INFO(LOG_EVENTS, "Event-management forced reset of DDASRT");
DEBUG_INFO(LOG_EVENTS, "| events | Event-management forced reset of DDASRT");
/* obtain reset */
dasslData->info[0] = 0;
dasslData->idid = 0;
Expand All @@ -255,8 +255,8 @@ int dasrt_step(DATA* simData, SOLVER_INFO* solverInfo)
* else will dassl get in trouble. If that is the case we skip the current step. */
if (solverInfo->currentTime - tout >= -1e-13)
{
DEBUG_INFO(LOG_SOLVER, "**Desired step to small try next one");
DEBUG_INFO(LOG_SOLVER, "**Interpolate linear");
DEBUG_INFO(LOG_SOLVER, "| DDASRT | Desired step to small try next one");
DEBUG_INFO(LOG_SOLVER, "| DDASRT | Interpolate linear");

for (i = 0; i < simData->modelData.nStates; i++)
{
Expand All @@ -270,11 +270,11 @@ int dasrt_step(DATA* simData, SOLVER_INFO* solverInfo)
return retVal;
}

DEBUG_INFO2(LOG_SOLVER, "**Calling DDASRT from %.10f to %.10f",
DEBUG_INFO2(LOG_SOLVER, "| DDASRT | Calling DDASRT from %.10f to %.10f",
solverInfo->currentTime, tout);
do
{
DEBUG_INFO2(LOG_SOLVER, "**Start step %.10f to %.10f", solverInfo->currentTime, tout);
DEBUG_INFO2(LOG_SOLVER, "| | Start step %.10f to %.10f", solverInfo->currentTime, tout);
if (dasslData->idid == 1){
/* rotate RingBuffer before step is calculated */
rotateRingBuffer(simData->simulationData, 1, (void**) simData->localData);
Expand Down Expand Up @@ -355,7 +355,8 @@ int dasrt_step(DATA* simData, SOLVER_INFO* solverInfo)
{
fflush(stderr);
fflush(stdout);
DEBUG_INFO(LOG_SOLVER, "DDASRT will try again...");
WARNING("| DDASRT | A large amount of work has been expended.(About 500 steps). Trying to continue ...");
DEBUG_INFO(LOG_SOLVER, "| DDASRT | DASSL will try again...");
dasslData->info[0] = 1; /* try again */
}
else if (dasslData->idid < 0)
Expand All @@ -366,7 +367,7 @@ int dasrt_step(DATA* simData, SOLVER_INFO* solverInfo)
solverInfo->currentTime = solverInfo->currentTime + solverInfo->currentStepSize;
sData->timeValue = solverInfo->currentTime;
functionODE(simData);
INFO1("DASRT can't continue. time = %f", sData->timeValue);
WARNING1("| DDASRT | can't continue. time = %f", sData->timeValue);
return retVal;
}

Expand All @@ -381,16 +382,17 @@ int dasrt_step(DATA* simData, SOLVER_INFO* solverInfo)

if (DEBUG_FLAG(LOG_SOLVER))
{
INFO1("DASSL call | value of idid: %d", dasslData->idid);
INFO1("DASSL call | current time value: %0.4g", solverInfo->currentTime);
INFO1("DASSL call | current integration time value: %0.4g", dasslData->rwork[3]);
INFO1("DASSL call | step size H to be attempted on next step: %0.4g", dasslData->rwork[2]);
INFO1("DASSL call | step size used on last successful step: %0.4g", dasslData->rwork[6]);
INFO1("DASSL call | number of steps taken so far: %d", dasslData->iwork[10]);
INFO1("DASSL call | number of calls of functionODE() : %d", dasslData->iwork[11]);
INFO1("DASSL call | number of calculation of jacobian : %d", dasslData->iwork[12]);
INFO1("DASSL call | total number of convergence test failures: %d", dasslData->iwork[13]);
INFO1("DASSL call | total number of error test failures: %d", dasslData->iwork[14]);
INFO("| DDASRT | dassl call staistics: ");
INFO_AL1(" | value of idid: %d", dasslData->idid);
INFO_AL1(" | current time value: %0.4g", solverInfo->currentTime);
INFO_AL1(" | current integration time value: %0.4g", dasslData->rwork[3]);
INFO_AL1(" | step size H to be attempted on next step: %0.4g", dasslData->rwork[2]);
INFO_AL1(" | step size used on last successful step: %0.4g", dasslData->rwork[6]);
INFO_AL1(" | number of steps taken so far: %d", dasslData->iwork[10]);
INFO_AL1(" | number of calls of functionODE() : %d", dasslData->iwork[11]);
INFO_AL1(" | number of calculation of jacobian : %d", dasslData->iwork[12]);
INFO_AL1(" | total number of convergence test failures: %d", dasslData->iwork[13]);
INFO_AL1(" | total number of error test failures: %d", dasslData->iwork[14]);
}
/* save dassl stats */
for (ui = 0; ui < numStatistics; ui++)
Expand All @@ -400,7 +402,7 @@ int dasrt_step(DATA* simData, SOLVER_INFO* solverInfo)
}


DEBUG_INFO(LOG_SOLVER, "*** Finished DDASRT step! ***");
DEBUG_INFO(LOG_SOLVER, "| DDASRT | Finished DDASRT step.");

return retVal;
}
Expand Down Expand Up @@ -506,39 +508,14 @@ int function_ZeroCrossingsDASSL(fortran_integer *neqm, double *t, double *y,

function_ZeroCrossings(data, gout, t);

DEBUG_INFO1(LOG_ZEROCROSSINGS, "Check ZeroCrossing at time: %g", *t);
for (i=0; i < *ng; i++) {
DEBUG_INFO_NELA1(LOG_ZEROCROSSINGS, "ZeroCrossing %d : ", i);
DEBUG_INFO_NELA1(LOG_ZEROCROSSINGS, " %d ", data->simulationInfo.zeroCrossingEnabled[i]);

DEBUG_INFO_NELA1(LOG_ZEROCROSSINGS, " %g \n", gout[i]);

/* For the first evaluation gout[i] != 0 has to be
* of ZeroCrossings by dassl.
*
*/
/*
if (!(data->simulationInfo.zeroCrossingEnabled[i]==0)){
if (gout[i] == 0.0 && data->simulationInfo.zeroCrossingEnabled[i] >=1){
gout[i] = DBL_EPSILON;
} else if (gout[i] == 0.0 && data->simulationInfo.zeroCrossingEnabled[i] <= -1){
gout[i] = -DBL_EPSILON;
}
}else{
if (data->simulationInfo.zeroCrossingEnabled[i]==1)
gout[i] = 0.1;
else if (data->simulationInfo.zeroCrossingEnabled[i]==-1)
gout[i] = -0.1;
else{
if (data->simulationInfo.zeroCrossingsPre[i]>=0)
gout[i] = 1;
else if (data->simulationInfo.zeroCrossingsPre[i]<0)
gout[i] = -1;
else
gout[i] = 1;
if (DEBUG_FLAG(LOG_ZEROCROSSINGS)){
INFO1("| DDASRT | events | check zero crossing at time: %.10f", *t);
for (i=0; i < *ng; i++) {
if (data->simulationInfo.zeroCrossings[i] != gout[i]){
INFO_AL1("| | %s", zeroCrossingDescription[i]);
INFO_AL2("| | changed : %s <> %s", (data->simulationInfo.zeroCrossings[i]>0)?"TRUE ":"FALSE", (gout[i]>0)?"TRUE ":"FALSE");
}
}
*/
}
data->localData[0]->timeValue = timeBackup;

Expand Down

0 comments on commit 9e432d4

Please sign in to comment.