Add PMF instrumentation points in TF

In order to quantify the overall time spent in the PSCI software
implementation, an initial collection of PMF instrumentation points
has been added.

Instrumentation has been added to the following code paths:

- Entry to PSCI SMC handler.  The timestamp is captured as early
  as possible during the runtime exception and stored in memory
  before entering the PSCI SMC handler.

- Exit from PSCI SMC handler.  The timestamp is captured after
  normal return from the PSCI SMC handler or if a low power state
  was requested it is captured in the bl31 warm boot path before
  return to normal world.

- Entry to low power state.  The timestamp is captured before entry
  to a low power state which implies either standby or power down.
  As these power states are mutually exclusive, only one timestamp
  is defined to describe both.  It is possible to differentiate between
  the two power states using the PSCI STAT interface.

- Exit from low power state.  The timestamp is captured after a standby
  or power up operation has completed.

To calculate the number of cycles spent running code in Trusted Firmware
one can perform the following calculation:

(exit_psci - enter_psci) - (exit_low_pwr - enter_low_pwr).

The resulting number of cycles can be converted to time given the
frequency of the counter.

Change-Id: Ie3b8f3d16409b6703747093b3a2d5c7429ad0166
Signed-off-by: dp-arm <dimitris.papastamos@arm.com>
diff --git a/Makefile b/Makefile
index 2b630b3..3521117 100644
--- a/Makefile
+++ b/Makefile
@@ -117,6 +117,12 @@
 SEPARATE_CODE_AND_RODATA	:= 0
 # Flag to enable new version of image loading
 LOAD_IMAGE_V2		:= 0
+# Flag to enable runtime instrumentation using PMF
+ENABLE_RUNTIME_INSTRUMENTATION	:= 0
+
+ifeq (${ENABLE_RUNTIME_INSTRUMENTATION}, 1)
+ENABLE_PMF			:= 1
+endif
 
 ################################################################################
 # Checkpatch script options
@@ -466,6 +472,7 @@
 $(eval $(call assert_boolean,ENABLE_PSCI_STAT))
 $(eval $(call assert_boolean,SEPARATE_CODE_AND_RODATA))
 $(eval $(call assert_boolean,LOAD_IMAGE_V2))
+$(eval $(call assert_boolean,ENABLE_RUNTIME_INSTRUMENTATION))
 
 
 ################################################################################
@@ -497,6 +504,7 @@
 $(eval $(call add_define,ENABLE_PSCI_STAT))
 $(eval $(call add_define,SEPARATE_CODE_AND_RODATA))
 $(eval $(call add_define,LOAD_IMAGE_V2))
+$(eval $(call add_define,ENABLE_RUNTIME_INSTRUMENTATION))
 # Define the EL3_PAYLOAD_BASE flag only if it is provided.
 ifdef EL3_PAYLOAD_BASE
         $(eval $(call add_define,EL3_PAYLOAD_BASE))
diff --git a/bl31/aarch64/bl31_entrypoint.S b/bl31/aarch64/bl31_entrypoint.S
index 4c3a515..d14a68d 100644
--- a/bl31/aarch64/bl31_entrypoint.S
+++ b/bl31/aarch64/bl31_entrypoint.S
@@ -31,6 +31,8 @@
 #include <arch.h>
 #include <bl_common.h>
 #include <el3_common_macros.S>
+#include <pmf_asm_macros.S>
+#include <runtime_instr.h>
 #include <xlat_tables.h>
 
 	.globl	bl31_entrypoint
@@ -141,6 +143,18 @@
 	 * --------------------------------------------------------------------
 	 */
 func bl31_warm_entrypoint
+#if ENABLE_RUNTIME_INSTRUMENTATION
+
+	/*
+	 * This timestamp update happens with cache off.  The next
+	 * timestamp collection will need to do cache maintenance prior
+	 * to timestamp update.
+	 */
+	pmf_calc_timestamp_addr rt_instr_svc RT_INSTR_EXIT_HW_LOW_PWR
+	mrs	x1, cntpct_el0
+	str	x1, [x0]
+#endif
+
 	/*
 	 * On the warm boot path, most of the EL3 initialisations performed by
 	 * 'el3_entrypoint_common' must be skipped:
@@ -188,5 +202,23 @@
 
 	bl	psci_warmboot_entrypoint
 
+#if ENABLE_RUNTIME_INSTRUMENTATION
+	pmf_calc_timestamp_addr rt_instr_svc RT_INSTR_EXIT_PSCI
+	mov	x19, x0
+
+	/*
+	 * Invalidate before updating timestamp to ensure previous timestamp
+	 * updates on the same cache line with caches disabled are properly
+	 * seen by the same core. Without the cache invalidate, the core might
+	 * write into a stale cache line.
+	 */
+	mov	x1, #PMF_TS_SIZE
+	mov	x20, x30
+	bl	inv_dcache_range
+	mov	x30, x20
+
+	mrs	x0, cntpct_el0
+	str	x0, [x19]
+#endif
 	b	el3_exit
 endfunc bl31_warm_entrypoint
diff --git a/bl31/aarch64/runtime_exceptions.S b/bl31/aarch64/runtime_exceptions.S
index 799062e..f333bf1 100644
--- a/bl31/aarch64/runtime_exceptions.S
+++ b/bl31/aarch64/runtime_exceptions.S
@@ -31,6 +31,7 @@
 #include <arch.h>
 #include <asm_macros.S>
 #include <context.h>
+#include <cpu_data.h>
 #include <interrupt_mgmt.h>
 #include <platform_def.h>
 #include <runtime_svc.h>
@@ -47,6 +48,21 @@
 	msr	daifclr, #DAIF_ABT_BIT
 
 	str	x30, [sp, #CTX_GPREGS_OFFSET + CTX_GPREG_LR]
+
+#if ENABLE_RUNTIME_INSTRUMENTATION
+
+	/*
+	 * Read the timestamp value and store it in per-cpu data.
+	 * The value will be extracted from per-cpu data by the
+	 * C level SMC handler and saved to the PMF timestamp region.
+	 */
+	mrs	x30, cntpct_el0
+	str	x29, [sp, #CTX_GPREGS_OFFSET + CTX_GPREG_X29]
+	mrs	x29, tpidr_el3
+	str	x30, [x29, #CPU_DATA_PMF_TS0_OFFSET]
+	ldr	x29, [sp, #CTX_GPREGS_OFFSET + CTX_GPREG_X29]
+#endif
+
 	mrs	x30, esr_el3
 	ubfx	x30, x30, #ESR_EC_SHIFT, #ESR_EC_LENGTH
 
diff --git a/bl31/bl31_main.c b/bl31/bl31_main.c
index fae5ee4..85b3ea1 100644
--- a/bl31/bl31_main.c
+++ b/bl31/bl31_main.c
@@ -36,9 +36,16 @@
 #include <context_mgmt.h>
 #include <debug.h>
 #include <platform.h>
+#include <pmf.h>
+#include <runtime_instr.h>
 #include <runtime_svc.h>
 #include <string.h>
 
+#if ENABLE_RUNTIME_INSTRUMENTATION
+PMF_REGISTER_SERVICE_SMC(rt_instr_svc, PMF_RT_INSTR_SVC_ID,
+	RT_INSTR_TOTAL_IDS, PMF_STORE_ENABLE)
+#endif
+
 /*******************************************************************************
  * This function pointer is used to initialise the BL32 image. It's initialized
  * by SPD calling bl31_register_bl32_init after setting up all things necessary
diff --git a/include/lib/el3_runtime/cpu_data.h b/include/lib/el3_runtime/cpu_data.h
index 910b153..3b00a5e 100644
--- a/include/lib/el3_runtime/cpu_data.h
+++ b/include/lib/el3_runtime/cpu_data.h
@@ -50,8 +50,18 @@
 
 #if CRASH_REPORTING
 #define CPU_DATA_LOG2SIZE		7
+#define CPU_DATA_CRASH_BUF_END		(CPU_DATA_CRASH_BUF_OFFSET + \
+						CPU_DATA_CRASH_BUF_SIZE)
 #else
 #define CPU_DATA_LOG2SIZE		6
+#define CPU_DATA_CRASH_BUF_END		CPU_DATA_CRASH_BUF_OFFSET
+#endif
+
+#if ENABLE_RUNTIME_INSTRUMENTATION
+/* Temporary space to store PMF timestamps from assembly code */
+#define CPU_DATA_PMF_TS_COUNT		1
+#define CPU_DATA_PMF_TS0_OFFSET		CPU_DATA_CRASH_BUF_END
+#define CPU_DATA_PMF_TS0_IDX		0
 #endif
 
 #ifndef __ASSEMBLY__
@@ -96,6 +106,9 @@
 #if CRASH_REPORTING
 	u_register_t crash_buf[CPU_DATA_CRASH_BUF_SIZE >> 3];
 #endif
+#if ENABLE_RUNTIME_INSTRUMENTATION
+	uint64_t cpu_data_pmf_ts[CPU_DATA_PMF_TS_COUNT];
+#endif
 	struct psci_cpu_data psci_svc_cpu_data;
 #if PLAT_PCPU_DATA_SIZE
 	uint8_t platform_cpu_data[PLAT_PCPU_DATA_SIZE];
@@ -116,6 +129,12 @@
 		(cpu_data_t, cpu_ops_ptr),
 		assert_cpu_data_cpu_ops_ptr_offset_mismatch);
 
+#if ENABLE_RUNTIME_INSTRUMENTATION
+CASSERT(CPU_DATA_PMF_TS0_OFFSET == __builtin_offsetof
+		(cpu_data_t, cpu_data_pmf_ts[0]),
+		assert_cpu_data_pmf_ts0_offset_mismatch);
+#endif
+
 struct cpu_data *_cpu_data_by_index(uint32_t cpu_index);
 
 #ifndef AARCH32
diff --git a/include/lib/pmf/pmf.h b/include/lib/pmf/pmf.h
index 5f953b5..7c33387 100644
--- a/include/lib/pmf/pmf.h
+++ b/include/lib/pmf/pmf.h
@@ -75,6 +75,7 @@
 
 /* Following are the supported PMF service IDs */
 #define PMF_PSCI_STAT_SVC_ID	0
+#define PMF_RT_INSTR_SVC_ID	1
 
 #if ENABLE_PMF
 /*
diff --git a/include/lib/pmf/pmf_helpers.h b/include/lib/pmf/pmf_helpers.h
index bb4242c..e7fd275 100644
--- a/include/lib/pmf/pmf_helpers.h
+++ b/include/lib/pmf/pmf_helpers.h
@@ -33,6 +33,7 @@
 
 #include <arch_helpers.h>
 #include <assert.h>
+#include <bl_common.h>
 #include <platform.h>
 #include <pmf.h>
 #include <stdint.h>
diff --git a/include/lib/runtime_instr.h b/include/lib/runtime_instr.h
new file mode 100644
index 0000000..d409002
--- /dev/null
+++ b/include/lib/runtime_instr.h
@@ -0,0 +1,45 @@
+/*
+ * Copyright (c) 2016, ARM Limited and Contributors. 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 ARM 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 HOLDER 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.
+ */
+
+#ifndef __RUNTIME_INSTR_H__
+#define __RUNTIME_INSTR_H__
+
+#define RT_INSTR_TOTAL_IDS		4
+#define RT_INSTR_ENTER_PSCI		0
+#define RT_INSTR_EXIT_PSCI		1
+#define RT_INSTR_ENTER_HW_LOW_PWR	2
+#define RT_INSTR_EXIT_HW_LOW_PWR	3
+
+#ifndef __ASSEMBLY__
+PMF_DECLARE_CAPTURE_TIMESTAMP(rt_instr_svc)
+PMF_DECLARE_GET_TIMESTAMP(rt_instr_svc)
+#endif /* __ASSEMBLY__ */
+
+#endif /* __RUNTIME_INSTR_H__ */
diff --git a/lib/psci/psci_main.c b/lib/psci/psci_main.c
index 23bd106..0a3a60a 100644
--- a/lib/psci/psci_main.c
+++ b/lib/psci/psci_main.c
@@ -33,6 +33,8 @@
 #include <assert.h>
 #include <debug.h>
 #include <platform.h>
+#include <pmf.h>
+#include <runtime_instr.h>
 #include <smcc.h>
 #include <string.h>
 #include "psci_private.h"
@@ -124,11 +126,23 @@
 			PMF_NO_CACHE_MAINT);
 #endif
 
+#if ENABLE_RUNTIME_INSTRUMENTATION
+		PMF_CAPTURE_TIMESTAMP(rt_instr_svc,
+		    RT_INSTR_ENTER_HW_LOW_PWR,
+		    PMF_NO_CACHE_MAINT);
+#endif
+
 		psci_plat_pm_ops->cpu_standby(cpu_pd_state);
 
 		/* Upon exit from standby, set the state back to RUN. */
 		psci_set_cpu_local_state(PSCI_LOCAL_STATE_RUN);
 
+#if ENABLE_RUNTIME_INSTRUMENTATION
+		PMF_CAPTURE_TIMESTAMP(rt_instr_svc,
+		    RT_INSTR_EXIT_HW_LOW_PWR,
+		    PMF_NO_CACHE_MAINT);
+#endif
+
 #if ENABLE_PSCI_STAT
 		/* Capture time-stamp after CPU standby */
 		PMF_CAPTURE_TIMESTAMP(psci_svc, PSCI_STAT_ID_EXIT_LOW_PWR,
diff --git a/lib/psci/psci_off.c b/lib/psci/psci_off.c
index 471141d..1cc6ede 100644
--- a/lib/psci/psci_off.c
+++ b/lib/psci/psci_off.c
@@ -33,6 +33,8 @@
 #include <assert.h>
 #include <debug.h>
 #include <platform.h>
+#include <pmf.h>
+#include <runtime_instr.h>
 #include <string.h>
 #include "psci_private.h"
 
@@ -153,6 +155,19 @@
 		dsbish();
 		inv_cpu_data(psci_svc_cpu_data.aff_info_state);
 
+#if ENABLE_RUNTIME_INSTRUMENTATION
+
+		/*
+		 * Update the timestamp with cache off.  We assume this
+		 * timestamp can only be read from the current CPU and the
+		 * timestamp cache line will be flushed before return to
+		 * normal world on wakeup.
+		 */
+		PMF_CAPTURE_TIMESTAMP(rt_instr_svc,
+		    RT_INSTR_ENTER_HW_LOW_PWR,
+		    PMF_NO_CACHE_MAINT);
+#endif
+
 		if (psci_plat_pm_ops->pwr_domain_pwr_down_wfi) {
 			/* This function must not return */
 			psci_plat_pm_ops->pwr_domain_pwr_down_wfi(&state_info);
diff --git a/lib/psci/psci_suspend.c b/lib/psci/psci_suspend.c
index 0887e3b..10d2481 100644
--- a/lib/psci/psci_suspend.c
+++ b/lib/psci/psci_suspend.c
@@ -37,6 +37,8 @@
 #include <cpu_data.h>
 #include <debug.h>
 #include <platform.h>
+#include <pmf.h>
+#include <runtime_instr.h>
 #include <stddef.h>
 #include "psci_private.h"
 
@@ -212,6 +214,19 @@
 		return;
 
 	if (is_power_down_state) {
+#if ENABLE_RUNTIME_INSTRUMENTATION
+
+		/*
+		 * Update the timestamp with cache off.  We assume this
+		 * timestamp can only be read from the current CPU and the
+		 * timestamp cache line will be flushed before return to
+		 * normal world on wakeup.
+		 */
+		PMF_CAPTURE_TIMESTAMP(rt_instr_svc,
+		    RT_INSTR_ENTER_HW_LOW_PWR,
+		    PMF_NO_CACHE_MAINT);
+#endif
+
 		/* The function calls below must not return */
 		if (psci_plat_pm_ops->pwr_domain_pwr_down_wfi)
 			psci_plat_pm_ops->pwr_domain_pwr_down_wfi(state_info);
@@ -219,6 +234,12 @@
 			psci_power_down_wfi();
 	}
 
+#if ENABLE_RUNTIME_INSTRUMENTATION
+	PMF_CAPTURE_TIMESTAMP(rt_instr_svc,
+	    RT_INSTR_ENTER_HW_LOW_PWR,
+	    PMF_NO_CACHE_MAINT);
+#endif
+
 	/*
 	 * We will reach here if only retention/standby states have been
 	 * requested at multiple power levels. This means that the cpu
@@ -226,6 +247,12 @@
 	 */
 	wfi();
 
+#if ENABLE_RUNTIME_INSTRUMENTATION
+	PMF_CAPTURE_TIMESTAMP(rt_instr_svc,
+	    RT_INSTR_EXIT_HW_LOW_PWR,
+	    PMF_NO_CACHE_MAINT);
+#endif
+
 	/*
 	 * After we wake up from context retaining suspend, call the
 	 * context retaining suspend finisher.
diff --git a/services/std_svc/std_svc_setup.c b/services/std_svc/std_svc_setup.c
index e096601..97a9fbd 100644
--- a/services/std_svc/std_svc_setup.c
+++ b/services/std_svc/std_svc_setup.c
@@ -29,8 +29,11 @@
  */
 
 #include <assert.h>
+#include <cpu_data.h>
 #include <debug.h>
+#include <pmf.h>
 #include <psci.h>
+#include <runtime_instr.h>
 #include <runtime_svc.h>
 #include <smcc_helpers.h>
 #include <std_svc.h>
@@ -75,9 +78,25 @@
 	 * value
 	 */
 	if (is_psci_fid(smc_fid)) {
-		SMC_RET1(handle,
-			psci_smc_handler(smc_fid, x1, x2, x3, x4,
-					cookie, handle, flags));
+		uint64_t ret;
+
+#if ENABLE_RUNTIME_INSTRUMENTATION
+		PMF_WRITE_TIMESTAMP(rt_instr_svc,
+		    RT_INSTR_ENTER_PSCI,
+		    PMF_NO_CACHE_MAINT,
+		    get_cpu_data(cpu_data_pmf_ts[CPU_DATA_PMF_TS0_IDX]));
+#endif
+
+		ret = psci_smc_handler(smc_fid, x1, x2, x3, x4,
+		    cookie, handle, flags);
+
+#if ENABLE_RUNTIME_INSTRUMENTATION
+		PMF_CAPTURE_TIMESTAMP(rt_instr_svc,
+		    RT_INSTR_EXIT_PSCI,
+		    PMF_NO_CACHE_MAINT);
+#endif
+
+		SMC_RET1(handle, ret);
 	}
 
 	switch (smc_fid) {