Add memory usage profiling feature
authorInki Dae <inki.dae@samsung.com>
Tue, 7 Apr 2020 06:21:53 +0000 (15:21 +0900)
committerInki Dae <inki.dae@samsung.com>
Tue, 14 Apr 2020 00:42:53 +0000 (09:42 +0900)
This patch adds memory usage profiling feature while in runtime.

Basially, there are some procfs to collect memory usage consumed
by current process, and we use /proc/self/stat.

These memory usage data are updated by Linux kernel scheduler so
they should be measured before and after current process.

As for this, this patch adds a new script file, start_profiler.sh.
SO if you want to profile exact memory usage in runtime then
run ./start_profiler.sh on Target.

Ps. the memory usage data can be measred by inference_engine_test app
but the data wouldn't be exact.

Change-Id: I5416587d4847c65538768b15f69f1e23862e2837
Signed-off-by: Inki Dae <inki.dae@samsung.com>
include/inference_engine_profiler.h
packaging/inference-engine-interface.spec
src/inference_engine_common_impl.cpp
src/inference_engine_profiler.cpp
start_profiler.sh [new file with mode: 0644]

index 134499c..d17b5d5 100644 (file)
@@ -84,7 +84,7 @@ typedef struct _ProfileEnv {
 } ProfileEnv;
 
 /**
- * @brief A structure of containg profiling data.
+ * @brief A structure of containg profiled elased time data.
  * @details This structure contains profiling data while in inference.
  *
  * @since_tizen 6.0
@@ -92,11 +92,22 @@ typedef struct _ProfileEnv {
 typedef struct _ProileData {
        unsigned int env_idx; /**< An index of v_mProfileEnv vector.*/
        std::string function_name; /**< A function name targetd to profile. */
-       size_t memory_usage; /**< memory size consumed by a given function. */
        unsigned int elapsed_time; /**< A latency to how long time a given function is performed. */
 } ProfileData;
 
 /**
+ * @brief A structure of containg profiled memory usage data.
+ * @details This structure contains profiling data while in inference.
+ *
+ * @since_tizen 6.0
+ */
+typedef struct _MemoryData {
+       long rss; /** A number of physical pages consumed by current process. */
+       long gpu_memory; /** A number of physical pages consumed by GPU device. */
+       // TODO.
+} MemoryData;
+
+/**
  * @brief A class of representing profiler.
  * @details This class interfaces will be called by InferenceEngineCommon class properly.
  *
@@ -165,7 +176,7 @@ public:
         * @param[in] env_idx A index to v_mProfileEnv vector object.
         * @param[in] func_name A function name to be profiled.
         */
-       void Stop(const unsigned int type, const char *func_name);
+       void Stop(const unsigned int type, const char *func_name = "Unknown");
 
        /**
         * @brief Dump profiled data to console or a given file.
@@ -189,6 +200,7 @@ private:
        void PushData(ProfileData &data);
        struct timespec GetTimeDiff(struct timespec &start, struct timespec &end);
        unsigned long ConvertMillisec(const struct timespec &time);
+       void GetMemoryUsage(MemoryData &data);
        void DumpToConsole(void);
        void DumpToFile(const unsigned int dump_type, std::string filename);
 
@@ -199,6 +211,8 @@ private:
        std::vector<ProfileData> v_mProfileData;
        std::map<const char *, const void *> m_mDataTable;
        std::string mDumpFilename;
+       MemoryData mStartMemoryData;
+       MemoryData mEndMemoryData;
 };
 } /* Profiler */
 } /* InferenceEngineInterface */
index 1a205ee..4c48e28 100644 (file)
@@ -67,7 +67,8 @@ mkdir -p %{buildroot}/usr/bin/
 mkdir -p %{buildroot}/opt/usr/images/
 %make_install
 
-install -m 755 test/bin/inference_engine_test %{buildroot}/%{_bindir}
+install -m 755 test/bin/inference_engine_test %{buildroot}%{_bindir}
+install -m 755 start_profiler.sh %{buildroot}%{_bindir}
 install -m 666 test/res/*.bin %{buildroot}/opt/usr/images
 
 %post -p /sbin/ldconfig
@@ -83,4 +84,5 @@ install -m 666 test/res/*.bin %{buildroot}/opt/usr/images
 %{_libdir}/pkgconfig/*common.pc
 %{_libdir}/lib*-common.so
 %{_bindir}/inference_engine_test
+%{_bindir}/start_profiler.sh
 /opt/usr/images/*.bin
index 73d75f2..1a87fd8 100755 (executable)
@@ -201,6 +201,11 @@ int InferenceEngineCommon::BindBackend(inference_engine_config *config)
 {
     LOGI("ENTER");
 
+       if (mUseProfiler == true) {
+               // Memory usage will be measured between BindBackend ~ UnbindBackend callbacks.
+               mProfiler->Start(IE_PROFILER_MEMORY);
+       }
+
     mBackendLibName = "libinference-engine-" + config->backend_name + ".so";
 
     char *error = NULL;
@@ -243,6 +248,11 @@ void InferenceEngineCommon::UnbindBackend(void)
 {
     LOGW("ENTER");
 
+       if (mUseProfiler == true) {
+               // Memory usage will be measured between BindBackend ~ UnbindBackend callbacks.
+               mProfiler->Stop(IE_PROFILER_MEMORY);
+       }
+
     if (mBackendModule) {
         destroy_t *engineDestroy = (destroy_t*)dlsym(mBackendModule, "EngineCommonDestroy");
         engineDestroy(mBackendHandle);
index aba71f3..06b233d 100644 (file)
@@ -19,6 +19,7 @@
 #include <fstream>
 #include <iostream>
 #include <time.h>
+#include <unistd.h>
 
 extern "C" {
 
@@ -39,7 +40,7 @@ namespace InferenceEngineInterface {
 namespace Profiler {
 
 // In default, we will use Markdown syntax to print out profile data.
-static const std::string sTitleMarkdown("backend|target devices|model name|Function name|Latency(ms)|Memory Usage(kb)\n--|--|--|--|--|--\n");
+static const std::string sTitleMarkdown("backend|target devices|model name|Function name|Latency(ms)\n--|--|--|--|--\n");
 
 InferenceEngineProfiler::InferenceEngineProfiler()
 {
@@ -50,6 +51,9 @@ InferenceEngineProfiler::InferenceEngineProfiler()
        // In default. we will store profile data to dump.txt file.
        // If you want to use other file then use SetDumpFilename function to change the filename.
        mDumpFilename = "dump.txt";
+
+       mStartMemoryData = {0, };
+       mEndMemoryData = {0, };
 }
 
 InferenceEngineProfiler::~InferenceEngineProfiler()
@@ -70,7 +74,6 @@ void InferenceEngineProfiler::PushData(ProfileData &data)
                if (iter != m_mDataTable.end()) {
                        ProfileData *item = (ProfileData *)iter->second;
                        item->elapsed_time = (item->elapsed_time + data.elapsed_time) >> 1;
-                       item->memory_usage = (item->memory_usage + data.memory_usage) >> 1;
                        return;
                }
        }
@@ -106,6 +109,28 @@ unsigned long InferenceEngineProfiler::ConvertMillisec(const struct timespec &ti
        return (unsigned long)(time.tv_sec * MILLI_PER_SEC + time.tv_nsec / NANO_PER_MILLI);
 }
 
+void InferenceEngineProfiler::GetMemoryUsage(MemoryData &data)
+{
+       unsigned long resident_set = 0, rss = 0;
+
+       std::string ignore;
+       std::ifstream ifs("/proc/self/stat", std::ios_base::in);
+       ifs >> ignore >> ignore >> ignore >> ignore >> ignore >> ignore >> ignore >> ignore >> ignore >> ignore
+               >> ignore >> ignore >> ignore >> ignore >> ignore >> ignore >> ignore >> ignore >> ignore >> ignore
+               >> ignore >> ignore >> ignore >> rss;
+
+       resident_set = (rss * getpagesize()) / 1024;
+       data.rss = resident_set;
+
+       // TODO. Collect GPU memory usage specific to board in case of GPU acceleration.
+       //
+       // If current Linux kernel used Linux DMA mapping framework which is a generic solution for GPU memory management
+       // then we can get all memory usage.
+       // On the other hands, GPU driver on some boards may use reserved memory which is hided
+       // from Linux kernel memory subsystem so the memory usage cannot be measured in generic way.
+       // In this case, board specific interface is required.
+}
+
 void InferenceEngineProfiler::Start(const unsigned int type)
 {
        if (IE_PROFILER_MIN >= type && IE_PROFILER_MAX <= type) {
@@ -118,6 +143,8 @@ void InferenceEngineProfiler::Start(const unsigned int type)
                clock_gettime(CLOCK_MONOTONIC, &mStartTime);
                break;
        case IE_PROFILER_MEMORY:
+               mStartMemoryData = { 0, };
+               GetMemoryUsage(mStartMemoryData);
                break;
        /* TODO */
        }
@@ -130,20 +157,22 @@ void InferenceEngineProfiler::Stop(const unsigned int type, const char *func_nam
                return;
        }
 
-       ProfileData data = { mEnvNum - 1, func_name, 0, 0 };
+       ProfileData data = { mEnvNum - 1, func_name, 0 };
 
        switch (type) {
        case IE_PROFILER_LATENCY: {
                clock_gettime(CLOCK_MONOTONIC, &mEndTime);
                data.elapsed_time = ConvertMillisec(GetTimeDiff(mStartTime, mEndTime));
+               // TODO.
+               PushData(data);
                break;
        }
        case IE_PROFILER_MEMORY:
+               mEndMemoryData = { 0, };
+               GetMemoryUsage(mEndMemoryData);
                break;
-               /* TODO */
+       /* TODO */
        }
-
-       PushData(data);
 }
 
 void InferenceEngineProfiler::DumpToConsole(void)
@@ -155,8 +184,11 @@ void InferenceEngineProfiler::DumpToConsole(void)
                ProfileData data = *iter;
                ProfileEnv env = v_mProfileEnv[data.env_idx];
                std::cout << env.backend_name << "|" << env.target_devices << "|" << env.model_name << "|";
-               std::cout << data.function_name << "|" << data.elapsed_time << "|" << "\n";
+               std::cout << data.function_name << "|" << data.elapsed_time << "\n";
        }
+
+       std::cout << "***" << "\n";
+       std::cout << "Memory Usage(kb) : " << mEndMemoryData.rss - mStartMemoryData.rss << "\n";
        std::cout << "***" << "\n";
 }
 
@@ -188,9 +220,13 @@ void InferenceEngineProfiler::DumpToFile(const unsigned int dump_type, std::stri
                        dump_file.write("|", 1);
                        std::string sElapsedTime(std::to_string(data.elapsed_time));
                        dump_file.write(sElapsedTime.c_str(), sElapsedTime.length());
-                       dump_file.write("|", 1);
                        dump_file.write("\n", 1);
                }
+
+               dump_file.write("***\n", 4);
+               std::string sMemoryUsage = std::to_string(mEndMemoryData.rss - mStartMemoryData.rss);
+               dump_file.write(sMemoryUsage.c_str(), sMemoryUsage.length());
+               dump_file.write("\n", 1);
                dump_file.write("***\n", 4);
        }
 
diff --git a/start_profiler.sh b/start_profiler.sh
new file mode 100644 (file)
index 0000000..e4c8103
--- /dev/null
@@ -0,0 +1,22 @@
+#!/bin/sh
+
+CNT=`/usr/bin/inference_engine_test --gtest_list_tests | wc -l`
+CNT=$(($CNT - 12))
+
+echo "Tflite model test case count = $CNT"
+
+LIST=$(seq 0 $CNT)
+for i in $LIST
+do
+  /usr/bin/inference_engine_test --gtest_filter=Prefix/InferenceEngineTfliteTest.Inference/$i
+done
+
+# If you want to add new model tests then add script for it below
+#
+# Make sure to calculate the test case count like this,
+# CNT=$(($CNT - 31)) which depends on a number of test cases above.
+# LIST=$(seq 0 $CNT)
+# for i in $LIST
+# do
+#   /usr/bin/inference_engine_test --gtest_filter=Prefix/InferenceEngine_model_name_Test.Inference/$i
+# done