基于QCA9531+AP143参考设计，开发板上电后wifi概率性启动失败问题排查

在开发过程中，遇到这种概率性发生的问题，比较不好排查。如果是致命的问题，比如像uboot完成后找不到内核，卡在staring kernel,或者内核panic死机，或者init进程运行失败.....这类问题的原因一般比较固定，每次都会卡死在启动过程中的某一个地方，可以通过捕捉开发板异常启动时候的串口输出日志或者demsg，很快定位到问题的大概位置和原因。但是前几天遇到了一个很奇怪的问题：开发板在启动的时候有概率性的wifi无法开机自动启动，但大多数时候都是可以启动。

我的思路和排查步骤如下：

由于出现这个问题的概率比较低，并且现在无法确定是软件bug还是硬件干扰或者供电不稳的原因。可能测试一百次才会出现一两次的概率，而每次开发板上电到wifi启动，都要经过大概45秒，如果通过人为每次给他反复断电上电，观察wifi启动后的led灯的状态，用这种方法来测试的话，无疑是很耗费精力的，所以我想了以下办法

同事帮我用PLC写了一个简单程序，三分钟为一组测试循环，先上电时间保持两分钟，这是为了给开发板充分的时间让它来启动wifi,然后断电半分钟（让整个无人机达到彻底断电的目的，避免有的电容还未放完电的情况，主要是为了模拟现场的使用环境），再重新上电并保持两分钟，然后断电半分钟.....就这样一直循环测试。

好了，现在硬件条件已经具备，现在还需要一个自动化的脚本，来自动监控启动情况，并统计启动成功和失败的次数，这样就不需要人一直盯着了，脚本内容如下：

#!/bin/bash
clear
START_TIME=$(date '+%Y-%m-%d %H:%M:%S')
echo "$0 start at $START_TIME" >> data/test_result.log

handle_stop() {
    TERMINATION_TIME=$(date +"%Y-%m-%d %H:%M:%S")
    echo "$0 finished at $TERMINATION_TIME"
    echo "请查看data/test_result.log文件获取最终结果。"
    echo "总计测试次数:$COLLECTED_COUNT
    成功次数：$SUCCESS_COUNT
    失败次数：$FAILURE_COUNT
    收集日志文件数量：$COLLECTED_COUNT
    finished at $TERMINATION_TIME
    " >> data/test_result.log
    exit 1
}

trap handle_stop SIGTSTP SIGINT

# 检测串口设备是否存在
SERIAL_PORT="/dev/ttyUSB0"
if [ ! -e "$SERIAL_PORT" ]; then
    echo "串口设备 $SERIAL_PORT 不存在，请检查连接。"
    exit 1
else
    sudo chmod 666 /dev/ttyUSB0
    sudo chown zzq /dev/ttyUSB0
    sudo usermod -aG dialout $USER
fi

# 检查当前用户是否有访问串口设备的权限
if [ ! -r "$SERIAL_PORT" ] || [ ! -w "$SERIAL_PORT" ]; then
    echo "当前用户没有访问 $SERIAL_PORT 的权限，请检查设备权限或将用户添加到 dialout 组。"
    exit 1
fi

# 配置串口参数
stty -F $SERIAL_PORT 115200 raw -echo

# 清空数据文件夹
if [ -d data ]; then
    rm -rf data/*.txt
else
    mkdir data
    chmod 777 data
fi

# 设置参数
MAX_FILES=500
SUCCESS_COUNT=0
FAILURE_COUNT=0
COLLECTED_COUNT=0
FAILED_FILES=""

# 记录开始时间
START_TIME=$(date +"%s")

# 打印实时结果的函数
print_results() {
    #tput clear  # 清除屏幕
    #tput cup 0 0  # 将光标移动到左上角
    echo "测试wifi板开机后AP自启动情况(计划500次测试)"
    echo "实时结果："
    echo "-------------------------"
    echo "当前总计测试次数:$COLLECTED_COUNT"
    echo "实际成功次数：$SUCCESS_COUNT"
    echo "实际失败次数：$FAILURE_COUNT"
    echo "失败文件名：$FAILED_FILES"
    echo "-------------------------"
}

# 初始化屏幕
tput clear
print_results

# 循环收集数据
while [ $COLLECTED_COUNT -lt $MAX_FILES ]; do
    # 等待串口有数据到来
    clear
       print_results
    echo "等待串口数据到来..."
    data_received=false

    while [ "$data_received" = false ]; do
        #first_line=$(timeout 1s cat $SERIAL_PORT | head -n 1)
        first_line=$(cat $SERIAL_PORT | head -n 1)
        echo "调试信息：first_line = $first_line"  # 添加调试信息
        if [ -n "$first_line" ]; then
    echo "检测到串口RX数据,开始收集启动日志"
            data_received=true
        else
            echo "没有检测到串口数据，继续等待..."
        fi
    done
    # 使用 `timeout` 和 `cat` 命令连续读取 60 秒的数据
    echo "正在收集数据.........第 $COLLECTED_COUNT 次"
    timeout 60s cat $SERIAL_PORT > data/$COLLECTED_COUNT.txt &
   CAT_PID=$!
    wait $CAT_PID
    if [ $? -ne 0 ]; then
        echo "-------------------------------------------------------"
       # ((FAILURE_COUNT++))
       # FAILED_FILES+=" $COLLECTED_COUNT.txt"
    fi

    # 计算时间戳
    CURRENT_TIME=$(date +"%s")
    ELAPSED_TIME=$((CURRENT_TIME - START_TIME))

    # 检查文件中是否包含指定字符串
    #if grep -a "shmget error: No such file or directory" data/$COLLECTED_COUNT.txt; then
if strings data/$COLLECTED_COUNT.txt | grep -q "shmget error: No such file or directory"; then
	echo "COLLECTED_COUNT:$COLLECTED_COUNT">>test_result.txt
        ((SUCCESS_COUNT++))
	echo "success times:$SUCCESS_COUNT">>test_result.txt
    else
        ((FAILURE_COUNT++))
	echo "failed times:$FAILURE_COUNT">>test_result.txt
        FAILED_FILES+=" $COLLECTED_COUNT.txt"
    fi
    echo "完成数据收集：第 $COLLECTED_COUNT 次"
	clear
    # 更新实时结果到终端界面
    ((COLLECTED_COUNT++))
    print_results
    # 如果达到了500次收集，并且串口正常工作，就结束任务
    if [ $COLLECTED_COUNT -eq $MAX_FILES ]; then
        echo "达到了最大收集次数 $MAX_FILES，结束任务。"
        echo "
        start at $START_TIME
        总计测试次数:$COLLECTED_COUNT
        成功次数：$SUCCESS_COUNT
        失败次数：$FAILURE_COUNT
        收集日志文件数量：$COLLECTED_COUNT
        finished at $TERMINATION_TIME
        " >> data/test_result.log
        break
    fi
    sleep 70
done

echo "操作已完成，请查看data/test_result.log文件获取最终结果。"
exit 1

运行时状态如下：

测试逻辑：脚本运行后，先检测串口设备 ttyUSB0 是否存在，如果不存在则输出提醒，如果存在，则设置波特率 115200， 其他一些串口设置就按照串口的常用的设置就行。设置完成后，打开串口设备并开始监控它，一旦检测到有数据发过来，收集这个串口收到的数据并开始计时， 120 秒以后，将收集到的数据保存到一个文件比如1.txt,然后清除这个串口以前接收到的数据以及串口缓冲区里的内容，重新打开并重新监控这个串口，一旦检测到串口收到数据，开始新一轮的 120 秒计时，并将 120 秒内收集到的数据保存到2.txt......以此规律循环，直到收集满500 次后停止，这个时候应该会有 500 次收集的数据，分别保存在 1-500.txt。 然后依次遍历这500个文件，看看这里面的文件有没有包含字符串“shmget error: No such file or directory”，把没有包含这个字符串的文件的名字找出来，并统计他们的个数，将这个结果输出到名为test_reslut.txt的文件中，比如：
当前总机测试次数：500次
实际成功次数：497
实际失败次数：3 
失败文件名为:1.txt 8.txt 9.txt

因为shmget error: No such file or directory这一串字符是在我的开发板启动完成最后打印的一句话，所以我把它当做启动成功的条件，如果没有这一句，当然就是启动异常终止了

------------------------------------------------------分割线------------------------------------------------------------------

用PLC自动化上电程序配合我的自动化测试脚本，在经历了几百次的测试后，发现出现了两次启动失败的情况，通过观察这些异常日志，我发现有两次是在uboot启动阶段卡死的，但是依然没办法定位到具体卡在uboot的哪个位置，因为我的开发板在接PC机器的时候，只能设置成117200才能不乱吗，如果设置成115200，那就会在uboot启动阶段乱码，如下图所示

设置成117200：

我检查过了uboot设置，串口的时钟频率设置是按照QCA9531datesheet上设置的，uboot环境变量设置也没问题，但是就是乱码

这个问题等以后再解决吧....
接着上面说，由于我是把串口连接到了ubuntu，但是ubuntu又没办法设置非标准波特率，所以我只能设置成115200，当然，这样的结果就是uboot日志为乱码，但是起码现在已经知道了启动失败是在uboot阶段，那么继续思考一下，uboot启动过程中在什么情况下会中断呢？我们一下就可以想到是因为在bootdelay的时候从标准输入接收到数据，他就会进入到命令行，导致uboot启动终止，无法再加载内核，为了验证这个猜想，我先是将bootdelay时间设置为0，这样就相当于屏蔽了从console stdin标准输入发来的数据，设置成这样之后，又自动化测试了一千多次，再也没出现过这个问题，看来确实是因为这个问题影响的。那么现在问题来了，为什么我在启动的时候会接受到串口RX的数据呢？我有三种猜想：

1，因为把开发板用usb转ttl接入了电脑，导致开发板在上电的瞬间由于串口供电点平突变不稳定造成的意外，因为usb端是5V，而TTL为3.3v，这中间
2.由于我的串口是和飞控板连接的，尽管之前已经和飞控开发人员确认过，他说在上电后的50秒之内不会给我发数据过来，目的就是为了怕打断我的启动，我想着50秒肯定够了，就算50秒我没启动完成，也不应该是在我刚上电还在uboot阶段发来数据。所以我没有过多怀疑飞控的问题

3.串口虚焊或者电源供电不稳定

现在要如何确定具体哪种原因，于是我又把串口接上了逻辑分析仪，在启动的时候，一边观察启动日志，一边看着启动时的串口波形变化，如下如示例

在经过多次对比观察后，我发现，uboot卡死的时候，是出现在bootdelay的那几秒的过程中，串口的电平突然被拉低，这个时候是RX接收到了数据导致的。对比在正常情况下：当bootdelay过程中没有RX数据过来的时候，他的电平一直都是保持一个状态的。好了，现在既然知道了是因为RX数据影响，那接下来要确定这个数据的来源，于是我把wifi板和飞控之间的串口线断开，直接用逻辑分析仪接上飞控的tx（也就相当于wifi板的RX），单独监控飞控板看一下他在刚上电的那几秒钟会不会发送数据过来。经验证，果然！如下图所示，飞控板在上电之后的几秒钟，TX有数据发出（箭头指向的数据），然后过了五十秒，飞控的app又给我发了数据过来

箭头指的地方的数据，是我不想要的数据，注意看箭头数据所处的时间，是在刚上电的几秒钟，这个时候刚好我wifi板的uboot还在启动，还没启动完成，可能刚好停留在bootdelay的那两三秒的时候，这个时候他的TX数据刚好发过来，我的rx收到之后，uboot以为是用户在键盘上按下了任意字符，导致进入了uboot命令行，导致启动中断。到现在终于找到了原因，至于飞控板在上电的时候为什么会发送TX数据过来，我想这是由于他这个板子的特性吧，可能是由于他板子在启动初始化的阶段有这个机制？或者是因为飞控板那里没有配置好？我不得而知，也没精力去研究飞控的东西，至于之前飞控开发人员说的上点之后50秒才会给我发数据过来，他说的也没错。因为毕竟他做的是APP层面的开发，刚上电时发来的数据不是他能控制的，因为那个时候还在各种外设以及硬件初始化阶段，系统还没启动完成，这时他的飞控PP程序还没开始运行，当然无法控制。

好了，既然已经确定了原因，那么接下来就是如何解决了，目前想到了两种方案：

1.通过将bootdelay改为0，意味着在uboot启动阶段屏蔽RX收到的数据，只要uboot能顺利启动完成，后面就没问题，这样就保证每次WIFI都可以正常启动，但是也有弊端：如果我在调试的时候想人为打断他，通过tftp给他更新固件，也是不可能了。取而代之的更新固件方式为：进入到linux系统之后通过命令的方式将uboot环境变量备份并且烧写回环境变量分区，然后重新启动

2，修改打断机制，我们知道在bootdelay的时候默认按下任意键都会打断启动，也就是无论串口RX无论受到什么数据都会中断，那么我是不是可以把它改成收到特定的字符他才会中断

这样就可以极大降低在uboot启动过程中意外收到RX数据对我们造成中断，以前是收到任意字符都会中断，现在只有收到'a'字符的时候才会中断进入uboot命令行，这样是为了方便我开发过程中的调试，我可以按下a去打断他进入uboot命令行。如果还是觉得不放心，担心可能会被打断的话，可以等产品出货的时候将bootdelay设置成0，屏蔽全部中断。