michaelh/zephyr
1
0
Fork 0
Code Releases Activity

profiler: use new ring buffer data structure

Browse source 
The profiler now uses the generic ring buffer. The dropped event
count is stored in the ring buffer's value field. The data size only
refers to the extra data attached to the message and NOT any internal
representation of metadata inside the ring buffer, the event_logger
APIs now pass this information along in dedicated parameters.

Change-Id: I1f168e6a05e8d937bf86b2a4cccecbb04b0118c6
Signed-off-by: Andrew Boie <andrew.p.boie@intel.com>
This commit is contained in:
Andrew Boie 2015-08-27 14:03:15 -07:00 • committed by Anas Nashif
commit 7c43992f22
8 changed files with 106 additions and 114 deletions
Download patch file Download diff file Expand all files Collapse all files

51
include/misc/event_logger.h
View file

@ -42,27 +42,11 @@
#include <nanokernel.h>
#include <errno.h>
struct event_header_bits {
/* length in 32-bit words */
uint32_t data_length :4;
uint32_t dropped_count :4;
uint32_t event_id :16;
uint32_t reserved :8;
};
union event_header {
uint32_t block;
struct event_header_bits bits;
};
#include <misc/ring_buffer.h>
struct event_logger {
uint32_t head;
uint32_t tail;
uint16_t dropped_event_count;
struct nano_sem sync_sema;
uint32_t *buffer;
uint32_t buffer_size;
struct ring_buf ring_buf;
};
@ -109,16 +93,19 @@ void sys_event_logger_put(struct event_logger *logger, uint16_t event_id,
* from a fiber.
*
* @param logger Pointer to the event logger used.
* @param event_id Pointer to the id of the event fetched
* @param dropped_event_count Pointer to how many events were dropped
* @param buffer Pointer to the buffer where the message will be copied.
* @param buffer_size Size of the buffer in 32-bit words.
* @param buffer_size Size of the buffer in 32-bit words. Updated with the
* actual message size.
*
* @return -EMSGSIZE if the buffer size is smaller than the message size, or
* the amount of 32-bit words copied. 0 (zero) if there was no message already
* available.
*/
int sys_event_logger_get(struct event_logger *logger, uint32_t *buffer,
uint8_t buffer_size);
int sys_event_logger_get(struct event_logger *logger, uint16_t *event_id,
uint8_t *dropped_event_count, uint32_t *buffer,
uint8_t *buffer_size);
/**
* @brief Retrieve an event message from the logger, wait if empty.
@ -131,14 +118,18 @@ int sys_event_logger_get(struct event_logger *logger, uint32_t *buffer,
* fiber.
*
* @param logger Pointer to the event logger used.
* @param event_id Pointer to the id of the event fetched
* @param dropped_event_count Pointer to how many events were dropped
* @param buffer Pointer to the buffer where the message will be copied.
* @param buffer_size Size of the buffer in 32-bit words.
* @param buffer_size Size of the buffer in 32-bit words. Updated with the
* actual message size.
*
* @return -EMSGSIZE if the buffer size is smaller than the message size. Or
* the amount of DWORDs copied.
*/
int sys_event_logger_get_wait(struct event_logger *logger, uint32_t *buffer,
uint8_t buffer_size);
int sys_event_logger_get_wait(struct event_logger *logger, uint16_t *event_id,
uint8_t *dropped_event_count, uint32_t *buffer,
uint8_t *buffer_size);
#ifdef CONFIG_NANO_TIMEOUTS
/**
@ -153,8 +144,11 @@ int sys_event_logger_get_wait(struct event_logger *logger, uint32_t *buffer,
* the timeout expires. It can only be called from a fiber.
*
* @param logger Pointer to the event logger used.
* @param event_id Pointer to the id of the event fetched
* @param dropped_event_count Pointer to how many events were dropped
* @param buffer Pointer to the buffer where the message will be copied.
* @param buffer_size Size of the buffer.
* @param buffer_size Size of the buffer in 32-bit words. Updated with the
* actual message size.
* @param timeout Timeout in ticks.
*
* @return -EMSGSIZE if the buffer size is smaller than the message size. Or
@ -162,7 +156,10 @@ int sys_event_logger_get_wait(struct event_logger *logger, uint32_t *buffer,
* was no message already available.
*/
int sys_event_logger_get_wait_timeout(struct event_logger *logger,
uint32_t *buffer, uint8_t buffer_size, uint32_t timeout);
uint16_t *event_id,
uint8_t *dropped_event_count,
uint32_t *buffer, uint8_t *buffer_size,
uint32_t timeout);
#endif /* CONFIG_NANO_TIMEOUTS */
#endif /* _ASMLANGUAGE */

24
include/misc/profiler.h
View file

@ -99,6 +99,8 @@ void sys_profiler_put_timed(uint16_t event_id);
* buffer. If the buffer is smaller than the message size the function returns
* an error. The function retrieves messages in FIFO order.
*
* @param event_id Pointer to the id of the event fetched
* @param dropped_event_count Pointer to how many events were dropped
* @param buffer Pointer to the buffer where the message will be copied.
* @param buffer_size Size of the buffer in 32-bit words.
*
@ -106,8 +108,9 @@ void sys_profiler_put_timed(uint16_t event_id);
* the amount of 32-bit words copied or zero if there are no profile event
* messages available.
*/
#define sys_profiler_get(buffer, buffer_size) \
sys_event_logger_get(&sys_profiler_logger, buffer, buffer_size)
#define sys_profiler_get(event_id, dropped, buffer, buffer_size) \
sys_event_logger_get(&sys_profiler_logger, event_id, dropped, buffer, \
buffer_size)
/**
@ -120,14 +123,17 @@ void sys_profiler_put_timed(uint16_t event_id);
* profiler event message available the caller pends until a new message is
* logged.
*
* @param event_id Pointer to the id of the event fetched
* @param dropped_event_count Pointer to how many events were dropped
* @param buffer Pointer to the buffer where the message will be copied.
* @param buffer_size Size of the buffer in 32-bit words.
*
* @return -EMSGSIZE if the buffer size is smaller than the message size, or
* the amount of 32-bit words copied.
*/
#define sys_profiler_get_wait(buffer, buffer_size) \
sys_event_logger_get_wait(&sys_profiler_logger, buffer, buffer_size)
#define sys_profiler_get_wait(event_id, dropped, buffer, buffer_size) \
sys_event_logger_get_wait(&sys_profiler_logger, event_id, dropped, \
buffer, buffer_size)
#ifdef CONFIG_NANO_TIMEOUTS
@ -142,6 +148,8 @@ void sys_profiler_put_timed(uint16_t event_id);
* profiler event messages available the caller pends until a new message is
* logged or the timeout expires.
*
* @param event_id Pointer to the id of the event fetched
* @param dropped_event_count Pointer to how many events were dropped
* @param buffer Pointer to the buffer where the message will be copied.
* @param buffer_size Size of the buffer in 32-bit words.
* @param timeout Timeout in ticks.
@ -150,9 +158,11 @@ void sys_profiler_put_timed(uint16_t event_id);
* amount of 32-bit words copied or zero if the timeout expires and the was no
* message available.
*/
#define sys_profiler_get_wait_timeout(buffer, buffer_size, timeout) \
sys_event_logger_get_wait_timeout(&sys_profiler_logger, buffer, \
buffer_size, timeout)
#define sys_profiler_get_wait_timeout(event_id, dropped, buffer, buffer_size, \
timeout) \
sys_event_logger_get_wait_timeout(event_id, dropped, \
&sys_profiler_logger, buffer, \
buffer_size, timeout)
#endif /* CONFIG_NANO_TIMEOUTS */

1
kernel/Kconfig
View file

@ -116,6 +116,7 @@ config EVENT_LOGGER
bool
prompt "Enable event logger"
default n
select RING_BUFFER
help
Enable event logging feature. Allow the usage of a ring buffer to
transmit event messages with a single interface to collect them.

105
kernel/nanokernel/event_logger.c
View file

@ -34,15 +34,12 @@
*/
#include <misc/event_logger.h>
#include <misc/ring_buffer.h>
void sys_event_logger_init(struct event_logger *logger,
uint32_t *logger_buffer, uint32_t buffer_size)
{
logger->head = logger->tail = 0;
logger->dropped_event_count = 0;
logger->buffer = logger_buffer;
logger->buffer_size = buffer_size;
sys_ring_buf_init(&logger->ring_buf, buffer_size, logger_buffer);
nano_sem_init(&(logger->sync_sema));
}
@ -51,45 +48,19 @@ static void event_logger_put(struct event_logger *logger, uint16_t event_id,
uint32_t *event_data, uint8_t data_size,
void(*sem_give_fn)(struct nano_sem *))
{
int ret;
unsigned int key;
unsigned int buffer_capacity_used;
union event_header header;
int i;
/* Lock interrupt to be sure this function will be atomic */
key = irq_lock();
buffer_capacity_used = (logger->head - logger->tail +
logger->buffer_size) % logger->buffer_size;
/* check if there is space to the new event */
if (buffer_capacity_used + EVENT_HEADER_SIZE + data_size >=
logger->buffer_size) {
(logger->dropped_event_count)++;
} else {
/* build the header */
header.bits.data_length = data_size;
header.bits.event_id = event_id;
header.bits.dropped_count = logger->dropped_event_count;
logger->dropped_event_count = 0;
/* copy the header to the buffer */
logger->buffer[logger->head] = header.block;
logger->head = (logger->head + EVENT_HEADER_SIZE) %
logger->buffer_size;
/* copy the extra data to the buffer */
for (i=0; i < header.bits.data_length; ++i) {
logger->buffer[(logger->head + i) %
logger->buffer_size] = event_data[i];
}
logger->head = (logger->head + header.bits.data_length) %
logger->buffer_size;
ret = sys_ring_buf_put(&logger->ring_buf, event_id,
logger->ring_buf.dropped_put_count, event_data,
data_size);
if (ret == 0) {
logger->ring_buf.dropped_put_count = 0;
/* inform that there is event data available on the buffer */
sem_give_fn(&(logger->sync_sema));
}
irq_unlock(key);
}
@ -129,57 +100,65 @@ void _sys_event_logger_put_non_preemptible(struct event_logger *logger,
}
static inline int event_logger_get(struct event_logger *logger,
uint32_t *buffer, uint8_t buffer_size)
static int event_logger_get(struct event_logger *logger,
uint16_t *event_id, uint8_t *dropped_event_count,
uint32_t *buffer, uint8_t *buffer_size)
{
int i;
union event_header *header;
int ret;
/* obtain the header */
header = (union event_header *) &(logger->buffer[logger->tail]);
if (buffer_size < EVENT_HEADER_SIZE + header->bits.data_length) {
/* if the user can not retrieve the message, we increase the semaphore
* to indicate that the message remains in the buffer */
ret = sys_ring_buf_get(&logger->ring_buf, event_id, dropped_event_count,
buffer, buffer_size);
if (likely(!ret)) {
return *buffer_size;
}
switch (ret) {
case -EMSGSIZE:
/* if the user can not retrieve the message, we increase the
* semaphore to indicate that the message remains in the buffer
*/
nano_fiber_sem_give(&(logger->sync_sema));
return -EMSGSIZE;
case -EAGAIN:
return 0;
default:
return ret;
}
for (i=0; i < header->bits.data_length + EVENT_HEADER_SIZE; i++) {
buffer[i] = logger->buffer[(logger->tail + i) %
logger->buffer_size];
}
logger->tail = (logger->tail + header->bits.data_length +
EVENT_HEADER_SIZE) % logger->buffer_size;
return header->bits.data_length + EVENT_HEADER_SIZE;
}
int sys_event_logger_get(struct event_logger *logger, uint32_t *buffer,
uint8_t buffer_size)
int sys_event_logger_get(struct event_logger *logger, uint16_t *event_id,
uint8_t *dropped_event_count, uint32_t *buffer,
uint8_t *buffer_size)
{
if (nano_fiber_sem_take(&(logger->sync_sema))) {
return sys_event_logger_get(logger, buffer, buffer_size);
return event_logger_get(logger, event_id, dropped_event_count,
buffer, buffer_size);
}
return 0;
}
int sys_event_logger_get_wait(struct event_logger *logger, uint32_t *buffer,
uint8_t buffer_size)
int sys_event_logger_get_wait(struct event_logger *logger, uint16_t *event_id,
uint8_t *dropped_event_count, uint32_t *buffer,
uint8_t *buffer_size)
{
nano_fiber_sem_take_wait(&(logger->sync_sema));
return event_logger_get(logger, buffer, buffer_size);
return event_logger_get(logger, event_id, dropped_event_count, buffer,
buffer_size);
}
#ifdef CONFIG_NANO_TIMEOUTS
int sys_event_logger_get_wait_timeout(struct event_logger *logger,
uint32_t *buffer, uint8_t buffer_size, uint32_t timeout)
uint16_t *event_id,
uint8_t *dropped_event_count,
uint32_t *buffer, uint8_t *buffer_size,
uint32_t timeout)
{
if (nano_fiber_sem_take_wait_timeout(&(logger->sync_sema), timeout)) {
return event_logger_get(logger, buffer, buffer_size);
return event_logger_get(logger, event_id, dropped_event_count,
buffer, buffer_size);
}
return 0;
}

2
kernel/nanokernel/profiler.c
View file

@ -91,7 +91,7 @@ void _sys_profiler_context_switch(void)
uint8_t data_size);
/* if the profiler has not been initialized, we do nothing */
if (sys_profiler_logger.buffer == NULL) {
if (sys_profiler_logger.ring_buf.buf == NULL) {
return;
}

1
samples/microkernel/apps/profiler_sample/prj_arm.conf
View file

@ -1,6 +1,7 @@
CONFIG_COMPILER_OPT="-O0"
CONFIG_NUM_IRQS=43
CONFIG_NANO_TIMEOUTS=y
CONFIG_RING_BUFFER=y
CONFIG_KERNEL_PROFILER=y
CONFIG_PROFILER_BUFFER_SIZE=16
CONFIG_PROFILER_CONTEXT_SWITCH=y

1
samples/microkernel/apps/profiler_sample/prj_x86.conf
View file

@ -1,5 +1,6 @@
# Let stack canaries use non-random number generator.
# This option is NOT to be used in production code.
CONFIG_RING_BUFFER=y
CONFIG_KERNEL_PROFILER=y
CONFIG_NANO_TIMEOUTS=y
CONFIG_PROFILER_BUFFER_SIZE=16

35
samples/microkernel/apps/profiler_sample/src/profiler_collector_sample.c
View file

@ -282,7 +282,8 @@ void profiling_data_collector(void)
{
int res;
uint32_t data[4];
union event_header *header;
uint8_t dropped_count;
uint16_t event_id;
/* We register the fiber as collector to avoid this fiber generating a
* context switch event every time it collects the data
@ -291,44 +292,46 @@ void profiling_data_collector(void)
while(1) {
/* collect the data */
res = sys_profiler_get_wait(data, 10);
uint8_t data_length = SIZE32_OF(data);
res = sys_profiler_get_wait(&event_id, &dropped_count, data,
&data_length);
if (res > 0) {
header = (union event_header *)&(data[0]);
/* Register the amount of droppped events occurred */
if (header->bits.dropped_count) {
total_dropped_counter += header->bits.dropped_count;
if (dropped_count) {
total_dropped_counter += dropped_count;
}
/* process the data */
switch (header->bits.event_id) {
switch (event_id) {
case PROFILER_CONTEXT_SWITCH_EVENT_ID:
if (header->bits.data_length != 2) {
if (data_length != 2) {
PRINTF("\x1b[13;1HError in context switch message. "
"event_id = %d, Expected %d, received %d\n",
header->bits.event_id, 2, header->bits.data_length);
event_id, 2, data_length);
} else {
register_context_switch_data(data[1], data[2]);
register_context_switch_data(data[0], data[1]);
}
break;
case PROFILER_INTERRUPT_EVENT_ID:
if (header->bits.data_length != 2) {
if (data_length != 2) {
PRINTF("\x1b[13;1HError in sleep message. "
"event_id = %d, Expected %d, received %d\n",
header->bits.event_id, 2, header->bits.data_length);
event_id, 2, data_length);
} else {
register_interrupt_event_data(data[1], data[2]);
register_interrupt_event_data(data[0], data[1]);
}
break;
case PROFILER_SLEEP_EVENT_ID:
if (header->bits.data_length != 3) {
if (data_length != 3) {
PRINTF("\x1b[13;1HError in sleep message. "
"event_id = %d, Expected %d, received %d\n",
header->bits.event_id, 3, header->bits.data_length);
event_id, 3, data_length);
} else {
register_sleep_event_data(data[1], data[2], data[3]);
register_sleep_event_data(data[0], data[1], data[2]);
}
break;
default:
PRINTF("unrecognized event id %d", event_id);
}
} else {
/* This error should never happen */