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>

Makefile

@@ -117,6 +117,12 @@ ENABLE_PSCI_STAT	:= 0
 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_PMF))
 $(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_PMF))
 $(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))

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 @@ endfunc bl31_entrypoint
 	 * --------------------------------------------------------------------
 	 */
 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 @@ func bl31_warm_entrypoint
 
 	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

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
 

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

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__
@@ -95,6 +105,9 @@ typedef struct cpu_data {
 	uintptr_t cpu_ops_ptr;
 #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
@@ -116,6 +129,12 @@ CASSERT(CPU_DATA_CPU_OPS_PTR == __builtin_offsetof
 		(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

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
 /*

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>

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__ */

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 @@ int psci_cpu_suspend(unsigned int power_state,
 			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,

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 @@ exit:
 		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);

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 @@ exit:
 		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 @@ exit:
 			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 @@ exit:
 	 */
 	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.

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 @@ uintptr_t std_svc_smc_handler(uint32_t smc_fid,
 	 * 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) {