最近一个新版本发布后,部分用户反馈收银速度慢了很多,平时只需两三秒的扫码付款,现在需要几分钟甚至更久
我们回顾整个版本改动,发现只是在原有基础上添加了网络监测功能,收银模块并无改动
排查日志时发现了,以下异常情况:
- 异常一:收银操作设置的超时时间为最长40秒,但是日志显示有超过一分钟的收银记录
- 异常二:网络监测模块明明设置了超时时间,但发现了最久达900秒的记录
网络后台监测功能的设计是这样的:每一分钟发起三个异步请求,根据收到响应的时间和结果,产生一个网络状态结果,根据该结果,保存日志帮我们鉴别客户端网络情况
初看代码貌似没有问题,但是细看发现,网络监测请求的连接超时时间为5000,读写超时时间为10000,外层调用没有传入时间单位,而内部则使用秒作为时间单位,所以超时时间就由预期的10秒变成了10000秒。。。好吧,异常二的原因找到了,那么,异常一呢?
首先由于超时时间的问题,就导致了在本异步场景中,被观察者发送事件速度(每分钟3次)远快于观察者的处理速度(最大10000秒一次),这是RxJava中背压的概念,那么当okhttp遇到了这种情况是怎么应对的呢?
首先okhttp会将请求加入到一个准备进行的异步任务队列中readyAsyncCalls,然后执行promoteAndExecute()方法
该方法判断正在运行的任务是否达到限制,是否存在准备中的任务,将准备中的异步任务移入到运行中的任务集合,直到运行中的任务达到上限或没有待执行的任务。
重点看maxRequests和maxRequestsPerHost
maxRequests很好理解,如果运行中的任务已经达到最大限制(64)个,则不再添加任务
maxRequestsPerHost的判断,内部则是遍历运行状态的异步任务,计算host相同的元素个数,如果大于5,则不再添加新任务
那么结合异常一来分析,假设用户网络环境较差,网络监测的发起速度快于该请求的返回响应速度,将会导致大量请求积累在异步请求队列(readyAsyncCalls)中,新进入的收银请求必须等待网络监测请求处理完毕才能被处理,即会出现异常一所描述的问题,收银请求速度慢,设置的超时时间和实际请求超时时间不匹配的问题
针对该问题的复盘:
一、后台网络监测任务优先级应低于前台网络请求,不能阻碍前台用户操作
二、后台网络任务和前台网络任务使用同一个okhttp时,在网络较差的情况下可能导致新发起的网络请求排在队列最末端,久久得不到执行
三、对异步场景中,被观察者发送事件速度远快于观察者的处理速度的情况,应尽早考虑使用支持背压策略的rxjava
四、在做网络模块封装时,不应过度封装,把时间单位也封装进去,造成调用者传入错误的值