有大佬提問說,在用合宙Air780EP模塊開發的時候,有時候會遇到收不到網絡數據的問題。
今天特邀合宙的技術大佬來解答啦!通過詳細咨詢客戶出現的問題,這里把遇到的問題和排查方法記錄下來,希望能夠幫助到大家!
不知道各位在用Cat.1模塊的時候,會不會遇到這樣的問題呢,
"用TCP做長鏈接,在進入休眠場景后進行保活,但時常出現丟包的現象,應該怎么分析呢?"
"MQTT服務器下行數據,模塊有概率接收不到,服務器也有遇到收不到模塊的上行數據,到底是什么情況"等等類似的問題。
針對上述情況,如果單純通過模塊這邊的看到的現象,也不能斷定是模塊這邊出了問題。要想準確的找出這個“罪犯”,這種時候就需要通過抓網絡包來分析排查出是以下哪種原因:
(1)模塊有發出數據->但服務器沒收到
(2)模塊未發出數據->導致服務器沒收到
(3)服務器有發出數據->但模塊沒收到
(4)服務器未發出數據->導致模塊沒收到
一、情況解析
以下是針對給用戶大佬解決問題時,遇到的一個實例,給各位提供個分析思路。
其中有個項目用的是AT開發,大致應用場景為TCP長鏈接,要求定時上報GPS/基站/wifi的定位數據,沒有休眠需求,但時不時在發送數據的時候,會出現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+CIPCLOSE去斷開連接,但我從AT流程的日志來看,明顯程序中還沒有走到AT+CIPCLOSE這一步,問題就已經復現了。
模塊端如果沒有主動通過指令斷開連接,那么在遇到網絡波動、信號差、卡沒流量等等,會影響網絡的事件時,模塊也可能會發起斷開連接的請求。
但上面也已經排查過,在出現AT+CIPSEND返回ERROR之后,也發送了AT+CEREG?、AT+CGATT?、AT+CSQ這三條指令,返回結果依次為+CEREG: 0,1、+CGATT: 1、+CSQ: 25,可以從CEREG和CGATT的返回結果看出,網絡狀態是正常已成功注冊網絡的,CSQ信號值為25,也很正常。
那這到底是怎么回事呢,這下不得不通過網絡抓包來進一步分析了。
三、網絡抓包分析
準備工作
四、日志怎么抓,用什么工具抓?
1.選擇正確且合適的日志輸出端口
USB的虛擬端口其中有一個為底層日志的輸出端口。可從設備管理器端口屬性中“設備實例路徑”的值為"USB\VID_19D1&PID_0001&MI_04\xxxxxx&0&0004"鎖定到底層日志輸出端口是哪一個。
建議使用USB來抓取日志
優點:USB虛擬端口輸出速率很高,所以基本不會出現丟日志的現象
缺點:連接USB時不會進入休眠
DBG_UART串口需要以6M波特率輸出底層日志,此串口輸出的數據要通過EPAT工具才可以解析。
優點:進入休眠的日志也同樣可以抓取
缺點:但因為波特率要求在6M,所以對串口線的要求很高,如果引出的杜邦線太長或者質量不高,也會影響日志輸出的數據,導致工具不能正常解析
2.認識EPAT工具中圖標功能
圖從左往右的順序介紹
- 打開日志文件,需要在打開EPAT工具時跳出的"Select Data Source"選擇框中選擇"Select From Local Files",才能點擊打開日志文件的功能,可以打開ZIP壓縮包和Bin格式的日志文件。
- 保存日志,會將已抓取到的日志導出,以ZIP壓縮包的方式保存,方便提供給技術同事或研發同事分析。
- 更新解析日志的數據庫文件,在抓日志的時候,可以不匹配,等在使用EPAT打開日志文件的時候再做匹配解析。
- 篩選查看日志,如果不了解,用不到這個功能
- 啟動開始抓日志,如果沒有日志出來,請檢查日志端口有沒有選擇正確,有沒有勾選打開;確認端口正確,也以勾選,還是沒有日志出來,請嘗試:
- 重啟模塊
- 勾選選擇的端口從其他串口調試工具嘗試打開是否可以正常輸出數據(正常打開輸出的就是亂碼)
- 如果使用AT固件,默認DBG_UART端口輸出是6M波特率,可以通過AT+ECPCFG=logBaudrate,6000000 指令修改,波特率設置請不要低于6M,不然很容易出現丟日志、抓的不全。
6.暫停日志
7.停止抓日志,點擊完停止后,就可以選擇保存日志 發給技術/研發同事分析了。
8.清除日志,建議每次正式準備抓日志前清理一下日志,這樣保存出來的日志給技術同事分析會方便很多。
9.搜索當前view視圖的日志內容
10.設備端口配置界面
3.底層日志抓取步驟
I. 打開EPAT工具,抓日志選擇第一項“Serial Device”
II. 選擇日志端口,準備抓取log
選擇使用USB的虛擬日志端口
- 打開設備端口配置界面
- 關閉或打開端口,如果端口被占用,工具也不會提示"端口已被占用",所以如果發現端口選擇正確,并且日志還是沒有出來的話,可以確認下日志端口是否有被占用,而導致EPAT沒有打開日志端口。
- Device0、Device1 兩個復選框,二選其一
- 打開日志輸出端口和修改波特率的界面。
- 選擇從設備管理器端口屬性中“設備實例路徑”的值為"USB\VID_19D1&PID_0001&MI_04\xxxxxx&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的虛擬端口,原因是780E模塊的USB驅動使用的是微軟系統自帶的usb驅動,所以僅支持在win10和win11上驅動。如果是win10/win11上面的方法都嘗試過,端口也依然沒有出來,也不妨用另一臺電腦試一下看看是否是驅動問題,可能電腦上裝的win10系統是簡裝版,缺少了一些驅動。
選擇使用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,那需要注意杜邦線的長度一定要短,不然也會影響輸出的日志出現丟失。
進階玩法--兩個端口都使用
沒錯,還可以同時使用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做重連。
那針對這個大佬的項目,最終導致斷開連接的這個“罪犯”也是找到了是服務器的問題。
大家可以根據我的排查思路和方法,來檢查一下是不是在哪一個環節出現了類似的問題。
希望對你們有所幫助~
有其他問題可以評論區留言喲~
-
模塊
+關注
關注
7文章
2695瀏覽量
47431 -
嵌入式
+關注
關注
5082文章
19104瀏覽量
304810 -
物聯網
+關注
關注
2909文章
44557瀏覽量
372777 -
TCP
+關注
關注
8文章
1353瀏覽量
79055 -
低功耗
+關注
關注
10文章
2396瀏覽量
103673
發布評論請先 登錄
相關推薦
評論