隐藏在android webview中的http超时BUG

瞎猫

遇见0和1

近日排查了我司在android webview实践中碰到的诡异http超时问题。

记录排查过程如下，供参考。

了解问题

问题现象：

在某web页面，会请求后台API；请求后，页面闲置20分钟后；再次请求相同API，会超时10秒后返回正确数据
相同web页，通过electron部署正常
electron与webview，在相同网络下，分别运行在PC与android上
android走手机热点、公司网络，问题消失

乍看，似乎是网络问题，但严谨考虑，我们还是找下根因。用表格列出所有已知信息、补上待验证项，并测试：

	客户网络	公司网络
android + webview	异常	正常
android + chrome	异常	正常
pc + chrome	正常	正常
pc + electron	正常	正常

从这个图看，是“特定网络”+“android”的组合会引入问题。（不是webview用法问题，因为chrome也会）

那接下来怎么查呢？按对比法，我们可以先列出参与网络通信的模块：

业务代码 -> webview -> android/linux -> 各级路由 -> 服务器

然后采用“单一变量”原则，检查各步骤，确定问题大致方向

然而，不论替换android还是路由，都不能让我们对bug有更深入的了解。那就要换个思路——chromium作为如此盛行的浏览器，其bug列表极可能有汇报过相似问题

找突破口

果不其然，找到了一篇： https://bugs.chromium.org/p/chromium/issues/detail?id=1142455&can=1&q=stalled component%3AInternals>Network%2CBlink>Network

这篇里看到了什么信息呢？

问题相似，也是特定网络；服务器迁移到其它国家（网络环境改变）解决了
有一个明显的错误信息：

t=202726 [st=165124]  HTTP2_SESSION_CLOSE
                      --> description = "Failed ping."
                      --> net_error = -352 (ERR_HTTP2_PING_FAILED)

接下来需要做什么：

了解这里的ERR_HTTP2_PING_FAILED是什么？
这样的错误信息是如何获取的？
通过相同的手段分别获取正常、异常下的调试信息，进行对比

经过搜索，了解到：

这里的PING是HTTP2的一条协议。关于HTTP2协议可上网了解：
这个调试信息可用 chrome://net-export 获取

于是，上手导出一份异常日志，确认到了ERR_HTTP2_PING_FAILED，也刚好发生在闲置后第一次http request前

这里碰到一些知识盲区，做了学习： 1. http2一般情况会尽可能复用一个socket连接进行多次通讯，避免socket连接的耗时 2. 对于跨域请求，会先发送又给preflight请求(option)鉴权（所以一个request会看到发送了两条） 3. chromium在发送http request前还会先通过http2 PING确认服务器是否在线，以确认http2 session是否能复用

复盘分析

掌握了net-export工具，对网络过程能细致分析；因此对比了pc electron与android webview在相同操作下的网络流量。

总结如下：

闲置20分钟发送http请求
pc electron	闲置期间无其它通信；闲置后PING成功
android webview	闲置期间无其它通信；闲置后PING失败

当然，过程中没有这么顺利：比如会急功近利地，屏蔽preflight看看是不是这个问题；会在复现对比时被业务中一些无关的HTTP请求干扰（因为后台同一个endpoint，有多个域名关联的API服务器）；会迷失在看chromium的代码中…… 所以要时不时停下来，捋一捋之前做到了哪里，接下来看什么（借助思维导图）

所以，是android 上 webview的ping会失败？

从目前的信息，知道是特定网络引发，但这个特定网络下PC正常，android异常（其实这里忽略了一个关键信息：webview即使版本相同，在不同平台编译结果可能不同！）；所谓的异常，更具体的说，是PING失败了。

大致浏览 chromium/src/net/ 代码后，发现所谓PING的10秒超时是，通过socket送出HTTP2 PING帧后，通过轮询（借助event loop），最多10秒来等待PING回包；回包失败就废弃这个HTTP2 session（socket），重新创建session。

换句话说：在Android下，长时闲置后，socket发送正常，但没有收到回包。而PC(Windows)正常。

构建最简Demo验证

既然如此，写一个简单的Echo服务验证——客户端发送一条消息后，间隔20分钟再发下一条，预期能看到：

	现象
windows	两条均能正常发送；正常接收
android	第一条正常发送/接收；第二条发送成功，服务器未收到，客户端收包超时

实验时直接找Github上别人的代码用： https:// github.com/vichargrave/ tcpsockets 。

只验证了Android，现象吻合（Windows未验证，不够严谨！！）

这么看来，似乎是android，或者Linux在处理tcp时，碰到特定网络出BUG了？

但是还是觉得不对劲：这似乎应该是很容易碰到的BUG，为何Linux带着如此严重的BUG？又或者是Android的某种控制策略，比如节能？或者把宽带识别为了蜂窝网络，擅自主张了？为什么其他人实践中没有大面积汇报这样的问题？（只在bug列表找到）

构建解决方案

目前为止，可以将问题定性为：因为Android的某种机制，在特定网络下，一个tcp socket莫名其妙失连，但内核不知道（服务端也不知道），所以在socket send的时候没发现啥问题（返回值正确），但是服务器又收不到包。

从这样的排查结果看，还是只能猜几个可能的解决方法：

客户端每隔一段时间发起一个空的HTTP请求，模拟“心跳包”
使用Connection: Closed让http session用完即关闭(关闭socket)
服务端配置keep-alive: timeout，在小于20分钟的时间，主动关闭连接，看是否能让客户端识别到

在从源码确认第三个解决方案能否生效过程中，意外找到了另一个bug report，讨论并修复该问题： https:// bugs.chromium.org/p/chr omium/issues/detail?id=27400

I examined the code and it looks like we actually are not setting SO_KEEPALIVE. We should probably set it and pick some "reasonable" value (30s?) for TCP keep alives. It seems some routers are lowering their idle TCP connection timeouts to 60s or so, so I picked 30s to help mitigate this. I don't think TCP keep alives at 30s intervals will substantially impact network traffic, but am open to discussion here.

意思是chromium中没有对socket设置SO_KEEPALIVE，这会在某些路由下出问题（一些路由甚至60秒就会出问题），然后他选择了一个30秒的keep alive interval（最终定稿45秒）

那为啥Android上还是有问题呢？没错，Android上没有开启！

void TCPSocketPosix::SetDefaultOptionsForClient() {
  DCHECK(socket_);
  // This mirrors the behaviour on Windows. See the comment in
  // tcp_socket_win.cc after searching for "NODELAY".
  // If SetTCPNoDelay fails, we don't care.
  SetTCPNoDelay(socket_->socket_fd(), true);
  // TCP keep alive wakes up the radio, which is expensive on mobile. Do not
  // enable it there. It's useful to prevent TCP middleboxes from timing out
  // connection mappings. Packets for timed out connection mappings at
  // middleboxes will either lead to:
  // a) Middleboxes sending TCP RSTs. It's up to higher layers to check for this
  // and retry. The HTTP network transaction code does this.
  // b) Middleboxes just drop the unrecognized TCP packet. This leads to the TCP
  // stack retransmitting packets per TCP stack retransmission timeouts, which
  // are very high (on the order of seconds). Given the number of
  // retransmissions required before killing the connection, this can lead to
  // tens of seconds or even minutes of delay, depending on OS.
#if !BUILDFLAG(IS_ANDROID) && !BUILDFLAG(IS_IOS)