千里马android framework实战开发-binder驱动之oneway导致的transaction failed

Posted 2021-10-25 Android高级知识分享官

csdn在线学习课程，课程咨询答疑和新课信息：QQ交流群：422901085进行课程讨论

android跨进程通信实战视频课程（加群获取优惠）

千里马android framework实战开发-binder驱动之oneway导致的transaction failed

首先来看错误：

06-15 12:10:36.686 31395 31507 W System.err: android.os.DeadObjectException: Transaction failed on small parcel; remote process probably died
06-15 12:10:36.686 31395 31512 E JavaBinder: !!! FAILED BINDER TRANSACTION !!!  (parcel size = 112)
06-15 12:10:36.686 31395 31507 W System.err: 	at android.os.BinderProxy.transactNative(Native Method)
06-15 12:10:36.687 31395 31507 W System.err: 	at android.os.BinderProxy.transact(BinderProxy.java:511)
06-15 12:10:36.688 31395 31507 W System.err: 	at com.example.servicedemo.IStudentInterface1$Stub$Proxy.addStudentId(IStudentInterface1.java:126)
06-15 12:10:36.688 31395 31507 W System.err: 	at com.example.servicedemo.MainActivity$2$1$1.run(MainActivity.java:71)
06-15 12:10:36.688 31395 31507 W System.err: 	at java.lang.Thread.run(Thread.java:919)
06-15 12:10:36.689 31395 31512 W System.err: android.os.DeadObjectException: Transaction failed on small parcel; remote process probably died
06-15 12:10:36.655     0     0 I binder  : 31395:31512 transaction failed 29201/-28, size 112-0 line 3132
06-15 12:10:36.657     0     0 I binder  : 31395:31509 transaction failed 29201/-28, size 112-0 line 3132
06-15 12:10:36.662     0     0 I binder  : 31395:31514 transaction failed 29201/-28, size 112-0 line 3132
06-15 12:10:36.662     0     0 I binder  : 31395:31513 transaction failed 29201/-28, size 112-0 line 3132
06-15 12:10:36.689 31395 31509 E JavaBinder: !!! FAILED BINDER TRANSACTION !!!  (parcel size = 112)
06-15 12:10:36.689 31395 31512 W System.err: 	at android.os.BinderProxy.transactNative(Native Method)
06-15 12:10:36.689 31395 31512 W System.err: 	at android.os.BinderProxy.transact(BinderProxy.java:511)
06-15 12:10:36.691 31395 31512 W System.err: 	at com.example.servicedemo.IStudentInterface1$Stub$Proxy.addStudentId(IStudentInterface1.java:126)
06-15 12:10:36.691 31395 31512 W System.err: 	at com.example.servicedemo.MainActivity$2$1$1.run(MainActivity.java:71)
06-15 12:10:36.692 31395 31512 W System.err: 	at java.lang.Thread.run(Thread.java:919)

大家看眨眼一看：
06-15 12:10:36.689 31395 31512 W System.err: android.os.DeadObjectException: Transaction failed on small parcel; remote process probably died

但是我们看了一下目标进程根本没有死，所以这里的日志写的目标进程可能死了压根就是不对的，故只能继续分析log
这里提醒大家注意，这种binder跨进程传输异常时候，如果用户空间看着没有什么明显不对，而且这个错误本身就是binder驱动返回的错误，那么接下来要分析的日志应该是kernel日志，对了这里提醒一下抓取kernel日志为：
adb logcat -b all > 1.txt这里-b all就是代表抓取所有日志：main，events，system，kernel，而平常的adb logcat就是只抓取main日志哦

kernel日志一般显示的进程号是 0，所以在W System.err: android.os.DeadObjectException: Transaction failed on small parcel; remote process probably died周围我们分析kernel日志有如下打印：

06-15 12:10:36.655     0     0 I binder  : 31395:31512 transaction failed 29201/-28, size 112-0 line 3132
06-15 12:10:36.657     0     0 I binder  : 31395:31509 transaction failed 29201/-28, size 112-0 line 3132
06-15 12:10:36.662     0     0 I binder  : 31395:31514 transaction failed 29201/-28, size 112-0 line 3132
06-15 12:10:36.662     0     0 I binder  : 31395:31513 transaction failed 29201/-28, size 112-0 line 3132

这里就明显是kernel中binder驱动打印出来的，这里是不是也打印transaction failed，而且还打印了对应的行数3132,这里我们来看3132行的代码：

这里明显可以看出是transaction时候去目标进程申请内存时候失败，那内存失败又可能有几种情况：
1、可能是目标进程内存满了不可以申请
2、本身有什么其他系统错误
那么基于以上怀疑再看日志发现：

在1ms以内有多次失败打印，那么这里我们是不是有理由怀疑是不是这里客户端发起了非常非常频繁的binder调用，而且应该还是个异步调用即oneway方式，为什么呢？因为只有oneway这种异步调用在内核binder驱动中是会采用积压队列的方式，这样如果说我们的客户端发起了很多次的oneway调用，那么驱动他也是依次来执行，把还没有执行的任务缓存到队列，，但是这里大家想一想，任务还没执行进入了队列，即代表只从目标进程申请的内存也是不可以释放的，这里目标进程的共享内存本身又是1M-8K而且异步的限制还是一半，即500K，意味着如果发起5000次调用，每次调用超过100字节，那么就很有可能导致无法在申请内存导致看到异常。具体oneway情况下队列的缓存起来依次处理可以看如下代码：

static bool binder_proc_transaction(struct binder_transaction *t,
				    struct binder_proc *proc,
				    struct binder_thread *thread)
{
	struct binder_node *node = t->buffer->target_node;
	struct binder_priority node_prio;
	bool oneway = !!(t->flags & TF_ONE_WAY);
	bool pending_async = false;

	BUG_ON(!node);
	binder_node_lock(node);
	node_prio.prio = node->min_priority;
	node_prio.sched_policy = node->sched_policy;

	if (oneway) {//如果是oneway
		BUG_ON(thread);
		if (node->has_async_transaction) {
		//第一次肯定还没执行async transaction，这里需要执行async过程中，又还没有结束，再次有对同一个node的 oneway调用
			pending_async = true;//这里如果已经有async任务正在执行，需要置位这里让下一延时执行
		} else {
		//首次置位正在执行
			node->has_async_transaction = 1;
		}
	}

	binder_inner_proc_lock(proc);
//忽略一般不会有这异常
	if (proc->is_dead || (thread && thread->is_dead)) {
		binder_inner_proc_unlock(proc);
		binder_node_unlock(node);
		return false;
	}
//第一次pending_async没有被置位true所以会寻找线程，如果pending_async被置位则不需要寻找目标线程
	if (!thread && !pending_async)
		thread = binder_select_thread_ilocked(proc);

	if (thread) {
		binder_transaction_priority(thread->task, t, node_prio,
					    node->inherit_rt);
		binder_enqueue_thread_work_ilocked(thread, &t->work);
	} else if (!pending_async) {
		binder_enqueue_work_ilocked(&t->work, &proc->todo);
	} else {
	//如果pending_async被置成了true,则不执行work，而是放入async_todo队列积压
		binder_enqueue_work_ilocked(&t->work, &node->async_todo);
	}

	if (!pending_async)//pending_async为true则不唤醒不执行
		binder_wakeup_thread_ilocked(proc, thread, !oneway /* sync */);

	binder_inner_proc_unlock(proc);
	binder_node_unlock(node);

	return true;
}

注释也很详细，总结就是oneway情况下一旦同一个binder_node有正在执行的async任务，则需要对后面来的任务进行缓存到async_todo队列

那么async_todo什么时候被取出来执行呢？

case BC_FREE_BUFFER: {
			binder_uintptr_t data_ptr;
			struct binder_buffer *buffer;

			if (get_user(data_ptr, (binder_uintptr_t __user *)ptr))
				return -EFAULT;
			ptr += sizeof(binder_uintptr_t);

			buffer = binder_alloc_prepare_to_free(&proc->alloc,
							      data_ptr);
			。。省略
			if (buffer->async_transaction && buffer->target_node) {
				struct binder_node *buf_node;
				struct binder_work *w;

				buf_node = buffer->target_node;
				binder_node_inner_lock(buf_node);
				BUG_ON(!buf_node->has_async_transaction);
				BUG_ON(buf_node->proc != proc);
				//取出async_todo
				w = binder_dequeue_work_head_ilocked(
						&buf_node->async_todo);
				if (!w) {
				//如果发现async_todo中已经没有任务了则has_async_transaction 又变成没有正在执行任务 
					buf_node->has_async_transaction = 0;
				} else {
					binder_enqueue_work_ilocked(
							w, &proc->todo);
					binder_wakeup_proc_ilocked(proc);
				}
				binder_node_inner_unlock(buf_node);
			}
			trace_binder_transaction_buffer_release(buffer);
			binder_transaction_buffer_release(proc, buffer, NULL);
			binder_alloc_free_buf(&proc->alloc, buffer);
			break;
		}

即在FREE_BUFFER时候才会从async todo队列中取出，即说明要正式执行完成这个通信才可以进行下一次

这里就清楚了oneway情况执行，也就说明了如果我们短时间发起非常非常频繁调用时候就非常容易导致有限的共享内存被耗尽，从而到了transaction failed。这里情况如果产生在应用大家可能只是说看到了Remote异常，大家业务可能影响不是非常非常大，大不了自己的应用crash，但是如果这个异常产生在systemserver那可能就比较麻烦，出现的问题表现可能是某个回调接收不到这种，排查就非常非常麻烦，所以这里课程的应用就故意写了这种oneway情况下频繁调用来模拟出这个报错：
06-15 12:10:36.657 0 0 I binder : 31395:31509 transaction failed 29201/-28, size 112-0 line 3132
如果你在分析日志过程中也发现这个错误，但是因为一些第三方应用你也无法获取代码，你就可以根据我们自己写一个频繁调用例子来报错，发现报错的类型（29201/-28这个就是表示类型）和行数（3132）既可以间接证明是这样一种报错，可以让对应第三方应用修改，或者说知道哪个接口了，就在框架中对这个接口调用进行一个频率限制，来规避这个问题。