Ability to log performance makers to ftrace for Tizen SPI tool
authorNick Holland <nick.holland@partner.samsung.com>
Fri, 21 Feb 2014 14:13:44 +0000 (14:13 +0000)
committerPaul Wisbey <p.wisbey@samsung.com>
Mon, 3 Mar 2014 18:59:38 +0000 (18:59 +0000)
[Issue] N/A

[Problem]
When using ftrace to analyse what the system is doing there is no way to see
what task Dali is doing. E.g. when does it start running its update-thread
in relation to the V-SYNC and event processing.

[Cause] No code

[Solution]

Added extra bitmask option to DALI_LOG_PERFORMANCE environment variable,
Example:

DALI_LOG_PERFORMANCE=4 dali-demo

cat /sys/kernel/debug/tracing/trace

 TASK-PID    CPU#    TIMESTAMP  FUNCTION

  <...>-28189 [001] 269275.222762: tracing_mark_write: SPI_EV_DALI_PROCESS_EVENT_START
  <...>-28189 [001] 269275.222812: tracing_mark_write: SPI_EV_DALI_PROCESS_EVENT_END
  <...>-28196 [000] 269275.239498: tracing_mark_write: SPI_EV_DALI_V_SYNC
  <...>-28194 [005] 269275.239527: tracing_mark_write: SPI_EV_DALI_UPDATE_START
  <...>-28194 [005] 269275.240401: tracing_mark_write: SPI_EV_DALI_UPDATE_END
  <...>-28196 [000] 269275.256192: tracing_mark_write: SPI_EV_DALI_V_SYNC
  <...>-28194 [005] 269275.256228: tracing_mark_write: SPI_EV_DALI_UPDATE_START
  <...>-28194 [005] 269275.256330: tracing_mark_write: SPI_EV_DALI_UPDATE_END

The SPI_EV_ prefix is added to allow SPI tool to detect the markers.

Change-Id: Idec9714308aa19a9f1ef509057f6ba7d227c4649

14 files changed:
adaptors/base/interfaces/adaptor-internal-services.h
adaptors/base/interfaces/kernel-trace-interface.h [new file with mode: 0644]
adaptors/base/interfaces/performance-interface.h
adaptors/base/performance-logging/performance-interface-factory.cpp
adaptors/base/performance-logging/performance-interface-factory.h
adaptors/base/performance-logging/performance-marker.cpp
adaptors/base/performance-logging/performance-marker.h
adaptors/base/performance-logging/performance-server.cpp
adaptors/base/performance-logging/performance-server.h
adaptors/tizen/internal/common/adaptor-impl.cpp
adaptors/tizen/internal/common/adaptor-impl.h
adaptors/tizen/internal/common/file.list
adaptors/tizen/internal/common/kernel-trace.cpp [new file with mode: 0644]
adaptors/tizen/internal/common/kernel-trace.h [new file with mode: 0644]

index 88700ec0f18a07f16b6b82b07e1b4a43be37a494..b9a2d0d45848083fd8848010440594b6fa423894 100644 (file)
@@ -25,6 +25,7 @@
 #include <base/interfaces/trigger-event-interface.h>
 #include <base/interfaces/performance-interface.h>
 #include <base/interfaces/vsync-monitor-interface.h>
+#include <base/interfaces/kernel-trace-interface.h>
 #include <internal/common/render-surface-impl.h> // @todo move to base/interfaces
 
 
@@ -88,6 +89,10 @@ public:
    */
   virtual PerformanceInterface* GetPerformanceInterface()  = 0;
 
+  /**
+   * @return kernel trace interface
+   */
+  virtual KernelTraceInterface& GetKernelTraceInterface()  = 0;
 
 protected:
 
diff --git a/adaptors/base/interfaces/kernel-trace-interface.h b/adaptors/base/interfaces/kernel-trace-interface.h
new file mode 100644 (file)
index 0000000..29290d8
--- /dev/null
@@ -0,0 +1,77 @@
+#ifndef __DALI_INTERNAL_BASE_KERNEL_TRACE_INTERFACE_H__
+#define __DALI_INTERNAL_BASE_KERNEL_TRACE_INTERFACE_H__
+
+//
+// Copyright (c) 2014 Samsung Electronics Co., Ltd.
+//
+// Licensed under the Flora License, Version 1.0 (the License);
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://floralicense.org/license/
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an AS IS BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+//
+
+#include <string>
+
+namespace Dali
+{
+
+namespace Internal
+{
+
+namespace Adaptor
+{
+
+/**
+ * Abstract Kernel Tracing Interface.
+ * Used to log trace messages to the kernel.
+ * E.g. On Linux this will use ftrace
+ *
+ */
+class KernelTraceInterface
+{
+
+public:
+
+  /**
+   * Write a trace message
+   * @param traceMessage trace message
+   */
+  virtual void Trace( const std::string& traceMessage ) = 0;
+
+protected:
+
+  /**
+   * Constructor
+   */
+  KernelTraceInterface()
+  {
+  }
+
+  /**
+   * virtual destructor
+   */
+  virtual ~KernelTraceInterface()
+  {
+  }
+
+  // Undefined copy constructor.
+  KernelTraceInterface( const KernelTraceInterface& );
+
+  // Undefined assignment operator.
+  KernelTraceInterface& operator=( const KernelTraceInterface& );
+};
+
+} // namespace Internal
+
+} // namespace Adaptor
+
+} // namespace Dali
+
+#endif
index cc6ebf4a1235000479eb097e256f6320367dc146..f0ef12c4495175ae8ef68cf23dc3481c2cab50e8 100644 (file)
@@ -44,9 +44,10 @@ public:
    */
   enum LogLevel
   {
-    DISABLED          = 0,
-    LOG_UPDATE_RENDER = 1 << 0, ///< Bit 0, log update and render times
-    LOG_EVENT_PROCESS = 1 << 1, ///< Bit 1, log event process times
+    DISABLED             = 0,
+    LOG_UPDATE_RENDER    = 1 << 0, ///< Bit 0, log update and render times
+    LOG_EVENT_PROCESS    = 1 << 1, ///< Bit 1, log event process times
+    LOG_EVENTS_TO_KERNEL = 1 << 2, ///< Bit 2, log all events to kernel trace
   };
 
   /**
index 978b28740fa60763b9f89d8ec440484ca2b533f6..eae83b9d3b78d050c5e3b95bc43820ce42a2edf9 100644 (file)
@@ -28,10 +28,10 @@ namespace Adaptor
 {
 
 PerformanceInterface* PerformanceInterfaceFactory::CreateInterface(
-                                 Integration::PlatformAbstraction& platformAbstraction,
+                                 AdaptorInternalServices& adaptorServices,
                                  const LogOptions& logOptions  )
 {
-  return new PerformanceServer( platformAbstraction, logOptions );
+  return new PerformanceServer( adaptorServices, logOptions );
 }
 
 
index 311f700aebf4c187c86f8e06d3a70b501c0c3c51..f32ac80c386d8d7010b7b1f8975c2b47868ac1f0 100644 (file)
@@ -18,8 +18,7 @@
 //
 
 // INTERNAL INCLUDES
-#include <base/interfaces/performance-interface.h>
-#include <dali/integration-api/platform-abstraction.h>
+#include <base/interfaces/adaptor-internal-services.h>
 #include <dali/integration-api/debug.h>
 #include <base/log-options.h>
 
@@ -42,11 +41,11 @@ public:
 
   /**
    * Create a new concrete implementation of the performance interface.
-   * @param platformAbstraction platform abstraction
+   * @param adaptorServices adaptor internal services
    * @param logOptions log options
    * @return pointer to a new performance interface
    */
-  static PerformanceInterface* CreateInterface( Integration::PlatformAbstraction& platformAbstraction,
+  static PerformanceInterface* CreateInterface( AdaptorInternalServices& adaptorServices,
                                                 const LogOptions& logOptions );
 
 };
index 0201e6e6910617c89b4ee01418df89c45ea4aed4..4f003ed3f6b577408f56caf9935b2f85d8618652 100644 (file)
@@ -26,6 +26,30 @@ namespace Internal
 namespace Adaptor
 {
 
+namespace
+{
+
+struct NamePair
+{
+  PerformanceMarker::MarkerType type;
+  const char* name;
+};
+
+const NamePair MarkerLookup[] =
+{
+    { PerformanceMarker::V_SYNC       ,        "V_SYNC"                },
+    { PerformanceMarker::UPDATE_START ,        "UPDATE_START"          },
+    { PerformanceMarker::UPDATE_END   ,        "UPDATE_END"            },
+    { PerformanceMarker::RENDER_START ,        "RENDER_START"          },
+    { PerformanceMarker::RENDER_END   ,        "RENDER_END"            },
+    { PerformanceMarker::SWAP_START   ,        "SWAP_START"            },
+    { PerformanceMarker::SWAP_END     ,        "SWAP_END"              },
+    { PerformanceMarker::PROCESS_EVENTS_START, "PROCESS_EVENT_START"   },
+    { PerformanceMarker::PROCESS_EVENTS_END,   "PROCESS_EVENT_END"     },
+    { PerformanceMarker::PAUSED       ,        "PAUSED"                },
+    { PerformanceMarker::RESUME       ,        "RESUMED"               }
+};
+}
 PerformanceMarker::PerformanceMarker( MarkerType type )
 :mType(type)
 {
@@ -37,6 +61,11 @@ PerformanceMarker::PerformanceMarker( MarkerType type, FrameTimeStamp frameInfo
 {
 }
 
+const char* PerformanceMarker::GetName( ) const
+{
+  return MarkerLookup[ mType ].name;
+}
+
 unsigned int PerformanceMarker::MicrosecondDiff( const PerformanceMarker& start,const PerformanceMarker& end )
 {
   return FrameTimeStamp::MicrosecondDiff( start.mTimeStamp, end.mTimeStamp );
index 51db6b3fa73c6e7bc0e4d4acf28b7d91a39ad21c..d563a20c5b4c4bc4786dda4d65dec40b4278f451 100644 (file)
@@ -37,11 +37,13 @@ class PerformanceMarker
 public:
 
   /**
-   * enum for difference performance markers
+   * enum for difference performance markers.
+   * Please modify the name lookup table in performance-marker.cpp
+   * file if adding new markers.
    */
   enum MarkerType
   {
-      V_SYNC       ,        ///< V-Sync
+      V_SYNC    = 0,        ///< V-Sync
       UPDATE_START ,        ///< Update start
       UPDATE_END   ,        ///< Update end
       RENDER_START ,        ///< Render start
@@ -83,6 +85,11 @@ public:
     return mType;
   }
 
+  /**
+   * @return the name of the marker
+   */
+  const char* GetName() const;
+
   /**
    * @param start the start marker
    * @param end the end marker
index fde773c51e78e65074924173630e2fda840a3bbb..b15cb2d3ccf293a1591d0aef98b4b9cd1e273e7e 100644 (file)
@@ -41,13 +41,14 @@ const unsigned int MICROSECONDS_PER_SECOND = 1000000; ///< 1000000 microseconds
 }
 
 
-PerformanceServer::PerformanceServer( Integration::PlatformAbstraction& platformAbstraction,
+PerformanceServer::PerformanceServer( AdaptorInternalServices& adaptorServices,
                                       const LogOptions& logOptions)
 :mLoggingEnabled( false),
  mLogFunctionInstalled( false ),
  mLogFrequencyMicroseconds( 0),
- mPlatformAbstraction( platformAbstraction ),
- mLogOptions(logOptions)
+ mPlatformAbstraction( adaptorServices.GetPlatformAbstractionInterface() ),
+ mLogOptions(logOptions),
+ mKernelTrace( adaptorServices.GetKernelTraceInterface() )
 {
   SetLogging( mLogOptions.GetPerformanceLoggingLevel(), mLogOptions.GetFrameRateLoggingFrequency());
 }
@@ -105,6 +106,11 @@ void PerformanceServer::AddMarkerToLog( PerformanceMarker marker )
   // store the marker
   mMarkers.PushBack( marker );
 
+  if( mLogLevel & LOG_EVENTS_TO_KERNEL )
+  {
+    mKernelTrace.Trace(marker.GetName());
+  }
+
   // only log on the v-sync thread, so we have less impact on update/render
   if( marker.GetType() != PerformanceMarker::V_SYNC )
   {
index 8c06becc74e8d91dd6260b064466820c40dc51f6..06b6ad51c5078f1609cc1cdaf52161fa5983bd45 100644 (file)
 //
 
 // INTERNAL INCLUDES
-#include <base/interfaces/performance-interface.h>
 #include <base/performance-logging/frame-time-stats.h>
 #include <dali/public-api/common/dali-vector.h>
-#include <dali/integration-api/platform-abstraction.h>
+#include <base/interfaces/adaptor-internal-services.h>
 
 // EXTERNAL INCLUDES
 #include <boost/thread/mutex.hpp>
@@ -48,10 +47,10 @@ public:
 
   /**
    * Constructor
-   * @param platformAbstraction platform abstraction
+   * @param adaptorServices adaptor internal services
    * @param logOptions log options
    */
-  PerformanceServer( Integration::PlatformAbstraction& platformAbstraction,
+  PerformanceServer( AdaptorInternalServices& adaptorServices,
                      const LogOptions& logOptions );
 
   /**
@@ -105,6 +104,7 @@ private:
   MarkerVector mMarkers;              ///< vector of markers
   boost::mutex mDataMutex;            ///< mutex
   const LogOptions& mLogOptions;      ///< log options
+  KernelTraceInterface& mKernelTrace; ///< kernel trace interface
 
 };
 
index f1635a6d94e0e45b0dff13d2a3fbc12e04006d1e..7c82bbdc951bb18621f0e4ceea12dd37fce38f26 100644 (file)
@@ -120,7 +120,7 @@ void Adaptor::Initialize()
 
   if( mLogOptions.GetPerformanceLoggingLevel() > 0 )
   {
-    mPerformanceInterface = PerformanceInterfaceFactory::CreateInterface( *mPlatformAbstraction, mLogOptions );
+    mPerformanceInterface = PerformanceInterfaceFactory::CreateInterface( *this, mLogOptions );
   }
 
   mCallbackManager = CallbackManager::New();
@@ -562,6 +562,11 @@ VSyncMonitorInterface* Adaptor::GetVSyncMonitorInterface()
   return mVSyncMonitor;
 }
 
+KernelTraceInterface& Adaptor::GetKernelTraceInterface()
+{
+  return mKernelTracer;
+}
+
 PerformanceInterface* Adaptor::GetPerformanceInterface()
 {
   return mPerformanceInterface;
index 406ed8d52c06e1eb32f45bbdf5915089706b1bdf..ac5b60fbb9d4f5621e63ceecbf65660f423f49bf 100644 (file)
@@ -42,6 +42,7 @@
 #include <internal/common/drag-and-drop-detector-impl.h>
 #include <internal/common/damage-observer.h>
 #include <internal/common/window-visibility-observer.h>
+#include <internal/common/kernel-trace.h>
 
 namespace Dali
 {
@@ -294,43 +295,48 @@ public:
    */
   void NotifyLanguageChanged();
 
-public:  //BaseAdaptorInterfaces
+public:  //AdaptorInternalServices
 
   /**
-   * @copydoc Dali::Internal::Adaptor::BaseAdaptorInterface::GetPlatformAbstractionInterface()
+   * @copydoc Dali::Internal::Adaptor::AdaptorInternalServices::GetPlatformAbstractionInterface()
    */
   virtual Dali::Integration::PlatformAbstraction& GetPlatformAbstractionInterface();
 
   /**
-   * @copydoc Dali::Internal::Adaptor::BaseAdaptorInterface::GetGlesInterface()
+   * @copydoc Dali::Internal::Adaptor::AdaptorInternalServices::GetGlesInterface()
    */
   virtual Dali::Integration::GlAbstraction& GetGlesInterface();
 
   /**
-  * @copydoc Dali::Internal::Adaptor::BaseAdaptorInterface::GetEGLFactoryInterface()
+  * @copydoc Dali::Internal::Adaptor::AdaptorInternalServices::GetEGLFactoryInterface()
   */
   virtual EglFactoryInterface& GetEGLFactoryInterface() const;
 
   /**
-   * @copydoc Dali::Internal::Adaptor::BaseAdaptorInterface::GetTriggerEventInterface()
+   * @copydoc Dali::Internal::Adaptor::AdaptorInternalServices::GetTriggerEventInterface()
    */
   virtual TriggerEventInterface& GetTriggerEventInterface();
 
   /**
-   * @copydoc Dali::Internal::Adaptor::BaseAdaptorInterface::GetRenderSurfaceInterface()
+   * @copydoc Dali::Internal::Adaptor::AdaptorInternalServices::GetRenderSurfaceInterface()
    */
   virtual RenderSurface* GetRenderSurfaceInterface();
 
   /**
-   * @copydoc Dali::Internal::Adaptor::BaseAdaptorInterface::GetVSyncMonitorInterface()
+   * @copydoc Dali::Internal::Adaptor::AdaptorInternalServices::GetVSyncMonitorInterface()
    */
   virtual VSyncMonitorInterface* GetVSyncMonitorInterface();
 
   /**
-   * @copydoc Dali::Internal::Adaptor::BaseAdaptorInterface::GetPerformanceInterface()
+   * @copydoc Dali::Internal::Adaptor::AdaptorInternalServices::GetPerformanceInterface()
    */
   virtual PerformanceInterface* GetPerformanceInterface();
 
+  /**
+   * copydoc Dali::Internal::Adaptor::AdaptorInternalServices::GetKernelTraceInterface()
+   */
+  virtual KernelTraceInterface& GetKernelTraceInterface();
+
 public: // Signals
 
   /**
@@ -481,6 +487,7 @@ private: // Data
   DeviceLayout                          mBaseLayout;                  ///< The base layout of the application
   LogOptions                            mLogOptions;                  ///< log options
   PerformanceInterface*                 mPerformanceInterface;        ///< Performance interface
+  KernelTrace                           mKernelTracer;
 public:
   inline static Adaptor& GetImplementation(Dali::Adaptor& adaptor) {return *adaptor.mImpl;}
 };
index 9155d59839927c9446a4d15959d75fe09f2fb971..5c4bb98fd55afd8cf44cae06588958002d068fc2 100644 (file)
@@ -13,6 +13,7 @@ tizen_adaptor_internal_common_src_files = \
   $(tizen_adaptor_internal_src_dir)/imf-manager-impl.cpp \
   $(tizen_adaptor_internal_src_dir)/indicator-impl.cpp  \
   $(tizen_adaptor_internal_src_dir)/indicator-buffer.cpp  \
+  $(tizen_adaptor_internal_src_dir)/kernel-trace.cpp  \
   $(tizen_adaptor_internal_src_dir)/key-impl.cpp  \
   $(tizen_adaptor_internal_src_dir)/locale-utils.cpp  \
   $(tizen_adaptor_internal_src_dir)/native-bitmap-buffer-impl.cpp \
diff --git a/adaptors/tizen/internal/common/kernel-trace.cpp b/adaptors/tizen/internal/common/kernel-trace.cpp
new file mode 100644 (file)
index 0000000..a290ca0
--- /dev/null
@@ -0,0 +1,112 @@
+//
+// Copyright (c) 2014 Samsung Electronics Co., Ltd.
+//
+// Licensed under the Flora License, Version 1.0 (the License);
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://floralicense.org/license/
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an AS IS BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+//
+
+// CLASS HEADER
+#include "kernel-trace.h"
+
+// INTERNAL HEADERS
+#include <dali/integration-api/debug.h>
+
+// EXTERNAL HEADERS
+#include <fcntl.h>
+#include <stdio.h>
+
+
+namespace Dali
+{
+
+namespace Internal
+{
+
+namespace Adaptor
+{
+
+namespace
+{
+const char* TRACE_MARKER_FILE = "/sys/kernel/debug/tracing/trace_marker";
+const char* SPI_PREFIX = "SPI_EV_DALI_"; ///< prefix to let the SPI tool know it should read the trace
+}// un-named name space
+
+KernelTrace::KernelTrace()
+: mFileDescriptor( 0 ),
+  mLoggedError( false )
+{
+}
+
+KernelTrace::~KernelTrace()
+{
+  if( mFileDescriptor )
+  {
+    close( mFileDescriptor );
+  }
+}
+
+// If this function doesn't appear to work, you can test manually on the device.
+// $ cd /sys/kernel/debug/tracing
+//
+// If the folder doesn't exist then the kernel needs to be re-built with ftrace enabled
+// If it does exist, then you can continue to test ftrace is working:
+//
+// $ echo 1 > tracing_enabled
+// $ echo "test" > trace_marker
+// $ cat trace
+// should print out test message
+// If the message did not get added to the trace, then check you have write permissions to the trace_marker file.
+//
+//
+void KernelTrace::Trace( const std::string& traceMessage )
+{
+  // Open the trace_marker file
+  if( mFileDescriptor == 0 )
+  {
+    mFileDescriptor = open( TRACE_MARKER_FILE , O_WRONLY);
+    if( mFileDescriptor == -1 )
+    {
+      // we want to keep trying to open it, so it will start working if someone fixes
+      // the permissions on the trace marker
+      mFileDescriptor = 0;
+
+      // first time we fail to open the file, log an error
+      if( !mLoggedError )
+      {
+        mLoggedError = true;
+        DALI_LOG_ERROR("Failed to open /sys/kernel/debug/tracing/trace_marker for writing please check file permissions.");
+      }
+
+    }
+  }
+
+  if( mFileDescriptor > 0 )
+  {
+      std::string msg( SPI_PREFIX );
+      msg+=traceMessage;
+
+      int ret = write( mFileDescriptor, msg.c_str(), msg.length() );
+          // if it failed then close the file description and try again next time we trace
+      if( ret < 0 )
+      {
+        close( mFileDescriptor );
+        mFileDescriptor = 0;
+      }
+  }
+}
+
+} // namespace Internal
+
+} // namespace Adaptor
+
+} // namespace Dali
+
diff --git a/adaptors/tizen/internal/common/kernel-trace.h b/adaptors/tizen/internal/common/kernel-trace.h
new file mode 100644 (file)
index 0000000..c3d50ca
--- /dev/null
@@ -0,0 +1,68 @@
+#ifndef __DALI_INTERNAL_ADAPTOR_KERNEL_TRACE_H__
+#define __DALI_INTERNAL_ADAPTOR_KERNEL_TRACE_H__
+
+//
+// Copyright (c) 2014 Samsung Electronics Co., Ltd.
+//
+// Licensed under the Flora License, Version 1.0 (the License);
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://floralicense.org/license/
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an AS IS BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+//
+
+#include <base/interfaces/kernel-trace-interface.h>
+
+namespace Dali
+{
+
+namespace Internal
+{
+
+namespace Adaptor
+{
+
+/**
+ * Concrete Kernel Tracing Interface.
+ * Used to log trace messages to the kernel using ftrace.
+ *
+ */
+class KernelTrace : public KernelTraceInterface
+{
+public:
+
+  /**
+   * Constructor
+   */
+  KernelTrace();
+
+  /**
+   * Destructor
+   */
+  virtual ~KernelTrace();
+
+  /**
+   * @copydoc KernelTracerInterface::KernelTrace()
+   */
+  virtual void Trace( const std::string& traceMessage );
+
+private:
+
+  int mFileDescriptor;
+  bool mLoggedError:1;
+
+};
+
+} // namespace Internal
+
+} // namespace Adaptor
+
+} // namespace Dali
+
+#endif // __DALI_INTERNAL_ADAPTOR_KERNEL_TRACE_H__