负载均衡策略问题导致服务宕机(记一次生产问题)

tags : 避坑指南


一.问题

2019年12月4日上午11点左右收到线上报警,核心服务CPU使用率达到了3000%,看了下进程的线程信息都是active。因为使用的容器是weblogic,所以在console平台查看线程相关信息。
信息整理如下:

  • 活动线程43个,队列的长度已经到了23个
  • 数据库连接为不可用连接数为5,活动连接数为5,可用连接数为15
  • 线程池 线程空闲指标大部分都是false(暂时不可用)
  • 查看线程池 不可用连接执行操作为请求CAS或者或者请求portal
  • 查看转储线程堆栈,部分异常信息如下:
"[ACTIVE] ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)'" id=34 idx=0xec tid=23897 prio=5 alive, native_blocked, daemon
at java/util/HashMap.put(HashMap.java:468)[optimized]
at org/jasig/cas/client/session/HashMapBackedSessionMappingStorage.addSessionById(HashMapBackedSessionMappingStorage.java:36)[optimized]
at org/jasig/cas/client/session/SingleSignOutFilter.doFilter(SingleSignOutFilter.java:95)[optimized]
at weblogic/servlet/internal/FilterChainImpl.doFilter(FilterChainImpl.java:56)[optimized]
at com/isoftstone/iaeap/web/filter/SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:105)[optimized]
at weblogic/servlet/internal/FilterChainImpl.doFilter(FilterChainImpl.java:56)[inlined]
at weblogic/servlet/internal/WebAppServletContext$ServletInvocationAction.wrapRun(WebAppServletContext.java:3730)[inlined]
at weblogic/servlet/internal/WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3696)[optimized]
at weblogic/security/acl/internal/AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)[optimized]
at weblogic/security/service/SecurityManager.runAs(SecurityManager.java:120)[inlined]
at weblogic/servlet/internal/WebAppServletContext.securedExecute(WebAppServletContext.java:2273)[inlined]
at weblogic/servlet/internal/WebAppServletContext.execute(WebAppServletContext.java:2179)[optimized]
at weblogic/servlet/internal/ServletRequestImpl.run(ServletRequestImpl.java:1490)[optimized]
at weblogic/work/ExecuteThread.execute(ExecuteThread.java:256)[optimized]
at weblogic/work/ExecuteThread.run(ExecuteThread.java:221)
at jrockit/vm/RNI.c2java(JJJJJ)V(Native Method)
-- end of trace
"GC Daemon" id=35 idx=0xf0 tid=23903 prio=2 alive, waiting, native_blocked, daemon
-- Waiting for notification on: sun/misc/GC$LatencyLock@0x51155130[fat lock]
at jrockit/vm/Threads.waitForNotifySignal(JLjava/lang/Object;)Z(Native Method)
at java/lang/Object.wait(J)V(Native Method)
at sun/misc/GC$Daemon.run(GC.java:100)
^-- Lock released while waiting: sun/misc/GC$LatencyLock@0x51155130[fat lock]
at jrockit/vm/RNI.c2java(JJJJJ)V(Native Method)
-- end of trace

此时发现熟悉的身影,因为项目引用的是cas-client3.1.3版本的jar包,其中存储session的数据结构是HashMap,且操作时未进行加锁,之前别的核心的小伙伴已经因为多线程环境下触发HashMap扩容死循环问题的BUG宕机过一次,此时看到这里立马确认CPU飙升罪魁祸首是这个jar包。

经过确认,核心一共9台服务器,其中4台为前端应用服务,CPU飙升的服务器正是这4台。

2.曲折

当有了一把锤子看什么都是钉子,因为此时心中已经认定是jar导致问题,所以看着服务器的各种异像都觉得符合逻辑。只是心中有些纳闷为何jar包问题这么久了都没有触发HashMap扩容死循环的bug,怎么单单就这次服务重启不过几十分钟CPU就又直线飙升。
在服务器刚重启完的时候此时收到一个信息,有出单员页面部分资源打不开了。开了network跟了下发现部分资源返回404,页面间不涉及到数据加载的页面跳转无异,但是点击查询时页面就会卡死,而此时该进程的CPU也会上升。这个时候就有点诡异,之前的猜测跟目前情形好像并无关联。
到了中午使用的人数少了一些抱着病急乱投医,总得做点什么的心态,将jar包更新到3.5升级了上去,经过了几个小时CPU仍然状态稳定,心中长舒了一口气。
好景不长,没过多久又有出单员反馈页面卡死问题,此时看了一下线程吓了一跳,多个线程触发GC,后台日志多处报错提示OOM。赶紧看了下源码,发现原来jar包中有一个守护线程来定时触发删除过期的session,而新的jar包去除了此方法,而留了一个clean的方法清理session。猜测到可能是因为没有显式调用该方法导致的内存泄漏,并且并没有解决前端资源丢失加载不出页面,还是紧急将jar包替换了回来,重新查找原因。

3.整理线索

3.1

重新梳理了下系统的日志,发现了除了正常的业务流程异常外还有一个异常信息比较可疑。

<2019-12-5 下午023541秒 CST> <Error> <HTTP> <BEA-101020> <[ServletContext@199457131[app:pcisv7 module:WebRoot path:/pcisv7 spec-version:2.5]] Servlet failed with Exception
java.lang.NullPointerException
	at jsp_servlet._core.__header._jspService(__header.java:295)
	at weblogic.servlet.jsp.JspBase.service(JspBase.java:34)
	at weblogic.servlet.internal.StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:227)
	at weblogic.servlet.internal.StubSecurityHelper.invokeServlet(StubSecurityHelper.java:125)
	at weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:301)
	Truncated. see log file for complete stacktrace
> 

找到了weblogic缓存目录下的文件和测试环境文件比对了下也并没有区别,此文件也没有涉及过开发改动。查看了下源码,找到了一处可能发生空指针的地方:

<%
 IUserDetails userDetails = CurrentUser.getUser();
 String operCnm = userDetails.getOpCnm();
 String companyCnm = userDetails.getCompanyCnm();
 long start = System.currentTimeMillis();
 GrtRightService grtRightService =(GrtRightService)SpringUtils.getSpringBean("grtRightService");
 List<GrtMenuVO> lstMenuVo=null;
 try{
   lstMenuVo = grtRightService.getPermissionRootMenus();
   if(lstMenuVo ==null || lstMenuVo.size()==0){
	   out.println("<script type='text/javascript'>parent.window.location ='./common/error/errorinfo.html';</script>");
	   return;
   }
 }catch(Exception e){
   e.printStackTrace();
 }
  String skin = (String)request.getSession().getAttribute("ISOFTSTONESKIN");
  String rootPath = request.getContextPath();
  String companyId = userDetails.getCompanyId();
  String[] companyIds =userDetails.getCompanyIds();
  String[] companyCnms =userDetails.getCompanyCnms();
%>

17行的skin 中是从session中取值,如果session没有set此处使用会产生空指针,从而导致页面部分资源加载不出来。向上查了一下代码,在session中存放ISOFTSTONESKIN的地方是登陆首页时存放,跳转到目标页面后获取的。查看了下源码ISOFTSTONESKIN的值也是设置的默认值,当时考虑了下并没有考虑到什么场景会导致session中的ISOFTSTONESKIN失效,就在代码中对该变量重新赋值了下。(其实在这个场景时就已经初步能看出来一些问题,既session丢失问题)

3.2

因为考虑到是因为CAS登陆导致的使用cas-client jar包产生的CPU使用率问题,考虑了下,决定先将核心模块从cas登陆中拿出,启用spring security验证登陆。
applicationContext.xml

<import resource="applicationContext-spring-security.xml"/>
<!-- <import resource="applicationContext-spring-security-cas-ns.xml"/> 启用单点登录时使用些配置文件-->

重新启动后,CPU使用率正常,header等几个从session取值的页面因为设置了默认值,也暂时没有出现空指针问题。但是出现了使用不到几分钟,就会跳转到登陆页面,提示重新登陆。(操作的页面没有嵌入别的系统页面,不存在跨系统登陆问题)
看了眼核心session失效时间
web.xml

<session-config>
	<session-timeout>300</session-timeout>
</session-config>

顺便看了下CAS的 Ticket超时时间
ticketExpirationPolicies.xml

<bean id="grantingTicketExpirationPolicy" class="org.jasig.cas.ticket.support.TimeoutExpirationPolicy">
    <constructor-arg index="0"  value="7200000" />
</bean>

CAS的session超时时间
web.xml

<session-config>
	<session-timeout>300</session-timeout>
</session-config>

核心系统客户端的session失效时间设置的半小时,cas的session失效时间是半小时,ticket的票据失效时间是两小时。移除了CAS的认证后半小时内操作是不会登出的,但是实际场景操作过程中就出现跳转到登陆页面的情况。(session方面的问题愈发明显,但是急于将问题解决,与真相一次次擦肩而过)

3.3

此时怀疑是网络负载方面的问题,因为系统切换了IPV6考虑到会产生的影响,决定将核心系统加入CAS验证,并且前端节点只开一个处理请求,进行观察。(因负责网络的同事当时不在,只是初步怀疑是IPV6的影响,后续经过确认只改造了公司官网,其余系统并未改造。)
开单节点运行了一上午发现CPU稳定,页面加载也再没有出现加载异常,开双节点时就会出现加载异常的情况。由此找到问题原因是负载均衡将客户端X请求转发到某台实例A的时候,由于未知原因将网络请求转发至另一服务器B。导致本应该存在于session的值直接访问另一台服务器时该值并不存在,因为客户端浏览器未关闭的原因,ticket会存在于header头中,转发请求至新的服务时,校验并没有登陆便会去CAS认证一次,但是并不会要求用户重新登陆。
负载是由citrix进行硬件方面的负载,它与Nginx软件负载功能类似,只是功能更加强劲,其中大部分的负载策略是一致的。查看了下负载策略使用的是least_conn最小连接数,会话保持时间为两分钟。该策略使用了很长时间都没有问题,考虑到使用iphash会导致服务分部不均,所以未做改动,仅将连接的会话时间修改为了30分钟,同session过期时间保持同步。(会话时间既将用户请求负载至某一IP,若在会话时间内如果有操作,则会话保持,若没有操作则会话断开,重新请求时将重新对其进行转发)

4.问题总结

至此问题已经找到了,对于其中相关问题进行分析梳理。

  1. 因为执行某些操作或者在页面中静止导致两分钟内没有与后台进行交互,再次操作时因为citrix使用最小连接数的策略会将新的请求负载至另一台服务器。
  2. 该服务器取出sessionID校验是否通过了登陆验证,浏览器Cookie中并没有缓存该台服务器的sessionID,验证失败,此时重定向请求至CAS服务,因CAS服务只有单台并且该浏览器已经通过了认证,此时访问通过Cookie直接认证通过,跳转到了目标页面。(此时还存在一个场景就是CAS的session也过期了,跳转到单点登录地址,带着ticket参数去验证用户,如果单点登录验证到ticket没过期,就不会去登录页面,但是会刷新当前页,因为从单点登录地址重定向到了当前页面地址。所以使用时的感觉就是长时间不操作时,点击页面元素会出现刷新页面的情况。)
  3. 因为在登陆页面中缓存在session中的一些默认值,重新登陆后直接跳转到了目标页面所以并没有缓存,jsp此时加载时就产生了资源丢失,后台报错空指针的情况。
  4. 而因为负载频繁的将请求转发,也导致出现了类似大规模登陆的场景(多次去CAS认证,认证通过将session缓存)因为CAS-Client.jar缓存使用的数据结构是HashMap,并且移除和添加缓存操作都没有加锁,导致HashMap出现扩容死循环问题。

5.浏览器访问过程

详细流程:https://4ark.me/post/b6c7c0a2.html
流程图:
[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-bNw79hB2-1577028699334)(https://ftp.bmp.ovh/imgs/2019/12/d1ecc658b38ca606.jpg)]
cas:https://www.cnblogs.com/notDog/p/5276643.html
http://www.voidcn.com/article/p-waqcmlak-bqr.html

6.内容扩展

IPV6与IPV4区别:https://blog.51cto.com/7658423/1339259

负载策略

  • 轮询策略(轮询加权/round-robin):加权轮询带有优先级,按照设置的权值分配请求比例。
  • ip hash :针对IP地址hash决定下一请求转发至哪一服务(负载不均问题,使用一致性hash)
  • 最少连接(least_conn) :下一个请求将被分派到活动连接数量最少的服务器
  • url hash
  • 随机Random
  • 最短响应时间LRT :通过ping等方式探测,请求分配给响应时间最短的服务。

虚拟IP

使用一个未分配给真实主机的IP,与真实主机IP,热备主机IP加起来一共三个IP。在以太网中IP地址只是逻辑地址,真正传输的是MAC地址,而每台设备中都有一个ARP缓存,缓存中用来存储同一网络内IP地址和MAC地址对应关系,在向其他主机发送数据时会先从缓存中查询目标IP所对应的MAC地址,拿到MAC地址后向主机发送数据。
例如缓存内容:
主机A:192.168.0.3 at ec:f4:bb:49:s4:44
主机B:192.168.0.4 at ec:f4:bb:49:s5:64
虚拟Ip:192.168.0.5 at ec:f4:bb:49:s4:44
其中A,B为真实主机,对外提供服务的是A,B为热备,如果A宕机了那么通过心跳检测到A已经发生故障,此时主机B会将自己的ARP缓存发送出去,让路由器修改路由表,告知虚拟地址由A指向B。
更新后的缓存内容:
主机A:192.168.0.3 at ec:f4:bb:49:s4:44
主机B:192.168.0.4 at ec:f4:bb:49:s5:64
虚拟Ip:192.168.0.5 at ec:f4:bb:49:s5:64
此时再次访问虚拟IP时,机器B会变成主服务器,A降级为热备服务器。这就完成了主从切换,这个过程称之为IP漂移
参考:http://xiaobaoqiu.github.io/blog/2015/04/02/xu-ni-iphe-ippiao-yi/

  • 0
    点赞
  • 0
    收藏
    觉得还不错? 一键收藏
  • 0
    评论

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值