Loading...
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240 241 242 243 244 245 246 247 248 249 250 251 252 253 254 255 256 257 258 259 260 261 262 263 264 265 266 267 268 269 270 271 272 273 274 275 276 277 278 279 280 281 282 283 284 285 286 287 288 289 290 291 292 293 294 295 296 297 298 299 300 301 302 303 304 305 306 307 308 309 310 311 312 313 314 315 316 317 318 319 320 321 322 323 324 325 326 327 328 329 330 331 332 333 334 335 336 337 338 339 340 341 342 343 344 345 346 347 348 349 350 351 352 353 354 355 356 357 358 359 | /* profiler.c - Profiler code for flushing data on UART */
/*
* Copyright (c) 2016 Intel Corporation
*
* Licensed under the Apache License, Version 2.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://www.apache.org/licenses/LICENSE-2.0
*
* 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 <zephyr.h>
#include <misc/kernel_event_logger.h>
#include <uart.h>
#define PROF_LOG_HEADER "*** [PROF] "
#if defined(CONFIG_STDOUT_CONSOLE)
#include <stdio.h>
#define PRINT(format, ...) printf(PROF_LOG_HEADER format, ##__VA_ARGS__)
#else
#include <misc/printk.h>
#define PRINT(format, ...) printk(PROF_LOG_HEADER format, ##__VA_ARGS__)
#endif
#define PROF_HEADER_SIZE_U8 4
#define PROF_MAX_EVENT_SIZE_U32 4
#define PROFILER_SLEEP_MS 5000
#define PROFILER_SLEEPTICKS (PROFILER_SLEEP_MS * sys_clock_ticks_per_sec / 1000)
/*
* This flag can be defined to check UART consistency
* In that case, "profterm" used on the host must be compiled
* in TESTMODE
*/
#undef PROF_UART_TESTMODE
struct prof_platform_info {
uint32_t hw_ticks_per_sec;
};
struct prof_platform_info prof_pltfm_info;
static struct device *uart_console_dev;
int prof_initialized;
#define out(c) uart_poll_out(uart_console_dev, (char)c)
#define DLE 16
#define PROFILER_INFO 255 /* Must not overlap with event ID */
void prof_send_platform_info(void)
{
uint8_t data_length = SIZE32_OF(prof_pltfm_info);
uint32_t *data = (uint32_t *)(&prof_pltfm_info);
int key;
int i;
key = irq_lock();
out(DLE);
out(PROFILER_INFO); /* Event ID */
out(data_length);
for (i = 0; i < data_length; i++) {
out((data[i] & 0x000000ff));
out(((data[i] & 0x0000ff00) >> 8));
out(((data[i] & 0x00ff0000) >> 16));
out(((data[i] & 0xff000000) >> 24));
}
irq_unlock(key);
}
#if defined(CONFIG_CONSOLE_HANDLER_SHELL) && defined(CONFIG_KERNEL_EVENT_LOGGER_DYNAMIC)
/* Profiler shell is only enabled if kernel event logger dynamic
* enable/disable and console handler shell are enabled
* Warning: if kernel event logger dynamic is enabled but no shell is available,
* kernel event logger won't log anything
*/
#define PROFILER_SHELL
#else
#undef PROFILER_SHELL
#endif
#ifdef PROFILER_SHELL
#include "profiler.h"
#include <stdlib.h>
#include <string.h>
#include <misc/shell.h>
/* kernel_event_logger flags. Bit N = enable event ID N, except for task monitor
* by default all enabled events at build time are logged when profiler enabled
*/
int cfg1 = 0xFFFF;
/* task monitor flags. By default set to build time configuration */
#if defined(CONFIG_TASK_MONITOR_MASK)
int cfg2 = CONFIG_TASK_MONITOR_MASK;
#else
int cfg2;
#endif
/*TODO: could configure flush period as well ? */
#define PROF_STOPPED 0
#define PROF_STARTING 1
#define PROF_STARTED 2
int prof_state;
int shell_cmd_prof(int argc, char *argv[])
{
/*
* prof [cmd]
* start
* stop
* cfg id1 id2
*/
int len = strlen(argv[1]);
if (!strncmp(argv[1], "start", len)) {
PRINT("Start\n");
sys_k_event_logger_set_mask(cfg1);
#ifdef CONFIG_TASK_MONITOR
sys_k_event_logger_set_monitor_mask(cfg2);
#endif
if ((sys_k_event_logger_get_mask() != 0)
#ifdef CONFIG_TASK_MONITOR
|| (sys_k_event_logger_get_monitor_mask() != 0)
#endif
) {
prof_state = PROF_STARTING;
}
} else if (!strncmp(argv[1], "stop", len)) {
PRINT("Stop\n");
sys_k_event_logger_set_mask(0);
#ifdef CONFIG_TASK_MONITOR
sys_k_event_logger_set_monitor_mask(0);
#endif
/* Could flush buffer here... but flush may be on-going... */
} else if (!strncmp(argv[1], "cfg", len)) {
if (argc >= 4) {
cfg1 = atoi(argv[2]);
cfg2 = atoi(argv[3]);
PRINT("Configure %d %d\n", cfg1, cfg2);
} else {
#ifdef CONFIG_TASK_MONITOR
PRINT("%d(%d) %d(%d)\n",
sys_k_event_logger_get_mask(),
cfg1,
sys_k_event_logger_get_monitor_mask(),
cfg2);
#else
PRINT("%d(%d)\n",
sys_k_event_logger_get_mask(),
cfg1);
#endif
}
} else {
return -EINVAL;
}
return 0;
}
struct shell_cmd prof_commands[] = {
PROF_CMD,
{ NULL, NULL}
};
#endif /* PROFILER_SHELL */
#undef TIMESTAMP_MODE_RTC
#undef TIMESTAMP_MODE_COUNTER
#if defined(CONFIG_KERNEL_EVENT_LOGGER_CUSTOM_TIMESTAMP)
#if defined(CONFIG_RTC) && !defined(PROFILER_USE_COUNTER)
#define TIMESTAMP_MODE_RTC
#elif defined(CONFIG_COUNTER)
#define TIMESTAMP_MODE_COUNTER
#else
#error KERNEL_EVENT_LOGGER_CUSTOM_TIMESTAMP set but RTC/COUNTER not enabled
#endif
#if defined(TIMESTAMP_MODE_RTC)
#include <rtc.h>
struct device *rtc_dev;
#elif defined(TIMESTAMP_MODE_COUNTER)
#include <counter.h>
struct device *counter_dev;
#endif
#if defined(TIMESTAMP_MODE_RTC)
uint32_t prof_read_timer(void)
{
return rtc_read(rtc_dev);
}
#elif defined(TIMESTAMP_MODE_COUNTER)
uint32_t prof_read_timer(void)
{
return counter_read(counter_dev);
}
#endif
#endif /* CONFIG_KERNEL_EVENT_LOGGER_CUSTOM_TIMESTAMP */
void prof_init(void)
{
#if defined(TIMESTAMP_MODE_RTC)
struct rtc_config config;
rtc_dev = device_get_binding("RTC_0");
config.init_val = 0;
config.alarm_enable = 0;
rtc_enable(rtc_dev);
rtc_set_config(rtc_dev, &config);
sys_k_event_logger_set_timer(prof_read_timer);
#elif defined(TIMESTAMP_MODE_COUNTER)
counter_dev = device_get_binding("AON_COUNTER");
counter_start(counter_dev);
sys_k_event_logger_set_timer(prof_read_timer);
#endif
#ifdef PROFILER_SHELL
#ifndef PROFILER_NO_SHELL_REGISTER
shell_init("shell> ", prof_commands);
#endif
#endif
#if defined(TIMESTAMP_MODE_RTC) || defined(TIMESTAMP_MODE_COUNTER)
prof_pltfm_info.hw_ticks_per_sec = 32768;
#else
prof_pltfm_info.hw_ticks_per_sec = (sys_clock_ticks_per_sec * sys_clock_hw_cycles_per_tick);
#endif
uart_console_dev = device_get_binding(CONFIG_UART_CONSOLE_ON_DEV_NAME);
prof_initialized = 1;
}
void prof_flush(void)
{
int i = 0;
#ifdef PROF_UART_TESTMODE
/* Send fixed sequence to UART to check integrity on host side */
key = irq_lock();
for (i = 0; i < 256; i++) {
out(i);
}
irq_unlock(key);
#else
int res;
uint32_t data[PROF_MAX_EVENT_SIZE_U32];
uint8_t data_length = SIZE32_OF(data);
uint8_t dropped_count;
uint16_t event_id;
static int dropped;
int key;
if (!prof_initialized)
prof_init();
#ifdef PROFILER_SHELL
/* Faster exit when profiling is disabled
* Microkernel: profiler background task remains active and schedules periodically
* when profiler is disabled to make things simple
* Nanokernel: the background task can continue calling flush without taking care
* of profiler state
* Have to consider improving this (task suspend/resume in microkernel mode)
*/
if (prof_state == PROF_STOPPED) {
return;
} else if (prof_state == PROF_STARTING) {
prof_send_platform_info();
prof_state = PROF_STARTED;
}
#else
prof_send_platform_info();
#endif
while (1) {
event_id = 0;
data_length = SIZE32_OF(data);
dropped_count = 0;
/* collect the data */
res = sys_k_event_logger_get(&event_id, &dropped_count, data,
&data_length);
dropped += dropped_count;
if (res == 0) {
if (dropped > 0) {
PRINT("#Dropped events=%d\n", dropped);
dropped = 0;
}
#ifdef PROFILER_SHELL
/* Profiler flush activity will be bypassed after buffer have been fully
* flushed. This is done atomically to avoid running conditions with shell
* command execution (e.g. profiler re-enabled in the mean time)
* Locking IRQs... since code must be nanokernel compliant
*/
key = irq_lock();
if ((sys_k_event_logger_get_mask() == 0)
#ifdef CONFIG_TASK_MONITOR
&& (sys_k_event_logger_get_monitor_mask() == 0)
#endif
) {
prof_state = PROF_STOPPED;
}
irq_unlock(key);
#endif
return;
} else if (res < 0) {
PRINT("#Error: %d\n", res);
} else {
if (event_id != 0) {
key = irq_lock();
/*PRINT("Event %x(%x): %x %x\n", event_id, data_length,
* data[0], data[1]);
*/
out(DLE);
/* NOTE: event ID is 16-bit but we only send 8-bits LSB */
out(event_id & 0xff);
out(data_length);
for (i = 0; i < data_length; i++) {
out((data[i] & 0x000000ff));
out(((data[i] & 0x0000ff00) >> 8));
out(((data[i] & 0x00ff0000) >> 16));
out(((data[i] & 0xff000000) >> 24));
}
irq_unlock(key);
}
}
}
#endif /* ! PROF_UART_TESTMODE */
}
#ifdef CONFIG_MICROKERNEL
void prof(void)
{
prof_init();
PRINT("Background task started\n");
while (1) {
prof_flush();
task_sleep(PROFILER_SLEEPTICKS);
}
}
#endif /* CONFIG_MICROKERNEL */
|