michaelh/zephyr
1
0
Fork 0
Code Releases Activity

power: trace power events

Browse source 
Trace PM transition sequence and events.

Signed-off-by: Anas Nashif <anas.nashif@intel.com>
This commit is contained in:
Anas Nashif 2021-05-13 09:49:18 -04:00
commit eccda68418
7 changed files with 81 additions and 15 deletions
Download patch file Download diff file Expand all files Collapse all files

11
include/tracing/tracing.h
View file

@ -11,6 +11,17 @@
#if defined CONFIG_PERCEPIO_TRACERECORDER #if defined CONFIG_PERCEPIO_TRACERECORDER
#include "tracing_tracerecorder.h" #include "tracing_tracerecorder.h"
/* Wait for those to be implemented by Tracealyzer */
#define sys_port_trace_pm_system_suspend_enter(ticks)
#define sys_port_trace_pm_system_suspend_exit(ticks, ret)
#define sys_port_trace_pm_device_request_enter(dev, target_state)
#define sys_port_trace_pm_device_request_exit(dev, ret)
#define sys_port_trace_pm_device_enable_enter(dev)
#define sys_port_trace_pm_device_enable_exit(dev)
#define sys_port_trace_pm_device_disable_enter(dev)
#define sys_port_trace_pm_device_disable_exit(dev)
#elif defined CONFIG_SEGGER_SYSTEMVIEW #elif defined CONFIG_SEGGER_SYSTEMVIEW
#include "tracing_sysview.h" #include "tracing_sysview.h"

21
subsys/pm/device_runtime.c
View file

@ -87,18 +87,22 @@ static int pm_device_request(const struct device *dev,
uint32_t target_state, uint32_t pm_flags) uint32_t target_state, uint32_t pm_flags)
{ {
struct k_mutex request_mutex; struct k_mutex request_mutex;
int ret;
SYS_PORT_TRACING_FUNC_ENTER(pm, device_request, dev, target_state);
__ASSERT((target_state == PM_DEVICE_STATE_ACTIVE) || __ASSERT((target_state == PM_DEVICE_STATE_ACTIVE) ||
(target_state == PM_DEVICE_STATE_SUSPEND), (target_state == PM_DEVICE_STATE_SUSPEND),
"Invalid device PM state requested"); "Invalid device PM state requested");
if (target_state == PM_DEVICE_STATE_ACTIVE) { if (target_state == PM_DEVICE_STATE_ACTIVE) {
if (atomic_inc(&dev->pm->usage) < 0) { if (atomic_inc(&dev->pm->usage) < 0) {
return 0; ret = 0;
goto out;
} }
} else { } else {
if (atomic_dec(&dev->pm->usage) > 1) { if (atomic_dec(&dev->pm->usage) > 1) {
return 0; ret = 0;
goto out;
} }
} }
@ -123,15 +127,17 @@ static int pm_device_request(const struct device *dev,
PM_DEVICE_STATE_SUSPEND, PM_DEVICE_STATE_SUSPEND,
NULL, NULL); NULL, NULL);
} }
ret = 0;
return 0; goto out;
} }
(void)k_work_schedule(&dev->pm->work, K_NO_WAIT); (void)k_work_schedule(&dev->pm->work, K_NO_WAIT);
/* Return in case of Async request */ /* Return in case of Async request */
if (pm_flags & PM_DEVICE_ASYNC) { if (pm_flags & PM_DEVICE_ASYNC) {
return 0; SYS_PORT_TRACING_FUNC_EXIT(pm, device_request, dev, 0);
ret = 0;
goto out;
} }
k_mutex_init(&request_mutex); k_mutex_init(&request_mutex);
@ -144,7 +150,10 @@ static int pm_device_request(const struct device *dev,
* may not have been properly changed to the target_state or another * may not have been properly changed to the target_state or another
* thread we check it here before returning. * thread we check it here before returning.
*/ */
return target_state == atomic_get(&dev->pm->state) ? 0 : -EIO; ret = target_state == atomic_get(&dev->pm->state) ? 0 : -EIO;
out:
SYS_PORT_TRACING_FUNC_EXIT(pm, device_request, dev, ret);
return ret;
} }
int pm_device_get(const struct device *dev) int pm_device_get(const struct device *dev)

12
subsys/pm/power.c
View file

@ -12,6 +12,7 @@
#include <pm/pm.h> #include <pm/pm.h>
#include <pm/state.h> #include <pm/state.h>
#include "policy/pm_policy.h" #include "policy/pm_policy.h"
#include <tracing/tracing.h>
#define PM_STATES_LEN (1 + PM_STATE_SOFT_OFF - PM_STATE_ACTIVE) #define PM_STATES_LEN (1 + PM_STATE_SOFT_OFF - PM_STATE_ACTIVE)
#define LOG_LEVEL CONFIG_PM_LOG_LEVEL #define LOG_LEVEL CONFIG_PM_LOG_LEVEL
@ -174,9 +175,11 @@ static enum pm_state _handle_device_abort(struct pm_state_info info)
enum pm_state pm_system_suspend(int32_t ticks) enum pm_state pm_system_suspend(int32_t ticks)
{ {
SYS_PORT_TRACING_FUNC_ENTER(pm, system_suspend, ticks);
z_power_state = pm_policy_next_state(ticks); z_power_state = pm_policy_next_state(ticks);
if (z_power_state.state == PM_STATE_ACTIVE) { if (z_power_state.state == PM_STATE_ACTIVE) {
LOG_DBG("No PM operations done."); LOG_DBG("No PM operations done.");
SYS_PORT_TRACING_FUNC_EXIT(pm, system_suspend, ticks, z_power_state.state);
return z_power_state.state; return z_power_state.state;
} }
post_ops_done = 0; post_ops_done = 0;
@ -210,12 +213,17 @@ enum pm_state pm_system_suspend(int32_t ticks)
case PM_STATE_STANDBY: case PM_STATE_STANDBY:
/* low power peripherals. */ /* low power peripherals. */
if (pm_low_power_devices()) { if (pm_low_power_devices()) {
SYS_PORT_TRACING_FUNC_EXIT(pm, system_suspend,
ticks, _handle_device_abort(z_power_state));
return _handle_device_abort(z_power_state); return _handle_device_abort(z_power_state);
} break; }
break;
case PM_STATE_SUSPEND_TO_RAM: case PM_STATE_SUSPEND_TO_RAM:
__fallthrough; __fallthrough;
case PM_STATE_SUSPEND_TO_DISK: case PM_STATE_SUSPEND_TO_DISK:
if (pm_suspend_devices()) { if (pm_suspend_devices()) {
SYS_PORT_TRACING_FUNC_EXIT(pm, system_suspend,
ticks, _handle_device_abort(z_power_state));
return _handle_device_abort(z_power_state); return _handle_device_abort(z_power_state);
} }
break; break;
@ -250,7 +258,7 @@ enum pm_state pm_system_suspend(int32_t ticks)
pm_log_debug_info(z_power_state.state); pm_log_debug_info(z_power_state.state);
pm_system_resume(); pm_system_resume();
k_sched_unlock(); k_sched_unlock();
SYS_PORT_TRACING_FUNC_EXIT(pm, system_suspend, ticks, z_power_state.state);
return z_power_state.state; return z_power_state.state;
} }

5
subsys/tracing/ctf/tracing_ctf.h
View file

@ -315,6 +315,11 @@ extern "C" {
#define sys_port_trace_syscall_enter() sys_trace_syscall_enter() #define sys_port_trace_syscall_enter() sys_trace_syscall_enter()
#define sys_port_trace_syscall_exit() sys_trace_syscall_exit() #define sys_port_trace_syscall_exit() sys_trace_syscall_exit()
#define sys_port_trace_pm_system_suspend_enter(ticks)
#define sys_port_trace_pm_system_suspend_exit(ticks, ret)
#define sys_port_trace_pm_device_request_enter(dev, target_state)
#define sys_port_trace_pm_device_request_exit(dev, ret)
void sys_trace_syscall_enter(void); void sys_trace_syscall_enter(void);
void sys_trace_syscall_exit(void); void sys_trace_syscall_exit(void);
void sys_trace_idle(void); void sys_trace_idle(void);

13
subsys/tracing/sysview/SYSVIEW_Zephyr.txt
View file

@ -17,6 +17,9 @@ NamedType ErrCodeNetIO *=%i 0=ESUCCESS -68=EINPROGRESS -69=EALREADY -11=EWOU
NamedType ErrCodeStream *=%i 0=ESUCCESS -74=ENOSR -75=ENOSTR -76=EPROTO -77=EBADMSG -78=ENODATA -79=ETIME -80=ENOMSG -138=EILSEQ NamedType ErrCodeStream *=%i 0=ESUCCESS -74=ENOSR -75=ENOSTR -76=EPROTO -77=EBADMSG -78=ENODATA -79=ETIME -80=ENOMSG -138=EILSEQ
NamedType ErrCodeMsg *=%i 0=ESUCCESS -11=EAGAIN -80=ENOMSG NamedType ErrCodeMsg *=%i 0=ESUCCESS -11=EAGAIN -80=ENOMSG
NamedType PowerState *=%i 0=ACTIVE 1=RUNTIME_IDLE 2=SUSPEND_TO_IDLE 3=STANDBY 4=SUSPEND_TO_RAM 5=SUSPEND_TO_DISK 6=SOFT_OFF
NamedType DevicePowerState *=%i 1=ACTIVE 2=LOW_POWER 3=SUSPEND 4=FORCE_SUSPEND 5=OFF 6=RESUMING 7=SUSPENDING
# #
# Task States # Task States
# #
@ -104,7 +107,7 @@ TaskState 0xBF 1=dummy, 2=Waiting, 4=New, 8=Terminated, 16=Suspended, 32=Termina
98 k_thread_priority_set thread=%t, priority=%u 98 k_thread_priority_set thread=%t, priority=%u
99 k_thread_wakeup 99 k_thread_wakeup
100 k_thread_abort 100 k_thread_abort
101 k_thread_start 101 k_thread_start thread=%t
102 k_thread_suspend 102 k_thread_suspend
103 k_thread_resume 103 k_thread_resume
104 k_thread_join 104 k_thread_join
@ -112,11 +115,11 @@ TaskState 0xBF 1=dummy, 2=Waiting, 4=New, 8=Terminated, 16=Suspended, 32=Termina
106 k_thread_usermode_enter 106 k_thread_usermode_enter
107 k_thread_foreach 107 k_thread_foreach
108 k_thread_foreach_unlocked 108 k_thread_foreach_unlocked
155 k_thread_name_set thread=%T 155 k_thread_name_set thread=%I
109 k_condvar_init condvar=%I 109 k_condvar_init condvar=%I
110 k_condvar_signal condvar=%I 110 k_condvar_signal condvar=%I
111 k_condvat_broadcast condvar=%I 111 k_condvar_broadcast condvar=%I
112 k_condvar_wait condvar=%I 112 k_condvar_wait condvar=%I
@ -158,3 +161,7 @@ TaskState 0xBF 1=dummy, 2=Waiting, 4=New, 8=Terminated, 16=Suspended, 32=Termina
152 k_lifo_put lifo=%I 152 k_lifo_put lifo=%I
153 k_lifo_get lifo=%I, Timeout=%TimeOut 153 k_lifo_get lifo=%I, Timeout=%TimeOut
154 k_lifo_alloc_put lifo=%I, data=%I 154 k_lifo_alloc_put lifo=%I, data=%I
156 pm_system_suspend ticks=%u | Returns %PowerState
157 pm_device_request dev=%I target_state=%DevicePowerState | Returns %u

27
subsys/tracing/sysview/tracing_sysview.h
View file

@ -149,7 +149,10 @@ extern "C" {
#define TID_LIFO_GET (121u + TID_OFFSET) #define TID_LIFO_GET (121u + TID_OFFSET)
#define TID_LIFO_ALLOC_PUT (122u + TID_OFFSET) #define TID_LIFO_ALLOC_PUT (122u + TID_OFFSET)
/* latest ID is 123 */
#define TID_PM_SUSPEND (124u + TID_OFFSET)
#define TID_PM_DEVICE_REQUEST (125u + TID_OFFSET)
/* latest ID is 125 */
void sys_trace_thread_info(struct k_thread *thread); void sys_trace_thread_info(struct k_thread *thread);
@ -181,7 +184,7 @@ void sys_trace_thread_info(struct k_thread *thread);
SEGGER_SYSVIEW_RecordEndCallU32(TID_THREAD_JOIN, (int32_t)ret) SEGGER_SYSVIEW_RecordEndCallU32(TID_THREAD_JOIN, (int32_t)ret)
#define sys_port_trace_k_thread_sleep_enter(timeout) \ #define sys_port_trace_k_thread_sleep_enter(timeout) \
SEGGER_SYSVIEW_RecordU32(TID_SLEEP, (uint32_t)timeout.ticks) SEGGER_SYSVIEW_RecordU32(TID_SLEEP, (uint32_t)k_ticks_to_ms_floor32(timeout.ticks))
#define sys_port_trace_k_thread_sleep_exit(timeout, ret) \ #define sys_port_trace_k_thread_sleep_exit(timeout, ret) \
SEGGER_SYSVIEW_RecordEndCallU32(TID_SLEEP, (int32_t)ret) SEGGER_SYSVIEW_RecordEndCallU32(TID_SLEEP, (int32_t)ret)
@ -228,8 +231,10 @@ void sys_trace_thread_info(struct k_thread *thread);
#define sys_port_trace_k_thread_sched_unlock() #define sys_port_trace_k_thread_sched_unlock()
#define sys_port_trace_k_thread_name_set(thread, ret) \ #define sys_port_trace_k_thread_name_set(thread, ret) do { \
SEGGER_SYSVIEW_RecordU32(TID_THREAD_NAME_SET, (uint32_t)(uintptr_t)thread) SEGGER_SYSVIEW_RecordU32(TID_THREAD_NAME_SET, (uint32_t)(uintptr_t)thread); \
sys_trace_thread_info(thread); \
} while (0)
#define sys_port_trace_k_thread_switched_out() sys_trace_k_thread_switched_out() #define sys_port_trace_k_thread_switched_out() sys_trace_k_thread_switched_out()
@ -739,6 +744,20 @@ void sys_trace_k_thread_ready(struct k_thread *thread);
void sys_trace_k_thread_pend(struct k_thread *thread); void sys_trace_k_thread_pend(struct k_thread *thread);
void sys_trace_k_thread_info(struct k_thread *thread); void sys_trace_k_thread_info(struct k_thread *thread);
#define sys_port_trace_pm_system_suspend_enter(ticks) \
SEGGER_SYSVIEW_RecordU32(TID_PM_SUSPEND, (uint32_t)ticks)
#define sys_port_trace_pm_system_suspend_exit(ticks, ret) \
SEGGER_SYSVIEW_RecordEndCallU32(TID_PM_SUSPEND, (uint32_t)ret)
#define sys_port_trace_pm_device_request_enter(dev, target_state) \
SEGGER_SYSVIEW_RecordU32x2(TID_PM_DEVICE_REQUEST, (uint32_t)(uintptr_t)dev, target_state)
#define sys_port_trace_pm_device_request_exit(dev, ret) \
SEGGER_SYSVIEW_RecordEndCallU32(TID_PM_DEVICE_REQUEST, (uint32_t)ret)
#ifdef __cplusplus #ifdef __cplusplus
} }
#endif #endif

7
subsys/tracing/test/tracing_test.h
View file

@ -416,6 +416,13 @@
#define sys_port_trace_syscall_enter() sys_trace_syscall_enter() #define sys_port_trace_syscall_enter() sys_trace_syscall_enter()
#define sys_port_trace_syscall_exit() sys_trace_syscall_exit() #define sys_port_trace_syscall_exit() sys_trace_syscall_exit()
#define sys_port_trace_pm_system_suspend_enter(ticks)
#define sys_port_trace_pm_system_suspend_exit(ticks, ret)
#define sys_port_trace_pm_device_request_enter(dev, target_state)
#define sys_port_trace_pm_device_request_exit(dev, ret)
void sys_trace_syscall_enter(void); void sys_trace_syscall_enter(void);
void sys_trace_syscall_exit(void); void sys_trace_syscall_exit(void);
void sys_trace_idle(void); void sys_trace_idle(void);