binder: add log information for binder transaction failures

Add additional information to determine the cause of binder
failures. Adds the following to failed transaction log and
kernel messages:
	return_error : value returned for transaction
	return_error_param : errno returned by binder allocator
	return_error_line : line number where error detected

Bug: 36406078
Change-Id: Ifc8881fa5adfcced3f2d67f9030fbd3efa3e2cab
Test: tested manually
Signed-off-by: Todd Kjos <tkjos@google.com>
This commit is contained in:
Todd Kjos
2017-03-22 17:19:52 -07:00
parent 00c7cfdff5
commit 333086d0cb
2 changed files with 67 additions and 11 deletions

View File

@@ -212,6 +212,9 @@ struct binder_transaction_log_entry {
int to_node;
int data_size;
int offsets_size;
int return_error_line;
uint32_t return_error;
uint32_t return_error_param;
const char *context_name;
};
struct binder_transaction_log {
@@ -1833,7 +1836,9 @@ static void binder_transaction(struct binder_proc *proc,
wait_queue_head_t *target_wait;
struct binder_transaction *in_reply_to = NULL;
struct binder_transaction_log_entry *e;
uint32_t return_error;
uint32_t return_error = 0;
uint32_t return_error_param = 0;
uint32_t return_error_line = 0;
struct binder_buffer_object *last_fixup_obj = NULL;
binder_size_t last_fixup_min_off = 0;
struct binder_context *context = proc->context;
@@ -1856,6 +1861,7 @@ static void binder_transaction(struct binder_proc *proc,
binder_user_error("%d:%d got reply transaction with no transaction stack\n",
proc->pid, thread->pid);
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
goto err_empty_call_stack;
}
if (in_reply_to->to_thread != thread) {
@@ -1867,6 +1873,7 @@ static void binder_transaction(struct binder_proc *proc,
in_reply_to->to_thread->pid : 0);
binder_proc_unlock(thread->proc, __LINE__);
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
in_reply_to = NULL;
goto err_bad_call_stack;
}
@@ -1876,6 +1883,7 @@ static void binder_transaction(struct binder_proc *proc,
target_thread = in_reply_to->from;
if (target_thread == NULL) {
return_error = BR_DEAD_REPLY;
return_error_line = __LINE__;
goto err_dead_binder;
}
binder_proc_lock(target_thread->proc, __LINE__);
@@ -1887,6 +1895,7 @@ static void binder_transaction(struct binder_proc *proc,
in_reply_to->debug_id);
binder_proc_unlock(target_thread->proc, __LINE__);
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
in_reply_to = NULL;
target_thread = NULL;
goto err_dead_binder;
@@ -1901,6 +1910,7 @@ static void binder_transaction(struct binder_proc *proc,
binder_user_error("%d:%d got transaction to invalid handle\n",
proc->pid, thread->pid);
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
goto err_invalid_target_handle;
}
target_node = target_ref->node;
@@ -1908,17 +1918,20 @@ static void binder_transaction(struct binder_proc *proc,
target_node = context->binder_context_mgr_node;
if (target_node == NULL) {
return_error = BR_DEAD_REPLY;
return_error_line = __LINE__;
goto err_no_context_mgr_node;
}
}
e->to_node = target_node->debug_id;
if (target_node->is_zombie) {
return_error = BR_DEAD_REPLY;
return_error_line = __LINE__;
goto err_dead_binder;
}
target_proc = target_node->proc;
if (security_binder_transaction(proc->tsk, target_proc->tsk) < 0) {
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
goto err_invalid_target_handle;
}
binder_proc_lock(thread->proc, __LINE__);
@@ -1934,6 +1947,7 @@ static void binder_transaction(struct binder_proc *proc,
tmp->to_thread->pid : 0);
binder_proc_unlock(thread->proc, __LINE__);
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
goto err_bad_call_stack;
}
while (tmp) {
@@ -1958,6 +1972,7 @@ static void binder_transaction(struct binder_proc *proc,
t = kzalloc(sizeof(*t), GFP_KERNEL);
if (t == NULL) {
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
goto err_alloc_t_failed;
}
binder_stats_created(BINDER_STAT_TRANSACTION);
@@ -1965,6 +1980,7 @@ static void binder_transaction(struct binder_proc *proc,
tcomplete = kzalloc(sizeof(*tcomplete), GFP_KERNEL);
if (tcomplete == NULL) {
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
goto err_alloc_tcomplete_failed;
}
binder_stats_created(BINDER_STAT_TRANSACTION_COMPLETE);
@@ -2009,9 +2025,12 @@ static void binder_transaction(struct binder_proc *proc,
t->buffer = binder_alloc_new_buf(&target_proc->alloc, tr->data_size,
tr->offsets_size, extra_buffers_size,
!reply && (t->flags & TF_ONE_WAY));
if (t->buffer == NULL) {
if (IS_ERR(t->buffer)) {
return_error = !(target_proc->tsk->flags & PF_EXITING) ?
BR_FAILED_REPLY : BR_DEAD_REPLY;
return_error_param = PTR_ERR(t->buffer);
return_error_line = __LINE__;
t->buffer = NULL;
goto err_binder_alloc_buf_failed;
}
t->buffer->allow_user_free = 0;
@@ -2035,6 +2054,7 @@ static void binder_transaction(struct binder_proc *proc,
binder_user_error("%d:%d got transaction with invalid data ptr\n",
proc->pid, thread->pid);
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
goto err_copy_data_failed;
}
if (copy_from_user(offp, (const void __user *)(uintptr_t)
@@ -2042,12 +2062,14 @@ static void binder_transaction(struct binder_proc *proc,
binder_user_error("%d:%d got transaction with invalid offsets ptr\n",
proc->pid, thread->pid);
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
goto err_copy_data_failed;
}
if (!IS_ALIGNED(tr->offsets_size, sizeof(binder_size_t))) {
binder_user_error("%d:%d got transaction with invalid offsets size, %lld\n",
proc->pid, thread->pid, (u64)tr->offsets_size);
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
goto err_bad_offset;
}
if (!IS_ALIGNED(extra_buffers_size, sizeof(u64))) {
@@ -2055,6 +2077,7 @@ static void binder_transaction(struct binder_proc *proc,
proc->pid, thread->pid,
extra_buffers_size);
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
goto err_bad_offset;
}
off_end = (void *)off_start + tr->offsets_size;
@@ -2071,6 +2094,7 @@ static void binder_transaction(struct binder_proc *proc,
(u64)off_min,
(u64)t->buffer->data_size);
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
goto err_bad_offset;
}
@@ -2085,6 +2109,8 @@ static void binder_transaction(struct binder_proc *proc,
ret = binder_translate_binder(fp, t, thread);
if (ret < 0) {
return_error = BR_FAILED_REPLY;
return_error_param = ret;
return_error_line = __LINE__;
goto err_translate_failed;
}
} break;
@@ -2096,6 +2122,8 @@ static void binder_transaction(struct binder_proc *proc,
ret = binder_translate_handle(fp, t, thread);
if (ret < 0) {
return_error = BR_FAILED_REPLY;
return_error_param = ret;
return_error_line = __LINE__;
goto err_translate_failed;
}
} break;
@@ -2107,6 +2135,8 @@ static void binder_transaction(struct binder_proc *proc,
if (target_fd < 0) {
return_error = BR_FAILED_REPLY;
return_error_param = target_fd;
return_error_line = __LINE__;
goto err_translate_failed;
}
fp->pad_binder = 0;
@@ -2123,6 +2153,7 @@ static void binder_transaction(struct binder_proc *proc,
binder_user_error("%d:%d got transaction with invalid parent offset or type\n",
proc->pid, thread->pid);
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
goto err_bad_parent;
}
if (!binder_validate_fixup(t->buffer, off_start,
@@ -2132,12 +2163,15 @@ static void binder_transaction(struct binder_proc *proc,
binder_user_error("%d:%d got transaction with out-of-order buffer fixup\n",
proc->pid, thread->pid);
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
goto err_bad_parent;
}
ret = binder_translate_fd_array(fda, parent, t, thread,
in_reply_to);
if (ret < 0) {
return_error = BR_FAILED_REPLY;
return_error_param = ret;
return_error_line = __LINE__;
goto err_translate_failed;
}
last_fixup_obj = parent;
@@ -2153,6 +2187,7 @@ static void binder_transaction(struct binder_proc *proc,
binder_user_error("%d:%d got transaction with too large buffer\n",
proc->pid, thread->pid);
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
goto err_bad_offset;
}
if (copy_from_user(sg_bufp,
@@ -2161,6 +2196,7 @@ static void binder_transaction(struct binder_proc *proc,
binder_user_error("%d:%d got transaction with invalid offsets ptr\n",
proc->pid, thread->pid);
return_error = BR_FAILED_REPLY;
return_error_line = __LINE__;
goto err_copy_data_failed;
}
/* Fixup buffer pointer to target proc address space */
@@ -2175,6 +2211,8 @@ static void binder_transaction(struct binder_proc *proc,
last_fixup_min_off);
if (ret < 0) {
return_error = BR_FAILED_REPLY;
return_error_param = ret;
return_error_line = __LINE__;
goto err_translate_failed;
}
last_fixup_obj = bp;
@@ -2184,6 +2222,8 @@ static void binder_transaction(struct binder_proc *proc,
binder_user_error("%d:%d got transaction with invalid object type, %x\n",
proc->pid, thread->pid, hdr->type);
return_error = BR_FAILED_REPLY;
return_error_param = hdr->type;
return_error_line = __LINE__;
goto err_bad_object_type;
}
}
@@ -2267,13 +2307,17 @@ err_no_context_mgr_node:
binder_put_ref(target_ref);
binder_debug(BINDER_DEBUG_FAILED_TRANSACTION,
"%d:%d transaction failed %d, size %lld-%lld\n",
proc->pid, thread->pid, return_error,
(u64)tr->data_size, (u64)tr->offsets_size);
"%d:%d transaction failed %d/%d, size %lld-%lld line %d\n",
proc->pid, thread->pid, return_error, return_error_param,
(u64)tr->data_size, (u64)tr->offsets_size,
return_error_line);
{
struct binder_transaction_log_entry *fe;
e->return_error = return_error;
e->return_error_param = return_error_param;
e->return_error_line = return_error_line;
fe = binder_transaction_log_add(&binder_transaction_log_failed);
*fe = *e;
}
@@ -4727,11 +4771,13 @@ static void print_binder_transaction_log_entry(struct seq_file *m,
struct binder_transaction_log_entry *e)
{
seq_printf(m,
"%d: %s from %d:%d to %d:%d context %s node %d handle %d size %d:%d\n",
"%d: %s from %d:%d to %d:%d context %s node %d handle %d size %d:%d ret %d/%d l=%d\n",
e->debug_id, (e->call_type == 2) ? "reply" :
((e->call_type == 1) ? "async" : "call "), e->from_proc,
e->from_thread, e->to_proc, e->to_thread, e->context_name,
e->to_node, e->target_handle, e->data_size, e->offsets_size);
e->to_node, e->target_handle, e->data_size, e->offsets_size,
e->return_error, e->return_error_param,
e->return_error_line);
}
static int binder_transaction_log_show(struct seq_file *m, void *unused)

View File

@@ -241,7 +241,7 @@ err_no_vma:
up_write(&mm->mmap_sem);
mmput(mm);
}
return -ENOMEM;
return vma ? -ENOMEM : -ESRCH;
}
struct binder_buffer *binder_alloc_new_buf(struct binder_alloc *alloc,
@@ -257,11 +257,14 @@ struct binder_buffer *binder_alloc_new_buf(struct binder_alloc *alloc,
void *has_page_addr;
void *end_page_addr;
size_t size, data_offsets_size;
struct binder_buffer *eret;
int ret;
mutex_lock(&alloc->mutex);
if (alloc->vma == NULL) {
pr_err("%d: binder_alloc_buf, no vma\n",
alloc->pid);
eret = ERR_PTR(-ESRCH);
goto error_unlock;
}
@@ -272,6 +275,7 @@ struct binder_buffer *binder_alloc_new_buf(struct binder_alloc *alloc,
binder_alloc_debug(BINDER_DEBUG_BUFFER_ALLOC,
"%d: got transaction with invalid size %zd-%zd\n",
alloc->pid, data_size, offsets_size);
eret = ERR_PTR(-EINVAL);
goto error_unlock;
}
size = data_offsets_size + ALIGN(extra_buffers_size, sizeof(void *));
@@ -279,6 +283,7 @@ struct binder_buffer *binder_alloc_new_buf(struct binder_alloc *alloc,
binder_alloc_debug(BINDER_DEBUG_BUFFER_ALLOC,
"%d: got transaction with invalid extra_buffers_size %zd\n",
alloc->pid, extra_buffers_size);
eret = ERR_PTR(-EINVAL);
goto error_unlock;
}
if (is_async &&
@@ -286,6 +291,7 @@ struct binder_buffer *binder_alloc_new_buf(struct binder_alloc *alloc,
binder_alloc_debug(BINDER_DEBUG_BUFFER_ALLOC,
"%d: binder_alloc_buf size %zd failed, no async space left\n",
alloc->pid, size);
eret = ERR_PTR(-ENOSPC);
goto error_unlock;
}
@@ -336,6 +342,7 @@ struct binder_buffer *binder_alloc_new_buf(struct binder_alloc *alloc,
pr_err("allocated: %zd (num: %zd largest: %zd), free: %zd (num: %zd largest: %zd)\n",
total_alloc_size, allocated_buffers, largest_alloc_size,
total_free_size, free_buffers, largest_free_size);
eret = ERR_PTR(-ENOSPC);
goto error_unlock;
}
if (n == NULL) {
@@ -359,9 +366,12 @@ struct binder_buffer *binder_alloc_new_buf(struct binder_alloc *alloc,
(void *)PAGE_ALIGN((uintptr_t)buffer->data + buffer_size);
if (end_page_addr > has_page_addr)
end_page_addr = has_page_addr;
if (binder_update_page_range(alloc, 1,
(void *)PAGE_ALIGN((uintptr_t)buffer->data), end_page_addr, NULL))
ret = binder_update_page_range(alloc, 1,
(void *)PAGE_ALIGN((uintptr_t)buffer->data), end_page_addr, NULL);
if (ret) {
eret = ERR_PTR(ret);
goto error_unlock;
}
rb_erase(best_fit, &alloc->free_buffers);
buffer->free = 0;
@@ -392,7 +402,7 @@ struct binder_buffer *binder_alloc_new_buf(struct binder_alloc *alloc,
error_unlock:
mutex_unlock(&alloc->mutex);
return NULL;
return eret;
}
static void *buffer_start_page(struct binder_buffer *buffer)