From 13a059ec1b33d7a920a3d41c477659b413511f92 Mon Sep 17 00:00:00 2001 From: Erwan MATHIEU Date: Thu, 2 Nov 2023 16:49:22 +0100 Subject: [PATCH] Detailed timing logging for layer export CURA-11255 --- include/FffGcodeWriter.h | 11 +++++-- include/LayerPlanBuffer.h | 9 +++--- include/progress/Progress.h | 46 ++++++++++++++------------ include/utils/gettime.h | 61 ++++++++++++++--------------------- src/FffGcodeWriter.cpp | 42 ++++++++++++++++-------- src/MeshGroup.cpp | 15 ++++++--- src/Scene.cpp | 13 +++++--- src/progress/Progress.cpp | 64 ++++++++++++++++++++++--------------- src/slicer.cpp | 18 +++++------ src/utils/gettime.cpp | 24 ++++++++++---- 10 files changed, 175 insertions(+), 128 deletions(-) diff --git a/include/FffGcodeWriter.h b/include/FffGcodeWriter.h index 7e5908e136..d63547692e 100644 --- a/include/FffGcodeWriter.h +++ b/include/FffGcodeWriter.h @@ -14,6 +14,7 @@ #include "settings/PathConfigStorage.h" //For the MeshPathConfigs subclass. #include "utils/ExtrusionLine.h" //Processing variable-width paths. #include "utils/NoCopy.h" +#include "utils/gettime.h" namespace cura { @@ -25,7 +26,6 @@ class SliceDataStorage; class SliceMeshStorage; class SliceLayer; class SliceLayerPart; -class TimeKeeper; /*! * Secondary stage in Fused Filament Fabrication processing: The generated polygons are used in the gcode generation. @@ -139,6 +139,13 @@ class FffGcodeWriter : public NoCopy void writeGCode(SliceDataStorage& storage, TimeKeeper& timeKeeper); private: + struct ProcessLayerResult + { + LayerPlan* layer_plan; + double total_elapsed_time; + TimeKeeper::RegisteredTimes stages_times; + }; + /*! * \brief Set the FffGcodeWriter::fan_speed_layer_time_settings by * retrieving all settings from the global/per-meshgroup settings. @@ -210,7 +217,7 @@ class FffGcodeWriter : public NoCopy * \param total_layers The total number of layers. * \return The layer plans */ - LayerPlan& processLayer(const SliceDataStorage& storage, LayerIndex layer_nr, const size_t total_layers) const; + ProcessLayerResult processLayer(const SliceDataStorage& storage, LayerIndex layer_nr, const size_t total_layers) const; /*! * This function checks whether prime blob should happen for any extruder on the first layer. diff --git a/include/LayerPlanBuffer.h b/include/LayerPlanBuffer.h index 8898137b87..2b1ce8cefc 100644 --- a/include/LayerPlanBuffer.h +++ b/include/LayerPlanBuffer.h @@ -4,6 +4,9 @@ #ifndef LAYER_PLAN_BUFFER_H #define LAYER_PLAN_BUFFER_H +#include +#include + #include "ExtruderPlan.h" #include "LayerPlan.h" #include "Preheat.h" @@ -11,9 +14,6 @@ #include "settings/Settings.h" #include "settings/types/Duration.h" -#include -#include - namespace cura { @@ -36,7 +36,6 @@ class GCodeExport; class LayerPlanBuffer { friend class LayerPlan; - friend class LayerPlanBuffer; GCodeExport& gcode; Preheat preheat_config; //!< the nozzle and material temperature settings for each extruder train. @@ -215,4 +214,4 @@ class LayerPlanBuffer } // namespace cura -#endif // LAYER_PLAN_BUFFER_H \ No newline at end of file +#endif // LAYER_PLAN_BUFFER_H diff --git a/include/progress/Progress.h b/include/progress/Progress.h index 6b9c83d532..4a513d94a2 100644 --- a/include/progress/Progress.h +++ b/include/progress/Progress.h @@ -1,58 +1,62 @@ -//Copyright (c) 2018 Ultimaker B.V. -//CuraEngine is released under the terms of the AGPLv3 or higher. +// Copyright (c) 2018 Ultimaker B.V. +// CuraEngine is released under the terms of the AGPLv3 or higher. #ifndef PROGRESS_H #define PROGRESS_H #include +#include "utils/gettime.h" + namespace cura { -class TimeKeeper; +struct LayerIndex; #define N_PROGRESS_STAGES 7 /*! * Class for handling the progress bar and the progress logging. - * + * * The progress bar is based on a single slicing of a rather large model which needs some complex support; * the relative timing of each stage is currently based on that of the slicing of dragon_65_tilted_large.stl */ -class Progress +class Progress { public: /*! - * The stage in the whole slicing process + * The stage in the whole slicing process */ enum class Stage : unsigned int { - START = 0, - SLICING = 1, - PARTS = 2, - INSET_SKIN = 3, - SUPPORT = 4, - EXPORT = 5, - FINISH = 6 + START = 0, + SLICING = 1, + PARTS = 2, + INSET_SKIN = 3, + SUPPORT = 4, + EXPORT = 5, + FINISH = 6 }; + private: - static double times [N_PROGRESS_STAGES]; //!< Time estimates per stage + static double times[N_PROGRESS_STAGES]; //!< Time estimates per stage static std::string names[N_PROGRESS_STAGES]; //!< name of each stage - static double accumulated_times [N_PROGRESS_STAGES]; //!< Time past before each stage + static double accumulated_times[N_PROGRESS_STAGES]; //!< Time past before each stage static double total_timing; //!< An estimate of the total time /*! * Give an estimate between 0 and 1 of how far the process is. - * + * * \param stage The current stage of processing * \param stage_process How far we currently are in the \p stage * \return An estimate of the overall progress. */ static float calcOverallProgress(Stage stage, float stage_progress); + public: static void init(); //!< Initialize some values needed in a fast computation of the progress /*! * Message progress over the CommandSocket and to the terminal (if the command line arg '-p' is provided). - * + * * \param stage The current stage of processing * \param progress_in_stage Any number giving the progress within the stage * \param progress_in_stage_max The maximal value of \p progress_in_stage @@ -60,13 +64,15 @@ class Progress static void messageProgress(Stage stage, int progress_in_stage, int progress_in_stage_max); /*! * Message the progress stage over the command socket. - * + * * \param stage The current stage * \param timeKeeper The stapwatch keeping track of the timings for each stage (optional) */ static void messageProgressStage(Stage stage, TimeKeeper* timeKeeper); + + static void messageProgressLayer(LayerIndex layer_nr, size_t total_layers, double total_time, const TimeKeeper::RegisteredTimes& stages); }; -} // name space cura -#endif//PROGRESS_H +} // namespace cura +#endif // PROGRESS_H diff --git a/include/utils/gettime.h b/include/utils/gettime.h index 319f5d750c..0f011360ad 100644 --- a/include/utils/gettime.h +++ b/include/utils/gettime.h @@ -4,55 +4,42 @@ #ifndef GETTIME_H #define GETTIME_H -#ifdef _WIN32 -#define WIN32_LEAN_AND_MEAN 1 -#include -#else -#ifdef USE_CPU_TIME -#include -#endif - -#include -#include -#include -#endif +#include +#include +#include + +#include namespace cura { -static inline double getTime() -{ -#ifdef _WIN32 - return double(GetTickCount()) / 1000.0; -#else // not __WIN32 -#if USE_CPU_TIME // Use cpu usage time if available, otherwise wall clock time - struct rusage usage; -#ifdef DEBUG - int ret = getrusage(RUSAGE_SELF, &usage); - assert(ret == 0); - ((void)ret); -#else - getrusage(RUSAGE_SELF, &usage); -#endif - double user_time = double(usage.ru_utime.tv_sec) + double(usage.ru_utime.tv_usec) / 1000000.0; - double sys_time = double(usage.ru_stime.tv_sec) + double(usage.ru_stime.tv_usec) / 1000000.0; - return user_time + sys_time; -#else // not USE_CPU_TIME - struct timeval tv; - gettimeofday(&tv, nullptr); - return double(tv.tv_sec) + double(tv.tv_usec) / 1000000.0; -#endif // USE_CPU_TIME -#endif // __WIN32 -} class TimeKeeper { +public: + struct RegisteredTime + { + std::string stage; + double duration; + }; + + using RegisteredTimes = std::vector; + private: - double startTime; + spdlog::stopwatch watch; + double start_time; + RegisteredTimes registered_times; public: TimeKeeper(); double restart(); + + void registerTime(const std::string& stage, double threshold = 0.01); + + const RegisteredTimes& getRegisteredTimes() const + { + return registered_times; + } }; } // namespace cura diff --git a/src/FffGcodeWriter.cpp b/src/FffGcodeWriter.cpp index b99161c1a2..a42d12889d 100644 --- a/src/FffGcodeWriter.cpp +++ b/src/FffGcodeWriter.cpp @@ -7,6 +7,7 @@ #include // numeric_limits #include #include +#include #include #include @@ -168,15 +169,15 @@ void FffGcodeWriter::writeGCode(SliceDataStorage& storage, TimeKeeper& time_keep total_layers, [&storage, total_layers, this](int layer_nr) { - return &processLayer(storage, layer_nr, total_layers); + return std::make_optional(processLayer(storage, layer_nr, total_layers)); }, - [this, total_layers](LayerPlan* gcode_layer) + [this, total_layers](std::optional result_opt) { - Progress::messageProgress(Progress::Stage::EXPORT, std::max(LayerIndex{ 0 }, gcode_layer->getLayerNr()) + 1, total_layers); - layer_plan_buffer.handle(*gcode_layer, gcode); + const ProcessLayerResult& result = result_opt.value(); + Progress::messageProgressLayer(result.layer_plan->getLayerNr(), total_layers, result.total_elapsed_time, result.stages_times); + layer_plan_buffer.handle(*result.layer_plan, gcode); }); - layer_plan_buffer.flush(); Progress::messageProgressStage(Progress::Stage::FINISH, &time_keeper); @@ -945,9 +946,11 @@ void FffGcodeWriter::processRaft(const SliceDataStorage& storage) } } -LayerPlan& FffGcodeWriter::processLayer(const SliceDataStorage& storage, LayerIndex layer_nr, const size_t total_layers) const +FffGcodeWriter::ProcessLayerResult FffGcodeWriter::processLayer(const SliceDataStorage& storage, LayerIndex layer_nr, const size_t total_layers) const { spdlog::debug("GcodeWriter processing layer {} of {}", layer_nr, total_layers); + TimeKeeper time_keeper; + spdlog::stopwatch timer_total; const Settings& mesh_group_settings = Application::getInstance().current_slice->scene.current_mesh_group->settings; coord_t layer_thickness = mesh_group_settings.get("layer_height"); @@ -1032,6 +1035,7 @@ LayerPlan& FffGcodeWriter::processLayer(const SliceDataStorage& storage, LayerIn comb_offset_from_outlines, first_outer_wall_line_width, avoid_distance); + time_keeper.registerTime("Init"); if (include_helper_parts) { @@ -1040,11 +1044,15 @@ LayerPlan& FffGcodeWriter::processLayer(const SliceDataStorage& storage, LayerIn if (storage.skirt_brim[extruder_nr].size() > 0) { processSkirtBrim(storage, gcode_layer, extruder_nr, layer_nr); + time_keeper.registerTime("Skirt/brim"); } // handle shield(s) first in a layer so that chances are higher that the other nozzle is wiped (for the ooze shield) processOozeShield(storage, gcode_layer); + time_keeper.registerTime("Ooze shield"); + processDraftShield(storage, gcode_layer); + time_keeper.registerTime("Draft shield"); } const size_t support_roof_extruder_nr = mesh_group_settings.get("support_roof_extruder_nr").extruder_nr; @@ -1065,10 +1073,12 @@ LayerPlan& FffGcodeWriter::processLayer(const SliceDataStorage& storage, LayerIn if (extruder_nr != extruder_order.front() || (extruder_order.size() == 1 && layer_nr >= 0) || extruder_nr == 0) { setExtruder_addPrime(storage, gcode_layer, extruder_nr); + time_keeper.registerTime("Prime tower pre"); } if (include_helper_parts && (extruder_nr == support_infill_extruder_nr || extruder_nr == support_roof_extruder_nr || extruder_nr == support_bottom_extruder_nr)) { addSupportToGCode(storage, gcode_layer, extruder_nr); + time_keeper.registerTime("Supports"); } if (layer_nr >= 0) { @@ -1088,6 +1098,7 @@ LayerPlan& FffGcodeWriter::processLayer(const SliceDataStorage& storage, LayerIn { addMeshLayerToGCode(storage, mesh, extruder_nr, mesh_config, gcode_layer); } + time_keeper.registerTime(fmt::format("Mesh {}", mesh_idx)); } } // Always print a prime tower before switching extruder. Unless: @@ -1096,12 +1107,17 @@ LayerPlan& FffGcodeWriter::processLayer(const SliceDataStorage& storage, LayerIn if (extruder_nr != extruder_order.back() && layer_nr >= 0) { setExtruder_addPrime(storage, gcode_layer, extruder_nr); + time_keeper.registerTime("Prime tower post"); } } gcode_layer.applyModifyPlugin(); + time_keeper.registerTime("Modify plugin"); + gcode_layer.applyBackPressureCompensation(); - return gcode_layer; + time_keeper.registerTime("Back pressure comp."); + + return { &gcode_layer, timer_total.elapsed().count(), time_keeper.getRegisteredTimes() }; } bool FffGcodeWriter::getExtruderNeedPrimeBlobDuringFirstLayer(const SliceDataStorage& storage, const size_t extruder_nr) const @@ -2036,8 +2052,8 @@ bool FffGcodeWriter::processSingleLayerInfill( else // So walls_generated must be true. { std::vector* start_paths = &wall_tool_paths[rand() % wall_tool_paths.size()]; - while (start_paths->empty() || (*start_paths)[0].empty()) // We know for sure (because walls_generated) that one of them is not empty. So randomise until we hit it. - // Should almost always be very quick. + while (start_paths->empty() || (*start_paths)[0].empty()) // We know for sure (because walls_generated) that one of them is not empty. So randomise until we hit + // it. Should almost always be very quick. { start_paths = &wall_tool_paths[rand() % wall_tool_paths.size()]; } @@ -2169,8 +2185,8 @@ bool FffGcodeWriter::partitionInfillBySkinAbove( } else // this layer is the 1st layer above the layer whose infill we're printing { - // add this layer's skin region without subtracting the overlap but still make a gap between this skin region and what has been accumulated so far - // we do this so that these skin region edges will definitely have infill walls below them + // add this layer's skin region without subtracting the overlap but still make a gap between this skin region and what has been accumulated so + // far we do this so that these skin region edges will definitely have infill walls below them // looking from the side, if the combined regions so far look like this... // @@ -2201,8 +2217,8 @@ bool FffGcodeWriter::partitionInfillBySkinAbove( } } - // the shrink/expand here is to remove regions of infill below skin that are narrower than the width of the infill walls otherwise the infill walls could merge and form a - // bump + // the shrink/expand here is to remove regions of infill below skin that are narrower than the width of the infill walls otherwise the infill walls could merge and form + // a bump infill_below_skin = skin_above_combined.intersection(part.infill_area_per_combine_per_density.back().front()).offset(-infill_line_width).offset(infill_line_width); constexpr bool remove_small_holes_from_infill_below_skin = true; diff --git a/src/MeshGroup.cpp b/src/MeshGroup.cpp index 1516e64190..84ef4d4923 100644 --- a/src/MeshGroup.cpp +++ b/src/MeshGroup.cpp @@ -1,6 +1,8 @@ // Copyright (c) 2023 UltiMaker // CuraEngine is released under the terms of the AGPLv3 or higher +#include "MeshGroup.h" + #include #include #include @@ -10,7 +12,6 @@ #include #include -#include "MeshGroup.h" #include "settings/types/Ratio.h" //For the shrinkage percentage and scale factor. #include "utils/FMatrix4x3.h" //To transform the input meshes for shrinkage compensation and to align in command line mode. #include "utils/floatpoint.h" //To accept incoming meshes with floating point vertices. @@ -48,7 +49,8 @@ Point3 MeshGroup::min() const Point3 ret(std::numeric_limits::max(), std::numeric_limits::max(), std::numeric_limits::max()); for (const Mesh& mesh : meshes) { - if (mesh.settings.get("infill_mesh") || mesh.settings.get("cutting_mesh") || mesh.settings.get("anti_overhang_mesh")) // Don't count pieces that are not printed. + if (mesh.settings.get("infill_mesh") || mesh.settings.get("cutting_mesh") + || mesh.settings.get("anti_overhang_mesh")) // Don't count pieces that are not printed. { continue; } @@ -69,7 +71,8 @@ Point3 MeshGroup::max() const Point3 ret(std::numeric_limits::min(), std::numeric_limits::min(), std::numeric_limits::min()); for (const Mesh& mesh : meshes) { - if (mesh.settings.get("infill_mesh") || mesh.settings.get("cutting_mesh") || mesh.settings.get("anti_overhang_mesh")) // Don't count pieces that are not printed. + if (mesh.settings.get("infill_mesh") || mesh.settings.get("cutting_mesh") + || mesh.settings.get("anti_overhang_mesh")) // Don't count pieces that are not printed. { continue; } @@ -112,7 +115,9 @@ void MeshGroup::finalize() } mesh.translate(mesh_offset + meshgroup_offset); } - scaleFromBottom(settings.get("material_shrinkage_percentage_xy"), settings.get("material_shrinkage_percentage_z")); // Compensate for the shrinkage of the material. + scaleFromBottom( + settings.get("material_shrinkage_percentage_xy"), + settings.get("material_shrinkage_percentage_z")); // Compensate for the shrinkage of the material. for (const auto& [idx, mesh] : meshes | ranges::views::enumerate) { scripta::log(fmt::format("mesh_{}", idx), mesh, SectionType::NA); @@ -285,7 +290,7 @@ bool loadMeshIntoMeshGroup(MeshGroup* meshgroup, const char* filename, const FMa if (loadMeshSTL(&mesh, filename, transformation)) // Load it! If successful... { meshgroup->meshes.push_back(mesh); - spdlog::info("loading '{}' took {:3} seconds", filename, load_timer.restart()); + spdlog::info("loading '{}' took {:03.3f} seconds", filename, load_timer.restart()); return true; } } diff --git a/src/Scene.cpp b/src/Scene.cpp index ff4baf9adc..ac50185b6d 100644 --- a/src/Scene.cpp +++ b/src/Scene.cpp @@ -1,11 +1,12 @@ // Copyright (c) 2023 UltiMaker // CuraEngine is released under the terms of the AGPLv3 or higher +#include "Scene.h" + #include #include "Application.h" #include "FffProcessor.h" //To start a slice. -#include "Scene.h" #include "communication/Communication.h" //To flush g-code and layer view when we're done. #include "progress/Progress.h" #include "sliceDataStorage.h" @@ -13,7 +14,9 @@ namespace cura { -Scene::Scene(const size_t num_mesh_groups) : mesh_groups(num_mesh_groups), current_mesh_group(mesh_groups.begin()) +Scene::Scene(const size_t num_mesh_groups) + : mesh_groups(num_mesh_groups) + , current_mesh_group(mesh_groups.begin()) { for (MeshGroup& mesh_group : mesh_groups) { @@ -78,7 +81,7 @@ void Scene::processMeshGroup(MeshGroup& mesh_group) if (empty) { Progress::messageProgress(Progress::Stage::FINISH, 1, 1); // 100% on this meshgroup - spdlog::info("Total time elapsed {:3}s.", time_keeper_total.restart()); + spdlog::info("Total time elapsed {:03.3f}s", time_keeper_total.restart()); return; } @@ -94,7 +97,7 @@ void Scene::processMeshGroup(MeshGroup& mesh_group) Progress::messageProgress(Progress::Stage::FINISH, 1, 1); // 100% on this meshgroup Application::getInstance().communication->flushGCode(); Application::getInstance().communication->sendOptimizedLayerData(); - spdlog::info("Total time elapsed {:3}s.\n", time_keeper_total.restart()); + spdlog::info("Total time elapsed {:03.3f}s\n", time_keeper_total.restart()); } -} // namespace cura \ No newline at end of file +} // namespace cura diff --git a/src/progress/Progress.cpp b/src/progress/Progress.cpp index 62687044c6..fb3331bc02 100644 --- a/src/progress/Progress.cpp +++ b/src/progress/Progress.cpp @@ -1,49 +1,40 @@ // Copyright (c) 2022 Ultimaker B.V. // CuraEngine is released under the terms of the AGPLv3 or higher +#include "progress/Progress.h" + #include #include #include "Application.h" //To get the communication channel to send progress through. #include "communication/Communication.h" //To send progress through the communication channel. -#include "progress/Progress.h" #include "utils/gettime.h" namespace cura { double Progress::times[] = { - 0.0, // START = 0, - 5.269, // SLICING = 1, - 1.533, // PARTS = 2, + 0.0, // START = 0, + 5.269, // SLICING = 1, + 1.533, // PARTS = 2, 71.811, // INSET_SKIN = 3 - 51.009, // SUPPORT = 4, - 154.62, // EXPORT = 5, - 0.1 // FINISH = 6 -}; -std::string Progress::names [] = -{ - "start", - "slice", - "layerparts", - "inset+skin", - "support", - "export", - "process" + 51.009, // SUPPORT = 4, + 154.62, // EXPORT = 5, + 0.1 // FINISH = 6 }; +std::string Progress::names[] = { "start", "slice", "layerparts", "inset+skin", "support", "export", "process" }; -double Progress::accumulated_times [N_PROGRESS_STAGES] = {-1}; +double Progress::accumulated_times[N_PROGRESS_STAGES] = { -1 }; double Progress::total_timing = -1; float Progress::calcOverallProgress(Stage stage, float stage_progress) { assert(stage_progress <= 1.0); assert(stage_progress >= 0.0); - return ( accumulated_times[(int)stage] + stage_progress * times[(int)stage] ) / total_timing; + return (accumulated_times[(int)stage] + stage_progress * times[(int)stage]) / total_timing; } - void Progress::init() { double accumulated_time = 0; @@ -59,8 +50,6 @@ void Progress::messageProgress(Progress::Stage stage, int progress_in_stage, int { float percentage = calcOverallProgress(stage, float(progress_in_stage) / float(progress_in_stage_max)); Application::getInstance().communication->sendProgress(percentage); - - // logProgress(names[(int)stage].c_str(), progress_in_stage, progress_in_stage_max, percentage); FIXME: use different sink } void Progress::messageProgressStage(Progress::Stage stage, TimeKeeper* time_keeper) @@ -69,13 +58,13 @@ void Progress::messageProgressStage(Progress::Stage stage, TimeKeeper* time_keep { if ((int)stage > 0) { - spdlog::info("Progress: {} accomplished in {:3}s", names[(int)stage - 1], time_keeper->restart()); + spdlog::info("Progress: {} accomplished in {:03.3f}s", names[(int)stage - 1], time_keeper->restart()); } else { time_keeper->restart(); } - + if ((int)stage < (int)Stage::FINISH) { spdlog::info("Starting {}...", names[(int)stage]); @@ -83,4 +72,29 @@ void Progress::messageProgressStage(Progress::Stage stage, TimeKeeper* time_keep } } -}// namespace cura \ No newline at end of file +void Progress::messageProgressLayer(LayerIndex layer_nr, size_t total_layers, double total_time, const TimeKeeper::RegisteredTimes& stages) +{ + messageProgress(Stage::EXPORT, std::max(layer_nr.value, LayerIndex::value_type(0)) + 1, total_layers); + + spdlog::info("+---- Layer export [{}] accomplished in {:03.3f}s", layer_nr.value, total_time); + + size_t padding = 0; + auto iterator_max_size = std::max_element( + stages.begin(), + stages.end(), + [](const TimeKeeper::RegisteredTime& time1, const TimeKeeper::RegisteredTime& time2) + { + return time1.stage.size() < time2.stage.size(); + }); + if (iterator_max_size != stages.end()) + { + padding = iterator_max_size->stage.size(); + + for (const TimeKeeper::RegisteredTime& time : stages) + { + spdlog::info("| *{}:{} {:03.3f}s", time.stage, std::string(padding - time.stage.size(), ' '), time.duration); + } + } +} + +} // namespace cura diff --git a/src/slicer.cpp b/src/slicer.cpp index 6b1ac7ea4d..f5127833bc 100644 --- a/src/slicer.cpp +++ b/src/slicer.cpp @@ -3,6 +3,13 @@ #include "slicer.h" +#include // remove_if +#include +#include + +#include +#include + #include "Application.h" #include "Slice.h" #include "plugins/slots.h" @@ -15,13 +22,6 @@ #include "utils/gettime.h" #include "utils/section_type.h" -#include -#include - -#include // remove_if -#include -#include - namespace cura { @@ -825,11 +825,11 @@ Slicer::Slicer(Mesh* i_mesh, const coord_t thickness, const size_t slice_layer_c buildSegments(*mesh, zbbox, slicing_tolerance, layers); - spdlog::info("Slice of mesh took {:3} seconds", slice_timer.restart()); + spdlog::info("Slice of mesh took {:03.3f} seconds", slice_timer.restart()); makePolygons(*i_mesh, slicing_tolerance, layers); scripta::log("sliced_polygons", layers, SectionType::NA); - spdlog::info("Make polygons took {:3} seconds", slice_timer.restart()); + spdlog::info("Make polygons took {:03.3f} seconds", slice_timer.restart()); } void Slicer::buildSegments(const Mesh& mesh, const std::vector>& zbbox, const SlicingTolerance& slicing_tolerance, std::vector& layers) diff --git a/src/utils/gettime.cpp b/src/utils/gettime.cpp index bfd665abaa..a7d8303857 100644 --- a/src/utils/gettime.cpp +++ b/src/utils/gettime.cpp @@ -1,21 +1,31 @@ -//Copyright (c) 2022 Ultimaker B.V. -//CuraEngine is released under the terms of the AGPLv3 or higher. +// Copyright (c) 2022 Ultimaker B.V. +// CuraEngine is released under the terms of the AGPLv3 or higher. #include "utils/gettime.h" +#include + namespace cura { - + TimeKeeper::TimeKeeper() { - restart(); } double TimeKeeper::restart() { - double ret = getTime() - startTime; - startTime = getTime(); + double ret = watch.elapsed().count(); + watch.reset(); return ret; } -}//namespace cura \ No newline at end of file +void TimeKeeper::registerTime(const std::string& stage, double threshold) +{ + double duration = restart(); + if (duration >= threshold) + { + registered_times.emplace_back(RegisteredTime{ stage, duration }); + } +} + +} // namespace cura