More tracing of the slicing process.

lib/Slic3r/Print.pm

@@ -42,7 +42,7 @@ sub size {
 sub process {
     my ($self) = @_;
     
-    $self->status_cb->(20, "Generating perimeters");
+    Slic3r::trace(3, "Staring the slicing process.");
     $_->make_perimeters for @{$self->objects};
     
     $self->status_cb->(70, "Infilling layers");
@@ -67,6 +67,7 @@ sub process {
         eval "use Slic3r::Test::SectionCut";
         Slic3r::Test::SectionCut->new(print => $self)->export_svg("section_cut.svg");
     }
+    Slic3r::trace(3, "Slicing process finished.")
 }
 
 sub export_gcode {

lib/Slic3r/Print/Object.pm

@@ -126,6 +126,8 @@ sub make_perimeters {
     
     # prerequisites
     $self->slice;
+
+    $self->print->status_cb->(20, "Generating perimeters");
     $self->_make_perimeters;
 }
 

xs/src/libslic3r/Layer.cpp

@@ -5,6 +5,8 @@
 #include "Fill/Fill.hpp"
 #include "SVG.hpp"
 
+#include <boost/log/trivial.hpp>
+
 namespace Slic3r {
 
 Layer::Layer(size_t id, PrintObject *object, coordf_t height, coordf_t print_z,
@@ -170,9 +172,7 @@ template bool Layer::any_bottom_region_slice_contains<Polyline>(const Polyline &
 void
 Layer::make_perimeters()
 {
-    #ifdef SLIC3R_DEBUG
-    printf("Making perimeters for layer " PRINTF_ZU "\n", this->id());
-    #endif
+    BOOST_LOG_TRIVIAL(trace) << "Generating perimeters for layer " << this->id();
     
     // keep track of regions whose perimeters we have already generated
     std::set<size_t> done;
@@ -180,6 +180,7 @@ Layer::make_perimeters()
     FOREACH_LAYERREGION(this, layerm) {
         size_t region_id = layerm - this->regions.begin();
         if (done.find(region_id) != done.end()) continue;
+        BOOST_LOG_TRIVIAL(trace) << "Generating perimeters for layer " << this->id() << ", region " << region_id;
         done.insert(region_id);
         const PrintRegionConfig &config = (*layerm)->region()->config;
         
@@ -237,6 +238,7 @@ Layer::make_perimeters()
             }
         }
     }
+    BOOST_LOG_TRIVIAL(trace) << "Generating perimeters for layer " << this->id() << " - Done";
 }
 
 void Layer::make_fills()

xs/src/libslic3r/PrintObject.cpp

@@ -363,7 +363,7 @@ void PrintObject::detect_surfaces_type()
     BOOST_LOG_TRIVIAL(info) << "Detecting solid surfaces...";
 
     for (int idx_region = 0; idx_region < this->_print->regions.size(); ++ idx_region) {
-        BOOST_LOG_TRIVIAL(trace) << "Detecting solid surfaces for region " << idx_region;
+        BOOST_LOG_TRIVIAL(debug) << "Detecting solid surfaces for region " << idx_region;
 #ifdef SLIC3R_DEBUG_SLICE_PROCESSING
         for (int idx_layer = 0; idx_layer < int(this->layer_count()); ++ idx_layer) {
             LayerRegion *layerm = this->layers[idx_layer]->get_region(idx_region);
@@ -825,8 +825,8 @@ PrintObject::discover_vertical_shells()
     } // for each region
 
     // Write the profiler measurements to file
-    PROFILE_UPDATE();
-    PROFILE_OUTPUT(debug_out_path("discover_vertical_shells-profile.txt").c_str());
+//    PROFILE_UPDATE();
+//    PROFILE_OUTPUT(debug_out_path("discover_vertical_shells-profile.txt").c_str());
 }
 
 /* This method applies bridge flow to the first internal solid layer above
@@ -1143,7 +1143,7 @@ end:
 
 std::vector<ExPolygons> PrintObject::_slice_region(size_t region_id, const std::vector<float> &z, bool modifier)
 {
-    BOOST_LOG_TRIVIAL(trace) << "Slicing region " << region_id;
+    BOOST_LOG_TRIVIAL(debug) << "Slicing region " << region_id;
 
     std::vector<ExPolygons> layers;
     assert(region_id < this->region_volumes.size());
@@ -1197,7 +1197,6 @@ PrintObject::_make_perimeters()
     // hollow objects
     FOREACH_REGION(this->_print, region_it) {
         size_t region_id = region_it - this->_print->regions.begin();
-        BOOST_LOG_TRIVIAL(trace) << "Generating perimeters for region " << region_id;
         const PrintRegion &region = **region_it;
         
         
@@ -1206,6 +1205,7 @@ PrintObject::_make_perimeters()
             || region.config.fill_density == 0
             || this->layer_count() < 2) continue;
         
+        BOOST_LOG_TRIVIAL(debug) << "Generating extra perimeters for region " << region_id;
         for (size_t i = 0; i < this->layer_count() - 1; ++ i) {
             LayerRegion &layerm                     = *this->get_layer(i)->get_region(region_id);
             const LayerRegion &upper_layerm         = *this->get_layer(i+1)->get_region(region_id);
@@ -1267,6 +1267,7 @@ PrintObject::_make_perimeters()
         }
     }
     
+    BOOST_LOG_TRIVIAL(debug) << "Generating perimeters in parallel";
     parallelize<Layer*>(
         std::queue<Layer*>(std::deque<Layer*>(this->layers.begin(), this->layers.end())),  // cast LayerPtrs to std::queue<Layer*>
         boost::bind(&Slic3r::Layer::make_perimeters, _1),
@@ -1289,6 +1290,7 @@ PrintObject::_infill()
     if (this->state.is_done(posInfill)) return;
     this->state.set_started(posInfill);
     
+    BOOST_LOG_TRIVIAL(debug) << "Filling layers in parallel";
     parallelize<Layer*>(
         std::queue<Layer*>(std::deque<Layer*>(this->layers.begin(), this->layers.end())),  // cast LayerPtrs to std::queue<Layer*>
         boost::bind(&Slic3r::Layer::make_fills, _1),

xs/src/libslic3r/TriangleMesh.cpp

@@ -12,6 +12,8 @@
 #include <algorithm>
 #include <math.h>
 
+#include <boost/log/trivial.hpp>
+
 #if 0
     #define DEBUG
     #define _DEBUG
@@ -543,6 +545,7 @@ TriangleMesh::require_shared_vertices()
 TriangleMeshSlicer::TriangleMeshSlicer(TriangleMesh* _mesh) : 
     mesh(_mesh)
 {
+    BOOST_LOG_TRIVIAL(trace) << "TriangleMeshSlicer::constructor";
     _mesh->require_shared_vertices();
     facets_edges.assign(_mesh->stl.stats.number_of_facets * 3, -1);
     v_scaled_shared.assign(_mesh->stl.v_shared, _mesh->stl.v_shared + _mesh->stl.stats.shared_vertices);
@@ -593,6 +596,8 @@ TriangleMeshSlicer::TriangleMeshSlicer(TriangleMesh* _mesh) :
 void
 TriangleMeshSlicer::slice(const std::vector<float> &z, std::vector<Polygons>* layers) const
 {
+    BOOST_LOG_TRIVIAL(trace) << "TriangleMeshSlicer::slice";
+
     /*
        This method gets called with a list of unscaled Z coordinates and outputs
        a vector pointer having the same number of items as the original list.
@@ -620,6 +625,7 @@ TriangleMeshSlicer::slice(const std::vector<float> &z, std::vector<Polygons>* la
         type is float.
     */
     
+    BOOST_LOG_TRIVIAL(trace) << "TriangleMeshSlicer::_slice_do";
     std::vector<IntersectionLines> lines(z.size());
     {
         boost::mutex lines_mutex;
@@ -633,12 +639,14 @@ TriangleMeshSlicer::slice(const std::vector<float> &z, std::vector<Polygons>* la
     // v_scaled_shared could be freed here
     
     // build loops
+    BOOST_LOG_TRIVIAL(trace) << "TriangleMeshSlicer::_make_loops_do";
     layers->resize(z.size());
     parallelize<size_t>(
         0,
         lines.size()-1,
         boost::bind(&TriangleMeshSlicer::_make_loops_do, this, _1, &lines, layers)
     );
+    BOOST_LOG_TRIVIAL(trace) << "TriangleMeshSlicer::slice finished";
 }
 
 void TriangleMeshSlicer::_slice_do(size_t facet_idx, std::vector<IntersectionLines>* lines, boost::mutex* lines_mutex, 

xs/src/libslic3r/Utils.hpp

@@ -4,6 +4,7 @@
 namespace Slic3r {
 
 extern void set_logging_level(unsigned int level);
+extern void trace(unsigned int level, const char *message);
 
 } // namespace Slic3r
 

xs/src/libslic3r/utils.cpp

@@ -9,11 +9,17 @@ static boost::log::trivial::severity_level logSeverity = boost::log::trivial::fa
 void set_logging_level(unsigned int level)
 {
     switch (level) {
+    // Report fatal errors only.
     case 0: logSeverity = boost::log::trivial::fatal; break;
+    // Report fatal errors and errors.
     case 1: logSeverity = boost::log::trivial::error; break;
+    // Report fatal errors, errors and warnings.
     case 2: logSeverity = boost::log::trivial::warning; break;
+    // Report all errors, warnings and infos.
     case 3: logSeverity = boost::log::trivial::info; break;
+    // Report all errors, warnings, infos and debugging.
     case 4: logSeverity = boost::log::trivial::debug; break;
+    // Report everyting including fine level tracing information.
     default: logSeverity = boost::log::trivial::trace; break;
     }
 
@@ -23,6 +29,28 @@ void set_logging_level(unsigned int level)
     );
 }
 
+void trace(unsigned int level, const char *message)
+{
+    boost::log::trivial::severity_level severity = boost::log::trivial::trace;
+    switch (level) {
+    // Report fatal errors only.
+    case 0: severity = boost::log::trivial::fatal; break;
+    // Report fatal errors and errors.
+    case 1: severity = boost::log::trivial::error; break;
+    // Report fatal errors, errors and warnings.
+    case 2: severity = boost::log::trivial::warning; break;
+    // Report all errors, warnings and infos.
+    case 3: severity = boost::log::trivial::info; break;
+    // Report all errors, warnings, infos and debugging.
+    case 4: severity = boost::log::trivial::debug; break;
+    // Report everyting including fine level tracing information.
+    default: severity = boost::log::trivial::trace; break;
+    }
+
+    BOOST_LOG_STREAM_WITH_PARAMS(::boost::log::trivial::logger::get(),\
+        (::boost::log::keywords::severity = severity)) << message;
+}
+
 } // namespace Slic3r
 
 #ifdef SLIC3R_HAS_BROKEN_CROAK

xs/xsp/XS.xsp

@@ -41,6 +41,13 @@ set_logging_level(level)
     CODE:
         Slic3r::set_logging_level(level);
 
+void
+trace(level, message)
+    unsigned int level;
+    char        *message;
+    CODE:
+        Slic3r::trace(level, message);
+
 void
 xspp_test_croak_hangs_on_strawberry()
     CODE: