最近在做一个基于芯科EFR32系列芯片的BLE主机项目简单说就是让设备作为Central端去扫描、连接周边的心率计、环境传感器这些外设再把数据汇聚起来统一上报。整个开发过程中最让我头疼的不是BLE协议本身反而是看起来最简单的打印LOG这件事。芯片端不像手机端有现成的Logcat可以用串口、RTT、SWO各种通道各有脾气踩了一堆坑之后我觉得有必要把这段经历完整记录下来给准备上手芯科BLE方案、尤其是做主机Central模式的工程师一点参考。这个项目会牵扯到扫描、多连接管理、GATT操作、连接参数维护每一层出了问题都要靠日志来定位。但无线协议栈项目里的日志打印和普通MCU开发完全不是一回事——它不只是“加个printf就行”打印太慢会干扰协议栈时序打印位置不对会直接卡死打印口没选好还会把功耗测试整个毁掉。这篇文章里我会把自己实际遇到的坑、排查过程和最终方案都讲清楚从日志通道选型到缓冲队列实现再到发布版怎么把日志关干净尽量做到看完了就能上手。1. 项目概述与整体思路1.1 这个项目在做什么EFR32跑BLE Central先说清楚项目背景。设备端用的是芯科EFR32BG22系列SoC这颗芯片在低功耗蓝牙市场很常见Cortex-M33内核BLE 5.x协议栈片上资源够用关键是低功耗表现确实好。我们的设备作为BLE主机Central主要任务是周期性扫描周围的BLE外设比如心率计、温湿度传感器、电量监测模块这些主动发起连接然后通过GATT读写特征值把数据取回来最多同时维护3~4路连接。这个“主机”角色看着简单实际写起来比从机麻烦不少。从机只需要广播然后等连接而主机要自己管理扫描窗口、连接间隔、连接超时还有多路连接之间的调度。我第一次拿到板子的时候觉得只要照着SDK里的例子把Scanner和Central跑起来就行结果真正调试起来才发现出问题的时候你根本不知道是协议栈配置错了还是外设那边没广播还是连接建立了但GATT操作失败——这时候唯一能依靠的就是日志。可以说日志系统就是无线调试时的眼睛眼睛好不好用直接决定项目进度。1.2 无线协议栈项目的日志调试和普通MCU开发有什么区别我以前做普通MCU开发时日志打印的套路很简单串口初始化一下重定向printf想打哪儿打哪儿。但在BLE这类带无线协议栈的项目里这个思路行不通原因有两个层面第一是时序敏感性。BLE协议栈底层是一个状态机连接事件、扫描事件、广播事件都是按特定时间窗调度的。比如连接间隔设成7.5ms意味着每7.5ms就要有一次射频收发。如果你在某个回调里打印了100字节日志在115200波特率下大约要耗时8.7ms这一个连接事件就整个错过了几次下来就会触发连接监督超时连接直接断开。这个坑我在3.1节会详细讲。第二是上下文约束。BLE协议栈有很多回调函数这些回调运行在协议栈的调度上下文里在里面做耗时操作会阻塞整个栈的事件处理。更危险的是中断里打日志printf这类标准库函数不是可重入的在中断上下文调用轻则丢数据重则死锁。所以日志方案必须从一开始就设计好而不是最后随便加个打印。除了这两点芯科的SDK和开发环境也有它自己的脾气。GSDK现在新版叫Simplicity SDK采用组件化设计日志相关的功能要自己选组件、自己配置不像Arduino那样默认就给你串口输出。SDK版本不同API还会有差异网上很多教程拿到新版SDK上直接编译不过。这些坑我都会在后面写到。2. 日志通道选型与搭建2.1 VCOM、RTT、SWO三种通道怎么选芯科平台常用的日志输出通道主要有三种板载VCOM、SEGGER RTT、SWO。先说结论调试阶段我选了VCOM但整套设计里预留了RTT作为备用方案。下面这个表是我实际对比后的结果通道物理载体速度是否占用UART功耗影响使用便利性VCOM虚拟串口板载J-Link桥接的CDC串口默认115200占用一组UART引脚调试时会增加功耗插USB即可用任意串口工具查看RTTJ-Link调试器内存通道很高可达MB级不占用UART需要在RAM中开缓冲区需要J-Link RTT Viewer或IDE支持SWO调试器SWO引脚较高不占用UART低需要配置SWO时钟和工具VCOM的优势是直观、门槛低打开串口助手就能看到数据适合最开始跑通逻辑。但它有个致命弱点是阻塞式的打印速度慢。RTT速度快得多它本质上是J-Link调试器直接读写芯片内存里的缓冲区不经过UART不占用额外引脚风险是调试器断开时看不到数据而且有些场景RTT Viewer配置起来比较繁琐。我在选型时的思路是这样的初期逻辑验证用VCOM因为方便团队里几个人连上串口都能看。到了后期调试时序、排查连接问题时如果发现日志打印本身影响了协议栈再切RTT。不过实际上后期我并没有切换到RTT而是改用“事件回调里不打印、只入队主循环里再打印”的异步日志方案既保留了VCOM的便利性又不阻塞协议栈。这个方案在第三章详细说。2.2 搭建VCOMprintf重定向的完整步骤在Simplicity Studio里搭建VCOM日志输出的步骤官方文档写得不算差但有几个细节容易忽略。第一步是在工程里添加UARTVCOM组件它会自动配置好开发板上VCOM对应的UART通常是在EUSART0上。注意这里说的是开发板自带的VCOM如果你用的是自己画的板子没有板载J-Link那就要自己添加一个EUSART组件把TX/RX引脚接到USB转串口模块上两者不是一个东西。第二步是重定向printf。GSDK里提供了Retarget Serial组件添加之后它会接管printf的底层输出。如果你用的是App Log组件那就更方便它会提供app_log函数同时支持日志级别控制我在4.3节会讲。我自己是用了Retarget Serial加标准printf代码里只需要在main函数初始化阶段调用#include sl_retarget_serial.h #include stdio.h void log_init(void) { sl_retarget_serial_init(); printf(\r\n---- BLE Central Log Init OK ----\r\n); }这一步看起来简单但有一个顺序问题很关键sl_retarget_serial_init()必须在协议栈初始化之前调用否则早期协议栈打印的日志会丢失而且一些外设模块可能在初始化时依赖串口做状态输出。我一开始是把打印初始化放在sl_bt_enable()之后结果前几十条带时间戳的消息全没了排查了半天才发现是初始化顺序反了。第三步是验证。把SDK自带的Empty例程跑起来在while(1)里加一个循环打印然后用串口助手连上波特率设为115200正常情况下应该能看到输出。如果看不到输出大概率是引脚配置问题或者DTR信号问题这一节末尾的坑会细说。2.3 日志串口的引脚与硬件接线坑关于硬件的坑我提两个。第一个是引脚冲突EFR32BG22的很多GPIO是内部外设复用的你配置UART时选的TX/RX引脚可能和SPI、I2C、PWM或者其他外设的引脚冲突。尤其是在做多外设项目时引脚分配要非常小心。我遇到的情况是日志TX脚和某个传感器的I2C时钟线选了同一个引脚I2C初始化之后串口输出就乱了。解决方法是画板子之前就把日志串口的引脚固定下来尽量避开多功能引脚或者在软件配置时通过Simplicity Studio的Pin Tool检查冲突。第二个坑是DTR信号。很多串口工具比如SSCOM、PuTTY在连接VCOM时要正确控制DTR或者RTS否则J-Link桥接的CDC串口可能不工作。我最初用某款串口助手日志一条都收不到换了一款串口工具却正常后来才发现是DTR的问题。如果遇到“串口能打开但没输出”的情况先换个串口工具试试或者检查一下工具里DTR和RTS的勾选状态这个排查成本很低但很实用。提醒一下VCOM是开发板调试阶段最方便的输出但它只在你插着USB调试线的场景下工作。如果用电池供电做低功耗验证或者设备独立运行就必须考虑日志通道断电或者自动关闭的问题我在3.4节会专门讲。3. 核心踩坑记录与解决过程3.1 坑一日志一多BLE就断连真正的元凶是阻塞打印这个坑是整个项目里最折磨人的一个值得单独写一节。现象是这样的设备以7.5ms的连接间隔连接了一个心率计单路连接时一切正常。后来我加了日志在扫描到外设的时候打印一些调试信息比如设备地址、广播数据、RSSI这些大概每遇到一个扫描包就打50字节左右。然后奇怪的事情出现了连接建立大约几十秒后设备莫名其妙地断连了而且不是每次都断是随机断特别难复现。一开始我以为是协议栈配置问题把连接参数调来调去结果问题依旧。后来我把日志调大打印用逻辑分析仪抓了串口和射频的时序关系才明白根因。BLE的连接事件是有严格时间窗的连接间隔7.5ms意味着协议栈每隔7.5ms就要处理一次射频收发的任务。而我打印50字节日志在115200波特率下一个字节大概耗时86.8微秒50字节就是4.3毫秒。这个时间已经超过了连接事件的处理窗口导致射频收发任务被推迟底层收不到对端的包就开始重传重传多了超出了连接监督超时Connection Supervision Timeout的时间协议栈就判定连接无效主动断开了。时间上的对应关系很清楚串口打印的阻塞时间直接叠加到了协议栈调度上。我当时打印一行日志处理完一个事件再进下一个事件时时间已经晚了连接就崩了。用公式表示就是日志耗时 字节数 / 波特率 * 10起始位8数据位停止位。所以日志越长波特率越低对时序破坏越严重。解决思路有两个方向一是提高波特率比如从115200提到921600同样50字节的耗时从4.3ms降到0.54ms效果立竿见影。二是不在关键回调里直接打印改成异步输出——先把日志内容放进内存缓冲区由外层循环慢慢往串口发。这两个方向我都试了波特率提高治标不治本因为日志量一大还是会堵真正彻底解决是后面3.2节要讲的异步方案。3.2 坑二回调函数里直接printf会导致协议栈卡死前面说了BLE协议栈的事件回调是运行在调度实体内部的。我之前习惯在sl_bt_evt_connection_opened_id这个事件回调里打印连接成功消息看起来天经地义。项目初期日志量不大确实没出问题但从某个版本加了更多调试信息之后开始出现偶发性的卡死——整个设备像死机了一样协议栈完全不再响应只有复位才能恢复。查了很久才定位到问题printf不是线程安全的也不可重入它内部会调用底层UART驱动如果UART驱动的发送是轮询等待方式printf就会一直忙等。而这个printf是在BLE协议栈的事件处理函数里被调用的一旦UART发送被某个更高优先级的事情打断或者和另一个上下文的打印产生了竞争就可能死锁。更隐蔽的是有些SDK的协议栈事件回调里会关中断保护临界区如果你在里面调用printf而printf又依赖UART中断就形成了一个“中断等待死锁”——临界区没退出时UART中断永远进不来UART发送永远不完成然后协议栈永远挂在回调里。解决方法是“回调里只记录不输出”。我写了一个简单的异步日志模块核心是一个环形缓冲区#define LOG_BUF_SIZE 1024 static volatile uint8_t log_ring[LOG_BUF_SIZE]; static volatile uint16_t log_head 0; static volatile uint16_t log_tail 0; void log_enqueue(const char *msg, uint16_t len) { for (uint16_t i 0; i len; i) { log_ring[log_head] msg[i]; log_head (log_head 1) % LOG_BUF_SIZE; if (log_head log_tail) { // 缓冲区满丢掉最旧的数据 log_tail (log_tail 1) % LOG_BUF_SIZE; } } }然后在主循环里做真正的打印void log_flush(void) { while (log_tail ! log_head) { uint8_t c log_ring[log_tail]; log_tail (log_tail 1) % LOG_BUF_SIZE; uart_write_byte(c); // 底层UART单字节发送 } }事件回调里需要打日志时只调用log_enqueue把数据丢进缓冲区就返回不回等待串口。主循环的log_flush在空闲时慢慢往外发这样即使一秒钟产生很多日志也不会阻塞协议栈的调度。这个方案的代价是内存占用多了一些但对于日志调试这个目的来说1KB的缓冲区完全不算什么。3.3 坑三printf不输出或者乱码这个坑虽然不像断连那么致命但浪费了我几乎一天的时间写出来希望大家少走弯路。现象之一是printf完全不输出。我当时把例程跑起来代码里写了打印串口助手打开一点反应都没有。排查过程是这样的先确认串口助手波特率没问题115200然后检查sl_retarget_serial_init()有没有被调用结果发现Simplicity Studio生成的项目里初始化顺序是自动生成的但Retarget Serial组件的初始化在platform_init阶段就执行了按理说没问题。最后想到去查UART引脚配置才发现例程默认的VCOM引脚和我在引脚配置工具里改掉的引脚不一致——我为了方便布线改了引脚配置但UARTVCOM组件还指向原来的引脚导致数据根本没从预期引脚出来。乱码的问题则主要出在两个地方一是波特率不匹配这个好排查二是时钟配置。EFR32的EUSART时钟源如果配置错了或者外部晶振频率和SDK默认值不一致会导致波特率实际偏差很大。比如实际波特率偏差超过2%串口接收就会开始出现乱码。我遇到的情况是用的32768低频外部晶振结果UART时钟源配到了HFXO上频率对不上输出全是乱码改成正确的时钟源后恢复正常。还遇到过一种特殊情况printf里忘记加\n终端工具不会刷新。有些串口助手默认遇到\n才刷新显示如果你打印的一句日志末尾没有换行它会一直存在缓冲区里看起来就像没输出。这个很好解决统一在日志后面加\r\n就行。3.4 坑四低功耗测量被日志口毁了我们做BLE设备低功耗是重点指标。项目后期测功耗时发现整机电流比规格书高了不少排查了半天罪魁祸首就是开发板上的日志串口调试时一直插着USB线VCOM一直接在供电状态再加上printf往UART发数据带来的功耗直接把电流拉高了几百微安甚至毫安级别。低功耗测量有一套标准做法在此之前得先把日志关干净。我总结了三个层级硬件层测量功耗时要用电池或者电流表直连供电插着J-Link测出来的电流没有任何参考意义因为J-Link本身就有功耗还会给板子额外供3.3V电压。外设层进入睡眠前要主动关闭UART外设时钟把TX、RX引脚配置成普通GPIO并拉低或者拉高避免悬空引脚产生漏电流。如果引脚浮空CMOS输入级的漏电路径会造成微安级甚至几十微安的额外功耗。软件层发布版里把日志全部关掉只保留错误级别或者干脆用一个宏彻底关闭日志功能。关于软件层怎么做我在4.3节会给出具体的开关方案。总之日志和低功耗天然是矛盾的必须在设计阶段就想好怎么切换而不是等到测功耗那天再临时改代码。4. 常见问题与排查技巧实录4.1 三类典型日志问题的定位流程调试过程中反复出现的日志问题归纳起来就是三类不打印、乱码、打印到一半卡死。我整理了一个快速排查思路遇到问题直接按顺序走一遍省很多时间。问题现象排查顺序常见根因完全不打印1. 串口工具和波特率 2. 引脚配置 3. 组件是否添加DTR未启用、引脚冲突、Retarget组件缺失乱码1. 波特率 2. 时钟源 3. 接线强弱上拉时钟频率不匹配、线路干扰、VCOM电平不符打印到一半卡死1. 是否在中断/回调中打印 2. 缓冲区溢出 3. 死锁在回调中阻塞打印、环形缓冲未做溢出保护、临界区嵌套具体来说“完全不打印”先换串口工具排除DTR问题。接着查工程里有没有UARTVCOM或Retarget Serial组件没有就添加。然后查引脚配置工具看UART的TX/RX引脚是否被其他外设占用。“乱码”优先确认波特率特别是SDK版本升级后默认波特率可能变化接着查时钟树确保UART时钟源和实际晶体频率一致。“打印到一半卡死”是最值得警惕的优先检查是否在BLE回调或中断里调用了printf如果是立刻改成异步日志。4.2 日志缓冲队列的实现思路与注意事项前面给出了环形缓冲区的核心代码这里补充几个实现上的注意事项这些是我实际踩过之后总结出来的。第一个是缓冲区大小的选择。1KB对调试日志来说够用但如果你的协议栈事件非常密集比如扫描到大量设备、多路连接同时有数据进来1KB可能不够会出现日志被覆盖的情况。建议刚开始设成2KB然后根据实际调试过程中的丢失情况调整。需要区分的是日志丢失本身不代表功能错误它只说明日志量超过了串口输出能力这时候要么减小日志量要么增大缓冲区要么提高串口波特率。第二个是缓冲区满时的策略。我在示例代码里用的是覆盖最旧的策略这对调试场景更友好因为最新的事件才是你最需要关注的。如果你希望保留早期的日志用于事后分析可以在覆盖时设置一个溢出标志把“发生过溢出”这个事实也打到日志里这样你就知道日志是否完整。第三个是单字节发送函数。uart_write_byte在芯科SDK里可以用EUSART的阻塞发送接口也可以用查询状态的方式等待上一个字节发完再发下一个。注意这个函数只在主循环的log_flush里调用不要在中断里调否则又回到了老问题。4.3 用日志级别与条件编译把日志关在发布版外面日志代码写得再优雅最终发布版里也不能带着一大堆调试打印既影响性能又可能泄露调试信息。芯科GSDK里App Log组件提供了日志级别控制但如果你用的是自己写的日志模块也可以用条件编译的方式来做。一种做法是定义日志级别宏#define LOG_LEVEL_ERROR 0 #define LOG_LEVEL_WARN 1 #define LOG_LEVEL_INFO 2 #define LOG_LEVEL_DEBUG 3 #define CURRENT_LOG_LEVEL LOG_LEVEL_DEBUG #define log_error(...) do { if (CURRENT_LOG_LEVEL LOG_LEVEL_ERROR) printf([E] __VA_ARGS__); } while(0) #define log_warn(...) do { if (CURRENT_LOG_LEVEL LOG_LEVEL_WARN) printf([W] __VA_ARGS__); } while(0) #define log_info(...) do { if (CURRENT_LOG_LEVEL LOG_LEVEL_INFO) printf([I] __VA_ARGS__); } while(0) #define log_debug(...) do { if (CURRENT_LOG_LEVEL LOG_LEVEL_DEBUG) printf([D] __VA_ARGS__); } while(0)开发阶段把CURRENT_LOG_LEVEL设成LOG_LEVEL_DEBUG日志全开发布前改成LOG_LEVEL_ERROR甚至直接把日志宏定义成空操作这样编译出来的二进制完全不包含调试字符串既减小了代码体积也彻底消除了日志对时序的影响。这个方法看起来很基础但很多人一开始图省事直接在代码里写printf到发布时再一行一行去删既费时又容易误删功能代码。从一开始就用宏包一层后面切换调试和发布版本只需要改一个宏定义非常省心。4.4 扫描密集场景下日志丢数据的处理思路还有一个我在主机模式下遇到的特定问题扫描阶段如果设备比较密集比如展会环境或者实验室里同时开着几十个BLE设备扫描报告事件会连续不断到来。如果你在sl_bt_evt_scanner_scan_report_id回调里做日志打印即使用了异步缓冲日志量还是会瞬间爆炸缓冲区被写满日志大量丢失。这个问题要从两个方向解。一是减小日志量扫描阶段不要每收到一个扫描报告就打印完整信息可以只打印设备地址的最后两个字节或者只打印RSSI值把这些关键信息浓缩成一行。二是调整日志策略扫描阶段优先输出到缓冲队列连接建立之后再把缓冲区的历史日志逐渐刷出来。这样既不会因为日志量过大拖累扫描性能也能保留足够的信息用于分析连接建立前后的状态变化。5. 几个让调试效率翻倍的小技巧5.1 打上时间戳定位时序黑洞掌握了异步日志之后我加了一个更有效的功能给每条日志打上时间戳。时间戳不一定要精确到微秒毫秒级别就够了关键是能帮助你看到事件之间的时序关系。我用的是芯科SDK里的sl_sleeptimer_get_tick_count()转换成毫秒后格式化进日志。这样打印出来的日志长这样[12345] [I] Scan report from 00:11:22:33:44:55, RSSI-42 [12389] [I] Connection opened to 00:11:22:33:44:55 [12501] [W] GATT service discovery started [13201] [E] GATT service discovery timeout有了时间戳很多问题一眼就能看出来比如GATT服务发现花了800ms说明对端设备响应慢或者MTU配置不合理扫描到连接之间隔了400ms说明连接参数没有优化到位。这些时序信息在调试无线项目时比什么都值钱。5.2 把日志通道和业务数据通道分开这个项目后期我对日志模块做了一次重构把调试日志和业务数据的输出通道彻底分开。方法很简单日志走VCOM业务数据走另一个独立的UART或者通过板上的LED灯做简单的状态指示。这样做的好处是平时开发调试时打开日志串口看细节做整机联调时只关注业务数据串口互不干扰。如果硬件上只有一个串口可用也可以指定某一个特定前缀标记日志消息然后在PC端用工具过滤。比如业务数据统一用#开头调试日志统一用[D]开头用串口助手的日志过滤功能就能切换。总之日志通道越独立后期分析问题越省力。5.3 现场排查经验一套日志排查的固定路径最后分享一个我自己沉淀下来的排查路径。遇到BLE问题先抓协议栈的原始上报事件日志看事件序列对不对再看GATT操作的关键节点比如服务发现、使能通知、读特征值这些有没有按顺序完成最后才加业务层的业务日志。如果一上来就打一堆业务日志很难定位问题到底出在链路层还是应用层。具体来说我会先用芯片原厂的health check例程验证硬件环境和基本射频状态然后把日志级别开到DEBUG跑一版带完整事件日志的固件问题复现后把日志导出来按时间线画出事件顺序和正常流程对比差异点基本就是问题所在。用这个思路前面说的断连、卡死、扫描异常这些问题都能在几轮之内定位。6. 写在最后的一些体会这次做BLE主机的经历让我对“打印日志”这件事有了非常不一样的认识。以前总觉得日志是代码里最简单的部分现在才知道在无线协议栈项目里日志设计的好坏直接影响项目进度和调试效率。日志不是你想打就能打的它的输出位置、输出方式、输出量每一个细节都可能影响到协议栈的时序和稳定性。我个人在实际调试中的最大感触是越早把日志系统搭好后面越省心。不要觉得项目刚开始没必要折腾日志缓冲、级别控制这些“不着急”的功能等真正遇到问题时再补往往已经定位不到复现条件了。如果你也是刚开始做芯科BLE方案建议第一步就把异步日志模块搭好顺手把时间戳加上这几个小时投入后面一定会加倍的回报给你。