如何使用 AT 命令可靠地拆卸和重新连接 TCP/IP 套接字
How to reliably teardown and reconnect a TCP/IP socket with AT Commands
我有一个问题,我觉得我几乎已经解决了,但卡在了 "last leg"。
我已经研究了几天了,虽然有所突破,但感觉我
由于存在一些盲点,我离可行的解决方案还有一段距离。
我有一个嵌入式移动固件应用程序(我不能直接编辑),它有问题
通过 TCP/IP/UMTS/GSM 重新连接到我们的服务器。固件仅使用 AT 命令来启动和
通过调制解调器控制连接。我们产品的原始版本已经
在生产中工作了大约 10 年,但是 "new" 版本的硬件是
遇到间歇性问题。
有很多变数,但我排除了所有变数,只有一个:调制解调器芯片。
- 我们有新版本的固件,有各种变化,但范围广泛 A/B
测试显示所有固件都遇到同样的问题,所以我已经排除了。
- 我们有一个遗留的 VB6 服务器,使用 Winsock。我最近写了一个更简单的 Node.js
版本也几乎完全相同地展示了同样的问题(令人惊讶的是)。
- 我们使用各种电信公司:Optus、Vodafone、Telstra。同样,它们似乎与问题无关。
- 我们直接使用电信公司,或使用拥有自己的专用网络 (APN) 的经销商。再次证明无关紧要。
- 我们有不同的 hosting/network 安装,但我再次测试了许多配置
包括我们的公司网络、生产托管、AWS 开发 EC2,它们都执行
差不多。
- 我们还对 emulated/mock 版本的 hardware/firmware 进行了自动化测试
这表明各种服务器和网络似乎都运行良好且相似。
- 显示显着 - 实际上是绝对 - 差异的最终变体是
泰利特 UC864 调制解调器和 HE910。以前的旧调制解调器工作完美,但较新的 HE910
总是遇到问题。我已经测试了所有可能的排列和问题
沿用HE910.
当然,我已经没完没了地阅读了 Telit 文档(特别是 "Easy IP",以及
AT 命令和软件参考),但看不出有多大区别
两种产品之间。 HE910 在 Glynn 的实体包装中,但我不相信
影响它的行为。
问题:
我们的固件应用程序连接到特定 port/address 上的服务器。服务器
启动固件必须响应的出站应用程序协议。 (所以真的
固件是 "server" 但这没关系。)它非常轻巧简单,
按照每 command/response.
10 字节的顺序
当固件重新连接时出现问题,由于一个事件,"on top of"一个现有的
插座连接。固件始终遵循相同的过程:拆解、配置、
connect - 无论是否存在现有连接(这是由于
"connected" 在 TCP 和 3G 上的模糊性,最好是 "try to send data",或者
重新连接以确保连接)。正如我所说,我无法在 F/W.
中更改此行为
连接步骤为:
- a) 套接字拆卸 AT#SH b) 等待 1s
- 配置PDP上下文AT+CGDCONT
- 配置TCP/IP堆栈:AT#SCFG
- 激活 PDP 上下文:AT#SGACT
- 连接TCP/IP到服务器:AT#SD
(您可能会问为什么每次连接都完成配置步骤 2、3、4:因为
它们可以通过我们的应用程序协议进行更新。但通常设置是不变的。)
我们遇到的问题是有时设备可以连接但无法通信。
连接似乎 "stuck" - 有时几个字节通过,有时整个
command/response 循环,却常常一事无成。在连接上通常有大约 10 个命令
服务,如果他们失败,服务器将断开连接。
到目前为止我发现了什么:
我已经使用协议分析器确定出了什么问题:这是因为 TCP
AT#SH 的 FIN 进程与下一个连接的 TCP SYN 握手重叠
使用 AT#SD 启动。这似乎是由于延迟的最终 FIN-ACK 数据包到达
晚 - 在启动下一个连接之后。
在下面的跟踪中,您可以看到帧 8799 迟到,作为对 8788 的 ACK,但它来了
在下一次 SYN-ACK 握手过程中出现乱序!
发生这种情况后,调制解调器基本上是 "broken"。所有后续连接
经历有效负载数据包丢失,大量重新传输并且双方重新发送他们的
有效载荷数据包,就好像它们没有收到有效载荷 ACK。
在第 1 步之后。(AT#SH) F/W 有 1 秒的停顿。由于问题,我们添加了这个
当我们第一次安装 HE910 时重新连接,(我知道这是一个错误,但它更
比TCP/IP)在我们的服务器状态下适应数据库延迟。然而看起来
这 1 秒的延迟甚至不影响 TPC 流量,正如您从下面的跟踪中看到的那样。
ATSH "causes" 帧 8786 位于 17:16:51.585,ATSD "causes" 帧 8792 的 SYN
在 17:16:51.595,但它们之间只有 10 毫秒。我研究过固件,可以
确认 1s 延迟代码看起来正确,并在终端中查看固件 - 有
这些步骤的调试输出之间有 1 秒的延迟 - 但 TCP 讲述了一个不同的故事。
我可以在固件中以有限的方式发送 AT 命令 - 每五个只能发送一个命令
秒,这显然会使手动测试变得既好又慢。如果我发送+++,AT#SH
连接A,然后触发连接事件,设备连接成功。
这很有趣,因为连接的第 1 步无论如何都在执行 AT#SH。
所以我可以得出以下两点之一:要么我们需要发送一个 AT#SH "earlier"(即
在与 AT#SD 连接之前等待更长的时间),或发送其中两个(不太可能)。
据我所知,这是应用程序中的常见问题。即使在维基百科
TCP/IP 上的页面提到了应用程序破坏 OSI 模型并掉落的风险
如果用于应用程序级会话终止,则违反 TCP 拆卸握手。
我很想在我们的应用程序协议中添加一个漂亮的 "Goodbye",但这不是
中期可行的选择...我想让我们的两个调制解调器的 TCP 堆栈对齐。
服务器在同一个 IP/Port 上为传入连接打开一个新套接字
组合。 Node 和 VB 都从监听的父节点创建一个新的套接字资源
端口,所以我很确定在服务器端什么都没有"reused"(这是一种怀疑)。
不幸的是,我对调制解调器的 TCP 堆栈的了解有限,仅使用 AT#SI 和 SO
它提供基本的和看似非实时的信息。例如当套接字关闭时
服务器端,AT#SO 仍然在调制解调器本地显示 IP/Port,就像它没有收到一样
FIN 拆解。
从全新启动,设备可以 "reconnect" 成功大约四次,直到
"jam" 发生了。这对于 4 +-1 连接来说非常可靠。也可以是 "reset"
等待几个小时。所以,(抱歉)感觉调制解调器有点乱。
(再次,我确实怀疑我们的电信公司是 "limiting" 我们的连接,但跨电信公司测试是
太相似了。并考虑在生产中我们有数千个这样的设备
其中之一可以触发此行为。只是统计上不太可能他们可以
"notice" 数百个中有四个连接?)
最后一个行为是当连接 "jammed" 即不传输
数据,服务器在 30-60 秒后收到 RST(Node 中的 ECONNRESET,只是 VB 中的错误)。
(只有当我们禁用更快的应用程序级连接终止时,
很长一段时间都没有注意到)。重置后,但是 AT#SO 仍然显示为已连接
(有 IP),所以一开始我又觉得是 3G/AP/gateway 掉线了
在中间但不告诉客户。但是由于问题的一致性
跨电信公司和网络,我现在发现这很难相信,只是认为 AT
回答与现实不"up to date"。
这个典型的 TCP 跟踪显示(我目前的解释,可能不正确)
- 连接 A,Syn/Ack 正常
- 我们的应用程序协议在第 8197 帧开始和完成 17:16:01
- 然后一个事件发生,启动另一个连接 B
- First Step 1. teardown, Frame 8786 开始FIN握手
- 拆解到第 8788 帧 17:16:51.58
- 然后下一个连接B从第8792帧开始17:16:51.59
- 这一切顺利,直到在第 8799 帧被来自连接 A 的最终 Fin Ack 中断
(也许这个被忽略了?)
- 应用程序协议再次尝试启动,但第一个 13 字节消息没有启动
得到 ACKed 并多次重传...
- 我们的服务器重新发送第一个命令,在第 8978 帧将缓冲区大小加倍
- 我们的服务器超时并断开连接,在 9016 发送 Fin
跟踪
Frame TIME REL TIME SOURCE DEST SEQ ACK FLAGS WINDOW PAYLOAD BYTES
8003 17:15:55.9409634 703.7329764 CLIENT_IP SERVER_IP 0 0 (0x0) ......S. 65000 0 Flags=......S., SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432024, Ack=0, Win=65000 ( ) = 65000 vb6.exe
8004 17:15:55.9410316 0.0000682 SERVER_IP CLIENT_IP 0 1 ...A..S. 8192 0 Flags=...A..S., SrcPort=50008, DstPort=17790, PayloadLen=0, Seq=319387462, Ack=316432025, Win=8192 ( Scale factor not supported ) = 8192 vb6.exe
8016 17:15:58.5707216 2.6296900 CLIENT_IP SERVER_IP 1 1 ...A.... 65000 0 Flags=...A...., SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432025, Ack=319387463, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8037 17:15:58.8632583 0.2925367 SERVER_IP CLIENT_IP 1 - 14 1 ...AP... 65000 13 Flags=...AP..., SrcPort=50008, DstPort=17790, PayloadLen=13, Seq=319387463 - 319387476, Ack=316432025, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8039 17:15:59.0105830 0.1473247 CLIENT_IP SERVER_IP 1 14 ...A.... 65000 0 Flags=...A...., SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432025, Ack=319387476, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8041 17:15:59.1006112 0.0900282 CLIENT_IP SERVER_IP 1 - 7 14 ...AP... 65000 6 Flags=...AP..., SrcPort=17790, DstPort=50008, PayloadLen=6, Seq=316432025 - 316432031, Ack=319387476, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8068 17:15:59.2997681 0.1991569 SERVER_IP CLIENT_IP 14 7 ...A.... 64994 0 Flags=...A...., SrcPort=50008, DstPort=17790, PayloadLen=0, Seq=319387476, Ack=316432031, Win=64994 (scale factor 0x0) = 64994 vb6.exe
8071 17:15:59.3590861 0.0593180 SERVER_IP CLIENT_IP 14 - 19 7 ...AP... 64994 5 Flags=...AP..., SrcPort=50008, DstPort=17790, PayloadLen=5, Seq=319387476 - 319387481, Ack=316432031, Win=64994 (scale factor 0x0) = 64994 vb6.exe
8076 17:15:59.5106103 0.1515242 CLIENT_IP SERVER_IP 7 19 ...A.... 65000 0 Flags=...A...., SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432031, Ack=319387481, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8078 17:15:59.6005478 0.0899375 CLIENT_IP SERVER_IP 7 - 28 19 ...AP... 65000 21 Flags=...AP..., SrcPort=17790, DstPort=50008, PayloadLen=21, Seq=316432031 - 316432052, Ack=319387481, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8100 17:15:59.7989459 0.1983981 SERVER_IP CLIENT_IP 19 28 ...A.... 64973 0 Flags=...A...., SrcPort=50008, DstPort=17790, PayloadLen=0, Seq=319387481, Ack=316432052, Win=64973 (scale factor 0x0) = 64973 vb6.exe
8110 17:15:59.9164691 0.1175232 SERVER_IP CLIENT_IP 19 - 37 28 ...AP... 64973 18 Flags=...AP..., SrcPort=50008, DstPort=17790, PayloadLen=18, Seq=319387481 - 319387499, Ack=316432052, Win=64973 (scale factor 0x0) = 64973 vb6.exe
8114 17:16:00.0005725 0.0841034 CLIENT_IP SERVER_IP 28 37 ...A.... 65000 0 Flags=...A...., SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432052, Ack=319387499, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8120 17:16:00.2005077 0.1999352 CLIENT_IP SERVER_IP 28 - 34 37 ...AP... 65000 6 Flags=...AP..., SrcPort=17790, DstPort=50008, PayloadLen=6, Seq=316432052 - 316432058, Ack=319387499, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8127 17:16:00.2509607 0.0504530 SERVER_IP CLIENT_IP 37 - 42 34 ...AP... 64967 5 Flags=...AP..., SrcPort=50008, DstPort=17790, PayloadLen=5, Seq=319387499 - 319387504, Ack=316432058, Win=64967 (scale factor 0x0) = 64967 vb6.exe
8131 17:16:00.5004721 0.2495114 CLIENT_IP SERVER_IP 34 42 ...A.... 65000 0 Flags=...A...., SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432058, Ack=319387504, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8132 17:16:00.5004721 0.0000000 CLIENT_IP SERVER_IP 34 - 43 42 ...AP... 65000 9 Flags=...AP..., SrcPort=17790, DstPort=50008, PayloadLen=9, Seq=316432058 - 316432067, Ack=319387504, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8160 17:16:00.6603237 0.1598516 SERVER_IP CLIENT_IP 42 - 49 43 ...AP... 64958 7 Flags=...AP..., SrcPort=50008, DstPort=17790, PayloadLen=7, Seq=319387504 - 319387511, Ack=316432067, Win=64958 (scale factor 0x0) = 64958 vb6.exe
8162 17:16:00.7505392 0.0902155 CLIENT_IP SERVER_IP 43 49 ...A.... 65000 0 Flags=...A...., SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432067, Ack=319387511, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8168 17:16:00.9005226 0.1499834 CLIENT_IP SERVER_IP 43 - 55 49 ...AP... 65000 12 Flags=...AP..., SrcPort=17790, DstPort=50008, PayloadLen=12, Seq=316432067 - 316432079, Ack=319387511, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8197 17:16:01.1093181 0.2087955 SERVER_IP CLIENT_IP 49 55 ...A.... 64946 0 Flags=...A...., SrcPort=50008, DstPort=17790, PayloadLen=0, Seq=319387511, Ack=316432079, Win=64946 (scale factor 0x0) = 64946 vb6.exe
8786 17:16:51.5853712 50.4760531 CLIENT_IP SERVER_IP 55 49 ...A...F 65000 0 Flags=...A...F, SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432079, Ack=319387511, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8787 17:16:51.5854172 0.0000460 SERVER_IP CLIENT_IP 49 56 ...A.... 64946 0 Flags=...A...., SrcPort=50008, DstPort=17790, PayloadLen=0, Seq=319387511, Ack=316432080, Win=64946 (scale factor 0x0) = 64946 vb6.exe
8788 17:16:51.5860033 0.0005861 SERVER_IP CLIENT_IP 49 56 ...A...F 64946 0 Flags=...A...F, SrcPort=50008, DstPort=17790, PayloadLen=0, Seq=319387511, Ack=316432080, Win=64946 (scale factor 0x0) = 64946 vb6.exe
8792 17:16:51.5954781 0.0094748 CLIENT_IP SERVER_IP 0 0 (0x0) ......S. 65000 0 Flags=......S., SrcPort=39522, DstPort=50008, PayloadLen=0, Seq=1817440308, Ack=0, Win=65000 ( ) = 65000 vb6.exe
8793 17:16:51.5955252 0.0000471 SERVER_IP CLIENT_IP 0 1 ...A..S. 8192 0 Flags=...A..S., SrcPort=50008, DstPort=39522, PayloadLen=0, Seq=4287314964, Ack=1817440309, Win=8192 ( Scale factor not supported ) = 8192 vb6.exe
8799 17:16:51.7152606 0.1197354 CLIENT_IP SERVER_IP 56 50 ...A.... 64999 0 Flags=...A...., SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432080, Ack=319387512, Win=64999 (scale factor 0x0) = 64999 vb6.exe
8801 17:16:51.7351969 0.0199363 CLIENT_IP SERVER_IP 1 1 ...A.... 65000 0 Flags=...A...., SrcPort=39522, DstPort=50008, PayloadLen=0, Seq=1817440309, Ack=4287314965, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8821 17:16:52.0333514 0.2981545 SERVER_IP CLIENT_IP 1 - 14 1 ...AP... 65000 13 Flags=...AP..., SrcPort=50008, DstPort=39522, PayloadLen=13, Seq=4287314965 - 4287314978, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8846 17:16:52.4579548 0.4246034 SERVER_IP CLIENT_IP 1 - 14 1 ...AP... 65000 13 [ReTransmit #8821]Flags=...AP..., SrcPort=50008, DstPort=39522, PayloadLen=13, Seq=4287314965 - 4287314978, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8855 17:16:53.3003681 0.8424133 SERVER_IP CLIENT_IP 1 - 14 1 ...AP... 65000 13 [ReTransmit #8821]Flags=...AP..., SrcPort=50008, DstPort=39522, PayloadLen=13, Seq=4287314965 - 4287314978, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8875 17:16:54.9852348 1.6848667 SERVER_IP CLIENT_IP 1 - 14 1 ...AP... 65000 13 [ReTransmit #8821]Flags=...AP..., SrcPort=50008, DstPort=39522, PayloadLen=13, Seq=4287314965 - 4287314978, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8890 17:16:56.6729734 1.6877386 SERVER_IP CLIENT_IP 1 - 14 1 ...AP... 65000 13 [ReTransmit #8821]Flags=...AP..., SrcPort=50008, DstPort=39522, PayloadLen=13, Seq=4287314965 - 4287314978, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8909 17:16:58.3734032 1.7004298 SERVER_IP CLIENT_IP 1 - 14 1 ...AP... 65000 13 [ReTransmit #8821]Flags=...AP..., SrcPort=50008, DstPort=39522, PayloadLen=13, Seq=4287314965 - 4287314978, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8921 17:17:01.7429692 3.3695660 SERVER_IP CLIENT_IP 1 - 14 1 ...AP... 65000 13 [ReTransmit #8821]Flags=...AP..., SrcPort=50008, DstPort=39522, PayloadLen=13, Seq=4287314965 - 4287314978, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8978 17:17:08.4665817 6.7236125 SERVER_IP CLIENT_IP 1 - 27 1 ...AP... 65000 26 [ReTransmit #8821]Flags=...AP..., SrcPort=50008, DstPort=39522, PayloadLen=26, Seq=4287314965 - 4287314991, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
9016 17:17:12.2738575 3.8072758 SERVER_IP CLIENT_IP 27 1 ...A...F 65000 0 Flags=...A...F, SrcPort=50008, DstPort=39522, PayloadLen=0, Seq=4287314991, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
观察(TCP 知识有限)
- 所有数据和 Fin 数据包都设置了 Ack 位 - 这对我来说很不寻常。
- fin 握手是四向的,但看起来服务器正在尝试三向握手,通过
在客户端 Fin 的 Ack 中包含一个 Fin。也许这是由于上述原因,
但也许这会导致问题,调制解调器正在进行四路拆解
但是服务器正在尝试进行三向拆解?但它也会发送一个独立的 Ack。
- 我不明白重传怎么这么快?
帧 8846 17:16:52.45 在原始帧之后仅发送 420 毫秒。这肯定不是
足够长以超时接收 ACK?我是否可能遗漏了一个潜在的 IP 错误
响应数据包,因为我只跟踪 TCP 级别?不然怎么知道重传?
最后 - 我的问题。
我怎样才能,纯粹用AT命令,可靠地拆除一个TCP/IP套接字,并建立
新套接字上的新连接到相同的 Port/IP,没有延迟拆卸的机会
数据包乱序到达。
或者更具体地说,我怎样才能让 HE910 调制解调器像 UC864 一样成功地做到这一点。
为了回答我自己的问题,我已经设法解决了这个问题,但不一定回答基本问题。
我设法在拆解和重新连接之间向固件添加了 2 秒的延迟(取代了描述的 1 秒延迟),因为这是一个简单的更改。
这完全修复了该行为并使我能够对超过 20 次重新连接的时间进行进一步分析。
事实证明,HE-910 调制解调器具有两个网络延迟级别的周期性循环。它每隔几分钟交替出现 900 毫秒和 1,200 毫秒。这意味着前几个连接(我可以每 30 秒执行一次)将在代码中延迟 1 秒成功,但是当达到 1.2 秒延迟时,FIN-ACK 数据包会溢出到下一个连接。
此图显示了 FIN/ACK 序列和下一个 SYN/ACK 握手之间的时间 "distance",此时 ATSH 命令和 ATSD 命令之间有 2 秒的延迟。它显然有一个周期性变化,偶尔会超过 1s 停顿的边缘。
所以事实证明,我之前的 1 秒延迟的拼凑 只是 有效。一年前更长时间的测试会证明这一点。
因此,虽然 2 秒的延迟只是一个较长的问题,但似乎有足够的余量来确保安全。我正在进行进一步的基准测试,看看我们是否可以冒着接近 2 秒延迟的风险。
这可能是某些 TCP/IP 堆栈的 "Delayed ACK" 特征,但 1.2s 似乎非常长。调制解调器没有控制 TCP_NODELAY 选项的命令,所以我无法对其进行测试。
似乎 AT#SH 命令也是异步的,因为在拆卸 甚至开始 之前返回 OK。否则,初始 FIN 将始终偏移 1 秒或 2 秒,而在上图中,FIN 和 ACK 均延迟 0.8 毫秒加上它们之间的时间。
我还将使用 2s 固件对 UC864 进行基准测试,以获得相同的图表,这应该更清楚地说明根本原因。
这个问题原来是Telit HE910固件v12.00.04的bug。
Glyn 说他们有信心升级后会解决这个问题,更新日志中有许多看起来相关的错误修复。
升级到 v12.00.06 后,所有问题都消失了。
我有一个问题,我觉得我几乎已经解决了,但卡在了 "last leg"。 我已经研究了几天了,虽然有所突破,但感觉我 由于存在一些盲点,我离可行的解决方案还有一段距离。
我有一个嵌入式移动固件应用程序(我不能直接编辑),它有问题 通过 TCP/IP/UMTS/GSM 重新连接到我们的服务器。固件仅使用 AT 命令来启动和 通过调制解调器控制连接。我们产品的原始版本已经 在生产中工作了大约 10 年,但是 "new" 版本的硬件是 遇到间歇性问题。
有很多变数,但我排除了所有变数,只有一个:调制解调器芯片。
- 我们有新版本的固件,有各种变化,但范围广泛 A/B 测试显示所有固件都遇到同样的问题,所以我已经排除了。
- 我们有一个遗留的 VB6 服务器,使用 Winsock。我最近写了一个更简单的 Node.js 版本也几乎完全相同地展示了同样的问题(令人惊讶的是)。
- 我们使用各种电信公司:Optus、Vodafone、Telstra。同样,它们似乎与问题无关。
- 我们直接使用电信公司,或使用拥有自己的专用网络 (APN) 的经销商。再次证明无关紧要。
- 我们有不同的 hosting/network 安装,但我再次测试了许多配置 包括我们的公司网络、生产托管、AWS 开发 EC2,它们都执行 差不多。
- 我们还对 emulated/mock 版本的 hardware/firmware 进行了自动化测试 这表明各种服务器和网络似乎都运行良好且相似。
- 显示显着 - 实际上是绝对 - 差异的最终变体是 泰利特 UC864 调制解调器和 HE910。以前的旧调制解调器工作完美,但较新的 HE910 总是遇到问题。我已经测试了所有可能的排列和问题 沿用HE910.
当然,我已经没完没了地阅读了 Telit 文档(特别是 "Easy IP",以及 AT 命令和软件参考),但看不出有多大区别 两种产品之间。 HE910 在 Glynn 的实体包装中,但我不相信 影响它的行为。
问题:
我们的固件应用程序连接到特定 port/address 上的服务器。服务器 启动固件必须响应的出站应用程序协议。 (所以真的 固件是 "server" 但这没关系。)它非常轻巧简单, 按照每 command/response.
10 字节的顺序当固件重新连接时出现问题,由于一个事件,"on top of"一个现有的 插座连接。固件始终遵循相同的过程:拆解、配置、 connect - 无论是否存在现有连接(这是由于 "connected" 在 TCP 和 3G 上的模糊性,最好是 "try to send data",或者 重新连接以确保连接)。正如我所说,我无法在 F/W.
中更改此行为连接步骤为:
- a) 套接字拆卸 AT#SH b) 等待 1s
- 配置PDP上下文AT+CGDCONT
- 配置TCP/IP堆栈:AT#SCFG
- 激活 PDP 上下文:AT#SGACT
- 连接TCP/IP到服务器:AT#SD
(您可能会问为什么每次连接都完成配置步骤 2、3、4:因为 它们可以通过我们的应用程序协议进行更新。但通常设置是不变的。)
我们遇到的问题是有时设备可以连接但无法通信。 连接似乎 "stuck" - 有时几个字节通过,有时整个 command/response 循环,却常常一事无成。在连接上通常有大约 10 个命令 服务,如果他们失败,服务器将断开连接。
到目前为止我发现了什么:
我已经使用协议分析器确定出了什么问题:这是因为 TCP AT#SH 的 FIN 进程与下一个连接的 TCP SYN 握手重叠 使用 AT#SD 启动。这似乎是由于延迟的最终 FIN-ACK 数据包到达 晚 - 在启动下一个连接之后。
在下面的跟踪中,您可以看到帧 8799 迟到,作为对 8788 的 ACK,但它来了 在下一次 SYN-ACK 握手过程中出现乱序!
发生这种情况后,调制解调器基本上是 "broken"。所有后续连接 经历有效负载数据包丢失,大量重新传输并且双方重新发送他们的 有效载荷数据包,就好像它们没有收到有效载荷 ACK。
在第 1 步之后。(AT#SH) F/W 有 1 秒的停顿。由于问题,我们添加了这个 当我们第一次安装 HE910 时重新连接,(我知道这是一个错误,但它更 比TCP/IP)在我们的服务器状态下适应数据库延迟。然而看起来 这 1 秒的延迟甚至不影响 TPC 流量,正如您从下面的跟踪中看到的那样。 ATSH "causes" 帧 8786 位于 17:16:51.585,ATSD "causes" 帧 8792 的 SYN 在 17:16:51.595,但它们之间只有 10 毫秒。我研究过固件,可以 确认 1s 延迟代码看起来正确,并在终端中查看固件 - 有 这些步骤的调试输出之间有 1 秒的延迟 - 但 TCP 讲述了一个不同的故事。
我可以在固件中以有限的方式发送 AT 命令 - 每五个只能发送一个命令 秒,这显然会使手动测试变得既好又慢。如果我发送+++,AT#SH 连接A,然后触发连接事件,设备连接成功。 这很有趣,因为连接的第 1 步无论如何都在执行 AT#SH。 所以我可以得出以下两点之一:要么我们需要发送一个 AT#SH "earlier"(即 在与 AT#SD 连接之前等待更长的时间),或发送其中两个(不太可能)。
据我所知,这是应用程序中的常见问题。即使在维基百科 TCP/IP 上的页面提到了应用程序破坏 OSI 模型并掉落的风险 如果用于应用程序级会话终止,则违反 TCP 拆卸握手。 我很想在我们的应用程序协议中添加一个漂亮的 "Goodbye",但这不是 中期可行的选择...我想让我们的两个调制解调器的 TCP 堆栈对齐。
服务器在同一个 IP/Port 上为传入连接打开一个新套接字 组合。 Node 和 VB 都从监听的父节点创建一个新的套接字资源 端口,所以我很确定在服务器端什么都没有"reused"(这是一种怀疑)。 不幸的是,我对调制解调器的 TCP 堆栈的了解有限,仅使用 AT#SI 和 SO 它提供基本的和看似非实时的信息。例如当套接字关闭时 服务器端,AT#SO 仍然在调制解调器本地显示 IP/Port,就像它没有收到一样 FIN 拆解。
从全新启动,设备可以 "reconnect" 成功大约四次,直到 "jam" 发生了。这对于 4 +-1 连接来说非常可靠。也可以是 "reset" 等待几个小时。所以,(抱歉)感觉调制解调器有点乱。 (再次,我确实怀疑我们的电信公司是 "limiting" 我们的连接,但跨电信公司测试是 太相似了。并考虑在生产中我们有数千个这样的设备 其中之一可以触发此行为。只是统计上不太可能他们可以 "notice" 数百个中有四个连接?)
最后一个行为是当连接 "jammed" 即不传输 数据,服务器在 30-60 秒后收到 RST(Node 中的 ECONNRESET,只是 VB 中的错误)。 (只有当我们禁用更快的应用程序级连接终止时, 很长一段时间都没有注意到)。重置后,但是 AT#SO 仍然显示为已连接 (有 IP),所以一开始我又觉得是 3G/AP/gateway 掉线了 在中间但不告诉客户。但是由于问题的一致性 跨电信公司和网络,我现在发现这很难相信,只是认为 AT 回答与现实不"up to date"。
这个典型的 TCP 跟踪显示(我目前的解释,可能不正确)
- 连接 A,Syn/Ack 正常
- 我们的应用程序协议在第 8197 帧开始和完成 17:16:01
- 然后一个事件发生,启动另一个连接 B
- First Step 1. teardown, Frame 8786 开始FIN握手
- 拆解到第 8788 帧 17:16:51.58
- 然后下一个连接B从第8792帧开始17:16:51.59
- 这一切顺利,直到在第 8799 帧被来自连接 A 的最终 Fin Ack 中断 (也许这个被忽略了?)
- 应用程序协议再次尝试启动,但第一个 13 字节消息没有启动 得到 ACKed 并多次重传...
- 我们的服务器重新发送第一个命令,在第 8978 帧将缓冲区大小加倍
- 我们的服务器超时并断开连接,在 9016 发送 Fin
跟踪
Frame TIME REL TIME SOURCE DEST SEQ ACK FLAGS WINDOW PAYLOAD BYTES
8003 17:15:55.9409634 703.7329764 CLIENT_IP SERVER_IP 0 0 (0x0) ......S. 65000 0 Flags=......S., SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432024, Ack=0, Win=65000 ( ) = 65000 vb6.exe
8004 17:15:55.9410316 0.0000682 SERVER_IP CLIENT_IP 0 1 ...A..S. 8192 0 Flags=...A..S., SrcPort=50008, DstPort=17790, PayloadLen=0, Seq=319387462, Ack=316432025, Win=8192 ( Scale factor not supported ) = 8192 vb6.exe
8016 17:15:58.5707216 2.6296900 CLIENT_IP SERVER_IP 1 1 ...A.... 65000 0 Flags=...A...., SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432025, Ack=319387463, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8037 17:15:58.8632583 0.2925367 SERVER_IP CLIENT_IP 1 - 14 1 ...AP... 65000 13 Flags=...AP..., SrcPort=50008, DstPort=17790, PayloadLen=13, Seq=319387463 - 319387476, Ack=316432025, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8039 17:15:59.0105830 0.1473247 CLIENT_IP SERVER_IP 1 14 ...A.... 65000 0 Flags=...A...., SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432025, Ack=319387476, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8041 17:15:59.1006112 0.0900282 CLIENT_IP SERVER_IP 1 - 7 14 ...AP... 65000 6 Flags=...AP..., SrcPort=17790, DstPort=50008, PayloadLen=6, Seq=316432025 - 316432031, Ack=319387476, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8068 17:15:59.2997681 0.1991569 SERVER_IP CLIENT_IP 14 7 ...A.... 64994 0 Flags=...A...., SrcPort=50008, DstPort=17790, PayloadLen=0, Seq=319387476, Ack=316432031, Win=64994 (scale factor 0x0) = 64994 vb6.exe
8071 17:15:59.3590861 0.0593180 SERVER_IP CLIENT_IP 14 - 19 7 ...AP... 64994 5 Flags=...AP..., SrcPort=50008, DstPort=17790, PayloadLen=5, Seq=319387476 - 319387481, Ack=316432031, Win=64994 (scale factor 0x0) = 64994 vb6.exe
8076 17:15:59.5106103 0.1515242 CLIENT_IP SERVER_IP 7 19 ...A.... 65000 0 Flags=...A...., SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432031, Ack=319387481, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8078 17:15:59.6005478 0.0899375 CLIENT_IP SERVER_IP 7 - 28 19 ...AP... 65000 21 Flags=...AP..., SrcPort=17790, DstPort=50008, PayloadLen=21, Seq=316432031 - 316432052, Ack=319387481, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8100 17:15:59.7989459 0.1983981 SERVER_IP CLIENT_IP 19 28 ...A.... 64973 0 Flags=...A...., SrcPort=50008, DstPort=17790, PayloadLen=0, Seq=319387481, Ack=316432052, Win=64973 (scale factor 0x0) = 64973 vb6.exe
8110 17:15:59.9164691 0.1175232 SERVER_IP CLIENT_IP 19 - 37 28 ...AP... 64973 18 Flags=...AP..., SrcPort=50008, DstPort=17790, PayloadLen=18, Seq=319387481 - 319387499, Ack=316432052, Win=64973 (scale factor 0x0) = 64973 vb6.exe
8114 17:16:00.0005725 0.0841034 CLIENT_IP SERVER_IP 28 37 ...A.... 65000 0 Flags=...A...., SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432052, Ack=319387499, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8120 17:16:00.2005077 0.1999352 CLIENT_IP SERVER_IP 28 - 34 37 ...AP... 65000 6 Flags=...AP..., SrcPort=17790, DstPort=50008, PayloadLen=6, Seq=316432052 - 316432058, Ack=319387499, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8127 17:16:00.2509607 0.0504530 SERVER_IP CLIENT_IP 37 - 42 34 ...AP... 64967 5 Flags=...AP..., SrcPort=50008, DstPort=17790, PayloadLen=5, Seq=319387499 - 319387504, Ack=316432058, Win=64967 (scale factor 0x0) = 64967 vb6.exe
8131 17:16:00.5004721 0.2495114 CLIENT_IP SERVER_IP 34 42 ...A.... 65000 0 Flags=...A...., SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432058, Ack=319387504, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8132 17:16:00.5004721 0.0000000 CLIENT_IP SERVER_IP 34 - 43 42 ...AP... 65000 9 Flags=...AP..., SrcPort=17790, DstPort=50008, PayloadLen=9, Seq=316432058 - 316432067, Ack=319387504, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8160 17:16:00.6603237 0.1598516 SERVER_IP CLIENT_IP 42 - 49 43 ...AP... 64958 7 Flags=...AP..., SrcPort=50008, DstPort=17790, PayloadLen=7, Seq=319387504 - 319387511, Ack=316432067, Win=64958 (scale factor 0x0) = 64958 vb6.exe
8162 17:16:00.7505392 0.0902155 CLIENT_IP SERVER_IP 43 49 ...A.... 65000 0 Flags=...A...., SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432067, Ack=319387511, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8168 17:16:00.9005226 0.1499834 CLIENT_IP SERVER_IP 43 - 55 49 ...AP... 65000 12 Flags=...AP..., SrcPort=17790, DstPort=50008, PayloadLen=12, Seq=316432067 - 316432079, Ack=319387511, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8197 17:16:01.1093181 0.2087955 SERVER_IP CLIENT_IP 49 55 ...A.... 64946 0 Flags=...A...., SrcPort=50008, DstPort=17790, PayloadLen=0, Seq=319387511, Ack=316432079, Win=64946 (scale factor 0x0) = 64946 vb6.exe
8786 17:16:51.5853712 50.4760531 CLIENT_IP SERVER_IP 55 49 ...A...F 65000 0 Flags=...A...F, SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432079, Ack=319387511, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8787 17:16:51.5854172 0.0000460 SERVER_IP CLIENT_IP 49 56 ...A.... 64946 0 Flags=...A...., SrcPort=50008, DstPort=17790, PayloadLen=0, Seq=319387511, Ack=316432080, Win=64946 (scale factor 0x0) = 64946 vb6.exe
8788 17:16:51.5860033 0.0005861 SERVER_IP CLIENT_IP 49 56 ...A...F 64946 0 Flags=...A...F, SrcPort=50008, DstPort=17790, PayloadLen=0, Seq=319387511, Ack=316432080, Win=64946 (scale factor 0x0) = 64946 vb6.exe
8792 17:16:51.5954781 0.0094748 CLIENT_IP SERVER_IP 0 0 (0x0) ......S. 65000 0 Flags=......S., SrcPort=39522, DstPort=50008, PayloadLen=0, Seq=1817440308, Ack=0, Win=65000 ( ) = 65000 vb6.exe
8793 17:16:51.5955252 0.0000471 SERVER_IP CLIENT_IP 0 1 ...A..S. 8192 0 Flags=...A..S., SrcPort=50008, DstPort=39522, PayloadLen=0, Seq=4287314964, Ack=1817440309, Win=8192 ( Scale factor not supported ) = 8192 vb6.exe
8799 17:16:51.7152606 0.1197354 CLIENT_IP SERVER_IP 56 50 ...A.... 64999 0 Flags=...A...., SrcPort=17790, DstPort=50008, PayloadLen=0, Seq=316432080, Ack=319387512, Win=64999 (scale factor 0x0) = 64999 vb6.exe
8801 17:16:51.7351969 0.0199363 CLIENT_IP SERVER_IP 1 1 ...A.... 65000 0 Flags=...A...., SrcPort=39522, DstPort=50008, PayloadLen=0, Seq=1817440309, Ack=4287314965, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8821 17:16:52.0333514 0.2981545 SERVER_IP CLIENT_IP 1 - 14 1 ...AP... 65000 13 Flags=...AP..., SrcPort=50008, DstPort=39522, PayloadLen=13, Seq=4287314965 - 4287314978, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8846 17:16:52.4579548 0.4246034 SERVER_IP CLIENT_IP 1 - 14 1 ...AP... 65000 13 [ReTransmit #8821]Flags=...AP..., SrcPort=50008, DstPort=39522, PayloadLen=13, Seq=4287314965 - 4287314978, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8855 17:16:53.3003681 0.8424133 SERVER_IP CLIENT_IP 1 - 14 1 ...AP... 65000 13 [ReTransmit #8821]Flags=...AP..., SrcPort=50008, DstPort=39522, PayloadLen=13, Seq=4287314965 - 4287314978, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8875 17:16:54.9852348 1.6848667 SERVER_IP CLIENT_IP 1 - 14 1 ...AP... 65000 13 [ReTransmit #8821]Flags=...AP..., SrcPort=50008, DstPort=39522, PayloadLen=13, Seq=4287314965 - 4287314978, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8890 17:16:56.6729734 1.6877386 SERVER_IP CLIENT_IP 1 - 14 1 ...AP... 65000 13 [ReTransmit #8821]Flags=...AP..., SrcPort=50008, DstPort=39522, PayloadLen=13, Seq=4287314965 - 4287314978, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8909 17:16:58.3734032 1.7004298 SERVER_IP CLIENT_IP 1 - 14 1 ...AP... 65000 13 [ReTransmit #8821]Flags=...AP..., SrcPort=50008, DstPort=39522, PayloadLen=13, Seq=4287314965 - 4287314978, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8921 17:17:01.7429692 3.3695660 SERVER_IP CLIENT_IP 1 - 14 1 ...AP... 65000 13 [ReTransmit #8821]Flags=...AP..., SrcPort=50008, DstPort=39522, PayloadLen=13, Seq=4287314965 - 4287314978, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
8978 17:17:08.4665817 6.7236125 SERVER_IP CLIENT_IP 1 - 27 1 ...AP... 65000 26 [ReTransmit #8821]Flags=...AP..., SrcPort=50008, DstPort=39522, PayloadLen=26, Seq=4287314965 - 4287314991, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
9016 17:17:12.2738575 3.8072758 SERVER_IP CLIENT_IP 27 1 ...A...F 65000 0 Flags=...A...F, SrcPort=50008, DstPort=39522, PayloadLen=0, Seq=4287314991, Ack=1817440309, Win=65000 (scale factor 0x0) = 65000 vb6.exe
观察(TCP 知识有限)
- 所有数据和 Fin 数据包都设置了 Ack 位 - 这对我来说很不寻常。
- fin 握手是四向的,但看起来服务器正在尝试三向握手,通过 在客户端 Fin 的 Ack 中包含一个 Fin。也许这是由于上述原因, 但也许这会导致问题,调制解调器正在进行四路拆解 但是服务器正在尝试进行三向拆解?但它也会发送一个独立的 Ack。
- 我不明白重传怎么这么快? 帧 8846 17:16:52.45 在原始帧之后仅发送 420 毫秒。这肯定不是 足够长以超时接收 ACK?我是否可能遗漏了一个潜在的 IP 错误 响应数据包,因为我只跟踪 TCP 级别?不然怎么知道重传?
最后 - 我的问题。
我怎样才能,纯粹用AT命令,可靠地拆除一个TCP/IP套接字,并建立 新套接字上的新连接到相同的 Port/IP,没有延迟拆卸的机会 数据包乱序到达。
或者更具体地说,我怎样才能让 HE910 调制解调器像 UC864 一样成功地做到这一点。
为了回答我自己的问题,我已经设法解决了这个问题,但不一定回答基本问题。
我设法在拆解和重新连接之间向固件添加了 2 秒的延迟(取代了描述的 1 秒延迟),因为这是一个简单的更改。
这完全修复了该行为并使我能够对超过 20 次重新连接的时间进行进一步分析。
事实证明,HE-910 调制解调器具有两个网络延迟级别的周期性循环。它每隔几分钟交替出现 900 毫秒和 1,200 毫秒。这意味着前几个连接(我可以每 30 秒执行一次)将在代码中延迟 1 秒成功,但是当达到 1.2 秒延迟时,FIN-ACK 数据包会溢出到下一个连接。
此图显示了 FIN/ACK 序列和下一个 SYN/ACK 握手之间的时间 "distance",此时 ATSH 命令和 ATSD 命令之间有 2 秒的延迟。它显然有一个周期性变化,偶尔会超过 1s 停顿的边缘。
所以事实证明,我之前的 1 秒延迟的拼凑 只是 有效。一年前更长时间的测试会证明这一点。
因此,虽然 2 秒的延迟只是一个较长的问题,但似乎有足够的余量来确保安全。我正在进行进一步的基准测试,看看我们是否可以冒着接近 2 秒延迟的风险。
这可能是某些 TCP/IP 堆栈的 "Delayed ACK" 特征,但 1.2s 似乎非常长。调制解调器没有控制 TCP_NODELAY 选项的命令,所以我无法对其进行测试。
似乎 AT#SH 命令也是异步的,因为在拆卸 甚至开始 之前返回 OK。否则,初始 FIN 将始终偏移 1 秒或 2 秒,而在上图中,FIN 和 ACK 均延迟 0.8 毫秒加上它们之间的时间。
我还将使用 2s 固件对 UC864 进行基准测试,以获得相同的图表,这应该更清楚地说明根本原因。
这个问题原来是Telit HE910固件v12.00.04的bug。
Glyn 说他们有信心升级后会解决这个问题,更新日志中有许多看起来相关的错误修复。
升级到 v12.00.06 后,所有问题都消失了。