Android平台RTL蓝牙适配偶现打不开问题调试笔记
2020-09-21
关键字：
这篇文章记录一下笔者在RTL一款蓝牙模块在集成到Android开发板上时遇到的一个奇怪的问题的调试过程。
1、问题背景
所述是笔者这边在一款自研Android开发板上集成RTL蓝牙模块时遇到的一个偶现问题。
所用开发板运行Android4.4操作系统，开发板主芯片是海思平台的，蓝牙模块是RTL8761。
2、问题现象
其实海思的SDK中默认就有RTL蓝牙模块的通用驱动。这份通用驱动所能支持的RTL系列蓝牙、WLAN模块的型号还不少，这当然也包括了RTL8761。
在其它若干型号的RTL模块中，这份驱动程序工作良好。但在适配RTL8761时却出现了偶发性的系统起来以后在应用层无法打开蓝牙功能的情况。在Android系统原生设置应用中蓝牙功能页面蓝牙开关一打开就立即自动关闭。
3、结论概要
这个问题的原因是因为驱动程序某些功能的启动时序不对造成的。
解决的办法有二：
1、将蓝牙驱动编进内核镜像中而不是以 ko 的形式由 Android 系统来加载；
2、延迟Android系统中蓝牙服务的相关功能初始化。
4、分析过程
对Android系统集成而言，遇到诸如这种功能上的问题首先当然是从上层应用抓打印以期定位并解决掉问题的。
但这个问题笔者在抓了大量的Logcat以后丝毫无法在框架层，或者说丝毫无法在Android系统层面发现异常点。
那只能去看驱动了。
海思SDK关于RTL的通用驱动位于以下目录中：
./device/hisilicon/bigfish/bluetooth/realtek8xxx/driver
同样，在笔者为这份驱动程序抓了大量的正常、异常情况的日志对比以后也未能定位出确切的问题点。唯一的收获就是发现在冷启动过程中正常的情况下驱动先经历了'COLD'模式启动，然后又来了一次'WARM'模式启动。而功能异常的情况下只有'COLD'模式启动。
相关日志片段如下所示：
rtk_btusb: download_patch: Check fw_info->fw_len:23818 max_patch_size 24576 rtk_btusb: check_fw_version: Controller lmp = 0x8761, patch lmp = 0xfcd2, default patch lmp = 0x8761 rtk_btusb: check_fw_version: Cold BT controller startup rtk_btusb: download_patch: Cold reset bt chip only download rtk_btusb: download_data: start rtk_btusb: download_data: Send frag num 0 rtk_btusb: download_data: Receive acked frag num 0
rtk_btusb: download_patch: Check fw_info->fw_len:23818 max_patch_size 24576 rtk_btusb: check_fw_version: Controller lmp = 0xfcd2, patch lmp = 0xfcd2, default patch lmp = 0x8761 rtk_btusb: check_fw_version: Warm BT controller startup with same lmp rtk_btusb: btusb_open: Start, PM usage count 0 rtk_btusb: btusb_submit_intr_urb: mMaxPacketSize 16, bEndpointAddress 0x81
同时，在这个过程中笔者还发现，如果将驱动程序中的“日志开关”打开了的话，出现问题的概率会显著提高。这个日志开关是位于驱动源码 rtk_btusb.h 中的一个宏定义，如下图所示：
但这仍然不足以定位问题的根源。并且一时之间还让笔者陷入了迷茫，不知接下来该怎样分析了。
在这个迷茫的过程中，笔者开始反思自己怀疑原厂这种通用型的驱动程序代码有Bug是否是自己打从一开始方向就错了。人类宗教，或者说人类的一系列“迷信文化”其实就是源于我们因为自己的“无知”而又恰好在某些机缘巧合的情况下观测到了无法解释的现象，在苦苦寻觅这些神秘现象的答案无果之后进而引发的一系列心理问题而产生的表现。但是笔者是坚定的无神论者与信奉科学的杰出青年，虽内心迷惑，但还不至于迷失自我与放弃底线。
在这些抓打印的日子中，笔者了解到原来所有的--至少笔者当前所在公司使用的RTL型号的--蓝牙模块的驱动过程都是大致如下步骤所示：
1、上电；
2、内核与模块建立通信；
3、根据通信结果决定是否要下载firmware到模块；
4、下载完成后重新驱动模块；
5、驱动完成，可以正常提供服务。
而前文提到的'COLD'与'WARM'启动差异中，'COLD'模式下正是内核向模块下载firmware的阶段，'WARM'模式看起来像是上述步骤中的第4步重新驱动模块的过程。但笔者抓到的所有内核日志中都没有表现出firmware下载失败的意思。
这么看来问题似乎是出在firmware下载完成后的重驱动过程。
查看这个驱动程序的 Makefile，发现它是以 ko 的形式单独编译并打包进Android系统中的，且在Android系统中的 init.rc 中加载。
这会有什么问题吗？
init.rc 是由Android系统执行的。这说明，当RTL8761驱动被加载的时候Android系统已经起来了。而Android系统在起来以后马上就会去启动各种系统服务，这其中就包括蓝牙系统服务的初始化。而且蓝牙驱动的加载与蓝牙系统服务的初始化是异步进行。
而且蓝牙系统服务又是依赖于蓝牙驱动所提供的基础功能服务的。如果蓝牙系统服务在初始化过程中要用到驱动中的某些功能或信息，而此时若蓝牙驱动尚未加载完成--这非常有可能，因为蓝牙模块在正常工作之前需要先下载firmware，这是比较耗时的--这些功能刚好还未能提供，那Android层的蓝牙系统服务是不是会初始化失败？若所涉及的模块没有足够强大的容错机制，那在后续Android应用层是否就会表现出无法正常使用蓝牙的现象？听起来非常合乎逻辑没错吧！
那接下来就去看看蓝牙系统服务是如何初始化的。
Android系统蓝牙服务的分析过程这里就不详细写了，笔者这边也并没有多详细的去研究它。总之，最终笔者通过延时了一个消息事件的传递而“规避”掉了这个问题。这个消息就是 BluetoothManagerService.java 中约 147 行的一个广播接收器中的消息转发，具体延时传递的消息修改如下图所示：
打上这个补丁以后，问题就没有再出现过了。这事实上就是因为蓝牙模块的驱动时序与Android系统的蓝牙服务初始化时序没有匹配好导致的问题。解决它的办法在本文第3节也贴出来了。
不过，这个问题虽然规避掉了，另外一个问题又出现了：为何同样的软件流程，这款通用驱动程序在其它型号的模块上没有问题呢？
笔者猜测，可能是跟驱动程序中所做的“耗时操作”太多了导致的。换言之，这份驱动程序在逻辑上是没问题的，但是存在隐患。隐患就是驱动过程所消耗的时间超过一定范围，就会导致上层无法使用蓝牙功能。
同时，笔者还发现 RTL8761 这款蓝牙模块的firmware的尺寸达到了67KB，笔者公司项目使用的其它型号的firmware只有40KB左右，体积增加了50%。而且内核到模块之间下载firmware所使用的是串行通信，速度是很慢的。这在无形之中又增加了驱动过程的时间消耗。各种“无心之举”加持之下，问题终于暴发了。
另外，尽可能地关闭驱动程序中的“日志打印”也是很有必要的。在嵌入式Linux内核中，消息打印还是比较消耗资源的。
最后，这个问题的原因其实还是基于笔者个人的猜测，并没有得到原厂的承认甚至于笔者本人也不敢保证自己的猜测就一定是其真实原因。但无论如何，强扭的瓜虽不甜，却也能解渴啊不是！
