Merge pull request #28752 from abhishek-gola:net_profiling

Added net profiling support #28752

### Pull Request Readiness Checklist

See details at https://github.com/opencv/opencv/wiki/How_to_contribute#making-a-good-pull-request

- [x] I agree to contribute to the project under Apache 2 License.
- [x] To the best of my knowledge, the proposed patch is not based on a code under GPL or another license that is incompatible with OpenCV
- [x] The PR is proposed to the proper branch
- [x] There is a reference to the original bug report and related work
- [x] There is accuracy test, performance test and test data in opencv_extra repository, if applicable
      Patch to opencv_extra has the same branch name.
- [x] The feature is well documented and sample code can be built with the project CMake

modules/dnn/include/opencv2/dnn/dnn.hpp

@@ -545,6 +545,33 @@ CV__DNN_INLINE_NS_BEGIN
         virtual void setProg(const std::vector<Ptr<Layer> >& newprog) = 0;
     };
 
+    /** @brief Single entry in a @ref PerfProfile.
+     *
+     * In DNN_PROFILE_DETAILED mode, @p label is "layer_name (type)" and @p count is 1.
+     * In DNN_PROFILE_SUMMARY mode, @p label is the layer type and @p count is the
+     * number of layers of that type that contributed to @p timeMs.
+     */
+    struct CV_EXPORTS_W_SIMPLE PerfProfileEntry
+    {
+        CV_WRAP PerfProfileEntry() : timeMs(0.0), count(0) {}
+        CV_PROP_RW String label;
+        CV_PROP_RW double timeMs;
+        CV_PROP_RW int count;
+    };
+
+    /** @brief Self-describing snapshot of profiling data from one inference.
+     *
+     * Carries the @ref ProfilingMode it was captured in so it can be saved, kept across
+     * runs (e.g. best-of-N by total time), and printed later via @ref Net::printPerfProfile
+     * without needing access to the originating @ref Net.
+     */
+    struct CV_EXPORTS_W_SIMPLE PerfProfile
+    {
+        CV_WRAP PerfProfile() : mode(DNN_PROFILE_NONE) {}
+        CV_PROP_RW ProfilingMode mode;
+        CV_PROP_RW std::vector<PerfProfileEntry> entries;
+    };
+
     /** @brief This class allows to create and manipulate comprehensive artificial neural networks.
      *
      * Neural network is presented as directed acyclic graph (DAG), where vertices are Layer instances,
@@ -1027,6 +1054,21 @@ CV__DNN_INLINE_NS_BEGIN
          */
         CV_WRAP int64 getPerfProfile(CV_OUT std::vector<double>& timings);
 
+        /** @brief Returns profiling data captured during the last forward pass.
+         *
+         * Entries are sorted by time in descending order. Empty vectors are returned
+         * if profiling is disabled (DNN_PROFILE_NONE).
+         */
+        CV_WRAP void getPerfProfile(CV_OUT std::vector<std::string>& names, CV_OUT std::vector<std::string>& timems, CV_OUT std::vector<std::string>& counts) const;
+
+        /** @brief Prints the profile captured during the last forward pass in a formatted table using CV_LOG_INFO.
+         *
+         * In DNN_PROFILE_DETAILED mode, prints per-layer label, time, and percentage.
+         * In DNN_PROFILE_SUMMARY mode, prints per-type count, time, and percentage.
+         * Does nothing if profiling is disabled (DNN_PROFILE_NONE) or all timings are zero.
+         */
+        CV_WRAP void printPerfProfile() const;
+
         // Get the main model graph
         Ptr<Graph> getMainGraph() const;
 

modules/dnn/src/net.cpp

@@ -446,6 +446,20 @@ int64 Net::getPerfProfile(std::vector<double>& timings)
     return impl->getPerfProfile(timings);
 }
 
+void Net::getPerfProfile(std::vector<std::string>& names,
+                         std::vector<std::string>& timems,
+                         std::vector<std::string>& counts) const
+{
+    CV_Assert(impl);
+    impl->getPerfProfile(names, timems, counts);
+}
+
+void Net::printPerfProfile() const
+{
+    CV_Assert(impl);
+    impl->printPerfProfile();
+}
+
 bool Net::isConstArg(Arg arg) const
 {
     return argKind(arg) == DNN_ARG_CONST;

modules/dnn/src/net_impl.cpp

@@ -6,6 +6,12 @@
 
 #include "net_impl.hpp"
 
+#ifdef HAVE_ONNXRUNTIME
+#include <onnxruntime_cxx_api.h>
+#include <fstream>
+#include <sstream>
+#endif
+
 namespace cv {
 namespace dnn {
 CV__DNN_INLINE_NS_BEGIN
@@ -2642,6 +2648,251 @@ int64 Net::Impl::getPerfProfile(std::vector<double>& timings) const
     return total;
 }
 
+void Net::Impl::collectLayerInfo(std::vector<String>& names, std::vector<String>& types) const
+{
+    if (mainGraph) {
+        names.reserve(totalLayers);
+        types.reserve(totalLayers);
+        for (const Ptr<Graph>& graph : allgraphs) {
+            const std::vector<Ptr<Layer>>& prog = graph->prog();
+            for (const Ptr<Layer>& layer : prog) {
+                names.push_back(layer ? layer->name : "null");
+                types.push_back(layer ? layer->type : "null");
+            }
+        }
+    } else {
+        for (MapIdToLayerData::const_iterator it = layers.begin(); it != layers.end(); ++it) {
+            if (it->second.id) {  // skip Data layer (id==0)
+                names.push_back(it->second.name);
+                types.push_back(it->second.type);
+            }
+        }
+    }
+}
+
+#ifdef HAVE_ONNXRUNTIME
+static void parseOrtProfileJson(const std::string& text,
+                                std::map<std::string, std::pair<std::string, double>>& out_ms)
+{
+    const std::string wrapped = "{\"events\":" + text + "}";
+    FileStorage fs(wrapped, FileStorage::READ | FileStorage::MEMORY | FileStorage::FORMAT_JSON);
+    if (!fs.isOpened()) {
+        CV_LOG_WARNING(NULL, "DNN/ORT: failed to parse profile JSON");
+        return;
+    }
+
+    static const std::string KT = "_kernel_time";
+    FileNode events = fs["events"];
+    for (FileNodeIterator it = events.begin(); it != events.end(); ++it) {
+        FileNode entry = *it;
+        if (!entry.isMap()) continue;
+        if ((std::string)entry["cat"] != "Node") continue;
+
+        const std::string name = (std::string)entry["name"];
+        if (name.size() < KT.size() ||
+            name.compare(name.size() - KT.size(), KT.size(), KT) != 0)
+            continue;
+
+        FileNode args = entry["args"];
+        if (args.empty()) continue;
+        const std::string op = (std::string)args["op_name"];
+        const double dur_us  = (double)entry["dur"];
+        if (op.empty() || dur_us <= 0) continue;
+
+        const std::string canonical = name.substr(0, name.size() - KT.size());
+        auto& slot = out_ms[canonical];
+        slot.first = op;
+        slot.second += dur_us / 1000.0;
+    }
+}
+
+void Net::Impl::collectOrtProfileData() const
+{
+    if (ort_profile_collected) return;
+    ort_profile_collected = true;
+    if (!ort_session || ort_profile_path_prefix.empty()) return;
+
+    // EndProfiling closes the file ORT has been writing to and returns its path.
+    Ort::AllocatorWithDefaultOptions allocator;
+    Ort::AllocatedStringPtr profile_path = ort_session->EndProfilingAllocated(allocator);
+    if (!profile_path) {
+        CV_LOG_WARNING(NULL, "DNN/ORT: EndProfiling did not return a path (prefix=" << ort_profile_path_prefix << ")");
+        return;
+    }
+
+    // Read the JSON entirely into memory, then parse it from the string.
+    std::ifstream in(profile_path.get());
+    if (!in.is_open()) {
+        CV_LOG_WARNING(NULL, "DNN/ORT: failed to open profile JSON " << profile_path.get());
+        return;
+    }
+    std::stringstream ss; ss << in.rdbuf();
+    const std::string text = ss.str();
+
+    std::map<std::string, std::pair<std::string, double>> by_name;
+    parseOrtProfileJson(text, by_name);
+
+    const int runs = ort_profile_runs > 0 ? ort_profile_runs : 1;
+    ort_profile_data.clear();
+    ort_profile_data.reserve(by_name.size());
+    for (auto& kv : by_name) {
+        const String name = kv.first;
+        const String type = kv.second.first;
+        const double ms_per_run = kv.second.second / runs;
+        ort_profile_data.emplace_back(name, type, ms_per_run);
+    }
+}
+#endif
+
+PerfProfile Net::Impl::getPerfProfile() const
+{
+    PerfProfile result;
+    result.mode = profilingMode;
+
+    if (profilingMode == DNN_PROFILE_NONE)
+        return result;
+
+#ifdef HAVE_ONNXRUNTIME
+    if (useOrtEngine && ort_session) {
+        collectOrtProfileData();
+        if (profilingMode == DNN_PROFILE_DETAILED) {
+            for (const auto& t : ort_profile_data) {
+                if (std::get<2>(t) <= 0) continue;
+                PerfProfileEntry e;
+                e.label = std::get<0>(t) + " (" + std::get<1>(t) + ")";
+                e.timeMs = std::get<2>(t);
+                e.count = 1;
+                result.entries.push_back(e);
+            }
+        } else if (profilingMode == DNN_PROFILE_SUMMARY) {
+            std::map<String, double> typeTimings;
+            std::map<String, int> typeCounts;
+            for (const auto& t : ort_profile_data) {
+                if (std::get<2>(t) <= 0) continue;
+                typeTimings[std::get<1>(t)] += std::get<2>(t);
+                typeCounts[std::get<1>(t)]++;
+            }
+            result.entries.reserve(typeTimings.size());
+            for (auto it = typeTimings.begin(); it != typeTimings.end(); ++it) {
+                PerfProfileEntry e;
+                e.label = it->first;
+                e.timeMs = it->second;
+                e.count = typeCounts[it->first];
+                result.entries.push_back(e);
+            }
+        }
+        std::sort(result.entries.begin(), result.entries.end(),
+                  [](const PerfProfileEntry& a, const PerfProfileEntry& b) {
+                      return a.timeMs > b.timeMs;
+                  });
+        return result;
+    }
+#endif
+
+    std::vector<double> timings(layersTimings.begin() + 1, layersTimings.end());
+    double tickFreq = getTickFrequency();
+
+    std::vector<String> names;
+    std::vector<String> types;
+    collectLayerInfo(names, types);
+
+    size_t n = std::min(timings.size(), names.size());
+
+    if (profilingMode == DNN_PROFILE_DETAILED) {
+        for (size_t i = 0; i < n; i++) {
+            if (timings[i] > 0) {
+                PerfProfileEntry e;
+                e.label = names[i] + " (" + types[i] + ")";
+                e.timeMs = timings[i] * 1000.0 / tickFreq;
+                e.count = 1;
+                result.entries.push_back(e);
+            }
+        }
+    } else if (profilingMode == DNN_PROFILE_SUMMARY) {
+        std::map<String, double> typeTimings;
+        std::map<String, int> typeCounts;
+        for (size_t i = 0; i < n; i++) {
+            if (timings[i] > 0) {
+                typeTimings[types[i]] += timings[i] * 1000.0 / tickFreq;
+                typeCounts[types[i]]++;
+            }
+        }
+        result.entries.reserve(typeTimings.size());
+        for (auto it = typeTimings.begin(); it != typeTimings.end(); ++it) {
+            PerfProfileEntry e;
+            e.label = it->first;
+            e.timeMs = it->second;
+            e.count = typeCounts[it->first];
+            result.entries.push_back(e);
+        }
+    }
+
+    std::sort(result.entries.begin(), result.entries.end(),
+              [](const PerfProfileEntry& a, const PerfProfileEntry& b) {
+                  return a.timeMs > b.timeMs;
+              });
+
+    return result;
+}
+
+void Net::Impl::getPerfProfile(std::vector<std::string>& names,
+                               std::vector<std::string>& timems,
+                               std::vector<std::string>& counts) const
+{
+    PerfProfile profile = getPerfProfile();
+    names.clear();
+    timems.clear();
+    counts.clear();
+    names.reserve(profile.entries.size());
+    timems.reserve(profile.entries.size());
+    counts.reserve(profile.entries.size());
+    for (const PerfProfileEntry& e : profile.entries) {
+        names.push_back(e.label);
+        timems.push_back(cv::format("%.3f", e.timeMs));
+        counts.push_back(cv::format("%d", e.count));
+    }
+}
+
+void Net::Impl::printPerfProfile() const
+{
+    PerfProfile profile = getPerfProfile();
+    if (profile.mode == DNN_PROFILE_NONE)
+        return;
+
+    double totalMs = 0.0;
+    for (const PerfProfileEntry& e : profile.entries)
+        totalMs += e.timeMs;
+    if (totalMs <= 0.0)
+        return;
+
+    if (profile.mode == DNN_PROFILE_DETAILED) {
+        CV_LOG_INFO(NULL, "\n=== DNN Layer Profiling (Detailed) ===");
+        CV_LOG_INFO(NULL, cv::format("%-5s %-60s %10s %8s", "ID", "Layer (Type)", "Time (ms)", "   (%)"));
+        CV_LOG_INFO(NULL, "-----------------------------------------------------------------------------------------------");
+        for (size_t i = 0; i < profile.entries.size(); i++) {
+            const PerfProfileEntry& e = profile.entries[i];
+            double pct = e.timeMs * 100.0 / totalMs;
+            CV_LOG_INFO(NULL, cv::format("%-5zu %-60s %10.3f %7.1f%%",
+                   i, e.label.c_str(), e.timeMs, pct));
+        }
+        CV_LOG_INFO(NULL, "-----------------------------------------------------------------------------------------------");
+        CV_LOG_INFO(NULL, cv::format("%-5s %-60s %10.3f %7s", "", "TOTAL", totalMs, "100.0%"));
+        CV_LOG_INFO(NULL, "");
+    } else if (profile.mode == DNN_PROFILE_SUMMARY) {
+        CV_LOG_INFO(NULL, "\n=== DNN Layer Profiling (Summary by Type) ===");
+        CV_LOG_INFO(NULL, cv::format("%-25s %6s %10s %8s", "Layer Type", "Count", "Time (ms)", "   (%)"));
+        CV_LOG_INFO(NULL, "-----------------------------------------------------------");
+        for (const PerfProfileEntry& e : profile.entries) {
+            double pct = e.timeMs * 100.0 / totalMs;
+            CV_LOG_INFO(NULL, cv::format("%-25s %6d %10.3f %7.1f%%",
+                   e.label.c_str(), e.count, e.timeMs, pct));
+        }
+        CV_LOG_INFO(NULL, "-----------------------------------------------------------");
+        CV_LOG_INFO(NULL, cv::format("%-25s %6s %10.3f %7s", "TOTAL", "", totalMs, "100.0%"));
+        CV_LOG_INFO(NULL, "");
+    }
+}
+
 void Net::Impl::getMemoryConsumption(
         const std::vector<MatShape>& netInputShapes,
         const std::vector<MatType>& netInputTypes,

modules/dnn/src/net_impl.hpp

@@ -254,12 +254,17 @@ struct Net::Impl : public detail::NetImplBase
     void finalizeOrt();
     void refreshOrtMainGraphOutputs();
     void applyStagedOrtInputs();
+    void collectOrtProfileData() const;
     std::vector<std::pair<std::string, Mat>> ort_staged_inputs;
     std::shared_ptr<Ort::Env> ort_env;
     std::shared_ptr<Ort::Session> ort_session;
     std::shared_ptr<OrtNamesCache> ort_names_cache;
     bool useOrtEngine = false;   // true only when user explicitly selected ENGINE_ORT
     bool ortNeedsReinit = false;  // session needs (re)creation on next finalizeNet
+    std::string ort_profile_path_prefix;          // prefix passed to EnableProfiling
+    mutable bool ort_profile_collected = false;   // EndProfiling was already called once
+    mutable int  ort_profile_runs = 0;            // number of session.Run calls since profiling started
+    mutable std::vector<std::tuple<String, String, double>> ort_profile_data;  // (name, type, ms_per_run)
 #endif
 
     void allocateLayer(int lid, const LayersShapesMap& layersShapes);
@@ -330,6 +335,10 @@ struct Net::Impl : public detail::NetImplBase
             std::vector<int>& layerIds, std::vector<size_t>& weights,
             std::vector<size_t>& blobs) /*const*/;
     int64 getPerfProfile(std::vector<double>& timings) const;
+    void collectLayerInfo(std::vector<String>& names, std::vector<String>& types) const;
+    PerfProfile getPerfProfile() const;
+    void getPerfProfile(std::vector<std::string>& names, std::vector<std::string>& timems, std::vector<std::string>& counts) const;
+    void printPerfProfile() const;
 
     // TODO drop
     LayerPin getLatestLayerPin(const std::vector<LayerPin>& pins) const;

modules/dnn/src/net_impl2.cpp

@@ -221,6 +221,7 @@ std::vector<Mat> Net::Impl::runOrtSession(std::vector<Mat> inputBlobs, const std
         Ort::RunOptions{nullptr},
         in_names.data(), input_tensors.data(), input_tensors.size(),
         out_names.data(), out_names.size());
+    if (profilingMode != DNN_PROFILE_NONE) ort_profile_runs++;
 
     CV_CheckEQ(output_tensors.size(), out_names.size(), "DNN/ORT: ORT returned unexpected number of outputs");
 

modules/dnn/src/net_impl_backend.cpp

@@ -88,6 +88,17 @@ void Net::Impl::finalizeOrt()
         }
     }
 
+    // If the user set DNN_PROFILE_*, turn on ORT's session profiler. The JSON
+    // file is parsed lazily by collectOrtProfileData() inside getPerfProfile()/printPerfProfile().
+    ort_profile_path_prefix.clear();
+    ort_profile_collected = false;
+    ort_profile_runs = 0;
+    ort_profile_data.clear();
+    if (profilingMode != DNN_PROFILE_NONE) {
+        ort_profile_path_prefix = cv::tempfile("opencv_ort_profile_");
+        opts.EnableProfiling(ort_profile_path_prefix.c_str());
+    }
+
 #ifdef _WIN32
     std::wstring wpath(modelFileName.begin(), modelFileName.end());
     ort_session = std::make_shared<Ort::Session>(*ort_env, wpath.c_str(), opts);