src/armnn/test/ProfilerTests.cpp

   1 //
   2 // Copyright © 2017 Arm Ltd. All rights reserved.
   3 // SPDX-License-Identifier: MIT
   4 //
   5
   6 #include <boost/test/unit_test.hpp>
   7 #include <boost/test/output_test_stream.hpp>
   8 #include <boost/algorithm/string.hpp>
   9
  10 #include <memory>
  11 #include <thread>
  12 #include <ostream>
  13
  14 #include <armnn/TypesUtils.hpp>
  15 #include <Profiling.hpp>
  16
  17 namespace armnn
  18 {
  19
  20 size_t GetProfilerEventSequenceSize(armnn::Profiler* profiler)
  21 {
  22     if (!profiler)
  23     {
  24         return static_cast<size_t>(-1);
  25     }
  26
  27     return profiler->m_EventSequence.size();
  28 }
  29 } // namespace armnn
  30
  31 namespace
  32 {
  33
  34 void RegisterUnregisterProfilerSingleThreadImpl(bool &res)
  35 {
  36     // Important! Don't use BOOST_TEST macros in this function as they
  37     // seem to have problems when used in threads
  38
  39     // Get a reference to the profiler manager.
  40     armnn::ProfilerManager& profilerManager = armnn::ProfilerManager::GetInstance();
  41
  42     // Check that there's no profiler registered for this thread.
  43     res = !profilerManager.GetProfiler();
  44
  45     // Create and register a profiler for this thread.
  46     std::unique_ptr<armnn::Profiler> profiler = std::make_unique<armnn::Profiler>();
  47     profilerManager.RegisterProfiler(profiler.get());
  48
  49     // Check that on a single thread we get the same profiler we registered.
  50     res &= profiler.get() == profilerManager.GetProfiler();
  51
  52     // Destroy the profiler.
  53     profiler.reset();
  54
  55     // Check that the profiler has been un-registered for this thread.
  56     res &= !profilerManager.GetProfiler();
  57 }
  58
  59 } // namespace
  60
  61 BOOST_AUTO_TEST_SUITE(Profiler)
  62
  63 BOOST_AUTO_TEST_CASE(EnableDisableProfiling)
  64 {
  65     std::unique_ptr<armnn::Profiler> profiler = std::make_unique<armnn::Profiler>();
  66
  67     // Check that profiling is disabled by default.
  68     BOOST_TEST(!profiler->IsProfilingEnabled());
  69
  70     // Enable profiling.
  71     profiler->EnableProfiling(true);
  72
  73     // Check that profiling is enabled.
  74     BOOST_TEST(profiler->IsProfilingEnabled());
  75
  76     // Disable profiling.
  77     profiler->EnableProfiling(false);
  78
  79     // Check that profiling is disabled.
  80     BOOST_TEST(!profiler->IsProfilingEnabled());
  81 }
  82
  83 BOOST_AUTO_TEST_CASE(RegisterUnregisterProfilerSingleThread)
  84 {
  85     bool res = false;
  86     RegisterUnregisterProfilerSingleThreadImpl(res);
  87     BOOST_TEST(res);
  88 }
  89
  90 BOOST_AUTO_TEST_CASE(RegisterUnregisterProfilerMultipleThreads)
  91 {
  92     bool res[3] = {false, false, false};
  93     std::thread thread1([&res]() { RegisterUnregisterProfilerSingleThreadImpl(res[0]); });
  94     std::thread thread2([&res]() { RegisterUnregisterProfilerSingleThreadImpl(res[1]); });
  95     std::thread thread3([&res]() { RegisterUnregisterProfilerSingleThreadImpl(res[2]); });
  96
  97     thread1.join();
  98     thread2.join();
  99     thread3.join();
 100
 101     for (int i = 0 ; i < 3 ; i++)
 102     {
 103         BOOST_TEST(res[i]);
 104     }
 105 }
 106
 107 BOOST_AUTO_TEST_CASE(ProfilingMacros)
 108 {
 109     // Get a reference to the profiler manager.
 110     armnn::ProfilerManager& profilerManager = armnn::ProfilerManager::GetInstance();
 111
 112     { // --- No profiler ---
 113
 114         // Check that there's no profiler registered for this thread.
 115         BOOST_TEST(!profilerManager.GetProfiler());
 116
 117         // Test scoped event.
 118         { ARMNN_SCOPED_PROFILING_EVENT(armnn::Compute::CpuAcc, "test"); }
 119
 120         // Check that we still cannot get a profiler for this thread.
 121         BOOST_TEST(!profilerManager.GetProfiler());
 122     }
 123
 124     // Create and register a profiler for this thread.
 125     std::unique_ptr<armnn::Profiler> profiler = std::make_unique<armnn::Profiler>();
 126     profilerManager.RegisterProfiler(profiler.get());
 127
 128     { // --- Profiler, but profiling disabled ---
 129
 130         // Get current event sequence size.
 131         size_t eventSequenceSizeBefore = armnn::GetProfilerEventSequenceSize(profiler.get());
 132
 133         // Test scoped macro.
 134         { ARMNN_SCOPED_PROFILING_EVENT(armnn::Compute::CpuAcc, "test"); }
 135
 136         // Check that no profiling event has been added to the sequence.
 137         size_t eventSequenceSizeAfter = armnn::GetProfilerEventSequenceSize(profiler.get());
 138         BOOST_TEST(eventSequenceSizeBefore == eventSequenceSizeAfter);
 139     }
 140
 141     // Enable profiling.
 142     profiler->EnableProfiling(true);
 143
 144     { // --- Profiler, and profiling enabled ---
 145
 146         // Get current event sequence size.
 147         size_t eventSequenceSizeBefore = armnn::GetProfilerEventSequenceSize(profiler.get());
 148
 149         // Test scoped macro.
 150         { ARMNN_SCOPED_PROFILING_EVENT(armnn::Compute::CpuAcc, "test"); }
 151
 152         // Check that a profiling event has been added to the sequence.
 153         size_t eventSequenceSizeAfter = armnn::GetProfilerEventSequenceSize(profiler.get());
 154         BOOST_TEST(eventSequenceSizeAfter == eventSequenceSizeBefore + 1);
 155     }
 156
 157     // Disable profiling here to not print out anything on stdout.
 158     profiler->EnableProfiling(false);
 159 }
 160
 161 #if defined(ARMNNREF_ENABLED)
 162
 163 // This test unit needs the reference backend, it's not available if the reference backend is not built
 164
 165 BOOST_AUTO_TEST_CASE(RuntimeLoadNetwork)
 166 {
 167     // Get a reference to the profiler manager.
 168     armnn::ProfilerManager& profilerManager = armnn::ProfilerManager::GetInstance();
 169
 170     // Check that there's no profiler registered for this thread.
 171     BOOST_TEST(!profilerManager.GetProfiler());
 172
 173     // Build a mock-network and load it into the runtime.
 174     armnn::IRuntime::CreationOptions options;
 175     armnn::IRuntimePtr runtime(armnn::IRuntime::Create(options));
 176     armnn::NetworkId networkIdentifier = 1;
 177     armnn::INetworkPtr mockNetwork(armnn::INetwork::Create());
 178     mockNetwork->AddInputLayer(0, "test layer");
 179     std::vector<armnn::BackendId> backends = { armnn::Compute::CpuRef };
 180     runtime->LoadNetwork(networkIdentifier, armnn::Optimize(*mockNetwork, backends, runtime->GetDeviceSpec()));
 181
 182     // Check that now there's a profiler registered for this thread (created and registered by the loading the network).
 183     BOOST_TEST(profilerManager.GetProfiler());
 184
 185     // Unload the network.
 186     runtime->UnloadNetwork(networkIdentifier);
 187
 188     // Check that the profiler has been un-registered for this thread.
 189     BOOST_TEST(!profilerManager.GetProfiler());
 190 }
 191
 192 #endif
 193
 194 BOOST_AUTO_TEST_CASE(WriteEventResults)
 195 {
 196     // Get a reference to the profiler manager.
 197     armnn::ProfilerManager& profileManager = armnn::ProfilerManager::GetInstance();
 198
 199     // Create and register a profiler for this thread.
 200     std::unique_ptr<armnn::Profiler> profiler = std::make_unique<armnn::Profiler>();
 201     profileManager.RegisterProfiler(profiler.get());
 202
 203     // Enable profiling.
 204     profiler->EnableProfiling(true);
 205
 206     { // --- Profiler, and profiling enabled ---
 207
 208         // Get current event sequence size.
 209         size_t eventSequenceSizeBefore = armnn::GetProfilerEventSequenceSize(profiler.get());
 210
 211         // Test scoped macro.
 212         {
 213             // Need to directly create a ScopedProfilingEvent as the one created by the macro falls out of scope
 214             // immediately causing the Event.Stop() function method to be called immediately after the Event.Start()
 215             // function resulting in periodic test failures on the Dent and Smith HiKeys
 216             armnn::ScopedProfilingEvent testEvent(armnn::Compute::CpuAcc, "test", armnn::WallClockTimer());
 217             std::this_thread::sleep_for(std::chrono::milliseconds(10));
 218         }
 219
 220         // Check that a profiling event has been added to the sequence.
 221         size_t eventSequenceSizeAfter = armnn::GetProfilerEventSequenceSize(profiler.get());
 222         BOOST_TEST(eventSequenceSizeAfter == eventSequenceSizeBefore + 1);
 223
 224         boost::test_tools::output_test_stream output;
 225         profiler->AnalyzeEventsAndWriteResults(output);
 226         BOOST_TEST(!output.is_empty(false));
 227
 228         // output should contain event name 'test'
 229         BOOST_CHECK(boost::contains(output.str(), "test"));
 230
 231         // output should contain headers
 232         BOOST_CHECK(boost::contains(output.str(), "Event Sequence - Name"));
 233         BOOST_CHECK(boost::contains(output.str(), "Event Stats - Name"));
 234         BOOST_CHECK(boost::contains(output.str(), "Total"));
 235         BOOST_CHECK(boost::contains(output.str(), "Device"));
 236         // output should contain compute device 'CpuAcc'
 237         BOOST_CHECK(boost::contains(output.str(), "CpuAcc"));
 238         // output should not contain un-readable numbers
 239         BOOST_CHECK(!(boost::contains(output.str(), "e+")));
 240         // output should not contain un-readable numbers
 241         BOOST_CHECK(!(boost::contains(output.str(), "+")));
 242         // output should not contain zero value
 243         BOOST_CHECK(!(boost::contains(output.str(), " 0 ")));
 244     }
 245
 246     // Disable profiling here to not print out anything on stdout.
 247     profiler->EnableProfiling(false);
 248 }
 249
 250 BOOST_AUTO_TEST_CASE(ProfilerJsonPrinter)
 251 {
 252     class TestInstrument : public armnn::Instrument
 253     {
 254     public:
 255         virtual ~TestInstrument() {}
 256         void Start() override {}
 257         void Stop() override {}
 258
 259         std::vector<armnn::Measurement> GetMeasurements() const override
 260         {
 261             std::vector<armnn::Measurement> measurements;
 262             measurements.emplace_back(armnn::Measurement("Measurement1",
 263                                                          1.0,
 264                                                          armnn::Measurement::Unit::TIME_MS));
 265             measurements.emplace_back(armnn::Measurement("Measurement2",
 266                                                          2.0,
 267                                                          armnn::Measurement::Unit::TIME_US));
 268             return measurements;
 269         }
 270
 271         const char* GetName() const override
 272         {
 273             return "TestInstrument";
 274         }
 275     };
 276
 277     // Get a reference to the profiler manager.
 278     armnn::ProfilerManager& profilerManager = armnn::ProfilerManager::GetInstance();
 279
 280     // Create and register a profiler for this thread.
 281     std::unique_ptr<armnn::Profiler> profiler = std::make_unique<armnn::Profiler>();
 282     profilerManager.RegisterProfiler(profiler.get());
 283
 284     profiler->EnableProfiling(true);
 285
 286     {
 287         // Test scoped macro.
 288         ARMNN_SCOPED_PROFILING_EVENT_WITH_INSTRUMENTS(armnn::Compute::CpuAcc, "EnqueueWorkload", TestInstrument())
 289         ARMNN_SCOPED_PROFILING_EVENT_WITH_INSTRUMENTS(armnn::Compute::CpuAcc, "Level 0", TestInstrument())
 290         {
 291             {
 292                 ARMNN_SCOPED_PROFILING_EVENT_WITH_INSTRUMENTS(armnn::Compute::CpuAcc, "Level 1A", TestInstrument())
 293             }
 294
 295             {
 296                 ARMNN_SCOPED_PROFILING_EVENT_WITH_INSTRUMENTS(armnn::Compute::CpuAcc, "Level 1B", TestInstrument())
 297
 298                 {
 299                     ARMNN_SCOPED_PROFILING_EVENT_WITH_INSTRUMENTS(armnn::Compute::CpuAcc, "Level 2A", TestInstrument())
 300                 }
 301             }
 302         }
 303     }
 304
 305     std::stringbuf buffer;
 306     std::ostream json(&buffer);
 307     profiler->Print(json);
 308
 309     std::string output = buffer.str();
 310     boost::ignore_unused(output);
 311
 312     // Disable profiling here to not print out anything on stdout.
 313     profiler->EnableProfiling(false);
 314
 315     // blessed output validated by a human eyeballing the output to make sure it's ok and then copying it here.
 316     // validation also included running the blessed output through an online json validation site
 317     std::string blessedOutput("{\n\t\"ArmNN\": {\n\t\t\"inference_measurements_#1\": {\n\t\t\t\"type\": \""
 318                               "Event\",\n\t\t\t\"Measurement1_#1\": {\n\t\t\t\t\"type\": \""
 319                               "Measurement\",\n\t\t\t\t\"raw\": [\n\t\t\t\t\t1.000000\n\t\t\t\t],\n\t\t\t\t\""
 320                               "unit\": \"ms\"\n\t\t\t},\n\t\t\t\"Measurement2_#1\": {\n\t\t\t\t\"type\": \""
 321                               "Measurement\",\n\t\t\t\t\"raw\": [\n\t\t\t\t\t2.000000\n\t\t\t\t],\n\t\t\t\t\""
 322                               "unit\": \"us\"\n\t\t\t},\n\t\t\t\"Level 0_#2\": {\n\t\t\t\t\"type\": \""
 323                               "Event\",\n\t\t\t\t\"Measurement1_#2\": {\n\t\t\t\t\t\"type\": \""
 324                               "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\""
 325                               "unit\": \"ms\"\n\t\t\t\t},\n\t\t\t\t\"Measurement2_#2\": {\n\t\t\t\t\t\"type\": \""
 326                               "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\""
 327                               "unit\": \"us\"\n\t\t\t\t},\n\t\t\t\t\"Level 1A_#3\": {\n\t\t\t\t\t\"type\": \""
 328                               "Event\",\n\t\t\t\t\t\"Measurement1_#3\": {\n\t\t\t\t\t\t\"type\": \""
 329                               "Measurement\",\n\t\t\t\t\t\t\"raw\": [\n\t\t\t\t\t\t\t"
 330                               "1.000000\n\t\t\t\t\t\t],\n\t\t\t\t\t\t\""
 331                               "unit\": \"ms\"\n\t\t\t\t\t},\n\t\t\t\t\t\"Measurement2_#3\": {\n\t\t\t\t\t\t\"type\": \""
 332                               "Measurement\",\n\t\t\t\t\t\t\"raw\": [\n\t\t\t\t\t\t\t"
 333                               "2.000000\n\t\t\t\t\t\t],\n\t\t\t\t\t\t\""
 334                               "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\""
 335                               "type\": \"Event\",\n\t\t\t\t\t\"Measurement1_#4\": {\n\t\t\t\t\t\t\"type\": \""
 336                               "Measurement\",\n\t\t\t\t\t\t\"raw\": [\n\t\t\t\t\t\t\t"
 337                               "1.000000\n\t\t\t\t\t\t],\n\t\t\t\t\t\t\""
 338                               "unit\": \"ms\"\n\t\t\t\t\t},\n\t\t\t\t\t\"Measurement2_#4\": {\n\t\t\t\t\t\t\""
 339                               "type\": \"Measurement\",\n\t\t\t\t\t\t\"raw\": [\n\t\t\t\t\t\t\t"
 340                               "2.000000\n\t\t\t\t\t\t],\n\t\t\t\t\t\t\""
 341                               "unit\": \"us\"\n\t\t\t\t\t},\n\t\t\t\t\t\"Level 2A_#5\": {\n\t\t\t\t\t\t\""
 342                               "type\": \"Event\",\n\t\t\t\t\t\t\"Measurement1_#5\": {\n\t\t\t\t\t\t\t\"type\": \""
 343                               "Measurement\",\n\t\t\t\t\t\t\t\"raw\": [\n\t\t\t\t\t\t\t\t"
 344                               "1.000000\n\t\t\t\t\t\t\t],\n\t\t\t\t\t\t\t\""
 345                               "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\""
 346                               "type\": \"Measurement\",\n\t\t\t\t\t\t\t\"raw\": [\n\t\t\t\t\t\t\t\t"
 347                               "2.000000\n\t\t\t\t\t\t\t],\n\t\t\t\t\t\t\t\""
 348                               "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");
 349
 350     BOOST_CHECK(output == blessedOutput);
 351 }
 352
 353 BOOST_AUTO_TEST_SUITE_END();