mboxd: Introduce a new DEBUG log level
Currently there is no output on the console unless -v is specified on
the command line which enables error output. A second -v will provide
info output.
We probably want error output irrespective of whether a -v was given
on the command line because people generally want to know why their
program stopped working.
Make error output unconditional.
A single -v will give minimal informational output which is a good
level to see what the daemon is doing without barfing all over the
console.
A second -v will enable debug output which will print highly verbose
information which will be useful for debugging. Probably don't enable
this under normal circumstances.
Signed-off-by: Suraj Jitindar Singh <sjitindarsingh@gmail.com>
Change-Id: I3da25f7e4e9e976c17389fcceb1d85ef98de7e0a
diff --git a/mboxd_msg.c b/mboxd_msg.c
index 0cc1cd2..65946e8 100644
--- a/mboxd_msg.c
+++ b/mboxd_msg.c
@@ -112,6 +112,7 @@
}
context->bmc_events |= (bmc_event & mask);
+ MSG_DBG("BMC Events set to: 0x%.2x\n", context->bmc_events);
return write_back ? write_bmc_event_reg(context) : 0;
}
@@ -128,6 +129,7 @@
bool write_back)
{
context->bmc_events &= ~bmc_event;
+ MSG_DBG("BMC Events clear to: 0x%.2x\n", context->bmc_events);
return write_back ? write_bmc_event_reg(context) : 0;
}
@@ -156,8 +158,13 @@
{
struct window_context *window = find_largest_window(context);
uint32_t max_size_mb = window ? (window->size >> 20) : 0;
+ uint8_t ret;
- return align_up(max_size_mb * FLASH_ACCESS_MS_PER_MB, 1000) / 1000;
+ ret = align_up(max_size_mb * FLASH_ACCESS_MS_PER_MB, 1000) / 1000;
+
+ MSG_DBG("Suggested Timeout: %us, max window size: %uMB, for %dms/MB\n",
+ ret, max_size_mb, FLASH_ACCESS_MS_PER_MB);
+ return ret;
}
/*
@@ -197,7 +204,7 @@
mbox_api_version = API_MAX_VERSION;
context->version = mbox_api_version;
- MSG_OUT("Using Protocol Version: %d\n", context->version);
+ MSG_INFO("Using Protocol Version: %d\n", context->version);
/*
* The reset state is currently to have the LPC bus point directly to
@@ -218,7 +225,8 @@
context->block_size_shift = log_2(context->mtd_info.erasesize);
break;
}
- MSG_OUT("Block Size Shift: %d\n", context->block_size_shift);
+ MSG_INFO("Block Size: 0x%.8x (shift: %u)\n",
+ 1 << context->block_size_shift, context->block_size_shift);
/* Now we know the blocksize we can allocate the window dirty_bytemap */
if (mbox_api_version != old_api_version) {
@@ -300,6 +308,8 @@
/* Total LPC Address */
lpc_addr = context->lpc_base + mem_offset;
+ MSG_DBG("LPC address of current window: 0x%.8x\n", lpc_addr);
+
return lpc_addr >> context->block_size_shift;
}
@@ -343,12 +353,13 @@
/* Offset the host has requested */
flash_offset = get_u16(&req->msg.args[0]) << context->block_size_shift;
- MSG_OUT("Host Requested Flash @ 0x%.8x\n", flash_offset);
+ MSG_INFO("Host requested flash @ 0x%.8x\n", flash_offset);
/* Check if we have an existing window */
context->current = search_windows(context, flash_offset,
context->version == API_VERSION_1);
if (!context->current) { /* No existing window */
+ MSG_DBG("No existing window which maps that flash offset\n");
rc = create_map_window(context, &context->current, flash_offset,
context->version == API_VERSION_1);
if (rc < 0) { /* Unable to map offset */
@@ -358,6 +369,10 @@
}
}
+ MSG_INFO("Window @ %p for size 0x%.8x maps flash offset 0x%.8x\n",
+ context->current->mem, context->current->size,
+ context->current->flash_offset);
+
put_u16(&resp->args[0], get_lpc_addr_shifted(context));
if (context->version >= API_VERSION_2) {
put_u16(&resp->args[2], context->current->size >>
@@ -462,6 +477,10 @@
size >>= context->block_size_shift;
}
+ MSG_INFO("Dirty window @ 0x%.8x for 0x%.8x\n",
+ offset << context->block_size_shift,
+ size << context->block_size_shift);
+
return set_window_bytemap(context, context->current, offset, size,
WINDOW_DIRTY);
}
@@ -498,6 +517,10 @@
offset = get_u16(&req->msg.args[0]);
size = get_u16(&req->msg.args[2]);
+ MSG_INFO("Erase window @ 0x%.8x for 0x%.8x\n",
+ offset << context->block_size_shift,
+ size << context->block_size_shift);
+
rc = set_window_bytemap(context, context->current, offset, size,
WINDOW_ERASED);
if (rc < 0) {
@@ -558,6 +581,10 @@
count = 0;
prev = WINDOW_CLEAN;
+ MSG_INFO("Flush window @ %p for size 0x%.8x which maps flash @ 0x%.8x\n",
+ context->current->mem, context->current->size,
+ context->current->flash_offset);
+
/*
* We look for streaks of the same type and keep a count, when the type
* (dirty/erased) changes we perform the required action on the backing
@@ -681,7 +708,8 @@
}
if (seq == context->prev_seq && cmd != MBOX_C_GET_MBOX_INFO) {
- MSG_ERR("Invalid sequence number: %d\n", seq);
+ MSG_ERR("Invalid sequence number: %d, previous: %d\n", seq,
+ context->prev_seq);
return -MBOX_R_SEQ_ERROR;
}
@@ -733,9 +761,9 @@
.args = { 0 },
.response = MBOX_R_SUCCESS
};
- int rc = 0, len;
+ int rc = 0, len, i;
- MSG_OUT("Got data in with command %d\n", req->msg.command);
+ MSG_INFO("Received MBOX command: %u\n", req->msg.command);
rc = check_req_valid(context, req);
if (rc < 0) {
resp.response = -rc;
@@ -751,7 +779,13 @@
context->prev_seq = req->msg.seq;
- MSG_OUT("Writing response to MBOX regs: %d\n", resp.response);
+ MSG_DBG("Writing MBOX response:\n");
+ MSG_DBG("MBOX cmd: %u\n", resp.command);
+ MSG_DBG("MBOX seq: %u\n", resp.seq);
+ for (i = 0; i < MBOX_ARGS_BYTES; i++) {
+ MSG_DBG("MBOX arg[%d]: 0x%.2x\n", i, resp.args[i]);
+ }
+ MSG_INFO("Writing MBOX response: %u\n", resp.response);
len = write(context->fds[MBOX_FD].fd, &resp, sizeof(resp));
if (len < sizeof(resp)) {
MSG_ERR("Didn't write the full response\n");
@@ -770,7 +804,7 @@
*/
static int get_message(struct mbox_context *context, union mbox_regs *msg)
{
- int rc;
+ int rc, i;
rc = read(context->fds[MBOX_FD].fd, msg, sizeof(msg->raw));
if (rc < 0) {
@@ -781,6 +815,13 @@
return -1;
}
+ MSG_DBG("Received MBOX request:\n");
+ MSG_DBG("MBOX cmd: %u\n", msg->msg.command);
+ MSG_DBG("MBOX seq: %u\n", msg->msg.seq);
+ for (i = 0; i < MBOX_ARGS_BYTES; i++) {
+ MSG_DBG("MBOX arg[%d]: 0x%.2x\n", i, msg->msg.args[i]);
+ }
+
return 0;
}
@@ -797,7 +838,6 @@
assert(context);
- MSG_OUT("Dispatched to mbox\n");
rc = get_message(context, &req);
if (rc) {
return rc;
@@ -817,6 +857,7 @@
path, strerror(errno));
return -errno;
}
+ MSG_DBG("Opened mbox dev: %s\n", path);
context->fds[MBOX_FD].fd = fd;