Logging of memory allocations on Windows during the slicing process

when the SLIC3R_LOGLEVEL >= info.

src/libslic3r/CMakeLists.txt

@@ -194,6 +194,10 @@ target_link_libraries(libslic3r
     tbb
     )
 
+if(WIN32)
+    target_link_libraries(libslic3r Psapi.lib)
+endif()
+
 if(SLIC3R_PROFILE)
     target_link_libraries(slic3r Shiny)
 endif()

src/libslic3r/GCode.cpp

@@ -423,7 +423,7 @@ void GCode::do_export(Print *print, const char *path, GCodePreviewData *preview_
 
 	print->set_started(psGCodeExport);
 
-    BOOST_LOG_TRIVIAL(info) << "Exporting G-code...";
+    BOOST_LOG_TRIVIAL(info) << "Exporting G-code..." << log_memory_info();
 
     // Remove the old g-code if it exists.
     boost::nowide::remove(path);
@@ -480,7 +480,7 @@ void GCode::do_export(Print *print, const char *path, GCodePreviewData *preview_
             std::string("Failed to rename the output G-code file from ") + path_tmp + " to " + path + '\n' +
             "Is " + path_tmp + " locked?" + '\n');
 
-    BOOST_LOG_TRIVIAL(info) << "Exporting G-code finished";
+    BOOST_LOG_TRIVIAL(info) << "Exporting G-code finished" << log_memory_info();
 	print->set_done(psGCodeExport);
 
     // Write the profiler measurements to file

src/libslic3r/Print.cpp

@@ -8,13 +8,14 @@
 #include "SupportMaterial.hpp"
 #include "GCode.hpp"
 #include "GCode/WipeTowerPrusaMM.hpp"
-#include <algorithm>
+#include "Utils.hpp"
-#include <unordered_set>
-#include <boost/log/trivial.hpp>
 
 #include "PrintExport.hpp"
 
+#include <algorithm>
+#include <unordered_set>
 #include <boost/filesystem/path.hpp>
+#include <boost/log/trivial.hpp>
 
 //! macro used to mark string used at localization, 
 //! return same string
@@ -1475,7 +1476,7 @@ void Print::auto_assign_extruders(ModelObject* model_object) const
 // Slicing process, running at a background thread.
 void Print::process()
 {
-    BOOST_LOG_TRIVIAL(info) << "Staring the slicing process.";
+    BOOST_LOG_TRIVIAL(info) << "Staring the slicing process." << log_memory_info();
     for (PrintObject *obj : m_objects)
         obj->make_perimeters();
     this->set_status(70, "Infilling layers");
@@ -1507,7 +1508,7 @@ void Print::process()
         }
        this->set_done(psWipeTower);
     }
-    BOOST_LOG_TRIVIAL(info) << "Slicing process finished.";
+    BOOST_LOG_TRIVIAL(info) << "Slicing process finished." << log_memory_info();
 }
 
 // G-code export process, running at a background thread.

src/libslic3r/PrintObject.cpp

@@ -5,6 +5,7 @@
 #include "SupportMaterial.hpp"
 #include "Surface.hpp"
 #include "Slicing.hpp"
+#include "Utils.hpp"
 
 #include <utility>
 #include <boost/log/trivial.hpp>
@@ -132,7 +133,7 @@ void PrintObject::make_perimeters()
         return;
 
     m_print->set_status(20, "Generating perimeters");
-    BOOST_LOG_TRIVIAL(info) << "Generating perimeters...";
+    BOOST_LOG_TRIVIAL(info) << "Generating perimeters..." << log_memory_info();
     
     // merge slices if they were split into types
     if (this->typed_slices) {
@@ -253,7 +254,7 @@ void PrintObject::prepare_infill()
     // Decide what surfaces are to be filled.
     // Here the S_TYPE_TOP / S_TYPE_BOTTOMBRIDGE / S_TYPE_BOTTOM infill is turned to just S_TYPE_INTERNAL if zero top / bottom infill layers are configured.
     // Also tiny S_TYPE_INTERNAL surfaces are turned to S_TYPE_INTERNAL_SOLID.
-    BOOST_LOG_TRIVIAL(info) << "Preparing fill surfaces...";
+    BOOST_LOG_TRIVIAL(info) << "Preparing fill surfaces..." << log_memory_info();
     for (auto *layer : m_layers)
         for (auto *region : layer->m_regions) {
             region->prepare_fill_surfaces();
@@ -601,7 +602,7 @@ bool PrintObject::has_support_material() const
 // If a part of a region is of stBottom and stTop, the stBottom wins.
 void PrintObject::detect_surfaces_type()
 {
-    BOOST_LOG_TRIVIAL(info) << "Detecting solid surfaces...";
+    BOOST_LOG_TRIVIAL(info) << "Detecting solid surfaces..." << log_memory_info();
 
     // Interface shells: the intersecting parts are treated as self standing objects supporting each other.
     // Each of the objects will have a full number of top / bottom layers, even if these top / bottom layers
@@ -793,7 +794,7 @@ void PrintObject::detect_surfaces_type()
 
 void PrintObject::process_external_surfaces()
 {
-    BOOST_LOG_TRIVIAL(info) << "Processing external surfaces...";
+    BOOST_LOG_TRIVIAL(info) << "Processing external surfaces..." << log_memory_info();
 
 	for (size_t region_id = 0; region_id < this->region_volumes.size(); ++region_id) {
         const PrintRegion &region = *m_print->regions()[region_id];
@@ -818,7 +819,7 @@ void PrintObject::discover_vertical_shells()
 {
     PROFILE_FUNC();
 
-    BOOST_LOG_TRIVIAL(info) << "Discovering vertical shells...";
+    BOOST_LOG_TRIVIAL(info) << "Discovering vertical shells..." << log_memory_info();
 
     struct DiscoverVerticalShellsCacheEntry
     {
@@ -1202,7 +1203,7 @@ void PrintObject::discover_vertical_shells()
    sparse infill */
 void PrintObject::bridge_over_infill()
 {
-    BOOST_LOG_TRIVIAL(info) << "Bridge over infill...";
+    BOOST_LOG_TRIVIAL(info) << "Bridge over infill..." << log_memory_info();
 
     for (size_t region_id = 0; region_id < this->region_volumes.size(); ++ region_id) {
         const PrintRegion &region = *m_print->regions()[region_id];
@@ -1387,7 +1388,7 @@ bool PrintObject::update_layer_height_profile()
 // this should be idempotent
 void PrintObject::_slice()
 {
-    BOOST_LOG_TRIVIAL(info) << "Slicing objects...";
+    BOOST_LOG_TRIVIAL(info) << "Slicing objects..." << log_memory_info();
 
     this->typed_slices = false;
 
@@ -1709,7 +1710,7 @@ void PrintObject::_make_perimeters()
     if (! this->set_started(posPerimeters))
         return;
 
-    BOOST_LOG_TRIVIAL(info) << "Generating perimeters...";
+    BOOST_LOG_TRIVIAL(info) << "Generating perimeters..." << log_memory_info();
     
     // merge slices if they were split into types
     if (this->typed_slices) {

src/libslic3r/Utils.hpp

@@ -12,6 +12,9 @@ namespace Slic3r {
 
 extern void set_logging_level(unsigned int level);
 extern void trace(unsigned int level, const char *message);
+// Return string to be added to the boost::log output to inform about the current process memory allocation.
+// The string is non-empty only if the loglevel >= info (3).
+extern std::string log_memory_info();
 extern void disable_multi_threading();
 
 // Set a path with GUI resource files.

src/libslic3r/utils.cpp

@@ -8,6 +8,7 @@
 
 #ifdef WIN32
 #include <windows.h>
+#include <psapi.h>
 #else
 #include <unistd.h>
 #endif
@@ -365,4 +366,66 @@ std::string xml_escape(std::string text)
     return text;
 }
 
+#ifdef WIN32
+
+#ifndef PROCESS_MEMORY_COUNTERS_EX
+    // MingW32 doesn't have this struct in psapi.h
+    typedef struct _PROCESS_MEMORY_COUNTERS_EX {
+      DWORD  cb;
+      DWORD  PageFaultCount;
+      SIZE_T PeakWorkingSetSize;
+      SIZE_T WorkingSetSize;
+      SIZE_T QuotaPeakPagedPoolUsage;
+      SIZE_T QuotaPagedPoolUsage;
+      SIZE_T QuotaPeakNonPagedPoolUsage;
+      SIZE_T QuotaNonPagedPoolUsage;
+      SIZE_T PagefileUsage;
+      SIZE_T PeakPagefileUsage;
+      SIZE_T PrivateUsage;
+    } PROCESS_MEMORY_COUNTERS_EX, *PPROCESS_MEMORY_COUNTERS_EX;
+#endif /* PROCESS_MEMORY_COUNTERS_EX */
+
+std::string format_memsize_MB(size_t n) 
+{
+	std::string out;
+	size_t n2 = 0;
+	size_t scale = 1;
+	// Round to MB
+	n +=  500000;
+	n /= 1000000;
+	while (n >= 1000) {
+		n2 = n2 + scale * (n % 1000);
+		n /= 1000;
+		scale *= 1000;
+	}
+	char buf[8];
+	sprintf(buf, "%d", n);
+	out = buf;
+	while (scale != 1) {
+		scale /= 1000;
+		n = n2 / scale;
+		n2 = n2  % scale;
+		sprintf(buf, ",%03d", n);
+		out += buf;
+	}
+	return out + "MB";
+}
+
+std::string log_memory_info()
+{
+    std::string out;
+    if (logSeverity <= boost::log::trivial::info) {
+        HANDLE hProcess = ::OpenProcess(PROCESS_QUERY_INFORMATION | PROCESS_VM_READ, FALSE, ::GetCurrentProcessId());
+        if (hProcess != nullptr) {
+            PROCESS_MEMORY_COUNTERS_EX pmc;
+            if (GetProcessMemoryInfo(hProcess, (PROCESS_MEMORY_COUNTERS*)&pmc, sizeof(pmc)))
+				out = " WorkingSet: " + format_memsize_MB(pmc.WorkingSetSize) + " PrivateBytes: " + format_memsize_MB(pmc.PrivateUsage) + " Pagefile(peak): " + format_memsize_MB(pmc.PagefileUsage) + "(" + format_memsize_MB(pmc.PeakPagefileUsage) + ")";
+            CloseHandle(hProcess);
+        }
+    }
+    return out;
+}
+
+#endif
+
 }; // namespace Slic3r