Make log of each separate child algorithm available for retrieval after

running model
This commit is contained in:
Nyall Dawson 2024-04-19 11:15:56 +10:00
parent 172a1c2b03
commit d4369f714d
5 changed files with 181 additions and 112 deletions

View File

@ -67,6 +67,20 @@ Returns the outputs generated by the child algorithm.
Sets the ``outputs`` used for the child algorithm.
.. seealso:: :py:func:`outputs`
%End
QString htmlLog() const;
%Docstring
Returns the HTML formatted contents of logged messages which occurred while running the child.
.. seealso:: :py:func:`setHtmlLog`
%End
void setHtmlLog( const QString &log );
%Docstring
Sets the HTML formatted contents of logged messages which occurred while running the child.
.. seealso:: :py:func:`htmlLog`
%End
bool operator==( const QgsProcessingModelChildAlgorithmResult &other ) const;

View File

@ -67,6 +67,20 @@ Returns the outputs generated by the child algorithm.
Sets the ``outputs`` used for the child algorithm.
.. seealso:: :py:func:`outputs`
%End
QString htmlLog() const;
%Docstring
Returns the HTML formatted contents of logged messages which occurred while running the child.
.. seealso:: :py:func:`setHtmlLog`
%End
void setHtmlLog( const QString &log );
%Docstring
Sets the HTML formatted contents of logged messages which occurred while running the child.
.. seealso:: :py:func:`htmlLog`
%End
bool operator==( const QgsProcessingModelChildAlgorithmResult &other ) const;

View File

@ -326,6 +326,7 @@ QVariantMap QgsProcessingModelAlgorithm::processAlgorithm( const QVariantMap &pa
QVariantMap finalResults;
QSet< QString > executed;
bool executedAlg = true;
int previousHtmlLogLength = 0;
while ( executedAlg && executed.count() < toExecute.count() )
{
executedAlg = false;
@ -503,124 +504,142 @@ QVariantMap QgsProcessingModelAlgorithm::processAlgorithm( const QVariantMap &pa
childResults.insert( childId, results );
childResult.setOutputs( results );
context.modelChildResults().insert( childId, childResult );
if ( runResult )
{
if ( feedback && !skipGenericLogging )
{
const QVariantMap displayOutputs = QgsProcessingUtils::removePointerValuesFromMap( results );
QStringList formattedOutputs;
for ( auto displayOutputIt = displayOutputs.constBegin(); displayOutputIt != displayOutputs.constEnd(); ++displayOutputIt )
{
formattedOutputs << QStringLiteral( "%1: %2" ).arg( displayOutputIt.key(),
QgsProcessingUtils::variantToPythonLiteral( displayOutputIt.value() ) );;
}
feedback->pushInfo( QObject::tr( "Results:" ) );
feedback->pushCommandInfo( QStringLiteral( "{ %1 }" ).arg( formattedOutputs.join( QLatin1String( ", " ) ) ) );
}
// look through child alg's outputs to determine whether any of these should be copied
// to the final model outputs
const QMap<QString, QgsProcessingModelOutput> outputs = child.modelOutputs();
for ( auto outputIt = outputs.constBegin(); outputIt != outputs.constEnd(); ++outputIt )
{
const int outputSortKey = mOutputOrder.indexOf( QStringLiteral( "%1:%2" ).arg( childId, outputIt->childOutputName() ) );
switch ( mInternalVersion )
{
case QgsProcessingModelAlgorithm::InternalVersion::Version1:
finalResults.insert( childId + ':' + outputIt->name(), results.value( outputIt->childOutputName() ) );
break;
case QgsProcessingModelAlgorithm::InternalVersion::Version2:
if ( const QgsProcessingParameterDefinition *modelParam = modelParameterFromChildIdAndOutputName( child.childId(), outputIt.key() ) )
{
finalResults.insert( modelParam->name(), results.value( outputIt->childOutputName() ) );
}
break;
}
if ( !results.value( outputIt->childOutputName() ).toString().isEmpty() )
{
QgsProcessingContext::LayerDetails &details = context.layerToLoadOnCompletionDetails( results.value( outputIt->childOutputName() ).toString() );
details.groupName = mOutputGroup;
if ( outputSortKey > 0 )
details.layerSortKey = outputSortKey;
}
}
executed.insert( childId );
std::function< void( const QString &, const QString & )> pruneAlgorithmBranchRecursive;
pruneAlgorithmBranchRecursive = [&]( const QString & id, const QString &branch = QString() )
{
const QSet<QString> toPrune = dependentChildAlgorithms( id, branch );
for ( const QString &targetId : toPrune )
{
if ( executed.contains( targetId ) )
continue;
executed.insert( targetId );
pruneAlgorithmBranchRecursive( targetId, branch );
}
};
// prune remaining algorithms if they are dependent on a branch from this child which didn't eventuate
const QgsProcessingOutputDefinitions outputDefs = childAlg->outputDefinitions();
for ( const QgsProcessingOutputDefinition *outputDef : outputDefs )
{
if ( outputDef->type() == QgsProcessingOutputConditionalBranch::typeName() && !results.value( outputDef->name() ).toBool() )
{
pruneAlgorithmBranchRecursive( childId, outputDef->name() );
}
}
if ( childAlg->flags() & Qgis::ProcessingAlgorithmFlag::PruneModelBranchesBasedOnAlgorithmResults )
{
// check if any dependent algorithms should be canceled based on the outputs of this algorithm run
// first find all direct dependencies of this algorithm by looking through all remaining child algorithms
for ( const QString &candidateId : std::as_const( toExecute ) )
{
if ( executed.contains( candidateId ) )
continue;
// a pending algorithm was found..., check it's parameter sources to see if it links to any of the current
// algorithm's outputs
const QgsProcessingModelChildAlgorithm &candidate = mChildAlgorithms[ candidateId ];
const QMap<QString, QgsProcessingModelChildParameterSources> candidateParams = candidate.parameterSources();
QMap<QString, QgsProcessingModelChildParameterSources>::const_iterator paramIt = candidateParams.constBegin();
bool pruned = false;
for ( ; paramIt != candidateParams.constEnd(); ++paramIt )
{
for ( const QgsProcessingModelChildParameterSource &source : paramIt.value() )
{
if ( source.source() == Qgis::ProcessingModelChildParameterSource::ChildOutput && source.outputChildId() == childId )
{
// ok, this one is dependent on the current alg. Did we get a value for it?
if ( !results.contains( source.outputName() ) )
{
// oh no, nothing returned for this parameter. Gotta trim the branch back!
pruned = true;
// skip the dependent alg..
executed.insert( candidateId );
//... and everything which depends on it
pruneAlgorithmBranchRecursive( candidateId, QString() );
break;
}
}
}
if ( pruned )
break;
}
}
}
childAlg.reset( nullptr );
modelFeedback.setCurrentStep( executed.count() );
if ( feedback && !skipGenericLogging )
{
feedback->pushInfo( QObject::tr( "OK. Execution took %1 s (%n output(s)).", nullptr, results.count() ).arg( childTime.elapsed() / 1000.0 ) );
}
}
// trim out just the portion of the overall log which relates to this child
const QString thisAlgorithmHtmlLog = feedback->htmlLog().mid( previousHtmlLogLength );
previousHtmlLogLength = feedback->htmlLog().length();
if ( !runResult )
{
const QString formattedException = QStringLiteral( "<span style=\"color:red\">%1</span><br/>" ).arg( error.toHtmlEscaped() ).replace( '\n', QLatin1String( "<br>" ) );
const QString formattedRunTime = QStringLiteral( "<span style=\"color:red\">%1</span><br/>" ).arg( QObject::tr( "Failed after %1 s." ).arg( childTime.elapsed() / 1000.0 ).toHtmlEscaped() ).replace( '\n', QLatin1String( "<br>" ) );
childResult.setHtmlLog( thisAlgorithmHtmlLog + formattedException + formattedRunTime );
context.modelChildResults().insert( childId, childResult );
throw QgsProcessingException( error );
}
if ( feedback && !skipGenericLogging )
else
{
const QVariantMap displayOutputs = QgsProcessingUtils::removePointerValuesFromMap( results );
QStringList formattedOutputs;
for ( auto displayOutputIt = displayOutputs.constBegin(); displayOutputIt != displayOutputs.constEnd(); ++displayOutputIt )
{
formattedOutputs << QStringLiteral( "%1: %2" ).arg( displayOutputIt.key(),
QgsProcessingUtils::variantToPythonLiteral( displayOutputIt.value() ) );;
}
feedback->pushInfo( QObject::tr( "Results:" ) );
feedback->pushCommandInfo( QStringLiteral( "{ %1 }" ).arg( formattedOutputs.join( QLatin1String( ", " ) ) ) );
childResult.setHtmlLog( thisAlgorithmHtmlLog );
context.modelChildResults().insert( childId, childResult );
}
// look through child alg's outputs to determine whether any of these should be copied
// to the final model outputs
const QMap<QString, QgsProcessingModelOutput> outputs = child.modelOutputs();
for ( auto outputIt = outputs.constBegin(); outputIt != outputs.constEnd(); ++outputIt )
{
const int outputSortKey = mOutputOrder.indexOf( QStringLiteral( "%1:%2" ).arg( childId, outputIt->childOutputName() ) );
switch ( mInternalVersion )
{
case QgsProcessingModelAlgorithm::InternalVersion::Version1:
finalResults.insert( childId + ':' + outputIt->name(), results.value( outputIt->childOutputName() ) );
break;
case QgsProcessingModelAlgorithm::InternalVersion::Version2:
if ( const QgsProcessingParameterDefinition *modelParam = modelParameterFromChildIdAndOutputName( child.childId(), outputIt.key() ) )
{
finalResults.insert( modelParam->name(), results.value( outputIt->childOutputName() ) );
}
break;
}
if ( !results.value( outputIt->childOutputName() ).toString().isEmpty() )
{
QgsProcessingContext::LayerDetails &details = context.layerToLoadOnCompletionDetails( results.value( outputIt->childOutputName() ).toString() );
details.groupName = mOutputGroup;
if ( outputSortKey > 0 )
details.layerSortKey = outputSortKey;
}
}
executed.insert( childId );
std::function< void( const QString &, const QString & )> pruneAlgorithmBranchRecursive;
pruneAlgorithmBranchRecursive = [&]( const QString & id, const QString &branch = QString() )
{
const QSet<QString> toPrune = dependentChildAlgorithms( id, branch );
for ( const QString &targetId : toPrune )
{
if ( executed.contains( targetId ) )
continue;
executed.insert( targetId );
pruneAlgorithmBranchRecursive( targetId, branch );
}
};
// prune remaining algorithms if they are dependent on a branch from this child which didn't eventuate
const QgsProcessingOutputDefinitions outputDefs = childAlg->outputDefinitions();
for ( const QgsProcessingOutputDefinition *outputDef : outputDefs )
{
if ( outputDef->type() == QgsProcessingOutputConditionalBranch::typeName() && !results.value( outputDef->name() ).toBool() )
{
pruneAlgorithmBranchRecursive( childId, outputDef->name() );
}
}
if ( childAlg->flags() & Qgis::ProcessingAlgorithmFlag::PruneModelBranchesBasedOnAlgorithmResults )
{
// check if any dependent algorithms should be canceled based on the outputs of this algorithm run
// first find all direct dependencies of this algorithm by looking through all remaining child algorithms
for ( const QString &candidateId : std::as_const( toExecute ) )
{
if ( executed.contains( candidateId ) )
continue;
// a pending algorithm was found..., check it's parameter sources to see if it links to any of the current
// algorithm's outputs
const QgsProcessingModelChildAlgorithm &candidate = mChildAlgorithms[ candidateId ];
const QMap<QString, QgsProcessingModelChildParameterSources> candidateParams = candidate.parameterSources();
QMap<QString, QgsProcessingModelChildParameterSources>::const_iterator paramIt = candidateParams.constBegin();
bool pruned = false;
for ( ; paramIt != candidateParams.constEnd(); ++paramIt )
{
for ( const QgsProcessingModelChildParameterSource &source : paramIt.value() )
{
if ( source.source() == Qgis::ProcessingModelChildParameterSource::ChildOutput && source.outputChildId() == childId )
{
// ok, this one is dependent on the current alg. Did we get a value for it?
if ( !results.contains( source.outputName() ) )
{
// oh no, nothing returned for this parameter. Gotta trim the branch back!
pruned = true;
// skip the dependent alg..
executed.insert( candidateId );
//... and everything which depends on it
pruneAlgorithmBranchRecursive( candidateId, QString() );
break;
}
}
}
if ( pruned )
break;
}
}
}
childAlg.reset( nullptr );
modelFeedback.setCurrentStep( executed.count() );
if ( feedback && !skipGenericLogging )
feedback->pushInfo( QObject::tr( "OK. Execution took %1 s (%n output(s)).", nullptr, results.count() ).arg( childTime.elapsed() / 1000.0 ) );
}
if ( feedback && feedback->isCanceled() )

View File

@ -86,9 +86,24 @@ class CORE_EXPORT QgsProcessingModelChildAlgorithmResult
*/
void setOutputs( const QVariantMap &outputs ) { mOutputs = outputs; }
/**
* Returns the HTML formatted contents of logged messages which occurred while running the child.
*
* \see setHtmlLog()
*/
QString htmlLog() const { return mHtmlLog; }
/**
* Sets the HTML formatted contents of logged messages which occurred while running the child.
*
* \see htmlLog()
*/
void setHtmlLog( const QString &log ) { mHtmlLog = log; }
bool operator==( const QgsProcessingModelChildAlgorithmResult &other ) const
{
return mExecutionStatus == other.mExecutionStatus
&& mHtmlLog == other.mHtmlLog
&& mInputs == other.mInputs
&& mOutputs == other.mOutputs;
}
@ -102,6 +117,7 @@ class CORE_EXPORT QgsProcessingModelChildAlgorithmResult
Qgis::ProcessingModelChildAlgorithmExecutionStatus mExecutionStatus = Qgis::ProcessingModelChildAlgorithmExecutionStatus::NotExecuted;
QVariantMap mInputs;
QVariantMap mOutputs;
QString mHtmlLog;
};

View File

@ -69,7 +69,7 @@ class DummyRaiseExceptionAlgorithm : public QgsProcessingAlgorithm
QString displayName() const override { return mName; }
QVariantMap processAlgorithm( const QVariantMap &, QgsProcessingContext &, QgsProcessingFeedback * ) override
{
throw QgsProcessingException( QString() );
throw QgsProcessingException( QStringLiteral( "something bad happened" ) );
}
static bool postProcessAlgorithmCalled;
QVariantMap postProcessAlgorithm( QgsProcessingContext &, QgsProcessingFeedback * ) final
@ -2330,12 +2330,14 @@ void TestQgsProcessingModelAlgorithm::modelWithChildException()
QgsProcessingModelChildAlgorithm algWhichRaisesException;
algWhichRaisesException.setChildId( QStringLiteral( "raise" ) );
algWhichRaisesException.setDescription( QStringLiteral( "my second step" ) );
algWhichRaisesException.setAlgorithmId( "dummy4:raise" );
algWhichRaisesException.setDependencies( {QgsProcessingModelChildDependency( QStringLiteral( "buffer" ) )} );
m.addChildAlgorithm( algWhichRaisesException );
// run and check context details
QgsProcessingContext context;
context.setLogLevel( Qgis::ProcessingLogLevel::ModelDebug );
QgsProcessingFeedback feedback;
QVariantMap params;
QgsVectorLayer *layer3111 = new QgsVectorLayer( "Point?crs=epsg:3111", "v1", "memory" );
@ -2359,9 +2361,13 @@ void TestQgsProcessingModelAlgorithm::modelWithChildException()
QCOMPARE( context.modelChildResults().value( "buffer" ).executionStatus(), Qgis::ProcessingModelChildAlgorithmExecutionStatus::Success );
QCOMPARE( context.modelChildResults().value( "buffer" ).inputs().value( "INPUT" ).toString(), QStringLiteral( "v1" ) );
QCOMPARE( context.modelChildResults().value( "buffer" ).inputs().value( "OUTPUT" ).toString(), QStringLiteral( "memory:Buffered" ) );
QCOMPARE( context.modelChildResults().value( "buffer" ).htmlLog().left( 50 ), QStringLiteral( "<span style=\"color:#777\">Prepare algorithm: buffer" ) );
QCOMPARE( context.modelChildResults().value( "buffer" ).htmlLog().right( 21 ), QStringLiteral( "s (1 output(s)).<br/>" ) );
QVERIFY( context.temporaryLayerStore()->mapLayer( context.modelChildResults().value( "buffer" ).outputs().value( "OUTPUT" ).toString() ) );
QCOMPARE( context.modelChildResults().value( "raise" ).executionStatus(), Qgis::ProcessingModelChildAlgorithmExecutionStatus::Failed );
QCOMPARE( context.modelChildResults().value( "raise" ).htmlLog().left( 49 ), QStringLiteral( "<span style=\"color:#777\">Prepare algorithm: raise" ) );
QVERIFY( context.modelChildResults().value( "raise" ).htmlLog().contains( QStringLiteral( "Error encountered while running my second step: something bad happened" ) ) );
}
void TestQgsProcessingModelAlgorithm::modelDependencies()