kindred/create
1
1
Fork 0
Code Issues 53 Pull Requests Actions Packages Projects 9 Releases 2 Wiki Activity

Base: Implement TimeElapsed

Browse Source 
Some instances of TimeInfo serve the sole purpose of measuring time
duration. Using system time is unfortunate as it returns wall clock,
which is not guaranteed to be monotonic. Replace such a usage with
the new TimeElapsed class based on steady clock.
This commit is contained in:
Ladislav Michl
2024-01-21 19:00:57 +01:00
parent 159fe5c21f
commit e4d304f934
10 changed files with 93 additions and 52 deletions
Download Patch File Download Diff File Expand all files Collapse all files

34
src/Base/TimeInfo.h
View File

@@ -94,6 +94,40 @@ public:
}
}; // class TimeInfo
using Ticks = std::chrono::steady_clock;
class TimeElapsed: public std::chrono::time_point<Ticks>
{
public:
TimeElapsed()
{
setCurrent();
}
TimeElapsed(const TimeElapsed&) = default;
TimeElapsed(TimeElapsed&&) = default;
~TimeElapsed() = default;
void setCurrent()
{
static_cast<std::chrono::time_point<Ticks>&>(*this) = Ticks::now();
}
static float diffTimeF(const TimeElapsed& start, const TimeElapsed& end = TimeElapsed())
{
const std::chrono::duration<float> duration = end - start;
return duration.count();
}
static std::string diffTime(const TimeElapsed& start, const TimeElapsed& end = TimeElapsed())
{
std::stringstream ss;
const std::chrono::duration<float> secs = end - start;
ss << secs.count();
return ss.str();
}
}; // class TimeElapsed
} // namespace Base
#endif // BASE_TIMEINFO_H

4
src/Gui/DAGView/DAGModel.cpp
View File

@@ -460,7 +460,7 @@ void Model::updateSlot()
//for speed. Not doing yet, as I want a simple algorithm until
//a more complete picture is formed.
Base::TimeInfo startTime;
Base::TimeElapsed startTime;
//here we will cycle through the graph updating edges.
//we have to do this first and in isolation because everything is dependent on an up to date graph.
@@ -761,7 +761,7 @@ void Model::updateSlot()
//Modeling_Challenge_Casting_ta4 with 59 features: "Initialize DAG View time: 0.007"
//keeping algo simple with extra loops only added 0.002 to above number.
// std::cout << "Initialize DAG View time: " << Base::TimeInfo::diffTimeF(startTime, Base::TimeInfo()) << std::endl;
// std::cout << "Initialize DAG View time: " << Base::TimeElapsed::diffTimeF(startTime, Base::TimeElapsed()) << std::endl;
// outputGraphviz<Graph>(*theGraph, "./graphviz.dot");
graphDirty = false;

26
src/Mod/Fem/App/FemMesh.cpp
View File

@@ -1621,7 +1621,7 @@ class CHEXA2Element: public NastranElement
void FemMesh::readNastran(const std::string& Filename)
{
Base::TimeInfo Start;
Base::TimeElapsed Start;
Base::Console().Log("Start: FemMesh::readNastran() =================================\n");
_Mtrx = Base::Matrix4D();
@@ -1699,7 +1699,7 @@ void FemMesh::readNastran(const std::string& Filename)
inputfile.close();
Base::Console().Log(" %f: File read, start building mesh\n",
Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
// Now fill the SMESH datastructure
SMESHDS_Mesh* meshds = this->myMesh->GetMeshDS();
@@ -1709,12 +1709,13 @@ void FemMesh::readNastran(const std::string& Filename)
it->addToMesh(meshds);
}
Base::Console().Log(" %f: Done \n", Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::Console().Log(" %f: Done \n",
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
}
void FemMesh::readNastran95(const std::string& Filename)
{
Base::TimeInfo Start;
Base::TimeElapsed Start;
Base::Console().Log("Start: FemMesh::readNastran95() =================================\n");
_Mtrx = Base::Matrix4D();
@@ -1825,7 +1826,7 @@ void FemMesh::readNastran95(const std::string& Filename)
inputfile.close();
Base::Console().Log(" %f: File read, start building mesh\n",
Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
// Now fill the SMESH datastructure
SMESHDS_Mesh* meshds = this->myMesh->GetMeshDS();
@@ -1839,12 +1840,13 @@ void FemMesh::readNastran95(const std::string& Filename)
it->addToMesh(meshds);
}
Base::Console().Log(" %f: Done \n", Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::Console().Log(" %f: Done \n",
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
}
void FemMesh::readAbaqus(const std::string& FileName)
{
Base::TimeInfo Start;
Base::TimeElapsed Start;
Base::Console().Log("Start: FemMesh::readAbaqus() =================================\n");
/*
@@ -1878,12 +1880,13 @@ void FemMesh::readAbaqus(const std::string& FileName)
catch (Py::Exception& e) {
e.clear();
}
Base::Console().Log(" %f: Done \n", Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::Console().Log(" %f: Done \n",
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
}
void FemMesh::readZ88(const std::string& FileName)
{
Base::TimeInfo Start;
Base::TimeElapsed Start;
Base::Console().Log("Start: FemMesh::readZ88() =================================\n");
/*
@@ -1917,7 +1920,8 @@ void FemMesh::readZ88(const std::string& FileName)
catch (Py::Exception& e) {
e.clear();
}
Base::Console().Log(" %f: Done \n", Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::Console().Log(" %f: Done \n",
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
}
void FemMesh::read(const char* FileName)
@@ -2416,7 +2420,7 @@ void FemMesh::writeABAQUS(const std::string& Filename, int elemParam, bool group
void FemMesh::writeZ88(const std::string& FileName) const
{
Base::TimeInfo Start;
Base::TimeElapsed Start;
Base::Console().Log("Start: FemMesh::writeZ88() =================================\n");
/*

21
src/Mod/Fem/App/FemVTKTools.cpp
View File

@@ -267,7 +267,7 @@ void FemVTKTools::importVTKMesh(vtkSmartPointer<vtkDataSet> dataset, FemMesh* me
FemMesh* FemVTKTools::readVTKMesh(const char* filename, FemMesh* mesh)
{
Base::TimeInfo Start;
Base::TimeElapsed Start;
Base::Console().Log("Start: read FemMesh from VTK unstructuredGrid ======================\n");
Base::FileInfo f(filename);
@@ -301,7 +301,8 @@ FemMesh* FemVTKTools::readVTKMesh(const char* filename, FemMesh* mesh)
}
// Mesh should link to the part feature, in order to set up FemConstraint
Base::Console().Log(" %f: Done \n", Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::Console().Log(" %f: Done \n",
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
return mesh;
}
@@ -543,7 +544,7 @@ void FemVTKTools::exportVTKMesh(const FemMesh* mesh,
void FemVTKTools::writeVTKMesh(const char* filename, const FemMesh* mesh)
{
Base::TimeInfo Start;
Base::TimeElapsed Start;
Base::Console().Log("Start: write FemMesh from VTK unstructuredGrid ======================\n");
Base::FileInfo f(filename);
@@ -561,7 +562,8 @@ void FemVTKTools::writeVTKMesh(const char* filename, const FemMesh* mesh)
Base::Console().Error("file name extension is not supported to write VTK\n");
}
Base::Console().Log(" %f: Done \n", Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::Console().Log(" %f: Done \n",
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
}
@@ -611,7 +613,7 @@ App::DocumentObject* createObjectByType(const Base::Type type)
App::DocumentObject* FemVTKTools::readResult(const char* filename, App::DocumentObject* res)
{
Base::TimeInfo Start;
Base::TimeElapsed Start;
Base::Console().Log(
"Start: read FemResult with FemMesh from VTK file ======================\n");
Base::FileInfo f(filename);
@@ -667,7 +669,8 @@ App::DocumentObject* FemVTKTools::readResult(const char* filename, App::Document
}
pcDoc->recompute();
Base::Console().Log(" %f: Done \n", Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::Console().Log(" %f: Done \n",
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
Base::Console().Log("End: read FemResult with FemMesh from VTK file ======================\n");
return result;
@@ -689,7 +692,7 @@ void FemVTKTools::writeResult(const char* filename, const App::DocumentObject* r
return;
}
Base::TimeInfo Start;
Base::TimeElapsed Start;
Base::Console().Log("Start: write FemResult to VTK unstructuredGrid dataset =======\n");
Base::FileInfo f(filename);
@@ -702,7 +705,7 @@ void FemVTKTools::writeResult(const char* filename, const App::DocumentObject* r
FemVTKTools::exportVTKMesh(&fmesh, grid);
Base::Console().Log(" %f: vtk mesh builder finished\n",
Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
// result
FemVTKTools::exportFreeCADResult(res, grid);
@@ -719,7 +722,7 @@ void FemVTKTools::writeResult(const char* filename, const App::DocumentObject* r
}
Base::Console().Log(" %f: writing result object to vtk finished\n",
Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
Base::Console().Log("End: write FemResult to VTK unstructuredGrid dataset =======\n");
}

20
src/Mod/Fem/Gui/ViewProviderFemMesh.cpp
View File

@@ -796,7 +796,7 @@ void ViewProviderFEMMeshBuilder::createMesh(const App::Property* prop,
lines->coordIndex.setNum(0);
return;
}
Base::TimeInfo Start;
Base::TimeElapsed Start;
Base::Console().Log(
"Start: ViewProviderFEMMeshBuilder::createMesh() =================================\n");
@@ -834,7 +834,7 @@ void ViewProviderFEMMeshBuilder::createMesh(const App::Property* prop,
std::vector<FemFace> facesHelper(numTries);
Base::Console().Log(" %f: Start build up %i face helper\n",
Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()),
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()),
facesHelper.size());
Base::BoundBox3d BndBox;
@@ -1359,7 +1359,7 @@ void ViewProviderFEMMeshBuilder::createMesh(const App::Property* prop,
if (FaceSize < MaxFacesShowInner) {
Base::Console().Log(" %f: Start eliminate internal faces SIMPLE\n",
Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
// search for double (inside) faces and hide them
if (!ShowInner) {
@@ -1376,7 +1376,7 @@ void ViewProviderFEMMeshBuilder::createMesh(const App::Property* prop,
}
else {
Base::Console().Log(" %f: Start eliminate internal faces GRID\n",
Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
BndBox.Enlarge(BndBox.CalcDiagonalLength() / 10000.0);
// calculate grid properties
double edge = pow(FaceSize, 1.0 / 3.0);
@@ -1444,7 +1444,7 @@ void ViewProviderFEMMeshBuilder::createMesh(const App::Property* prop,
Base::Console().Log(" %f: Start build up node map\n",
Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
// sort out double nodes and build up index map
std::map<const SMDS_MeshNode*, int> mapNodeIndex;
@@ -1477,7 +1477,7 @@ void ViewProviderFEMMeshBuilder::createMesh(const App::Property* prop,
}
}
Base::Console().Log(" %f: Start set point vector\n",
Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
// set the point coordinates
coords->point.setNum(mapNodeIndex.size());
@@ -1495,7 +1495,7 @@ void ViewProviderFEMMeshBuilder::createMesh(const App::Property* prop,
// count triangle size
Base::Console().Log(" %f: Start count triangle size\n",
Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
int triangleCount = 0;
for (int l = 0; l < FaceSize; l++) {
if (!facesHelper[l].hide) {
@@ -1551,7 +1551,7 @@ void ViewProviderFEMMeshBuilder::createMesh(const App::Property* prop,
}
Base::Console().Log(" %f: Start build up triangle vector\n",
Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
// set the triangle face indices
faces->coordIndex.setNum(4 * triangleCount);
vFaceElementIdx.resize(triangleCount);
@@ -2971,7 +2971,7 @@ void ViewProviderFEMMeshBuilder::createMesh(const App::Property* prop,
faces->coordIndex.finishEditing();
Base::Console().Log(" %f: Start build up edge vector\n",
Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
// std::map<int,std::set<int> > EdgeMap;
// count edges
int EdgeSize = 0;
@@ -3000,7 +3000,7 @@ void ViewProviderFEMMeshBuilder::createMesh(const App::Property* prop,
Base::Console().Log(
" %f: Finish =========================================================\n",
Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
}

6
src/Mod/Fem/Gui/ViewProviderFemMeshPyImp.cpp
View File

@@ -186,7 +186,7 @@ void ViewProviderFemMeshPy::setNodeColor(Py::Dict arg)
this->getViewProviderFemMeshPtr()->resetColorByNodeId();
}
else {
Base::TimeInfo Start;
Base::TimeElapsed Start;
Base::Console().Log(
"Start: ViewProviderFemMeshPy::setNodeColor() =================================\n");
// std::map<long,App::Color> NodeColorMap;
@@ -209,12 +209,12 @@ void ViewProviderFemMeshPy::setNodeColor(Py::Dict arg)
App::Color(Py::Float(color[0]), Py::Float(color[1]), Py::Float(color[2]), 0);
}
Base::Console().Log(" %f: Start ViewProviderFemMeshPy::setNodeColor() call \n",
Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
// this->getViewProviderFemMeshPtr()->setColorByNodeId(NodeColorMap);
this->getViewProviderFemMeshPtr()->setColorByNodeId(NodeIds, NodeColors);
Base::Console().Log(" %f: Finish ViewProviderFemMeshPy::setNodeColor() call \n",
Base::TimeInfo::diffTimeF(Start, Base::TimeInfo()));
Base::TimeElapsed::diffTimeF(Start, Base::TimeElapsed()));
}
}

4
src/Mod/Part/Gui/TaskCheckGeometry.cpp
View File

@@ -678,13 +678,13 @@ int TaskCheckGeometryResults::goBOPSingleCheck(const TopoDS_Shape& shapeIn, Resu
BOPCheck.CurveOnSurfaceMode() = curveOnSurfaceMode;
#ifdef FC_DEBUG
Base::TimeInfo start_time;
Base::TimeElapsed start_time;
#endif
BOPCheck.Perform();
#ifdef FC_DEBUG
float bopAlgoTime = Base::TimeInfo::diffTimeF(start_time,Base::TimeInfo());
float bopAlgoTime = Base::TimeElapsed::diffTimeF(start_time, Base::TimeElapsed());
std::cout << std::endl << "BopAlgo check time is: " << bopAlgoTime << std::endl << std::endl;
#endif

4
src/Mod/Part/Gui/ViewProviderExt.cpp
View File

@@ -921,7 +921,7 @@ void ViewProviderPartExt::updateVisual()
}
// time measurement and book keeping
Base::TimeInfo start_time;
Base::TimeElapsed start_time;
int numTriangles=0,numNodes=0,numNorms=0,numFaces=0,numEdges=0,numLines=0;
std::set<int> faceEdges;
@@ -1281,7 +1281,7 @@ void ViewProviderPartExt::updateVisual()
# ifdef FC_DEBUG
// printing some information
Base::Console().Log("ViewProvider update time: %f s\n",Base::TimeInfo::diffTimeF(start_time,Base::TimeInfo()));
Base::Console().Log("ViewProvider update time: %f s\n",Base::TimeElapsed::diffTimeF(start_time,Base::TimeElapsed()));
Base::Console().Log("Shape tria info: Faces:%d Edges:%d Nodes:%d Triangles:%d IdxVec:%d\n",numFaces,numEdges,numNodes,numTriangles,numLines);
# else
(void)numEdges;

14
src/Mod/Sketcher/App/Sketch.cpp
View File

@@ -197,7 +197,7 @@ int Sketch::setUpSketch(const std::vector<Part::Geometry*>& GeoList,
const std::vector<Constraint*>& ConstraintList,
int extGeoCount)
{
Base::TimeInfo start_time;
Base::TimeElapsed start_time;
clear();
@@ -339,10 +339,10 @@ int Sketch::setUpSketch(const std::vector<Part::Geometry*>& GeoList,
calculateDependentParametersElements();
if (debugMode == GCS::Minimal || debugMode == GCS::IterationLevel) {
Base::TimeInfo end_time;
Base::TimeElapsed end_time;
Base::Console().Log("Sketcher::setUpSketch()-T:%s\n",
Base::TimeInfo::diffTime(start_time, end_time).c_str());
Base::TimeElapsed::diffTime(start_time, end_time).c_str());
}
return GCSsys.dofsNumber();
@@ -4538,21 +4538,21 @@ bool Sketch::updateNonDrivingConstraints()
int Sketch::solve()
{
Base::TimeInfo start_time;
Base::TimeElapsed start_time;
std::string solvername;
auto result = internalSolve(solvername);
Base::TimeInfo end_time;
Base::TimeElapsed end_time;
if (debugMode == GCS::Minimal || debugMode == GCS::IterationLevel) {
Base::Console().Log("Sketcher::Solve()-%s-T:%s\n",
solvername.c_str(),
Base::TimeInfo::diffTime(start_time, end_time).c_str());
Base::TimeElapsed::diffTime(start_time, end_time).c_str());
}
SolveTime = Base::TimeInfo::diffTimeF(start_time, end_time);
SolveTime = Base::TimeElapsed::diffTimeF(start_time, end_time);
return result;
}

12
src/Mod/Sketcher/App/planegcs/GCS.cpp
View File

@@ -5043,7 +5043,7 @@ int System::diagnose(Algorithm alg)
if (qrAlgorithm == EigenDenseQR) {
#ifdef PROFILE_DIAGNOSE
Base::TimeInfo DenseQR_start_time;
Base::TimeElapsed DenseQR_start_time;
#endif
if (J.rows() > 0) {
int rank = 0; // rank is not cheap to retrieve from qrJT in DenseQR
@@ -5101,9 +5101,9 @@ int System::diagnose(Algorithm alg)
}
}
#ifdef PROFILE_DIAGNOSE
Base::TimeInfo DenseQR_end_time;
Base::TimeElapsed DenseQR_end_time;
auto SolveTime = Base::TimeInfo::diffTimeF(DenseQR_start_time, DenseQR_end_time);
auto SolveTime = Base::TimeElapsed::diffTimeF(DenseQR_start_time, DenseQR_end_time);
Base::Console().Log("\nDenseQR - Lapsed Time: %f seconds\n", SolveTime);
#endif
@@ -5112,7 +5112,7 @@ int System::diagnose(Algorithm alg)
#ifdef EIGEN_SPARSEQR_COMPATIBLE
else if (qrAlgorithm == EigenSparseQR) {
#ifdef PROFILE_DIAGNOSE
Base::TimeInfo SparseQR_start_time;
Base::TimeElapsed SparseQR_start_time;
#endif
if (J.rows() > 0) {
int rank = 0;
@@ -5178,9 +5178,9 @@ int System::diagnose(Algorithm alg)
}
#ifdef PROFILE_DIAGNOSE
Base::TimeInfo SparseQR_end_time;
Base::TimeElapsed SparseQR_end_time;
auto SolveTime = Base::TimeInfo::diffTimeF(SparseQR_start_time, SparseQR_end_time);
auto SolveTime = Base::TimeElapsed::diffTimeF(SparseQR_start_time, SparseQR_end_time);
Base::Console().Log("\nSparseQR - Lapsed Time: %f seconds\n", SolveTime);
#endif