STF ‘Socket connection was lost’ 问题咨询

今天也是收获满满的一天啊 · April 12, 2019 · Last by 今天也是收获满满的一天啊 replied at April 12, 2019 · 1759 hits

问题描述

在使用 STF 过程中,时常会发生 “Socket connection was lost” 的情况。错误截图如下所示:

环境描述

系统:Ubuntu 18.04
电脑型号:Acer TMP249-G2-M-5102
内存:16GB DDR4/500GB HDD

复现步骤

Server 端启动服务,同一局域网下的另一台电脑使用 Opera 浏览器(Chrome 浏览器、FireFox 浏览器也行)访问 STF 平台,选择控制某一台手机设备,随机将浏览器窗口最小化。

初步分析

在浏览器弹框提示 “Socket connection was lost” 后,不点击 “try to reconnect” ,直接关闭弹框。
此时在浏览器上虽然无法再通过鼠标操纵手机,但是在手机端操作后,浏览器端仍然能实时显示手机屏幕截图。

再通过查阅 OpenSTF 资料及查看源码,发现 实时显示设备截图 和 操作手机 是维护在两条连接上的。

实时显示设备截图,服务运行在 7400-7700 端口上,每个手机会分配在此区间内的不同端口并建立链接。
代码路径:/home/ubuntu/git/stf/lib/cli/provider/index.js

.option('max-port', {
  describe: 'Highest port number for device workers to use.'
, type: 'number'
, default: 7700
})
.option('min-port', {
  describe: 'Lowest port number for device workers to use.'
, type: 'number'
, default: 7400
})

操作手机,服务运行在 7110 端口上,会有多个客户端(对应不同设备)与此端口建立连接。
代码路径:/home/ubuntu/git/stf/lib/units/websocket/index.js

.option('websocket-port', {
  describe: 'The port the websocket unit should run at.'
, type: 'number'
, default: 7110
})

综上,我这边发生的 socket 连接端口,其实是建立在 7110 端口上的连接断开了。

抓包分析

为了了解为什么建立在 7110 端口上的连接会断开,使用 wireshark 进行了抓包。发现了一个规律:
每隔 26s,客户端会给服务包发一个包,包内容(Line-based text data)为 2,服务端会给客户端返回一个包,包内容(Line-based text data)为 3;如果在下一个 26s,这两个包未能成功发送,在第 30s 时,服务端便会向客户端发起 close socket 的包,随即客户端给予响应,建立在 7110 端口上的连接就断开了。

为了直观表述,下面列出截图:
客户端:192.168.2.1 服务端:192.168.2.3

  • 第一次断开


第 18968 帧,在第 498s,客户端给服务端发包(Line-based text data 为 2 )


第 18969 帧,在第 498s,服务端给客户端发包(Line-based text data 为 3 )


第 19003 帧,在第 524s,客户端给服务端发包(Line-based text data 为 2 )


第 19004 帧,在第 524s,服务端给客户端发包(Line-based text data 为 3 )


第 19012 帧,在第 550s,客户端给服务端发包(Line-based text data 为 2 )


第 19013 帧,在第 550s,服务端给客户端发包(Line-based text data 为 3 )
第 19038 帧,在第 580s,服务端给客户端发包(Websocket connection close )
第 19040 帧,在第 580s,客户端给服务端发包(Websocket connection close )

  • 第二次断开


第 25169 帧,在第 726s,客户端给服务端发包(Line-based text data 为 2 )
第 25171 帧,在第 726s,服务端给客户端发包(Line-based text data 为 3 )
第 25333 帧,在第 757s,服务端给客户端发包(Websocket connection close )
第 25335 帧,在第 757s,客户端给服务端发包(Websocket connection close )

  • 第三次断开


第 33709 帧,在第 1424s,客户端给服务端发包(Line-based text data 为 2 )
第 33710 帧,在第 1424s,服务端给客户端发包(Line-based text data 为 3 )
第 33724 帧,在第 1451s,客户端给服务端发包(Line-based text data 为 2 )
第 33725 帧,在第 1451s,服务端给客户端发包(Line-based text data 为 3 )
第 33800 帧,在第 1478s,客户端给服务端发包(Line-based text data 为 2 )
第 33803 帧,在第 1478s,服务端给客户端发包(Line-based text data 为 3 )
第 33818 帧,在第 1504s,客户端给服务端发包(Line-based text data 为 2 )
第 33819 帧,在第 1504s,服务端给客户端发包(Line-based text data 为 3 )
第 33827 帧,在第 1530s,客户端给服务端发包(Line-based text data 为 2 )
第 33828 帧,在第 1530s,服务端给客户端发包(Line-based text data 为 3 )
第 33843 帧,在第 1560s,服务端给客户端发包(Websocket connection close )
第 33844 帧,在第 1560s,客户端给服务端发包(Websocket connection close )

以上,大概是这样一个规律。

咨询

曾尝试看 stf 代码,奈何对 nodejs 及 angularjs 都不太熟悉,看的一知半解也没太明白。所以想请教各位大神和前辈,能帮忙解答一下疑惑吗?
建立在 7110 端口上的连接是有类似的心跳机制吗?心跳间隔为 26s?而又为什么是在第 30s 的时候连接会断开?

共收到 2 条回复 时间 点赞

定位方法有问题,你为什么不先看 log 而是抓包分析?心跳机制是可以配置的在启动项里面配置的。我也是不懂 js 然后做二次开发的,不要让语言成为阻碍。

0x88 回复

感谢回复呀~ 我悄悄关注了的前辈~😀

回复问题 1 为什么不先看 log: 您是指的 stf local 启动后的命令行中输出的日志嘛?这个日志我有看,可能我看的还不够仔细,印象中日志中只输出了正在监听 7110 端口,之后建立在 7110 端口上的 socket 连接断开了 日志中似乎没有异常信息输出。所以就没把这个分析过程列出来。(有错误的地方还请指教呀。)

回复问题 2 心跳机制可以在启动项中配置:这个可以麻烦您再具体一点嘛?这一块逻辑在哪个地方呀,我还没找着,所以来社区求助了。

感谢您的激励呀~ 您写的二次开发和 adb 断线分析等我都反反复复读了好多遍~ 语言正在学习中,也在努力啃,向各位看齐呀😉

需要 Sign In 后方可回复, 如果你还没有账号请点击这里 Sign Up