DOMX: framework to dynamically enable/disable perf trace + OMX buffer events trace

Added framework to control activation of perf trace:
- set DEBUG_DOMX_KPI_STATUS environment variable
- or set debug.domx.kpi_status android property. Env variable takes precedence

kpi_status is a bitfield to control enabling of various perf traces.
Currently only OMX buffers events are available with bitfield value of 1. It will
trace EmptyThisBuffer, FillThisBuffer, EmptyBufferDone, FillBufferDone.
It is aligned with Ducati equivalent trace. Enabling the 2 allows computing
MPU<->Ducati latency

Following parameters are included for each message:
- message type: ETB, FTB, EBD, FBD
- OMX component name: DECODE, H264E, CAMERA, ...
- number of such requests for this component
- time in us, from clock_gettime(CLOCK_MONOTONIC, ...)
- Remote buffer header to match Ducati trace
- FBD nTimeStamp metadata to identify an FBD buffer among framework SW layers

visual post-processing is described at
http://opbuwiki.dal.design.ti.com/index.php/Benelli-Ducati_performance_instrumentation
It is the same for MPU or Ducati trace

Example:
- setprop debug.domx.trace_level 3 (perf trace is trace level >= 3)
- setprop debug.domx.kpi_status 1
- logcat DOMX:D *:S

Change-Id: I3b8a996fb861ba84a9f96c98285a30209880423a
Signed-off-by: Frederic Turgis <f-turgis@ti.com>

5 files changed, 407 insertions, 3 deletions

diff --git a/domx/Android.mk b/domx/Android.mk
index 0997db5..b3e9c68 100644
--- a/domx/Android.mk
+++ b/domx/Android.mk
@@ -8,12 +8,14 @@ LOCAL_SRC_FILES:= \
     omx_rpc/src/omx_rpc_stub.c \
     omx_rpc/src/omx_rpc_config.c \
     omx_rpc/src/omx_rpc_platform.c \
-    omx_proxy_common/src/omx_proxy_common.c
+    omx_proxy_common/src/omx_proxy_common.c \
+    profiling/src/profile.c
 
 LOCAL_C_INCLUDES += \
     $(LOCAL_PATH)/omx_rpc/inc \
     $(LOCAL_PATH)/../omx_core/inc \
     $(LOCAL_PATH)/../mm_osal/inc \
+    $(LOCAL_PATH)/profiling/inc \
     $(HARDWARE_TI_OMAP4_BASE)/hwc/ \
     $(HARDWARE_TI_OMAP4_BASE)/ion/ \
     system/core/include/cutils \
@@ -26,7 +28,8 @@ LOCAL_SHARED_LIBRARIES := \
     libmm_osal \
     libc \
     liblog \
-    libion
+    libion \
+    libcutils
 
 LOCAL_MODULE:= libdomx
 LOCAL_MODULE_TAGS:= optional
diff --git a/domx/Makefile b/domx/Makefile
index 72bdf06..cab0b80 100644
--- a/domx/Makefile
+++ b/domx/Makefile
@@ -71,7 +71,8 @@ SOURCES     = \
 omx_rpc/src/omx_rpc.c \
 omx_rpc/src/omx_rpc_skel.c \
 omx_rpc/src/omx_rpc_stub.c \
-omx_proxy_common/src/omx_proxy_common.c
+omx_proxy_common/src/omx_proxy_common.c \
+profiling/profile.c
 # The below files are currently empty, so removed them from building
 # omx_rpc/src/omx_rpc_config.c \
 # omx_rpc/src/omx_rpc_platform.c \
diff --git a/domx/omx_proxy_common/src/omx_proxy_common.c b/domx/omx_proxy_common/src/omx_proxy_common.c
index 3aa03c9..119cf04 100644
--- a/domx/omx_proxy_common/src/omx_proxy_common.c
+++ b/domx/omx_proxy_common/src/omx_proxy_common.c
@@ -70,6 +70,7 @@
 #include "omx_rpc_stub.h"
 #include "omx_rpc_utils.h"
 #include "OMX_TI_IVCommon.h"
+#include "profile.h"
 
 #ifdef ALLOCATE_TILER_BUFFER_IN_PROXY
 
@@ -379,6 +380,8 @@ static OMX_ERRORTYPE PROXY_EmptyBufferDone(OMX_HANDLETYPE hComponent,
 	    OMX_ErrorBadParameter,
 	    "Received invalid-buffer header from OMX component");
 
+	KPI_OmxCompBufferEvent(KPI_BUFFER_EBD, hComponent, &(pCompPrv->tBufList[count]));
+
       EXIT:
 	if (eError == OMX_ErrorNone)
 	{
@@ -454,6 +457,8 @@ OMX_ERRORTYPE PROXY_FillBufferDone(OMX_HANDLETYPE hComponent,
 	    OMX_ErrorBadParameter,
 	    "Received invalid-buffer header from OMX component");
 
+	KPI_OmxCompBufferEvent(KPI_BUFFER_FBD, hComponent, &(pCompPrv->tBufList[count]));
+
       EXIT:
 	if (eError == OMX_ErrorNone)
 	{
@@ -557,6 +562,9 @@ OMX_ERRORTYPE PROXY_EmptyThisBuffer(OMX_HANDLETYPE hComponent,
 	bMapBuffer =
 		pCompPrv->proxyPortBuffers[pBufferHdr->nInputPortIndex].proxyBufferType ==
 			EncoderMetadataPointers;
+
+	KPI_OmxCompBufferEvent(KPI_BUFFER_ETB, hComponent, &(pCompPrv->tBufList[count]));
+
 	eRPCError =
 	    RPC_EmptyThisBuffer(pCompPrv->hRemoteComp, pBufferHdr,
 	    pCompPrv->tBufList[count].pBufHeaderRemote, &eCompReturn,bMapBuffer);
@@ -628,6 +636,8 @@ OMX_ERRORTYPE PROXY_FillThisBuffer(OMX_HANDLETYPE hComponent,
 	    OMX_ErrorBadParameter,
 	    "Could not find the remote header in buffer list");
 
+	KPI_OmxCompBufferEvent(KPI_BUFFER_FTB, hComponent, &(pCompPrv->tBufList[count]));
+
 	eRPCError = RPC_FillThisBuffer(pCompPrv->hRemoteComp, pBufferHdr,
 	    pCompPrv->tBufList[count].pBufHeaderRemote, &eCompReturn);
 
@@ -2163,6 +2173,8 @@ OMX_ERRORTYPE PROXY_ComponentDeInit(OMX_HANDLETYPE hComponent)
 		}
 	}
 
+	KPI_OmxCompDeinit(hComponent);
+
 	eRPCError = RPC_FreeHandle(pCompPrv->hRemoteComp, &eCompReturn);
 	if (eRPCError != RPC_OMX_ErrorNone)
 		eTmpRPCError = eRPCError;
@@ -2275,6 +2287,8 @@ OMX_ERRORTYPE OMX_ProxyCommonInit(OMX_HANDLETYPE hComponent)
 	}
 #endif
 
+	KPI_OmxCompInit(hComponent);
+
       EXIT:
 	if (eError != OMX_ErrorNone)
 		RPC_InstanceDeInit(hRemoteComp);
diff --git a/domx/profiling/inc/profile.h b/domx/profiling/inc/profile.h
new file mode 100644
index 0000000..352a91c
--- /dev/null
+++ b/domx/profiling/inc/profile.h
@@ -0,0 +1,87 @@
+/*
+ * Copyright (c) 2010, Texas Instruments Incorporated
+ * All rights reserved.
+ *
+ * Redistribution and use in source and binary forms, with or without
+ * modification, are permitted provided that the following conditions
+ * are met:
+ *
+ * *  Redistributions of source code must retain the above copyright
+ *    notice, this list of conditions and the following disclaimer.
+ *
+ * *  Redistributions in binary form must reproduce the above copyright
+ *    notice, this list of conditions and the following disclaimer in the
+ *    documentation and/or other materials provided with the distribution.
+ *
+ * *  Neither the name of Texas Instruments Incorporated nor the names of
+ *    its contributors may be used to endorse or promote products derived
+ *    from this software without specific prior written permission.
+ *
+ * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
+ * AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO,
+ * THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
+ * PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR
+ * CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL,
+ * EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO,
+ * PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS;
+ * OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY,
+ * WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR
+ * OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE,
+ * EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+ */
+
+/*
+*  @file profile.h
+*  The header file defines the trace events definitions.
+*  @path platform\hardware\ti\domx\domx\profiling\inc\
+*
+*/
+/* -------------------------------------------------------------------------- */
+/* =========================================================================
+ *!
+ *! Revision History
+ *! ===================================
+ *! 1.0: Created the first draft version
+ * ========================================================================= */
+
+#ifndef _PROFILE_H_
+#define _PROFILE_H_
+
+#ifdef __cplusplus
+extern "C"
+{
+#endif /* #ifdef __cplusplus */
+
+#include <OMX_Types.h>
+#include <OMX_Component.h>
+
+#include "omx_rpc_utils.h"
+#include "omx_proxy_common.h"
+
+enum KPI_BUFFER_EVENT {
+        KPI_BUFFER_ETB = 1,
+        KPI_BUFFER_FTB = 2,
+        KPI_BUFFER_EBD = 3,
+        KPI_BUFFER_FBD = 4
+};
+
+/**
+ * OMX monitoring component init. Registers component
+ */
+void KPI_OmxCompInit(OMX_HANDLETYPE hComponent);
+
+/**
+ * OMX monitoring component deinit. Unregisters component
+ */
+void KPI_OmxCompDeinit(OMX_HANDLETYPE hComponent);
+
+/**
+ * OMA monitoring buffer event trace. Traces FTB/ETB/FBD/EBD event
+ */
+void KPI_OmxCompBufferEvent(enum KPI_BUFFER_EVENT event, OMX_HANDLETYPE hComponent, PROXY_BUFFER_INFO* pBuffer);
+
+#ifdef __cplusplus
+}
+#endif /* #ifdef __cplusplus */
+
+#endif /* #ifndef _PROFILE_H_ */
diff --git a/domx/profiling/src/profile.c b/domx/profiling/src/profile.c
new file mode 100644
index 0000000..bc050b7
--- /dev/null
+++ b/domx/profiling/src/profile.c
@@ -0,0 +1,299 @@
+/*
+ * Copyright (c) 2010, Texas Instruments Incorporated
+ * All rights reserved.
+ *
+ * Redistribution and use in source and binary forms, with or without
+ * modification, are permitted provided that the following conditions
+ * are met:
+ *
+ * *  Redistributions of source code must retain the above copyright
+ *    notice, this list of conditions and the following disclaimer.
+ *
+ * *  Redistributions in binary form must reproduce the above copyright
+ *    notice, this list of conditions and the following disclaimer in the
+ *    documentation and/or other materials provided with the distribution.
+ *
+ * *  Neither the name of Texas Instruments Incorporated nor the names of
+ *    its contributors may be used to endorse or promote products derived
+ *    from this software without specific prior written permission.
+ *
+ * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
+ * AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO,
+ * THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
+ * PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR
+ * CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL,
+ * EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO,
+ * PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS;
+ * OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY,
+ * WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR
+ * OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE,
+ * EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+ */
+
+/**
+ *  @file  profile.c
+ *         This file contains methods to profile DOMX
+ *
+ *  @path ...\hardware\ti\domx\domx\profiling\inc
+ *
+ *  @rev 1.0
+ */
+
+/******************************************************************
+ *   INCLUDE FILES
+ ******************************************************************/
+/* ----- system and platform files ----------------------------*/
+#include <stdlib.h>
+#include <string.h>
+#include <time.h>
+
+#ifdef _Android
+#include <cutils/properties.h>
+#endif
+
+#include <OMX_Types.h>
+#include <OMX_Component.h>
+
+/*-------program files ----------------------------------------*/
+#include "omx_rpc_utils.h"
+#include "omx_proxy_common.h"
+#include "profile.h"
+
+
+/******************************************************************
+ *   DEFINES - CONSTANTS
+ ******************************************************************/
+/* Events that can be dynamically enabled */
+enum KPI_STATUS {
+	KPI_BUFFER_EVENTS = 1
+};
+
+/* OMX buffer events per component */
+typedef struct {
+	OMX_HANDLETYPE hComponent;
+	OMX_U32 count_ftb;
+	OMX_U32 count_fbd;
+	OMX_U32 count_etb;
+	OMX_U32 count_ebd;
+	char name[50];
+} kpi_omx_component;
+
+/* we trace up to MAX_OMX_COMP components */
+#define MAX_OMX_COMP 8
+
+
+/***************************************************************
+ * kpi_omx_monitor
+ * -------------------------------------------------------------
+ * Contains up to 8 components data
+ *
+ ***************************************************************/
+kpi_omx_component kpi_omx_monitor[MAX_OMX_COMP]; /* we trace up to MAX_OMX_COMP components */
+OMX_U32 kpi_omx_monitor_cnt = 0; /* no component yet */
+unsigned int kpi_status = 0;
+
+
+/* ===========================================================================*/
+/**
+ * @name KPI_GetTime()
+ * @brief Compute time since boot to timestamp events
+ * @param void
+ * @return OMX_U64 = time since boot in us
+ * @sa TBD
+ *
+ */
+/* ===========================================================================*/
+OMX_U64 KPI_GetTime(void)
+{
+	struct timespec tp;
+
+	clock_gettime(CLOCK_MONOTONIC, &tp);
+	return (tp.tv_sec * 1000000 + tp.tv_nsec / 1000);
+}
+
+/* ===========================================================================*/
+/**
+ * @name KPI_OmxCompKpiUpdateStatus()
+ * @brief Update dynamic activation of traces
+ * @param void
+ * @return void
+ * @sa TBD
+ *
+ */
+/* ===========================================================================*/
+void KPI_OmxCompKpiUpdateStatus(void)
+{
+        char *val = getenv("DEBUG_DOMX_KPI_STATUS");
+
+        if (val)
+        {
+                kpi_status = strtol(val, NULL, 0);
+        }
+#ifdef _Android
+        else
+        {
+                char value[PROPERTY_VALUE_MAX];
+                int val;
+
+                property_get("debug.domx.kpi_status", value, "0");
+                val = atoi(value);
+                if (val >= 0)
+                        kpi_status = val;
+        }
+#endif
+}
+
+/* ===========================================================================*/
+/**
+ * @name KPI_OmxCompInit()
+ * @brief Prepare monitoring structure for new component starting
+ * @param void
+ * @return void
+ * @sa TBD
+ *
+ */
+/* ===========================================================================*/
+void KPI_OmxCompInit(OMX_HANDLETYPE hComponent)
+{
+	OMX_VERSIONTYPE nVersionComp;
+	OMX_VERSIONTYPE nVersionSpec;
+	OMX_UUIDTYPE    compUUID;
+	char compName[OMX_MAX_STRINGNAME_SIZE];
+	char* p;
+	OMX_U32 omx_cnt;
+	struct timespec tp;
+
+	/* Check if some profiling events have been enabled/disabled */
+	KPI_OmxCompKpiUpdateStatus();
+
+	if ( !(kpi_status & KPI_BUFFER_EVENTS) )
+		return;
+
+	/* First init: clear kpi_omx_monitor components */
+	if( kpi_omx_monitor_cnt == 0) {
+		for (omx_cnt = 0; omx_cnt < MAX_OMX_COMP; omx_cnt++) {
+			/*clear handler registry */
+			kpi_omx_monitor[omx_cnt].hComponent = 0;
+		}
+	}
+
+	/* find an empty monitoring structure */
+	for( omx_cnt = 0; omx_cnt < MAX_OMX_COMP;  omx_cnt++ ) {
+		if( kpi_omx_monitor[omx_cnt].hComponent == 0 ) break;
+	}
+
+	/* too omany components started, do not monitor */
+	if( omx_cnt >= MAX_OMX_COMP) return;
+
+	/* current comp num and update */
+	kpi_omx_monitor_cnt++;
+
+	/* register the component handle */
+	kpi_omx_monitor[omx_cnt].hComponent = hComponent;
+
+	/* reset event counts */
+	kpi_omx_monitor[omx_cnt].count_ftb = 0;
+	kpi_omx_monitor[omx_cnt].count_fbd = 0;
+	kpi_omx_monitor[omx_cnt].count_etb = 0;
+	kpi_omx_monitor[omx_cnt].count_ebd = 0;
+
+	/* register the component name */
+	((OMX_COMPONENTTYPE*) hComponent)->GetComponentVersion(hComponent, compName, &nVersionComp, &nVersionSpec, &compUUID);
+
+	/* get the end of the string compName... */
+	p = compName + strlen( compName ) - 1;
+	while( (*p != '.' ) && (p != compName) ) p--;
+	strncpy(kpi_omx_monitor[omx_cnt].name, p + 1, 6);
+
+	/* trace component init */
+	DOMX_PROF("<KPI> OMX %-6s Init %-8lld", kpi_omx_monitor[omx_cnt].name, KPI_GetTime());
+
+	return;
+}
+
+/* ===========================================================================*/
+/**
+ * @name KPI_OmxCompDeinit()
+ * @brief Reset monitoring structure for component stopping
+ * @param void
+ * @return void
+ * @sa TBD
+ *
+ */
+/* ===========================================================================*/
+void KPI_OmxCompDeinit( OMX_HANDLETYPE hComponent)
+{
+	OMX_U32 omx_cnt;
+
+	if ( !(kpi_status & KPI_BUFFER_EVENTS) )
+		return;
+
+	if( kpi_omx_monitor_cnt == 0) return;
+
+	/* identify the component from the registry */
+	for( omx_cnt = 0; omx_cnt < MAX_OMX_COMP;  omx_cnt++ ) {
+		if( kpi_omx_monitor[omx_cnt].hComponent == hComponent ) break;
+	}
+
+	/* trace component init */
+	DOMX_PROF( "<KPI> OMX %-6s Deinit %-8lld", kpi_omx_monitor[omx_cnt].name, KPI_GetTime());
+
+	/* unregister the component */
+	kpi_omx_monitor[omx_cnt].hComponent = 0;
+
+	kpi_omx_monitor_cnt--;
+
+	return;
+}
+
+/* ===========================================================================*/
+/**
+ * @name KPI_OmxCompBufferEvent()
+ * @brief Trace FTB/ETB/FBD/EBD events
+ * @param void
+ * @return void
+ * @sa TBD
+ *
+ */
+/* ===========================================================================*/
+void KPI_OmxCompBufferEvent(enum KPI_BUFFER_EVENT event, OMX_HANDLETYPE hComponent, PROXY_BUFFER_INFO* pBuffer)
+{
+        OMX_U32 omx_cnt;
+
+	if ( !(kpi_status & KPI_BUFFER_EVENTS) )
+		return;
+
+        if (kpi_omx_monitor_cnt == 0) return;
+
+        /* identify the component from the registry */
+        for (omx_cnt = 0; omx_cnt < MAX_OMX_COMP;  omx_cnt++) {
+                if( kpi_omx_monitor[omx_cnt].hComponent == hComponent ) break;
+        }
+
+        /* Update counts and trace the event */
+        if( omx_cnt < MAX_OMX_COMP ) {
+                /* trace the event, we trace remote address to correlate to Ducati trace */
+		switch(event) {
+			case KPI_BUFFER_ETB:
+				DOMX_PROF("ETB %-6s %-4u %-8lld x%-8x", kpi_omx_monitor[omx_cnt].name, \
+					(unsigned int)++kpi_omx_monitor[omx_cnt].count_etb, KPI_GetTime(), (unsigned int)pBuffer->pBufHeaderRemote);
+			break;
+			case KPI_BUFFER_FTB:
+				DOMX_PROF("FTB %-6s %-4u %-8lld x%-8x", kpi_omx_monitor[omx_cnt].name, \
+					(unsigned int)++kpi_omx_monitor[omx_cnt].count_ftb, KPI_GetTime(), (unsigned int)pBuffer->pBufHeaderRemote);
+			break;
+			case KPI_BUFFER_EBD:
+				DOMX_PROF("EBD %-6s %-4u %-8lld x%-8x", kpi_omx_monitor[omx_cnt].name, \
+					(unsigned int)++kpi_omx_monitor[omx_cnt].count_ebd, KPI_GetTime(), (unsigned int)pBuffer->pBufHeaderRemote);
+			break;
+			/* we add timestamp metadata because this is a unique identifier of buffer among all SW layers */
+			case KPI_BUFFER_FBD:
+		                DOMX_PROF("FBD %-6s %-4u %-8lld x%-8x %lld", kpi_omx_monitor[omx_cnt].name, \
+					(unsigned int)++kpi_omx_monitor[omx_cnt].count_fbd, KPI_GetTime(), (unsigned int)pBuffer->pBufHeaderRemote, pBuffer->pBufHeader->nTimeStamp);
+			break;
+
+		}
+        }
+
+        return;
+}