joel16/android_kernel_sony_msm8994
1
0
Fork 0
mirror of https://github.com/joel16/android_kernel_sony_msm8994.git synced 2024-11-27 14:11:04 +00:00
Code Issues Actions Packages Projects Releases Wiki Activity

msm: ipc_logging: enhance log-extraction support

Browse Source 
One of the main goals of the IPC Logging is to allow extracting logs
from memory dumps.  The current implementation has the following
limitations:

  1) if logs are being dumped through debugfs at the time of the crash,
     it is not possible to extract logs that were already dumped

  2) it is not always possible to tell the difference between empty,
     partially full, and full log pages resulting in extraction
     complications

  3) if the system memory is not cleared between reboots, then the same
     log ID and log page may be extracted leading to duplicate log
     pages

Add additional debugfs read index, timestamps for log pages, and change
the read/write indices to easily differentiate between empty, partially
full, and full log pages.

CRs-Fixed: 670345
Change-Id: I695f6e0605f3755b868ede59851f5ca919f8fb0d
Signed-off-by: Eric Holmberg <eholmber@codeaurora.org>
This commit is contained in:
Eric Holmberg 2013-10-04 12:17:36 -06:00
parent 37aab70b81
commit ae0b5e6c34
3 changed files with 294 additions and 73 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

89
Documentation/arm/msm/msm_ipc_logging.txt
View File

@ -66,34 +66,71 @@ event log size will be defined as 256 bytes.
Log Space
----------
Each context will have an associated log space, which is dynamically
allocated from the kernel memory-space. The log space is organized as a
list of kernel memory pages. Each page contains header information which
is used to differentiate the log kernel page from the other kernel pages.
Each context (Figure 1) has an associated log space, which is dynamically
allocated from the kernel memory-space. The log space is organized as a list of
1 or more kernel memory pages. Each page (Figure 2) contains header information
which is used to differentiate the log kernel page from the other kernel pages.
0 ---------------------------------
| magic_no = 0x52784425 |
---------------------------------
| nmagic_no = 0xAD87BBDA |
---------------------------------
| log_id |
---------------------------------
| page_num |
---------------------------------
| read_offset | write_offset |
---------------------------------
| next/prev page |
---------------------------------
| |
| Data |
| . |
| . |
| . |
| |
--------------------------------- PAGE_SIZE - 1
This approach will support extracting the logs either from the memory dumps
or from the live targets using DEBUGFS.
0 ---------------------------------
| magic_no = 0x25874452 |
---------------------------------
| nmagic_no = 0x52784425 |
---------------------------------
| version |
---------------------------------
| user_version |
---------------------------------
| log_id |
---------------------------------
| header_size |
---------------------------------
| |
| |
| name [20 chars] |
| |
| |
---------------------------------
| run-time data structures |
---------------------------------
Figure 1 - Log Context Structure
31 0
0 ---------------------------------
| magic_no = 0x52784425 |
---------------------------------
| nmagic_no = 0xAD87BBDA |
---------------------------------
|1| page_num |
---------------------------------
| read_offset | write_offset |
---------------------------------
| log_id |
---------------------------------
| start_time low word |
| start_time high word |
---------------------------------
| end_time low word |
| end_time high word |
---------------------------------
| context offset |
---------------------------------
| run-time data structures |
. . . . .
---------------------------------
| |
| Log Data |
. . .
. . .
| |
--------------------------------- PAGE_SIZE - 1
Figure 2 - Log Page Structure
In addition to extracting logs at runtime through DebugFS, IPC Logging has been
designed to allow extraction of logs from a memory dump. The magic numbers,
timestamps, and context offset are all added to support the memory-dump
extraction use case.
Design
======

215
kernel/trace/ipc_logging.c
View File

@ -30,9 +30,11 @@
#include "ipc_logging_private.h"
#define LOG_PAGE_DATA_SIZE sizeof(((struct ipc_log_page *)0)->data)
#define LOG_PAGE_FLAG (1 << 31)
static LIST_HEAD(ipc_log_context_list);
static DEFINE_RWLOCK(context_list_lock_lha1);
static atomic_t next_log_id = ATOMIC_INIT(0);
static void *get_deserialization_func(struct ipc_log_context *ilctxt,
int type);
@ -50,12 +52,34 @@ static struct ipc_log_page *get_first_page(struct ipc_log_context *ilctxt)
}
/**
* is_ilctxt_empty - Returns true if no data is available to read in log
* is_nd_read_empty - Returns true if no data is available to read in log
*
* @ilctxt: logging context
* @returns: > 1 if context is empty; 0 if not empty; <0 for failure
*
* This is for the debugfs read pointer which allows for a non-destructive read.
* There may still be data in the log, but it may have already been read.
*/
static int is_ilctxt_empty(struct ipc_log_context *ilctxt)
static int is_nd_read_empty(struct ipc_log_context *ilctxt)
{
if (!ilctxt)
return -EINVAL;
return ((ilctxt->nd_read_page == ilctxt->write_page) &&
(ilctxt->nd_read_page->hdr.nd_read_offset ==
ilctxt->write_page->hdr.write_offset));
}
/**
* is_read_empty - Returns true if no data is available in log
*
* @ilctxt: logging context
* @returns: > 1 if context is empty; 0 if not empty; <0 for failure
*
* This is for the actual log contents. If it is empty, then there
* is no data at all in the log.
*/
static int is_read_empty(struct ipc_log_context *ilctxt)
{
if (!ilctxt)
return -EINVAL;
@ -84,64 +108,151 @@ static struct ipc_log_page *get_next_page(struct ipc_log_context *ilctxt,
return pg;
}
/* If data == NULL, drop the log of size data_size*/
/**
* ipc_log_read - do non-destructive read of the log
*
* @ilctxt: Logging context
* @data: Data pointer to receive the data
* @data_size: Number of bytes to read (must be <= bytes available in log)
*
* This read will update a runtime read pointer, but will not affect the actual
* contents of the log which allows for reading the logs continuously while
* debugging and if the system crashes, then the full logs can still be
* extracted.
*/
static void ipc_log_read(struct ipc_log_context *ilctxt,
void *data, int data_size)
{
int bytes_to_read;
bytes_to_read = MIN(((PAGE_SIZE - sizeof(struct ipc_log_page_header))
- ilctxt->read_page->hdr.read_offset),
bytes_to_read = MIN(LOG_PAGE_DATA_SIZE
- ilctxt->nd_read_page->hdr.nd_read_offset,
data_size);
memcpy(data, (ilctxt->nd_read_page->data +
ilctxt->nd_read_page->hdr.nd_read_offset), bytes_to_read);
if (bytes_to_read != data_size) {
/* not enough space, wrap read to next page */
ilctxt->nd_read_page->hdr.nd_read_offset = 0;
ilctxt->nd_read_page = get_next_page(ilctxt,
ilctxt->nd_read_page);
memcpy((data + bytes_to_read),
(ilctxt->nd_read_page->data +
ilctxt->nd_read_page->hdr.nd_read_offset),
(data_size - bytes_to_read));
bytes_to_read = (data_size - bytes_to_read);
}
ilctxt->nd_read_page->hdr.nd_read_offset += bytes_to_read;
}
/**
* ipc_log_drop - do destructive read of the log
*
* @ilctxt: Logging context
* @data: Data pointer to receive the data (or NULL)
* @data_size: Number of bytes to read (must be <= bytes available in log)
*/
static void ipc_log_drop(struct ipc_log_context *ilctxt, void *data,
int data_size)
{
int bytes_to_read;
bytes_to_read = MIN(LOG_PAGE_DATA_SIZE
- ilctxt->read_page->hdr.read_offset,
data_size);
if (data)
memcpy(data, (ilctxt->read_page->data +
ilctxt->read_page->hdr.read_offset), bytes_to_read);
if (bytes_to_read != data_size) {
ilctxt->read_page->hdr.read_offset = 0xFFFF;
ilctxt->read_page = get_next_page(ilctxt, ilctxt->read_page);
/* not enough space, wrap read to next page */
ilctxt->read_page->hdr.read_offset = 0;
if (ilctxt->nd_read_page == ilctxt->read_page) {
/* app reading from the same page */
ilctxt->read_page->hdr.nd_read_offset = 0;
ilctxt->read_page = get_next_page(ilctxt,
ilctxt->read_page);
ilctxt->nd_read_page = ilctxt->read_page;
} else {
ilctxt->read_page = get_next_page(ilctxt,
ilctxt->read_page);
}
if (data)
memcpy((data + bytes_to_read),
(ilctxt->read_page->data +
(ilctxt->read_page->data +
ilctxt->read_page->hdr.read_offset),
(data_size - bytes_to_read));
(data_size - bytes_to_read));
bytes_to_read = (data_size - bytes_to_read);
}
ilctxt->read_page->hdr.read_offset += bytes_to_read;
ilctxt->write_avail += data_size;
/* update non-destructive read pointer if necessary */
if (ilctxt->nd_read_page == ilctxt->read_page) {
uint16_t read_offset, nd_read_offset;
read_offset = ilctxt->read_page->hdr.read_offset;
nd_read_offset = ilctxt->nd_read_page->hdr.nd_read_offset;
if (read_offset > nd_read_offset)
ilctxt->nd_read_page->hdr.nd_read_offset = read_offset;
}
}
/*
* Reads a message.
/**
* msg_read - Reads a message.
*
* If a message is read successfully, then the the message context
* If a message is read successfully, then the message context
* will be set to:
* .hdr message header .size and .type values
* .offset beginning of message data
*
* @ectxt Message context and if NULL, drops the message.
* @ilctxt Logging context
* @ectxt Message context
*
* @returns 0 - no message available
* 1 - message read
* @returns 0 - no message available; >0 message size; <0 error
*/
int msg_read(struct ipc_log_context *ilctxt,
static int msg_read(struct ipc_log_context *ilctxt,
struct encode_context *ectxt)
{
struct tsv_header hdr;
if (!ectxt)
return -EINVAL;
if (is_nd_read_empty(ilctxt))
return 0;
ipc_log_read(ilctxt, &hdr, sizeof(hdr));
if (ectxt) {
ectxt->hdr.type = hdr.type;
ectxt->hdr.size = hdr.size;
ectxt->offset = sizeof(hdr);
ipc_log_read(ilctxt, (ectxt->buff + ectxt->offset),
(int)hdr.size);
} else {
ipc_log_read(ilctxt, NULL, (int)hdr.size);
}
ectxt->hdr.type = hdr.type;
ectxt->hdr.size = hdr.size;
ectxt->offset = sizeof(hdr);
ipc_log_read(ilctxt, (ectxt->buff + ectxt->offset),
(int)hdr.size);
return sizeof(hdr) + (int)hdr.size;
}
/**
* msg_drop - Drops a message.
*
* @ilctxt Logging context
*/
static void msg_drop(struct ipc_log_context *ilctxt)
{
struct tsv_header hdr;
if (!is_read_empty(ilctxt)) {
ipc_log_drop(ilctxt, &hdr, sizeof(hdr));
ipc_log_drop(ilctxt, NULL, (int)hdr.size);
}
}
/*
* Commits messages to the FIFO. If the FIFO is full, then enough
* messages are dropped to create space for the new message.
@ -159,19 +270,25 @@ void ipc_log_write(void *ctxt, struct encode_context *ectxt)
read_lock_irqsave(&context_list_lock_lha1, flags);
spin_lock(&ilctxt->context_lock_lhb1);
while (ilctxt->write_avail < ectxt->offset)
msg_read(ilctxt, NULL);
while (ilctxt->write_avail <= ectxt->offset)
msg_drop(ilctxt);
bytes_to_write = MIN(((PAGE_SIZE - sizeof(struct ipc_log_page_header))
- ilctxt->write_page->hdr.write_offset),
bytes_to_write = MIN(LOG_PAGE_DATA_SIZE
- ilctxt->write_page->hdr.write_offset,
ectxt->offset);
memcpy((ilctxt->write_page->data +
ilctxt->write_page->hdr.write_offset),
ectxt->buff, bytes_to_write);
if (bytes_to_write != ectxt->offset) {
ilctxt->write_page->hdr.write_offset = 0xFFFF;
uint64_t t_now = sched_clock();
ilctxt->write_page->hdr.write_offset += bytes_to_write;
ilctxt->write_page->hdr.end_time = t_now;
ilctxt->write_page = get_next_page(ilctxt, ilctxt->write_page);
ilctxt->write_page->hdr.write_offset = 0;
ilctxt->write_page->hdr.start_time = t_now;
memcpy((ilctxt->write_page->data +
ilctxt->write_page->hdr.write_offset),
(ectxt->buff + bytes_to_write),
@ -269,7 +386,7 @@ static inline int tsv_write_header(struct encode_context *ectxt,
int tsv_timestamp_write(struct encode_context *ectxt)
{
int ret;
unsigned long long t_now = sched_clock();
uint64_t t_now = sched_clock();
ret = tsv_write_header(ectxt, TSV_TYPE_TIMESTAMP, sizeof(t_now));
if (ret)
@ -388,7 +505,7 @@ int ipc_log_extract(void *ctxt, char *buff, int size)
read_lock_irqsave(&context_list_lock_lha1, flags);
spin_lock(&ilctxt->context_lock_lhb1);
while (dctxt.size >= MAX_MSG_DECODED_SIZE &&
!is_ilctxt_empty(ilctxt)) {
!is_nd_read_empty(ilctxt)) {
msg_read(ilctxt, &ectxt);
deserialize_func = get_deserialization_func(ilctxt,
ectxt.hdr.type);
@ -451,7 +568,7 @@ void tsv_timestamp_read(struct encode_context *ectxt,
struct decode_context *dctxt, const char *format)
{
struct tsv_header hdr;
unsigned long long val;
uint64_t val;
unsigned long nanosec_rem;
tsv_read_header(ectxt, &hdr);
@ -582,7 +699,7 @@ void *ipc_log_context_create(int max_num_pages,
{
struct ipc_log_context *ctxt;
struct ipc_log_page *pg = NULL;
int page_cnt, local_log_id;
int page_cnt;
unsigned long flags;
ctxt = kzalloc(sizeof(struct ipc_log_context), GFP_KERNEL);
@ -591,7 +708,6 @@ void *ipc_log_context_create(int max_num_pages,
return 0;
}
local_log_id = atomic_add_return(1, &next_log_id);
init_completion(&ctxt->read_avail);
INIT_LIST_HEAD(&ctxt->page_list);
INIT_LIST_HEAD(&ctxt->dfunc_info_list);
@ -602,28 +718,37 @@ void *ipc_log_context_create(int max_num_pages,
pr_err("%s: cannot create ipc_log_page\n", __func__);
goto release_ipc_log_context;
}
pg->hdr.log_id = (uint64_t)(uintptr_t)ctxt;
pg->hdr.page_num = LOG_PAGE_FLAG | page_cnt;
pg->hdr.ctx_offset = (int64_t)((uint64_t)(uintptr_t)ctxt -
(uint64_t)(uintptr_t)&pg->hdr);
/* set magic last to signal that page init is complete */
pg->hdr.magic = IPC_LOGGING_MAGIC_NUM;
pg->hdr.nmagic = ~(IPC_LOGGING_MAGIC_NUM);
pg->hdr.log_id = (uint32_t)local_log_id;
pg->hdr.page_num = page_cnt;
pg->hdr.read_offset = 0xFFFF;
pg->hdr.write_offset = 0xFFFF;
spin_lock_irqsave(&ctxt->context_lock_lhb1, flags);
list_add_tail(&pg->hdr.list, &ctxt->page_list);
spin_unlock_irqrestore(&ctxt->context_lock_lhb1, flags);
}
ctxt->log_id = (uint64_t)(uintptr_t)ctxt;
ctxt->version = IPC_LOG_VERSION;
strlcpy(ctxt->name, mod_name, IPC_LOG_MAX_CONTEXT_NAME_LEN);
ctxt->user_version = user_version;
ctxt->first_page = get_first_page(ctxt);
ctxt->last_page = pg;
ctxt->write_page = ctxt->first_page;
ctxt->read_page = ctxt->first_page;
ctxt->write_page->hdr.write_offset = 0;
ctxt->read_page->hdr.read_offset = 0;
ctxt->write_avail = max_num_pages * (PAGE_SIZE -
sizeof(struct ipc_log_page_header));
ctxt->nd_read_page = ctxt->first_page;
ctxt->write_avail = max_num_pages * LOG_PAGE_DATA_SIZE;
ctxt->header_size = sizeof(struct ipc_log_page_header);
create_ctx_debugfs(ctxt, mod_name);
/* set magic last to signal context init is complete */
ctxt->magic = IPC_LOG_CONTEXT_MAGIC_NUM;
ctxt->nmagic = ~(IPC_LOG_CONTEXT_MAGIC_NUM);
write_lock_irqsave(&context_list_lock_lha1, flags);
list_add_tail(&ctxt->list, &ipc_log_context_list);
write_unlock_irqrestore(&context_list_lock_lha1, flags);

63
kernel/trace/ipc_logging_private.h
View File

@ -15,16 +15,56 @@
#include <linux/ipc_logging.h>
#define IPC_LOG_VERSION 0x0001
#define IPC_LOG_MAX_CONTEXT_NAME_LEN 20
/**
* struct ipc_log_page_header - Individual log page header
*
* @magic: Magic number (used for log extraction)
* @nmagic: Inverse of magic number (used for log extraction)
* @page_num: Index of page (0.. N - 1) (note top bit is always set)
* @read_offset: Read offset in page
* @write_offset: Write offset in page (or 0xFFFF if full)
* @log_id: ID of logging context that owns this page
* @start_time: Scheduler clock for first write time in page
* @end_time: Scheduler clock for last write time in page
* @ctx_offset: Signed offset from page to the logging context. Used to
* optimize ram-dump extraction.
*
* @list: Linked list of pages that make up a log
* @nd_read_offset: Non-destructive read offset used for debugfs
*
* The first part of the structure defines data that is used to extract the
* logs from a memory dump and elements in this section should not be changed
* or re-ordered. New local data structures can be added to the end of the
* structure since they will be ignored by the extraction tool.
*/
struct ipc_log_page_header {
uint32_t magic;
uint32_t nmagic; /* inverse of magic number */
uint32_t log_id; /* owner of log */
uint32_t nmagic;
uint32_t page_num;
uint16_t read_offset;
uint16_t write_offset;
uint64_t log_id;
uint64_t start_time;
uint64_t end_time;
int64_t ctx_offset;
/* add local data structures after this point */
struct list_head list;
uint16_t nd_read_offset;
};
/**
* struct ipc_log_page - Individual log page
*
* @hdr: Log page header
* @data: Log data
*
* Each log consists of 1 to N log pages. Data size is adjusted to always fit
* the structure into a single kernel page.
*/
struct ipc_log_page {
struct ipc_log_page_header hdr;
char data[PAGE_SIZE - sizeof(struct ipc_log_page_header)];
@ -33,13 +73,23 @@ struct ipc_log_page {
/**
* struct ipc_log_context - main logging context
*
* @magic: Magic number (used for log extraction)
* @nmagic: Inverse of magic number (used for log extraction)
* @version: IPC Logging version of log format
* @user_version: Version number for user-defined messages
* @header_size: Size of the log header which is used to determine the offset
* of ipc_log_page::data
* @log_id: Log ID (assigned when log is created)
* @name: Name of the log used to uniquely identify the log during extraction
*
* @list: List of log contexts (struct ipc_log_context)
* @page_list: List of log pages (struct ipc_log_page)
* @first_page: First page in list of logging pages
* @last_page: Last page in list of logging pages
* @write_page: Current write page
* @read_page: Current read page (for internal reads)
* @nd_read_page: Current debugfs extraction page (non-destructive)
*
* @write_avail: Number of bytes available to write in all pages
* @dent: Debugfs node for run-time log extraction
* @dfunc_info_list: List of deserialization functions
@ -47,7 +97,13 @@ struct ipc_log_page {
* @read_avail: Completed when new data is added to the log
*/
struct ipc_log_context {
uint32_t magic;
uint32_t nmagic;
uint32_t version;
uint16_t user_version;
uint16_t header_size;
uint64_t log_id;
char name[IPC_LOG_MAX_CONTEXT_NAME_LEN];
/* add local data structures after this point */
struct list_head list;
@ -56,6 +112,8 @@ struct ipc_log_context {
struct ipc_log_page *last_page;
struct ipc_log_page *write_page;
struct ipc_log_page *read_page;
struct ipc_log_page *nd_read_page;
uint32_t write_avail;
struct dentry *dent;
struct list_head dfunc_info_list;
@ -81,6 +139,7 @@ enum {
OUTPUT_DEBUGFS,
};
#define IPC_LOG_CONTEXT_MAGIC_NUM 0x25874452
#define IPC_LOGGING_MAGIC_NUM 0x52784425
#define MIN(x, y) ((x) < (y) ? (x) : (y))
#define IS_MSG_TYPE(x) (((x) > TSV_TYPE_MSG_START) && \