? 必須要吐槽一下:最近被老板驅使,要用Air780EP模塊做幾個緊急項目。。。
就怕緊急項目,時間緊任務重,遇到了一些棘手問題,可把我給折騰死了……
這里把遇到的問題,排查記錄下來,看能不能幫到因遇到類似的問題,并且一直沒找到原因,而被老板要求加班解決的兄弟們。
一、相關背景簡介
不知道各位在用Cat.1模塊的時候,會不會遇到收不到網絡數據的問題呢?
比如:
"用TCP做長鏈接,在進入休眠場景后進行保活,但時常出現丟包的現象,應該怎么分析呢"、"MQTT服務器下行數據,模塊有概率接收不到,服務器也有遇到收不到模塊的上行數據,到底是什么情況"等等類似的問題。
但單純通過模塊這邊看到的現象,也不能斷定就是模塊出了問題。
要想準確地找出這個“罪犯”,這種時候就需要通過網絡抓包來分析排查是以下哪種原因:
- 模塊有發出數據->但服務器沒收到
- 模塊未發出數據->導致服務器沒收到
- 服務器有發出數據->但模塊沒收到
- 服務器未發出數據->導致模塊沒收到
以下通過最近遇到的一個實例,給各位提供個分析思路。
目前有個項目用的是AT開發,大致應用場景為TCP長鏈接,要求定時上報GPS/基站/Wi-Fi的定位數據,沒有休眠需求。
但時不時在發送數據的時候,會出現AT+CIPSEND發數據發著發著返回**+CME: ERROR 3**的問題。
基本情況解析:
- 使用的數據傳輸協議為TCP
- 問題現象為偶現,小概率出現
- 從模塊查看到的異常情況為:
AT+CIPSEND發送TCP數據的指令,出現了+CME: ERROR 3的錯誤碼
首先按照+CME: ERROR 3這個錯誤碼出現的條件,篩選一下可能出現的有哪些情況:
- 最先想到的就是TCP鏈接已經不存****在,斷開了
導致發送數據時檢測TCP通道關閉,而出現AT+CIPSEND命令返回錯誤。 - 發送的AT+CIPSEND命令前后攜帶了其他的字符
一起作為一整條指令發送給了模塊,導致模塊解析出錯。
AT+CIPSEND這條指令會出現+CME: ERROR 3,基本上就是以上兩種情況了。
那么先嘗試排除下第二條:
我在偶現第一次AT+CIPSEND出現錯誤之后,后面也嘗試發送了的多條AT+CIPSEND命令發現也都會出錯。
但中間穿插發送的AT+CEREG?、AT+CGATT?、AT+CSQ 查網絡狀態、信號強度的命令返回都正常,也沒有報錯。
而且把發送的整條數據轉為以HEX格式來看,指令前后也沒有多余的字符出現。
那可以排除第二種情況了。
接下來這個時候為了印證第一條的猜想,
就需要排查下問題是否為TCP鏈接已經斷開了:
在掛測了一段時間再次復現問題的時候,
加一條AT+CIPSTATUS的命令查一下連接狀態。
結果不出所料:
返回的結果是 STATE: TCP CLOSED ,
TCP鏈接是斷開的狀態!
已經鎖定問題原因是有概率出現TCP突然斷鏈的現象。
由于目前條件抓不了服務器端的網絡日志,只能暫且想辦法從模塊端排查問題。
出現斷鏈也可以分為:
模塊端發起斷開連接和服務器端發起斷開連接。
如果為模塊端斷接:
可以看下是否有主動發送AT+CIPCL****OSE去斷開連接,但我從AT流程的日志來看,明顯程序中還沒有走到AT+CIPCLOSE這一步,問題就已經復現了。
模塊端如果沒有主動通過指令斷開連接:
那么在遇到網絡波動、信號差、卡沒流量等等,會影響網絡的事件時,模塊也可能會發起斷開連接的請求。
但上面也已經排查過:
在出現AT+CIPSEND返回ERROR之后,
也發送了AT+CEREG?、AT+CGATT?、AT+CSQ這三條指令。
返回結果依次為:
+CEREG: 0,1
+CGATT: 1
+CSQ: 25
可以從CEREG和CGATT的返回結果看出,網絡狀態是正常已成功注冊網絡的,CSQ信號值為25,也很正常。
那這到底是怎么回事呢?
這下不得不通過網絡抓包來進一步分析了。
二、準備工作要點
根據項目需求準備相關硬件及軟件,以下供參考:
- 自制板子需要引出USB或者DBG_UART串口,二選一。
但如果問題是 只有在休眠環境下才能復現的,那么只能使用DBG_UART串口, 進入休眠后USB要斷開會導致抓不到休眠中的日志。 - 如果使用DBG_UART串口,還需要準備一個高速串口工具(能支持6M波特率,例如ch343、ft4232)。
- 合宙開發板默認有引出USB和DBG_UART串口,可以直接接線使用。
- EPAT log工具 EPAT_V1.3.262.573,使用方式本文章也會簡單說明,在EPAT軟件 Manual 目錄中也有一份使用介紹的PDF。
- Wireshark網絡包分析工具:
三、怎么抓日志
3.1 選擇正確且合適的日志輸出端口
USB的虛擬端口其中有一個為底層日志的輸出端口。
可從設備管理器端口屬性中“設備實例路徑”的值為:
"USBVID_19D1&PID_0001&MI_04xxxxxx&0&0004"
鎖定到底層日志輸出端口是哪一個。
?
**建議使用USB來抓取日志 **
優點: USB虛擬端口輸出速率很高,所以基本不會出現丟日志的現象;
缺點: 連接USB時不會進入休眠。
DBG_UART串口需要以6M波特率輸出底層日志,此串口輸出的數據要通過EPAT工具才可以解析。
優點: 進入休眠的日志也同樣可以抓取。
缺點: 但因為波特率要求在6M,所以對串口線的要求很高,如果引出的杜邦線太長或者質量不高,也會影響日志輸出的數據,導致工具不能正常解析。
3.2 ****認識EPAT工具中的圖標功能
以下從左至右依次介紹:
?
1)重啟模塊;
2)勾選選擇的端口從其他串口調試工具嘗試打開是否可以正常輸出數據(正常打開輸出的就是亂碼);
3)如果使用AT固件,默認DBG_UART端口輸出是6M波特率。
可以通過:
AT+ECPCFG=logBaudrate,6000000 指令修改,
波特率設置請不要低于6M,不然很容易出現丟日志、抓的不全。
- 打開日志文件
需要在打開EPAT工具時跳出的"Select Data Source"選擇框中選擇"Select From Local Files",才能點擊打開日志文件的功能,可以打開ZIP壓縮包和Bin格式的日志文件。 - 保存日志
會將已抓取到的日志導出,以ZIP壓縮包的方式保存,方便提供給技術同事或研發同事分析。 - 更新解析日志的數據庫文件
在抓日志的時候,可以不匹配,等在使用EPAT打開日志文件的時候再做匹配解析。 - 篩選查看日志
如果不了解,用不到這個功能。 - 啟動開始抓日志
如果沒有日志出來,請檢查日志端口有沒有選擇正確,有沒有勾選打開;確認端口正確,也以勾選,還是沒有日志出來,請嘗試: - 暫停日志
- 停止抓日志
點擊完停止后,就可以選擇保存日志,發給技術/研發同事分析了。 - 清除日志
建議每次正式準備抓日志前清理一下日志,這樣保存出來的日志給技術同事分析會方便很多。 - 搜索當前view視圖的日志內容
- 設備端口配置界面
3.3 底層日志抓取步驟
3.3.1 打開EPAT工具,抓日志選擇第一項“Serial Device”
?
3.3.2 選擇日志端口,準備抓取log
?
接下來將從選擇使用USB的虛擬日志端口 、選擇使用DBG_UART串口,以及兩個端口都使用的方式,分別進行詳細講解:
3.3.3 選擇使用USB的虛擬日志端口
**使用USB的虛擬日志端口流程 **
- 打開設備端口配置界面;
- 關閉或打開端口,如果端口被占用,工具也不會提示"端口已被占用",所以如果發現端口選擇正確,并且日志還是沒有出來的話,可以確認下日志端口是否有被占用,而導致EPAT沒有打開日志端口。
- Device0、Device1兩個復選框,二選其一;
- 打開日志輸出端口和修改波特率的界面:
選擇從設備管理器端口屬性中“設備實例路徑”的值為:
"USBVID_19D1&PID_0001&MI_04xxxxxx&0&0004"的日志輸出端口。 - USB的虛擬日志端口不用修改波特率。
這時前面流程都走完了,但是發現沒有日志出來。
首先可以確認下模塊是否開機:
最直接的方式就是量vbat的電壓是否在4.3v~3.3v之間,并且看VDD_EXT是否有1.8v或3.3v,電壓正常就說明模塊是處于開機狀態了。
其他類似于看網絡燈沒亮、USB端口沒顯示這種條件不夠準確,因為這些也會存在其他因素而導致狀態不正常。
接下來繼續排查,USB虛擬日志端口選擇的是否正確:
如果虛擬端口沒顯示出來:
確認下LuatOS開發程序內,是否調用了"pm.power(pm.USB, false)"關閉usb功能的接口;
AT開發使用AT+ECPCFG?指令查看" usbCtrl "屬性的值是否為2,如果是2代表關閉了usb功能,需要手動設置下AT+ECPCFG="usbCtrl",0 將usb功能打開。
然后重啟模塊,如果還是沒有端口顯示,就需要從硬件、USB數據線、電腦端口方面排查,先做交叉測試。
有時還遇到過從模塊dm、dp飛出的連接線過長,
也會導致usb虛擬端口無法識別不能正常顯示:
把dm、dp和usb的連接線整體縮短到30cm左右,端口才能正常顯示;但理論上還是要看使用的USB線和杜邦線的傳輸質量是否優秀。
有時使用Win7/Win8的系統,
遇到怎么著都出不來USB的虛擬端口:
原因是Air780E模塊的USB驅動使用的是微軟系統自帶的USB驅動,所以僅支持在Win10和Win11上驅動。
如果是Win10/Win11上面的方法都嘗試過,端口也依然沒有出來,也不妨用另一臺電腦試一下看看是否是驅動問題,可能電腦上裝的Win10系統是簡裝版,缺少了一些驅動。
3.3.4 選擇使用DBG_UART串口
** 使用DBG_UART串口流程**
- 抓日志用的USB轉TTL的串口工具需要支持6M波特率,電腦上并且裝了對應串口工具用到的驅動(一般從網絡上或者購買商家那里,可以了解到需要用什么驅動);
- 打開設備端口配置界面;
- 關閉或打開端口:
如果端口被占用,工具也不會提示"端口已被占用",所以如果發現端口選擇正確,并且日志還是沒有出來的話,可以確認下日志端口是否有被占用,而導致EPAT沒有打開日志端口。 - Device0、Device1兩個復選框,二選其一;
- 打開日志輸出端口和修改波特率的界面;
- 選擇日志輸出端口;
- DBG_UART端口波特率輸出可手動寫入修改為 6000000(6M) 波特率。
使用DBG_UART串口沒輸出出來日志,排除步驟和USB也有點相同之處。
首先確認下模塊是否開機:
最直接的方式就是量vbat的電壓是否在4.3v~3.3v之間,并且看VDD_EXT是否有1.8v或3.3v,電壓正常就說明模塊是處于開機狀態了。
其他類似于看網絡燈沒亮、USB端口沒顯示這種條件不夠準確,因為這些也會存在其他因素而導致狀態不正常。
接下來繼續排查,DBG_UART日志串口選擇的是否正確:
確認下LuatOS開發程序內是否有通過云編譯關閉了uart0的日志輸出;
AT開發使用AT+ECPCFG?指令查看,要DBG_UART0輸出日志,需要幾條指令配置一下:
AT+ECPCFG="logPortSel",1
// 只從UART0輸出日志
AT+ECPCFG=logBaudrate,6000000
// 修改日志輸出波特率為6M
AT+ECPCFG="logCtrl",2
// 輸出log等級為ALL,全部任何日志都輸出
指令配置完之后重啟模塊,正常來說日志應該就可以輸出了。
如果還是沒有日志,嘗試用sscom這種串口調試工具打開相同的端口,看下是否有日志輸出(正常會輸出一堆的亂碼);
沒有輸出的話,就需要排查下打開的端口:
串口接線,比如rx/tx反接一下,有沒有短路。
并且如果是從預留的測試點用杜邦線飛出的DBG_UART_TX和DBG_UART_RX, 那需要注意杜邦線的長度一定要短,不然也會影響輸出的日志出現丟失 。
3.3.5 進階玩法--兩個端口都使用
沒錯,還可以同時使用USB的虛擬日志端口和DBG_UART日志串口來抓取日志。
這樣做的好處是:
在進入休眠場景的時候,待USB斷開,就會用DBG串口輸出日志,等模塊喚醒時就會重新虛擬出來USB端口,就會從USB的日志口抓取日志。
如果通過DBG_UART串口來抓取非休眠場景的日志:
由于底層業務邏輯過多,各種日志都會長時間大批量輸出,只用6M的波特率,還是避免不了可能出現丟日志的情況。
而用串口抓取休眠中的日志時,由于一些底層業務會關閉,輸出的日志相對并沒有特別頻繁,所以在休眠中丟日志概率會小一些。
但兩個端口同時使用,
這樣就把兩個端口的優勢都使用上了:
無論是休眠場景還是其他業務邏輯場景,基本上不會出現任何日志丟失的情況,但要求就是兩個端口都要有預留出來。
兩個端口同時使用流程要點
- 打開設備端口配置界面;
- 關閉或打開端口:
如果端口被占用,工具也不會提示"端口已被占用",所以如果發現端口選擇正確,并且日志還是沒有出來的話,可以確認下日志端口是否有被占用,而導致EPAT沒有打開日志端口。 - 日志端口可以同時打開兩個,一個用模塊的DBG_UART端口打開,另一個使用USB的日志輸出端口。
AT固件需要設置以下指令(重啟生效)才能設置日志端口可以從USB和DBG_UART兩個端口輸出。
AT+ECPCFG=logPortSel,2
// USB和DBG_UART都允許輸出底層日志
下面兩個指令如果不配置,那么插入usb不會進入休眠,配置下面指令之后,相當于就算接入usb也允許進入休眠。
AT+ECPCFG="usbSlpMask",1
// USB不參與休眠投票
AT+ECUSBSYS="VBUSModeEn",1,"VBUSWkupPad",1
// usb的vbus引腳不參與休眠投票
- 打開日志輸出端口和修改波特率的界面;
- 選擇日志輸出端口;
- USB的虛擬日志端口不用修改波特率:
- DBG_UART端口波特率輸出可手動寫入修改為6000000(6M)波特率。
因為這個項目沒有用休眠場景,就直接用USB來抓日志了。
按照上面的流程接上USB,打開日志的虛擬端口,成功看到了有日志出來。下面只需要掛著等問題出現就好了。
有抓過底層日志的朋友肯定想起來,
不是還有一步匹配解析日志的數據庫MDB.txt文件嗎?
其實如果只是導出pcap看網絡包,不需要去匹配數據庫文件。
?
四、導出pcap文件,查看網絡抓包
首先在抓取到復現的日志之后,不要著急,先停止日志打印。
然后在當前是SigLogger視圖的日志窗口時,才能看到并點擊右上角的SigLog菜單欄。
打開SigLog菜單欄后,點擊"Export As pcap file":
選擇一個導出路徑并起一個文件名稱, 切記:文件名稱不能和當前文件夾內的.pcap名稱重復!!! 因為導出同名文件,根據提示點擊覆蓋,但實際上內容卻并不會覆蓋變化。
隨后點擊保存,即可導出pcap格式的抓包文件。
?
五、通過Wireshark開始分析
好的,網絡包也抓到了,調轉回來繼續分析:
——“TCP長鏈接,定時上報GPS/基站/wifi的定位數據,沒有休眠需求,但時不時在發送數據的時候,會出現AT+CIPSEND發數據發著發著返回+CME: ERROR 3”的問題。
先前文章開頭已經分析出是TCP鏈接出現斷開,而導致AT+CIPSEND命令返回+CME: ERROR 3。但還不清楚具體是模塊主動斷開的,還是服務器端斷開的鏈接。
下面我們就通過導出的pcap文件,打開看一下。
根據日志的時間戳看到復現時間在18:56.24左右,那我們先定位到這個時間附近看一下。
?
結果確實找到了[FIN,ACK]請求斷開連接的網絡包,在確認下發出的ip地址是 112.74.41.204 ,目標地址是 10.49.81.92 。
怎么判斷哪個是模塊,哪個是服務器端呢?
也很簡單,還是從上面那張圖片舉例:
流程中現在有檢測如果發現AT+CIPSEND發送失敗,
就發送 AT+CEREG?、AT+CIPSTATUS ,
等返回結果為+CEREG:0,1和STATE: TCP CLOSED時,
就重新建立連接。
從AT流程中看出:
在19:00:12時有發送AT+CIPSTART=xxxxxx,xxx,來建立新鏈接。
從圖片中網絡包的同一時間19:00:12,也確實出現了[SYN]建立連接的請求,發出的地址是10.49.81.92,那這個就是模塊端的IP地址了。
以此推斷出:
另一個112.74.41.204就是服務器端的IP地址 (一般如果服務器是自己公司建立維護的,可以向自己公司的相關負責的同事詢問一下,服務器IP是哪一個)。
既然找出了發出[FIN,ACK]請求斷開連接的網絡包是112.74.41.204這個服務器端的IP地址,這樣就明白了是服務器端主動把鏈接關閉的。
不過正常來說,被動斷開連接模塊應該會出現" CLOSED "的URC上報,但為什么沒。。。
哦~ 原來有上報啊,是我忘記加在收到CLOSED的URC上報后,嘗試重連的邏輯了。
那這個就很簡單了,出現斷鏈之后:
先通過AT+CEREG?獲取到模塊已成功注網的狀態,
然后再發送AT+CIPSTART=xxxxxx,xxx做重連。
**最終,導致斷開連接的這個“罪犯”找到了
——是服務器的問題。**
不過我們用的服務器,是老板找的第三方。在拿出這個網絡抓包(證據)之后,以為能知道是什么原因呢,結果一直在"踢皮球",說他們也是負責代理,他們也要去確認……
哎,溝通起來那是可真累啊~一整天都過去了,也不知道是啥原因。
由于項目趕時間,解決完這個問題后,又要看下一個問題了!
?審核編輯 黃宇
-
服務器
+關注
關注
13文章
9795瀏覽量
87996 -
TCP
+關注
關注
8文章
1402瀏覽量
81050 -
Cat.1
+關注
關注
2文章
136瀏覽量
13418
發布評論請先 登錄
MQTT應用看這篇!合宙Air780EP_LuatOS_MQTT應用指南

合宙Air780EP模塊——AT指令MQTT接入OneNET開發指南

合宙低功耗4G模組Air780EP——硬件設計01

FTP應用看這篇!合宙Air780EP低功耗4G模組AT開發示例

合宙 Air780E/Air780EP/Air780EQ/Air201模塊遇到死機問題如何分析

評論