Replace tracking of timings in ContourTree with logging

This commit is contained in:
Oliver Ruebel 2020-01-22 01:11:45 -08:00
parent 7ed921d247
commit 43aae4870b
5 changed files with 81 additions and 93 deletions

@ -376,24 +376,29 @@ int main(int argc, char* argv[])
" computeIsovalues=" << (numLevels > 0));
VTKM_LOG_IF_S(vtkm::cont::LogLevel::Info,
numLevels > 0,
" levels=" << numLevels << std::endl
<< " eps="
<< eps
<< std::endl
<< " comp"
<< numComp
<< std::endl
<< " type="
<< contourType
<< std::endl
<< " method="
<< contourSelectMethod
<< std::endl
<< " mc="
<< useMarchingCubes
<< std::endl
<< " use"
<< (usePersistenceSorter ? "PersistenceSorter" : "VolumeSorter"));
std::endl
<< " ------------ Settings Isolevel Selection -----------"
<< std::endl
<< " levels="
<< numLevels
<< std::endl
<< " eps="
<< eps
<< std::endl
<< " comp"
<< numComp
<< std::endl
<< " type="
<< contourType
<< std::endl
<< " method="
<< contourSelectMethod
<< std::endl
<< " mc="
<< useMarchingCubes
<< std::endl
<< " use"
<< (usePersistenceSorter ? "PersistenceSorter" : "VolumeSorter"));
}
currTime = totalTime.GetElapsedTime();
vtkm::Float64 startUpTime = currTime - prevTime;
@ -466,7 +471,7 @@ int main(int argc, char* argv[])
{
VTKM_LOG_S(vtkm::cont::LogLevel::Info,
std::endl
<< " ---------------- Input Mesh Propoerties --------------"
<< " ---------------- Input Mesh Properties --------------"
<< std::endl
<< " Number of dimensions: "
<< nDims
@ -662,23 +667,6 @@ int main(int argc, char* argv[])
vtkm::Float64 computeContourTreeTime = currTime - prevTime;
prevTime = currTime;
#ifdef DEBUG_TIMING
std::stringstream timingsStream; // Use a string stream to log in one message
timingsStream << std::endl;
timingsStream << " ------------------- Contour Tree Timings " << rank
<< " ----------------------" << std::endl;
// Get the timings from the contour tree computation
const std::vector<std::pair<std::string, vtkm::Float64>>& contourTreeTimings =
filter.GetTimings();
for (std::size_t i = 0; i < contourTreeTimings.size(); ++i)
{
timingsStream << " " << std::setw(38) << std::left << contourTreeTimings[i].first << ": "
<< contourTreeTimings[i].second << " seconds" << std::endl;
}
VTKM_LOG_IF_S(vtkm::cont::LogLevel::Info, rank == 0, timingsStream.str());
timingsStream.str(std::string()); // Reset the string stream so we can reuse it
#endif
////////////////////////////////////////////
// Compute the branch decomposition
////////////////////////////////////////////
@ -701,6 +689,7 @@ int main(int argc, char* argv[])
supernodeTransferWeight, // (output)
hyperarcDependentWeight); // (output)
#ifdef DEBUG_TIMING
std::stringstream timingsStream; // Use a string stream to log in one message
timingsStream << std::endl;
timingsStream << " --------------- Branch Decomposition Timings " << rank
<< " --------------" << std::endl;
@ -881,6 +870,7 @@ int main(int argc, char* argv[])
<< ": "
<< computeBranchDecompTime
<< " seconds"
<< std::endl
<< std::setw(42)
<< std::left
<< " Total Time"

@ -121,7 +121,6 @@ public:
const vtkm::worklet::contourtree_augmented::ContourTree& GetContourTree() const;
const vtkm::worklet::contourtree_augmented::IdArrayType& GetSortOrder() const;
vtkm::Id GetNumIterations() const;
const std::vector<std::pair<std::string, vtkm::Float64>>& GetTimings() const;
private:
// Given the input dataset determine the number of rows, cols, and slices
@ -133,8 +132,6 @@ private:
bool UseMarchingCubes;
// 0=no augmentation, 1=full augmentation, 2=boundary augmentation
unsigned int ComputeRegularStructure;
// Store timings about the contour tree computation
std::vector<std::pair<std::string, vtkm::Float64>> Timings;
// TODO Should the additional fields below be add to the vtkm::filter::ResultField and what is the best way to represent them
// Additional result fields not included in the vtkm::filter::ResultField returned by DoExecute

@ -469,7 +469,6 @@ void merge_block_functor(
else // If we are a block that will continue to be merged then we need compute the contour tree here
{
// Compute the contour tree from our merged mesh
std::vector<std::pair<std::string, vtkm::Float64>> currTimings;
vtkm::Id currNumIterations;
vtkm::worklet::contourtree_augmented::ContourTree currContourTree;
vtkm::worklet::contourtree_augmented::IdArrayType currSortOrder;
@ -487,7 +486,6 @@ void merge_block_functor(
worklet.Run(
contourTreeMeshOut.sortedValues, // Unused param. Provide something to keep the API happy
contourTreeMeshOut,
currTimings,
currContourTree,
currSortOrder,
currNumIterations,
@ -550,7 +548,6 @@ ContourTreePPP2::ContourTreePPP2(bool useMarchingCubes, unsigned int computeRegu
: vtkm::filter::FilterCell<ContourTreePPP2>()
, UseMarchingCubes(useMarchingCubes)
, ComputeRegularStructure(computeRegularStructure)
, Timings()
, MultiBlockTreeHelper(nullptr)
{
this->SetOutputFieldName("resultData");
@ -587,11 +584,6 @@ vtkm::Id ContourTreePPP2::GetNumIterations() const
return this->NumIterations;
}
const std::vector<std::pair<std::string, vtkm::Float64>>& ContourTreePPP2::GetTimings() const
{
return this->Timings;
}
//-----------------------------------------------------------------------------
template <typename T, typename StorageType, typename DerivedPolicy>
vtkm::cont::DataSet ContourTreePPP2::DoExecute(const vtkm::cont::DataSet& input,
@ -599,11 +591,8 @@ vtkm::cont::DataSet ContourTreePPP2::DoExecute(const vtkm::cont::DataSet& input,
const vtkm::filter::FieldMetadata& fieldMeta,
vtkm::filter::PolicyBase<DerivedPolicy> policy)
{
// TODO: This should be switched to use the logging macros defined in vtkm/cont/logging.h
// Start the timer
vtkm::cont::Timer timer;
timer.Start();
Timings.clear();
// Check that the field is Ok
if (fieldMeta.IsPointField() == false)
@ -638,7 +627,6 @@ vtkm::cont::DataSet ContourTreePPP2::DoExecute(const vtkm::cont::DataSet& input,
// Run the worklet
worklet.Run(field,
this->Timings,
MultiBlockTreeHelper ? MultiBlockTreeHelper->mLocalContourTrees[blockIndex]
: this->ContourTreeData,
MultiBlockTreeHelper ? MultiBlockTreeHelper->mLocalSortOrders[blockIndex]
@ -650,13 +638,6 @@ vtkm::cont::DataSet ContourTreePPP2::DoExecute(const vtkm::cont::DataSet& input,
this->UseMarchingCubes,
compRegularStruct);
// Update the total timings
vtkm::Float64 totalTimeWorklet = 0;
for (std::vector<std::pair<std::string, vtkm::Float64>>::size_type i = 0; i < Timings.size(); i++)
totalTimeWorklet += Timings[i].second;
Timings.push_back(std::pair<std::string, vtkm::Float64>(
"Others (ContourTreePPP2 Filter): ", timer.GetElapsedTime() - totalTimeWorklet));
// If we run in parallel but with only one global block, then we need set our outputs correctly
// here to match the expected behavior in parallel
if (this->MultiBlockTreeHelper)
@ -679,6 +660,17 @@ vtkm::cont::DataSet ContourTreePPP2::DoExecute(const vtkm::cont::DataSet& input,
return result;
}
}
VTKM_LOG_S(vtkm::cont::LogLevel::Info,
std::endl
<< " "
<< std::setw(38)
<< std::left
<< "Contour Tree Filter DoExecute"
<< ": "
<< timer.GetElapsedTime()
<< " seconds");
// Construct the expected result for serial execution. Note, in serial the result currently
// not actually being used, but in parallel we need the sorted mesh values as output
// This part is being hit when we run in serial or parallel with more then one rank
@ -851,7 +843,6 @@ VTKM_CONT void ContourTreePPP2::DoPostExecute(
if (rank == 0)
{
// Now run the contour tree algorithm on the last block to compute the final tree
std::vector<std::pair<std::string, vtkm::Float64>> currTimings;
vtkm::Id currNumIterations;
vtkm::worklet::contourtree_augmented::ContourTree currContourTree;
vtkm::worklet::contourtree_augmented::IdArrayType currSortOrder;
@ -881,7 +872,6 @@ VTKM_CONT void ContourTreePPP2::DoPostExecute(
worklet.Run(
contourTreeMeshOut.sortedValues, // Unused param. Provide something to keep API happy
contourTreeMeshOut,
currTimings,
this->ContourTreeData,
this->MeshSortOrder,
currNumIterations,
@ -930,6 +920,8 @@ inline VTKM_CONT void ContourTreePPP2::PostExecute(
{
if (this->MultiBlockTreeHelper)
{
vtkm::cont::Timer timer;
timer.Start();
// We are running in parallel and need to merge the contour tree in PostExecute
if (MultiBlockTreeHelper->getGlobalNumberOfBlocks() == 1)
{
@ -950,6 +942,15 @@ inline VTKM_CONT void ContourTreePPP2::PostExecute(
delete this->MultiBlockTreeHelper;
this->MultiBlockTreeHelper = nullptr;
VTKM_LOG_S(vtkm::cont::LogLevel::Info,
std::endl
<< " "
<< std::setw(38)
<< std::left
<< "Contour Tree Filter PostExecute"
<< ": "
<< timer.GetElapsedTime()
<< " seconds");
}
}

@ -54,8 +54,8 @@
#define vtk_m_worklet_ContourTreeUniformAugmented_h
#include <sstream>
#include <utility>
#include <vector>
// VTKM includes
#include <vtkm/Math.h>
@ -98,7 +98,6 @@ public:
void Run(const vtkm::cont::ArrayHandle<FieldType, StorageType>
fieldArray, // TODO: We really should not need this
contourtree_augmented::ContourTreeMesh<FieldType>& mesh,
std::vector<std::pair<std::string, vtkm::Float64>>& timings,
contourtree_augmented::ContourTree& contourTree,
contourtree_augmented::IdArrayType sortOrder,
vtkm::Id& nIterations,
@ -107,7 +106,6 @@ public:
{
RunContourTree(
fieldArray, // Just a place-holder to fill the required field. Used when calling SortData on the contour tree which is a no-op
timings,
contourTree,
sortOrder,
nIterations,
@ -128,7 +126,6 @@ public:
*/
template <typename FieldType, typename StorageType>
void Run(const vtkm::cont::ArrayHandle<FieldType, StorageType> fieldArray,
std::vector<std::pair<std::string, vtkm::Float64>>& timings,
contourtree_augmented::ContourTree& contourTree,
contourtree_augmented::IdArrayType& sortOrder,
vtkm::Id& nIterations,
@ -146,7 +143,6 @@ public:
Mesh_DEM_Triangulation_2D_Freudenthal<FieldType, StorageType> mesh(nRows, nCols);
// Run the contour tree on the mesh
RunContourTree(fieldArray,
timings,
contourTree,
sortOrder,
nIterations,
@ -162,7 +158,6 @@ public:
Mesh_DEM_Triangulation_3D_MarchingCubes<FieldType, StorageType> mesh(nRows, nCols, nSlices);
// Run the contour tree on the mesh
RunContourTree(fieldArray,
timings,
contourTree,
sortOrder,
nIterations,
@ -178,7 +173,6 @@ public:
Mesh_DEM_Triangulation_3D_Freudenthal<FieldType, StorageType> mesh(nRows, nCols, nSlices);
// Run the contour tree on the mesh
RunContourTree(fieldArray,
timings,
contourTree,
sortOrder,
nIterations,
@ -213,7 +207,6 @@ private:
typename MeshClass,
typename MeshBoundaryClass>
void RunContourTree(const vtkm::cont::ArrayHandle<FieldType, StorageType> fieldArray,
std::vector<std::pair<std::string, vtkm::Float64>>& timings,
contourtree_augmented::ContourTree& contourTree,
contourtree_augmented::IdArrayType& sortOrder,
vtkm::Id& nIterations,
@ -230,24 +223,31 @@ private:
// Start the timer for the mesh sort
vtkm::cont::Timer timer;
timer.Start();
std::stringstream timingsStream; // Use a string stream to log in one message
timingsStream << std::endl;
timingsStream << " ------------------- Contour Tree Worklet Timings ----------------------"
<< std::endl;
// Sort the mesh data
mesh.SortData(fieldArray);
timings.push_back(std::pair<std::string, vtkm::Float64>("Sort Data", timer.GetElapsedTime()));
timingsStream << " " << std::setw(38) << std::left << "Sort Data"
<< ": " << timer.GetElapsedTime() << " seconds" << std::endl;
timer.Start();
// Stage 3: Assign every mesh vertex to a peak
MeshExtrema extrema(mesh.nVertices);
extrema.SetStarts(mesh, true);
extrema.BuildRegularChains(true);
timings.push_back(
std::pair<std::string, vtkm::Float64>("Join Tree Regular Chains", timer.GetElapsedTime()));
timingsStream << " " << std::setw(38) << std::left << "Join Tree Regular Chains"
<< ": " << timer.GetElapsedTime() << " seconds" << std::endl;
timer.Start();
// Stage 4: Identify join saddles & construct Active Join Graph
MergeTree joinTree(mesh.nVertices, true);
ActiveGraph joinGraph(true);
joinGraph.Initialise(mesh, extrema);
timings.push_back(std::pair<std::string, vtkm::Float64>("Join Tree Initialize Active Graph",
timer.GetElapsedTime()));
timingsStream << " " << std::setw(38) << std::left << "Join Tree Initialize Active Graph"
<< ": " << timer.GetElapsedTime() << " seconds" << std::endl;
#ifdef DEBUG_PRINT
joinGraph.DebugPrint("Active Graph Instantiated", __FILE__, __LINE__);
@ -256,8 +256,8 @@ private:
// Stage 5: Compute Join Tree Hyperarcs from Active Join Graph
joinGraph.MakeMergeTree(joinTree, extrema);
timings.push_back(
std::pair<std::string, vtkm::Float64>("Join Tree Compute", timer.GetElapsedTime()));
timingsStream << " " << std::setw(38) << std::left << "Join Tree Compute"
<< ": " << timer.GetElapsedTime() << " seconds" << std::endl;
#ifdef DEBUG_PRINT
joinTree.DebugPrint("Join tree Computed", __FILE__, __LINE__);
joinTree.DebugPrintTree("Join tree", __FILE__, __LINE__, mesh);
@ -267,16 +267,16 @@ private:
// Stage 6: Assign every mesh vertex to a pit
extrema.SetStarts(mesh, false);
extrema.BuildRegularChains(false);
timings.push_back(
std::pair<std::string, vtkm::Float64>("Spit Tree Regular Chains", timer.GetElapsedTime()));
timingsStream << " " << std::setw(38) << std::left << "Split Tree Regular Chains"
<< ": " << timer.GetElapsedTime() << " seconds" << std::endl;
timer.Start();
// Stage 7: Identify split saddles & construct Active Split Graph
MergeTree splitTree(mesh.nVertices, false);
ActiveGraph splitGraph(false);
splitGraph.Initialise(mesh, extrema);
timings.push_back(std::pair<std::string, vtkm::Float64>("Split Tree Initialize Active Graph",
timer.GetElapsedTime()));
timingsStream << " " << std::setw(38) << std::left << "Splot Tree Initialize Active Graph"
<< ": " << timer.GetElapsedTime() << " seconds" << std::endl;
#ifdef DEBUG_PRINT
splitGraph.DebugPrint("Active Graph Instantiated", __FILE__, __LINE__);
#endif
@ -284,8 +284,8 @@ private:
// Stage 8: Compute Split Tree Hyperarcs from Active Split Graph
splitGraph.MakeMergeTree(splitTree, extrema);
timings.push_back(
std::pair<std::string, vtkm::Float64>("Split Tree Compute", timer.GetElapsedTime()));
timingsStream << " " << std::setw(38) << std::left << "Split Tree Compute"
<< ": " << timer.GetElapsedTime() << " seconds" << std::endl;
#ifdef DEBUG_PRINT
splitTree.DebugPrint("Split tree Computed", __FILE__, __LINE__);
// Debug split and join tree
@ -299,23 +299,26 @@ private:
ContourTreeMaker treeMaker(contourTree, joinTree, splitTree);
// 9.1 First we compute the hyper- and super- structure
treeMaker.ComputeHyperAndSuperStructure();
timings.push_back(std::pair<std::string, vtkm::Float64>(
"Contour Tree Hyper and Super Structure", timer.GetElapsedTime()));
timingsStream << " " << std::setw(38) << std::left
<< "Contour Tree Hyper and Super Structure"
<< ": " << timer.GetElapsedTime() << " seconds" << std::endl;
timer.Start();
// 9.2 Then we compute the regular structure
if (computeRegularStructure == 1) // augment with all vertices
{
treeMaker.ComputeRegularStructure(extrema);
timings.push_back(std::pair<std::string, vtkm::Float64>("Contour Tree Regular Structure",
timer.GetElapsedTime()));
timingsStream << " " << std::setw(38) << std::left << "Contour Tree Regular Structure"
<< ": " << timer.GetElapsedTime() << " seconds" << std::endl;
}
else if (computeRegularStructure == 2) // augment by the mesh boundary
{
treeMaker.ComputeBoundaryRegularStructure(extrema, mesh, meshBoundary);
timings.push_back(std::pair<std::string, vtkm::Float64>(
"Contour Tree Boundary Regular Structure", timer.GetElapsedTime()));
timingsStream << " " << std::setw(38) << std::left
<< "Contour Tree Boundary Regular Structure"
<< ": " << timer.GetElapsedTime() << " seconds" << std::endl;
}
timer.Start();
// Collect the output data
nIterations = treeMaker.nIterations;
@ -323,6 +326,9 @@ private:
// ProcessContourTree::CollectSortedSuperarcs<DeviceAdapter>(contourTree, mesh.sortOrder, saddlePeak);
// contourTree.SortedArcPrint(mesh.sortOrder);
// contourTree.PrintDotSuperStructure();
// Log the collected timing results in one coherent log entry
VTKM_LOG_S(vtkm::cont::LogLevel::Info, timingsStream.str());
}
};

@ -95,7 +95,6 @@ public:
// Create the worklet and run it
vtkm::worklet::ContourTreePPP2 contourTreeWorklet;
std::vector<std::pair<std::string, vtkm::Float64>> timings;
vtkm::worklet::contourtree_augmented::ContourTree contourTree;
vtkm::worklet::contourtree_augmented::IdArrayType meshSortOrder;
vtkm::Id numIterations;
@ -103,7 +102,6 @@ public:
const int computeRegularStructure = 1;
contourTreeWorklet.Run(field,
timings,
contourTree,
meshSortOrder,
numIterations,
@ -168,7 +166,6 @@ public:
// Create the worklet and run it
vtkm::worklet::ContourTreePPP2 contourTreeWorklet;
std::vector<std::pair<std::string, vtkm::Float64>> timings;
vtkm::worklet::contourtree_augmented::ContourTree contourTree;
vtkm::worklet::contourtree_augmented::IdArrayType meshSortOrder;
vtkm::Id numIterations;
@ -176,7 +173,6 @@ public:
const int computeRegularStructure = 1;
contourTreeWorklet.Run(field,
timings,
contourTree,
meshSortOrder,
numIterations,
@ -248,7 +244,6 @@ public:
// Create the worklet and run it
vtkm::worklet::ContourTreePPP2 contourTreeWorklet;
std::vector<std::pair<std::string, vtkm::Float64>> timings;
vtkm::worklet::contourtree_augmented::ContourTree contourTree;
vtkm::worklet::contourtree_augmented::IdArrayType meshSortOrder;
vtkm::Id numIterations;
@ -256,7 +251,6 @@ public:
const int computeRegularStructure = 1;
contourTreeWorklet.Run(field,
timings,
contourTree,
meshSortOrder,
numIterations,