Add debug flag to print time stamps

Change-Id: I198dca8e1310f7663baeebb20f6ae2552e608e99
Signed-off-by: Lukasz Jobczyk <[email protected]>

Author: LukaszJobczyk

opencl/source/event/event.cpp

@@ -250,6 +250,19 @@ bool Event::calcProfilingData() {
             const auto timestamps = timestampPacketContainer->peekNodes();
             auto isMultiOsContextCapable = this->getCommandQueue()->getGpgpuCommandStreamReceiver().isMultiOsContextCapable();
 
+            if (DebugManager.flags.PrintTimestampPacketContents.get()) {
+                for (auto i = 0u; i < timestamps.size(); i++) {
+                    for (auto j = 0u; j < timestamps[i]->tagForCpuAccess->packetsUsed; j++) {
+                        const auto &packet = timestamps[i]->tagForCpuAccess->packets[j];
+                        std::cout << "Timestamp " << i << ", packet " << j << ": "
+                                  << "global start: " << packet.globalStart << ", "
+                                  << "global end: " << packet.globalEnd << ", "
+                                  << "context start: " << packet.contextStart << ", "
+                                  << "context end: " << packet.contextEnd << std::endl;
+                    }
+                }
+            }
+
             if (isMultiOsContextCapable) {
                 auto globalStartTS = timestamps[0]->tagForCpuAccess->packets[0].globalStart;
                 uint64_t globalEndTS = timestamps[0]->tagForCpuAccess->packets[0].globalEnd;

opencl/test/unit_test/profiling/profiling_tests.cpp

@@ -924,14 +924,16 @@ struct ProfilingTimestampPacketsTest : public ::testing::Test {
         ev->timestampPacketContainer->add(node);
     }
 
-    void addTimestampNodeMultiOsContext(int globalStart[16], int globalEnd[16], uint32_t size) {
+    void addTimestampNodeMultiOsContext(int globalStart[16], int globalEnd[16], int contextStart[16], int contextEnd[16], uint32_t size) {
         auto node = new MockTagNode<TimestampPacketStorage>();
         auto timestampPacketStorage = new TimestampPacketStorage();
         timestampPacketStorage->packetsUsed = size;
 
         for (uint32_t i = 0u; i < timestampPacketStorage->packetsUsed; ++i) {
             timestampPacketStorage->packets[i].globalStart = globalStart[i];
             timestampPacketStorage->packets[i].globalEnd = globalEnd[i];
+            timestampPacketStorage->packets[i].contextStart = contextStart[i];
+            timestampPacketStorage->packets[i].contextEnd = contextEnd[i];
         }
 
         node->tagForCpuAccess = timestampPacketStorage;
@@ -981,8 +983,10 @@ TEST_F(ProfilingTimestampPacketsTest, givenTimestampsPacketContainerWithOneEleme
 TEST_F(ProfilingTimestampPacketsTest, givenMultiOsContextCapableSetToTrueWhenCalcProfilingDataIsCalledThenCorrectedValuesAreReturned) {
     int globalStart[16] = {0};
     int globalEnd[16] = {0};
+    int contextStart[16] = {0};
+    int contextEnd[16] = {0};
     initTimestampNodeMultiOsContextData(globalStart, globalEnd, 16u);
-    addTimestampNodeMultiOsContext(globalStart, globalEnd, 16u);
+    addTimestampNodeMultiOsContext(globalStart, globalEnd, contextStart, contextEnd, 16u);
     auto &device = reinterpret_cast<MockDevice &>(cmdQ->getDevice());
     auto &csr = device.getUltCommandStreamReceiver<DEFAULT_TEST_FAMILY_NAME>();
     csr.multiOsContextCapable = true;
@@ -992,6 +996,41 @@ TEST_F(ProfilingTimestampPacketsTest, givenMultiOsContextCapableSetToTrueWhenCal
     EXPECT_EQ(350u, ev->getEndTimeStamp());
 }
 
+TEST_F(ProfilingTimestampPacketsTest, givenPrintTimestampPacketContentsSetWhenCalcProfilingDataThenTimeStampsArePrinted) {
+    DebugManagerStateRestore restorer;
+    DebugManager.flags.PrintTimestampPacketContents.set(true);
+    testing::internal::CaptureStdout();
+
+    auto &device = reinterpret_cast<MockDevice &>(cmdQ->getDevice());
+    auto &csr = device.getUltCommandStreamReceiver<DEFAULT_TEST_FAMILY_NAME>();
+    csr.multiOsContextCapable = true;
+
+    int globalStart[16] = {0};
+    int globalEnd[16] = {0};
+    int contextStart[16] = {0};
+    int contextEnd[16] = {0};
+    for (int i = 0; i < 16; i++) {
+        globalStart[i] = 2 * i;
+        globalEnd[i] = 500 * i;
+        contextStart[i] = 7 * i;
+        contextEnd[i] = 94 * i;
+    }
+    addTimestampNodeMultiOsContext(globalStart, globalEnd, contextStart, contextEnd, 16u);
+
+    ev->calcProfilingData();
+
+    std::string output = testing::internal::GetCapturedStdout();
+    std::stringstream expected;
+    for (int i = 0; i < 16; i++) {
+        expected << "Timestamp 0, packet " << i << ": "
+                 << "global start: " << globalStart[i] << ", "
+                 << "global end: " << globalEnd[i] << ", "
+                 << "context start: " << contextStart[i] << ", "
+                 << "context end: " << contextEnd[i] << std::endl;
+    }
+    EXPECT_EQ(0, output.compare(expected.str().c_str()));
+}
+
 TEST_F(ProfilingTimestampPacketsTest, givenTimestampsPacketContainerWithThreeElementsWhenCalculatingProfilingThenTimesAreTakenFromProperPacket) {
     addTimestampNode(10, 11, 12);
     addTimestampNode(1, 21, 22);

opencl/test/unit_test/test_files/igdrcl.config

@@ -67,6 +67,7 @@ PrintLWSSizes = 0
 PrintDispatchParameters = 0
 PrintProgramBinaryProcessingTime = 0
 PrintRelocations = 0
+PrintTimestampPacketContents = 0
 WddmResidencyLogger = 0
 PrintDriverDiagnostics = -1
 PrintDeviceAndEngineIdOnSubmission = 0

shared/source/debug_settings/debug_variables_base.inl

@@ -83,6 +83,7 @@ DECLARE_DEBUG_VARIABLE(bool, PrintLWSSizes, false, "prints driver choosen local
 DECLARE_DEBUG_VARIABLE(bool, PrintDispatchParameters, false, "prints dispatch paramters of kernels passed to clEnqueueNDRangeKernel")
 DECLARE_DEBUG_VARIABLE(bool, PrintProgramBinaryProcessingTime, false, "prints execution time of Program::processGenBinary() method during program building")
 DECLARE_DEBUG_VARIABLE(bool, PrintRelocations, false, "prints relocations debug information")
+DECLARE_DEBUG_VARIABLE(bool, PrintTimestampPacketContents, false, "prints all timestamps values during profiling data calculation")
 DECLARE_DEBUG_VARIABLE(bool, WddmResidencyLogger, false, "gather Wddm residency statistics to file")
 DECLARE_DEBUG_VARIABLE(int32_t, PrintDriverDiagnostics, -1, "prints driver diagnostics messages to standard output, value corresponds to hint level")
 DECLARE_DEBUG_VARIABLE(bool, PrintDeviceAndEngineIdOnSubmission, false, "print submissions device and engine IDs to standard output")