IVGCVSW-3603 *Json printer prints full profiling hierarchy
Change-Id: Ide5acbf993c2bcff5265b72fc979caa6f183bb22
Signed-off-by: Derek Lamberti <derek.lamberti@arm.com>
diff --git a/src/armnn/JsonPrinter.cpp b/src/armnn/JsonPrinter.cpp
index 97cd5f2..9dc648c 100644
--- a/src/armnn/JsonPrinter.cpp
+++ b/src/armnn/JsonPrinter.cpp
@@ -7,25 +7,41 @@
#include <iomanip>
#include <iostream>
+#include <sstream>
namespace armnn
{
-void JsonPrinter::PrintJsonChildObject(const JsonChildObject& object)
+void JsonPrinter::PrintJsonChildObject(const JsonChildObject& object, size_t& id)
{
- PrintLabel(object.m_Label);
- PrintMeasurementsList(object.m_Measurements);
- PrintSeparator();
- PrintNewLine();
- PrintUnit(object.m_Unit);
+ if (object.GetType() == JsonObjectType::Event)
+ {
+ // Increase the Id for new events. This ensures a new event has a unique ID and any measurements belonging
+ // to the event have the same id. This id is appended to the name during the call to PrintLabel() below.
+ id++;
+ }
- if (!object.m_Children.empty())
+ PrintLabel(object.m_Label, id);
+ PrintType(object.m_Type);
+
+ if (!object.m_Measurements.empty() || !object.m_Children.empty())
{
PrintSeparator();
PrintNewLine();
+ }
+
+ if (object.GetType() == JsonObjectType::Measurement)
+ {
+ PrintMeasurementsList(object.m_Measurements);
+ PrintSeparator();
+ PrintNewLine();
+ PrintUnit(object.m_Unit);
+ }
+ if (!object.m_Children.empty())
+ {
for (unsigned int childIndex = 0; childIndex < object.m_Children.size(); ++childIndex)
{
- PrintJsonChildObject(object.m_Children[childIndex]);
+ PrintJsonChildObject(object.m_Children[childIndex], id);
// Only print separator and new line if current child is not the last element.
if (&object.m_Children[childIndex] != &object.m_Children.back())
{
@@ -51,10 +67,17 @@
IncrementNumberOfTabs();
}
-void JsonPrinter::PrintLabel(const std::string& label)
+std::string JsonPrinter::MakeKey(const std::string& label, size_t id)
+{
+ std::stringstream ss;
+ ss << label << std::string("_#") << id;
+ return ss.str();
+}
+
+void JsonPrinter::PrintLabel(const std::string& label, size_t id)
{
PrintTabs();
- m_OutputStream << R"(")" << label << R"(": {)" << std::endl;
+ m_OutputStream << R"(")" << MakeKey(label, id) << R"(": {)" << std::endl;
IncrementNumberOfTabs();
}
@@ -66,6 +89,33 @@
m_OutputStream << R"(")";
}
+void JsonPrinter::PrintType(armnn::JsonObjectType type)
+{
+ auto ToString = [](armnn::JsonObjectType type)
+ {
+ switch (type)
+ {
+ case JsonObjectType::Measurement:
+ {
+ return "Measurement";
+ }
+ case JsonObjectType::Event:
+ {
+ return "Event";
+ }
+ default:
+ {
+ return "Unknown";
+ }
+ }
+ };
+ PrintTabs();
+ m_OutputStream << R"("type": ")";
+ m_OutputStream << ToString(type);
+ m_OutputStream << R"(")";
+}
+
+
void JsonPrinter::PrintMeasurementsList(const std::vector<double>& measurementsVector)
{
if (measurementsVector.empty())
diff --git a/src/armnn/JsonPrinter.hpp b/src/armnn/JsonPrinter.hpp
index 12a0891..04f56b0 100644
--- a/src/armnn/JsonPrinter.hpp
+++ b/src/armnn/JsonPrinter.hpp
@@ -8,16 +8,23 @@
#include <ostream>
#include <string.h>
#include <map>
+#include <set>
#include "Instrument.hpp"
namespace armnn
{
+enum class JsonObjectType
+{
+ Measurement,
+ Event
+};
+
struct JsonChildObject
{
JsonChildObject(const std::string& label)
- : m_Label(label), m_Unit(Measurement::Unit::TIME_MS)
+ : m_Label(label), m_Unit(Measurement::Unit::TIME_MS), m_Type(JsonObjectType::Event)
{}
JsonChildObject(const JsonChildObject&) = default;
@@ -31,7 +38,7 @@
m_Children.push_back(childObject);
}
- JsonChildObject GetChild(const unsigned int index)
+ JsonChildObject& GetChild(const unsigned int index)
{
return m_Children[index];
}
@@ -41,10 +48,26 @@
m_Unit = unit;
}
+ size_t NumChildren() const
+ {
+ return m_Children.size();
+ }
+
+ void SetType(JsonObjectType type)
+ {
+ m_Type = type;
+ }
+
+ JsonObjectType GetType() const
+ {
+ return m_Type;
+ }
+
~JsonChildObject() = default;
std::string m_Label;
Measurement::Unit m_Unit;
+ JsonObjectType m_Type;
std::vector<double> m_Measurements;
std::vector<JsonChildObject> m_Children;
@@ -55,14 +78,15 @@
class JsonPrinter
{
public:
- void PrintJsonChildObject(const JsonChildObject& object);
+ void PrintJsonChildObject(const JsonChildObject& object, size_t& id);
void PrintHeader();
void PrintArmNNHeader();
void PrintFooter();
void PrintSeparator();
void PrintNewLine();
- void PrintLabel(const std::string& label);
+ void PrintLabel(const std::string& label, size_t id);
void PrintUnit(armnn::Measurement::Unit unit);
+ void PrintType(armnn::JsonObjectType type);
void PrintMeasurementsList(const std::vector<double>& measurementsVector);
public:
@@ -71,6 +95,7 @@
{}
private:
+ std::string MakeKey(const std::string& label, size_t id);
void PrintTabs();
void DecrementNumberOfTabs();
void IncrementNumberOfTabs();
diff --git a/src/armnn/Profiling.cpp b/src/armnn/Profiling.cpp
index d30a64f..1cd21ab 100644
--- a/src/armnn/Profiling.cpp
+++ b/src/armnn/Profiling.cpp
@@ -280,6 +280,53 @@
}
}
+
+void ExtractJsonObjects(unsigned int inferenceIndex,
+ const Event* parentEvent,
+ JsonChildObject& parentObject,
+ std::map<const Event*, std::vector<const Event*>> descendantsMap)
+{
+ BOOST_ASSERT(parentEvent);
+ std::vector<Measurement> instrumentMeasurements = parentEvent->GetMeasurements();
+ unsigned int childIdx=0;
+ for(size_t measurementIndex = 0; measurementIndex < instrumentMeasurements.size(); ++measurementIndex, ++childIdx)
+ {
+ if (inferenceIndex == 0)
+ {
+ // Only add kernel measurement once, in case of multiple inferences
+ JsonChildObject measurementObject{instrumentMeasurements[measurementIndex].m_Name};
+ measurementObject.SetUnit(instrumentMeasurements[measurementIndex].m_Unit);
+ measurementObject.SetType(JsonObjectType::Measurement);
+
+ BOOST_ASSERT(parentObject.NumChildren() == childIdx);
+ parentObject.AddChild(measurementObject);
+ }
+
+ parentObject.GetChild(childIdx).AddMeasurement(instrumentMeasurements[measurementIndex].m_Value);
+ }
+
+
+ auto childEventsIt = descendantsMap.find(parentEvent);
+ if (childEventsIt != descendantsMap.end())
+ {
+ for (auto childEvent : childEventsIt->second)
+ {
+ if (inferenceIndex == 0)
+ {
+ // Only add second level once, in case of multiple inferences
+ JsonChildObject childObject{childEvent->GetName()};
+ childObject.SetType(JsonObjectType::Event);
+ parentObject.AddChild(childObject);
+ }
+
+ // Recursively process children. In reality this won't be very deep recursion. ~4-6 levels deep.
+ ExtractJsonObjects(inferenceIndex, childEvent, parentObject.GetChild(childIdx), descendantsMap);
+
+ childIdx++;
+ }
+ }
+}
+
void Profiler::Print(std::ostream& outStream) const
{
// Makes sure timestamps are output with 6 decimals, and save old settings.
@@ -306,72 +353,15 @@
for (unsigned int inferenceIndex = 0; inferenceIndex < inferences.size(); ++inferenceIndex)
{
auto inference = inferences[inferenceIndex];
- Measurement measurement = FindMeasurement(WallClockTimer::WALL_CLOCK_TIME, inference);
- inferenceObject.SetUnit(measurement.m_Unit);
- inferenceObject.AddMeasurement(measurement.m_Value);
-
- auto layerEventsIt = descendantsMap.find(inference);
-
- // Assuming 1 Execute per inference
- if (layerEventsIt != descendantsMap.end())
- {
- auto layerEvent = layerEventsIt->second[0];
- Measurement measurement = FindMeasurement(WallClockTimer::WALL_CLOCK_TIME, layerEvent);
- layerObject.SetUnit(measurement.m_Unit);
- layerObject.AddMeasurement(measurement.m_Value);
-
- // Get Descendant Events for Execute
- auto workloadEventsIt = descendantsMap.find(layerEvent);
- for(unsigned int workloadIndex = 0; workloadIndex < workloadEventsIt->second.size(); ++workloadIndex)
- {
- auto workloadEvent = workloadEventsIt->second[workloadIndex];
- Measurement measurement = FindMeasurement(WallClockTimer::WALL_CLOCK_TIME, workloadEvent);
- std::vector<Measurement> kernelMeasurements = FindKernelMeasurements(workloadEvent);
- if (inferenceIndex == 0)
- {
- // Only add second level once, in case of multiple inferences
- JsonChildObject workloadObject{workloadEvent->GetName()};
- workloadObject.SetUnit(measurement.m_Unit);
- workloadObjects.push_back(workloadObject);
- }
- workloadObjects[workloadIndex].AddMeasurement(measurement.m_Value);
-
- for(unsigned int kernelIndex = 0; kernelIndex < kernelMeasurements.size(); ++kernelIndex)
- {
- if (inferenceIndex == 0)
- {
- // Only add kernel measurement once, in case of multiple inferences
- JsonChildObject kernelObject{kernelMeasurements[kernelIndex].m_Name};
- kernelObject.SetUnit(kernelMeasurements[kernelIndex].m_Unit);
- workloadToKernelObjects[workloadIndex].push_back(kernelObject);
-
- }
- workloadToKernelObjects[workloadIndex][kernelIndex].
- AddMeasurement(kernelMeasurements[kernelIndex].m_Value);
- }
- }
- }
+ ExtractJsonObjects(inferenceIndex, inference, inferenceObject, descendantsMap);
}
- for (auto workloadToKernelPair : workloadToKernelObjects)
- {
- for (auto kernelObject : workloadToKernelPair.second)
- {
- workloadObjects[workloadToKernelPair.first].AddChild(kernelObject);
- }
- }
-
- for (auto workloadObject : workloadObjects)
- {
- layerObject.AddChild(workloadObject);
- }
- inferenceObject.AddChild(layerObject);
-
printer.PrintHeader();
printer.PrintArmNNHeader();
// print inference object, also prints child layer and kernel measurements
- printer.PrintJsonChildObject(inferenceObject);
+ size_t id=0;
+ printer.PrintJsonChildObject(inferenceObject, id);
// end of ArmNN
printer.PrintNewLine();
diff --git a/src/armnn/Profiling.hpp b/src/armnn/Profiling.hpp
index 0b2e46d..d52bbb0 100644
--- a/src/armnn/Profiling.hpp
+++ b/src/armnn/Profiling.hpp
@@ -158,9 +158,15 @@
} // namespace armnn
+
+#include <boost/preprocessor.hpp>
+
+#define ARMNN_SCOPED_PROFILING_EVENT_WITH_INSTRUMENTS_UNIQUE_LOC(backendId, /*name,*/ ...) \
+ armnn::ScopedProfilingEvent BOOST_PP_CAT(e_,__LINE__)(backendId, /*name,*/ __VA_ARGS__);
+
// The event name must be known at compile time
#define ARMNN_SCOPED_PROFILING_EVENT_WITH_INSTRUMENTS(backendId, /*name,*/ ...) \
- armnn::ScopedProfilingEvent e_##__FILE__##__LINE__(backendId, /*name,*/ __VA_ARGS__);
+ ARMNN_SCOPED_PROFILING_EVENT_WITH_INSTRUMENTS_UNIQUE_LOC(backendId, /*name,*/ __VA_ARGS__);
#define ARMNN_SCOPED_PROFILING_EVENT(backendId, name) \
ARMNN_SCOPED_PROFILING_EVENT_WITH_INSTRUMENTS(backendId, name, armnn::WallClockTimer())
diff --git a/src/armnn/test/ProfilerTests.cpp b/src/armnn/test/ProfilerTests.cpp
index f6688ea..90f6d8b 100644
--- a/src/armnn/test/ProfilerTests.cpp
+++ b/src/armnn/test/ProfilerTests.cpp
@@ -9,6 +9,7 @@
#include <memory>
#include <thread>
+#include <ostream>
#include <armnn/TypesUtils.hpp>
#include <Profiling.hpp>
@@ -240,4 +241,107 @@
profiler->EnableProfiling(false);
}
-BOOST_AUTO_TEST_SUITE_END()
+BOOST_AUTO_TEST_CASE(ProfilerJsonPrinter)
+{
+ class TestInstrument : public armnn::Instrument
+ {
+ public:
+ virtual ~TestInstrument() {}
+ void Start() override {}
+ void Stop() override {}
+
+ std::vector<armnn::Measurement> GetMeasurements() const override
+ {
+ std::vector<armnn::Measurement> measurements;
+ measurements.emplace_back(armnn::Measurement("Measurement1",
+ 1.0,
+ armnn::Measurement::Unit::TIME_MS));
+ measurements.emplace_back(armnn::Measurement("Measurement2",
+ 2.0,
+ armnn::Measurement::Unit::TIME_US));
+ return measurements;
+ }
+
+ const char* GetName() const override
+ {
+ return "TestInstrument";
+ }
+ };
+
+ // Get a reference to the profiler manager.
+ armnn::ProfilerManager& profilerManager = armnn::ProfilerManager::GetInstance();
+
+ // Create and register a profiler for this thread.
+ std::unique_ptr<armnn::Profiler> profiler = std::make_unique<armnn::Profiler>();
+ profilerManager.RegisterProfiler(profiler.get());
+
+ profiler->EnableProfiling(true);
+
+ {
+ // Test scoped macro.
+ ARMNN_SCOPED_PROFILING_EVENT_WITH_INSTRUMENTS(armnn::Compute::CpuAcc, "EnqueueWorkload", TestInstrument())
+ ARMNN_SCOPED_PROFILING_EVENT_WITH_INSTRUMENTS(armnn::Compute::CpuAcc, "Level 0", TestInstrument())
+ {
+ {
+ ARMNN_SCOPED_PROFILING_EVENT_WITH_INSTRUMENTS(armnn::Compute::CpuAcc, "Level 1A", TestInstrument())
+ }
+
+ {
+ ARMNN_SCOPED_PROFILING_EVENT_WITH_INSTRUMENTS(armnn::Compute::CpuAcc, "Level 1B", TestInstrument())
+
+ {
+ ARMNN_SCOPED_PROFILING_EVENT_WITH_INSTRUMENTS(armnn::Compute::CpuAcc, "Level 2A", TestInstrument())
+ }
+ }
+ }
+ }
+
+ std::stringbuf buffer;
+ std::ostream json(&buffer);
+ profiler->Print(json);
+
+ std::string output = buffer.str();
+ boost::ignore_unused(output);
+
+ // Disable profiling here to not print out anything on stdout.
+ profiler->EnableProfiling(false);
+
+ // blessed output validated by a human eyeballing the output to make sure it's ok and then copying it here.
+ // validation also included running the blessed output through an online json validation site
+ std::string blessedOutput("{\n\t\"ArmNN\": {\n\t\t\"inference_measurements_#1\": {\n\t\t\t\"type\": \""
+ "Event\",\n\t\t\t\"Measurement1_#1\": {\n\t\t\t\t\"type\": \""
+ "Measurement\",\n\t\t\t\t\"raw\": [\n\t\t\t\t\t1.000000\n\t\t\t\t],\n\t\t\t\t\""
+ "unit\": \"ms\"\n\t\t\t},\n\t\t\t\"Measurement2_#1\": {\n\t\t\t\t\"type\": \""
+ "Measurement\",\n\t\t\t\t\"raw\": [\n\t\t\t\t\t2.000000\n\t\t\t\t],\n\t\t\t\t\""
+ "unit\": \"us\"\n\t\t\t},\n\t\t\t\"Level 0_#2\": {\n\t\t\t\t\"type\": \""
+ "Event\",\n\t\t\t\t\"Measurement1_#2\": {\n\t\t\t\t\t\"type\": \""
+ "Measurement\",\n\t\t\t\t\t\"raw\": [\n\t\t\t\t\t\t1.000000\n\t\t\t\t\t],\n\t\t\t\t\t\""
+ "unit\": \"ms\"\n\t\t\t\t},\n\t\t\t\t\"Measurement2_#2\": {\n\t\t\t\t\t\"type\": \""
+ "Measurement\",\n\t\t\t\t\t\"raw\": [\n\t\t\t\t\t\t2.000000\n\t\t\t\t\t],\n\t\t\t\t\t\""
+ "unit\": \"us\"\n\t\t\t\t},\n\t\t\t\t\"Level 1A_#3\": {\n\t\t\t\t\t\"type\": \""
+ "Event\",\n\t\t\t\t\t\"Measurement1_#3\": {\n\t\t\t\t\t\t\"type\": \""
+ "Measurement\",\n\t\t\t\t\t\t\"raw\": [\n\t\t\t\t\t\t\t"
+ "1.000000\n\t\t\t\t\t\t],\n\t\t\t\t\t\t\""
+ "unit\": \"ms\"\n\t\t\t\t\t},\n\t\t\t\t\t\"Measurement2_#3\": {\n\t\t\t\t\t\t\"type\": \""
+ "Measurement\",\n\t\t\t\t\t\t\"raw\": [\n\t\t\t\t\t\t\t"
+ "2.000000\n\t\t\t\t\t\t],\n\t\t\t\t\t\t\""
+ "unit\": \"us\"\n\t\t\t\t\t}\n\t\t\t\t},\n\t\t\t\t\"Level 1B_#4\": {\n\t\t\t\t\t\""
+ "type\": \"Event\",\n\t\t\t\t\t\"Measurement1_#4\": {\n\t\t\t\t\t\t\"type\": \""
+ "Measurement\",\n\t\t\t\t\t\t\"raw\": [\n\t\t\t\t\t\t\t"
+ "1.000000\n\t\t\t\t\t\t],\n\t\t\t\t\t\t\""
+ "unit\": \"ms\"\n\t\t\t\t\t},\n\t\t\t\t\t\"Measurement2_#4\": {\n\t\t\t\t\t\t\""
+ "type\": \"Measurement\",\n\t\t\t\t\t\t\"raw\": [\n\t\t\t\t\t\t\t"
+ "2.000000\n\t\t\t\t\t\t],\n\t\t\t\t\t\t\""
+ "unit\": \"us\"\n\t\t\t\t\t},\n\t\t\t\t\t\"Level 2A_#5\": {\n\t\t\t\t\t\t\""
+ "type\": \"Event\",\n\t\t\t\t\t\t\"Measurement1_#5\": {\n\t\t\t\t\t\t\t\"type\": \""
+ "Measurement\",\n\t\t\t\t\t\t\t\"raw\": [\n\t\t\t\t\t\t\t\t"
+ "1.000000\n\t\t\t\t\t\t\t],\n\t\t\t\t\t\t\t\""
+ "unit\": \"ms\"\n\t\t\t\t\t\t},\n\t\t\t\t\t\t\"Measurement2_#5\": {\n\t\t\t\t\t\t\t\""
+ "type\": \"Measurement\",\n\t\t\t\t\t\t\t\"raw\": [\n\t\t\t\t\t\t\t\t"
+ "2.000000\n\t\t\t\t\t\t\t],\n\t\t\t\t\t\t\t\""
+ "unit\": \"us\"\n\t\t\t\t\t\t}\n\t\t\t\t\t}\n\t\t\t\t}\n\t\t\t}\n\t\t}\n\t}\n}\n");
+
+ BOOST_CHECK(output == blessedOutput);
+}
+
+BOOST_AUTO_TEST_SUITE_END();
diff --git a/src/backends/backendsCommon/test/JsonPrinterTestImpl.cpp b/src/backends/backendsCommon/test/JsonPrinterTestImpl.cpp
index c7870d9..9273a79 100644
--- a/src/backends/backendsCommon/test/JsonPrinterTestImpl.cpp
+++ b/src/backends/backendsCommon/test/JsonPrinterTestImpl.cpp
@@ -199,7 +199,7 @@
return ss.str();
}
-inline void ValidateProfilerJson(std::string& result, const std::string& testData)
+inline void ValidateProfilerJson(std::string& result)
{
// ensure all measurements are greater than zero
std::vector<double> measurementsVector = ExtractMeasurements(result);
@@ -237,8 +237,6 @@
BOOST_CHECK(boost::contains(result, "ArmNN"));
BOOST_CHECK(boost::contains(result, "inference_measurements"));
- BOOST_CHECK(boost::contains(result, "layer_measurements"));
- BOOST_CHECK_EQUAL(result, testData);
// ensure no spare parenthesis present in print output
BOOST_CHECK(AreParenthesesMatching(result));
@@ -249,118 +247,18 @@
// setup the test fixture and obtain JSON Printer result
std::string result = GetSoftmaxProfilerJson(backends);
- std::string backend = "Ref";
- std::string testName = "SoftmaxWorkload_Execute";
- std::string changeLine31 = "\n},\n\"CopyMemGeneric_Execute\": {";
- std::string changeLine39 = "us\"";
- std::string changeLine40;
- std::string changeLine45;
+ // validate the JSON Printer result
+ ValidateProfilerJson(result);
const armnn::BackendId& firstBackend = backends.at(0);
if (firstBackend == armnn::Compute::GpuAcc)
{
- backend = "Cl";
- testName = "SoftmaxUintWorkload_Execute";
- changeLine31 = ",\n\"OpenClKernelTimer/: softmax_layer_max_shift_exp_sum_quantized_serial GWS[,,]\": {";
- changeLine39 = R"(us"
-},
-"OpenClKernelTimer/: softmax_layer_norm_quantized GWS[,,]": {
-"raw": [
-,
-,
-
-],
-"unit": "us")";
-
- changeLine40 = R"(
-},
-"CopyMemGeneric_Execute": {
-"raw": [
-,
-,
-
-],
-"unit": "us")";
- changeLine45 = "}\n";
+ BOOST_CHECK(boost::contains(result,
+ "OpenClKernelTimer/: softmax_layer_max_shift_exp_sum_quantized_serial GWS[,,]"));
}
else if (firstBackend == armnn::Compute::CpuAcc)
{
- backend = "Neon";
- testName = "SoftmaxUintWorkload_Execute";
- changeLine31 = ",\n\"NeonKernelTimer/: NEFillBorderKernel\": {";
- changeLine39 = R"(us"
-},
-"NeonKernelTimer/: NELogitsDMaxKernel": {
-"raw": [
-,
-,
-
-],
-"unit": "us"
-},
-"NeonKernelTimer/: NELogitsDSoftmaxKernel": {
-"raw": [
-,
-,
-
-],
-"unit": "us")";
- changeLine40 = R"(
-},
-"CopyMemGeneric_Execute": {
-"raw": [
-,
-,
-
-],
-"unit": "us")";
- changeLine45 = "}\n";
+ BOOST_CHECK(boost::contains(result,
+ "NeonKernelTimer/: NEFillBorderKernel"));
}
-
- std::string testData = R"({
-"ArmNN": {
-"inference_measurements": {
-"raw": [
-,
-,
-
-],
-"unit": "us",
-"layer_measurements": {
-"raw": [
-,
-,
-
-],
-"unit": "us",
-"CopyMemGeneric_Execute": {
-"raw": [
-,
-,
-
-],
-"unit": "us"
-},
-")" + backend + testName + R"(": {
-"raw": [
-,
-,
-
-],
-"unit": "us")" + changeLine31 + R"(
-"raw": [
-,
-,
-
-],
-"unit": ")" + changeLine39 + R"(
-})" + changeLine40 + R"(
-}
-}
-}
-}
-)" + changeLine45 + R"()";
-
- // validate the JSON Printer result
- ValidateProfilerJson(result, testData);
}