Tomcat应用报redis超时的故事
业务背景介绍
系统架构是通过分布式的方式进行部署的,登录的时候不会调用redis数据,假如用户登录成功了,会跳转到其它的项目上,并根据从redis中查到的权限缓存,像是相应的数据模块
问题排查
问题君发飙最初手段
问题一:用户登录失败,系统巨卡无比
问题二:Tomcat抛出 connect timed out错误
2016-09-24 16:44:24,397 - [ERROR] [RedisClient]:269- java.net.SocketTimeoutException: connect timed out
redis.clients.jedis.exceptions.JedisConnectionException: java.net.SocketTimeoutException: connect timed outat redis.clients.jedis.Connection.connect(Connection.java:134)at redis.clients.jedis.BinaryClient.connect(BinaryClient.java:69)at redis.clients.jedis.Connection.sendCommand(Connection.java:79)at redis.clients.jedis.BinaryClient.exists(BinaryClient.java:99)at redis.clients.jedis.Client.exists(Client.java:29)at redis.clients.jedis.Jedis.exists(Jedis.java:92)at redis.clients.jedis.ShardedJedis.exists(ShardedJedis.java:48)at com.tools.common.redis.client.RedisClient.exists(RedisClient.java:267)at com.group.erp.rpc.dubbo.service.impl.ActionRpcServiceImpl.getActionList(ActionRpcServiceImpl.java:23)at com.alibaba.dubbo.common.bytecode.Wrapper1.invokeMethod(Wrapper1.java)at com.alibaba.dubbo.rpc.proxy.javassist.JavassistProxyFactory$1.doInvoke(JavassistProxyFactory.java:46)at com.alibaba.dubbo.rpc.proxy.AbstractProxyInvoker.invoke(AbstractProxyInvoker.java:72)at com.alibaba.dubbo.rpc.filter.ExceptionFilter.invoke(ExceptionFilter.java:55)at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91)at com.alibaba.dubbo.rpc.filter.ClassLoaderFilter.invoke(ClassLoaderFilter.java:38)at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91)at com.alibaba.dubbo.rpc.filter.EchoFilter.invoke(EchoFilter.java:38)at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91)at com.alibaba.dubbo.monitor.support.MonitorFilter.invoke(MonitorFilter.java:73)at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91)at com.alibaba.dubbo.rpc.filter.GenericFilter.invoke(GenericFilter.java:68)at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91)at com.alibaba.dubbo.rpc.filter.TimeoutFilter.invoke(TimeoutFilter.java:42)at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91)at com.alibaba.dubbo.rpc.protocol.dubbo.filter.TraceFilter.invoke(TraceFilter.java:78)at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91)at com.alibaba.dubbo.rpc.filter.ContextFilter.invoke(ContextFilter.java:60)at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91)at com.alibaba.dubbo.rpc.protocol.dubbo.DubboProtocol$1.reply(DubboProtocol.java:108)at com.alibaba.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.handleRequest(HeaderExchangeHandler.java:84)at com.alibaba.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.received(HeaderExchangeHandler.java:170)at com.alibaba.dubbo.remoting.transport.dispather.ChannelEventRunnable.run(ChannelEventRunnable.java:78)at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)at java.lang.Thread.run(Thread.java:745)
Caused by: java.net.SocketTimeoutException: connect timed outat java.net.PlainSocketImpl.socketConnect(Native Method)at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)at java.net.Socket.connect(Socket.java:589)at redis.clients.jedis.Connection.connect(Connection.java:129)... 34 more
按照常规思路进行排查
查找问题君之网卡流量状况
:sar -n DEV 1
09时00分30秒 IFACE rxpck/s txpck/s rxkB/s txkB/s rxcmp/s txcmp/s rxmcst/s 09时00分31秒 lo 0.00 0.00 0.00 0.00 0.00 0.00 0.00 09时00分31秒 eth1 873.74 257.58 66.75 49.75 0.00 0.00 0.00
查找问题君之CPU状况
:top
[root@ZWCLC6X-10939 ~]# top top - 08:58:52 up 1 day, 15:05, 1 user, load average: 0.00, 0.00, 0.00 Tasks: 187 total, 1 running, 186 sleeping, 0 stopped, 0 zombie Cpu(s): 0.2%us, 0.2%sy, 0.0%ni, 98.7%id, 0.1%wa, 0.3%hi, 0.5%si, 0.0%st Mem: 16333752k total, 12914752k used, 3419000k free, 286716k buffers Swap: 1048572k total, 0k used, 1048572k free, 1013568k cached
查找问题君之内存状况
:free -m
total used free shared buffers cached Mem: 15950 14612 1338 0 279 990 -/+ buffers/cache: 11342 4608 Swap: 1023 997 26
这里发现了一个问题,服务器的内存资源居高不下,暂且不考虑服务器资源的正常与否
查找问题君之可疑进程状况
ps -ef 显示系统进程
这里不方便把服务器开启了那些进程罗列到此处,还请见谅;最后的分析结果就是,并无异常进程
这就奇怪了,到底是哪的问题呢?继续查找
查找问题君之生产环境应用
生产环境有两个java项目都调用了这个服务器的redis服务,然后找到了这两个项目分别查看日志,几乎在相同时间都抛出了Time out的错误,因此断定应该是redis单方面的问题
查找问题君之生产环境redis服务
查看了redis日志,并没有什么报错请求
[1008] 24 Sep 17:17:20.378 - Accepted XX.XX.XX.XX:40688
[1008] 24 Sep 17:17:20.394 - Accepted XX.XX.XX.XX:40691
[1008] 24 Sep 17:17:20.470 - Accepted XX.XX.XX.XX:40692
[1008] 24 Sep 17:17:20.470 - Accepted XX.XX.XX.XX:40693
[1008] 24 Sep 17:17:20.484 - Accepted XX.XX.XX.XX:55622
[1008] 24 Sep 17:17:20.486 - Accepted XX.XX.XX.XX:40697
[1008] 24 Sep 17:17:20.488 - Accepted XX.XX.XX.XX:55624
查找问题君之redis压力测试
使用redis-benchmark测试了redis的压力,也没有什么问题。
查找问题君之redis慢查询
怀疑是有慢查询 连接数不够用 等待了 导致超时了
有这么几个命令:
./redis-cli -h 127.0.0.1 -p 6378 # 这个是连接上本机的6378的redis
auth password #如果redis设置的有密码,使用auth进行密码验证
CONFIG GET slowlog-log-slower-than #(10000us,Redis中的执行单位是微秒,相当于10ms)
CONFIG GET slowlog-max-len (最多存储128条慢日志,应该是默认的吧?)
SLOWLOG LEN #查看redis存储的慢查询记录,默认查看128条
SLOWLOG GET # 查看redis存储的慢查询记录,默认10条
6) 1) (integer) 1662) (integer) 14749625583) (integer) 55972 # 这个是慢查询时间,微秒级别的,1秒=1000毫秒,1毫秒=1000微妙4) 1) "SETEX"2) "company_info_nan857920"3) "7200"4) "\x1f\x8b\b\x00\x00\x00\x00\x00\x00\x00\xedUKo\x1bU\x14\xbeq\xc8\xbb\r\xa1\b!\x16\x85\x05\xe2)a\xc7\x8dJ\x12uG\xca\xc2\xe0V\x15)\x0b\x96S\xcf\x8d3\xc5\x9e\x99\xcc\\'\x0e\x0b\xd4\xb4u\x1c'N\x9d\x904\xad\x1b\xf7\x11\xd5\xa1\t4N+L\xe2\xfa\xd1JH\xac\xf9\x0b\x88\xce\xb5g\x16(K\xb6\x9c\xeby\xd8A\xb0cYK\x1e\x9f\xf3\x9d\xef<\xee9g\xae\x1f\xfe\x89\xdaT\x05\xbd\x17\x90\xc2n\x95\x9fvGT... (1218 more
从上面可以看出一个满查询在55毫秒左右,项目的配置文件在10秒左右,所以不存在超时的问题
查找问题君之redis内存
怀疑redis的内存用到上线,因此查看了redis的配置
maxmonery # 我的配置文件没有设置,默认是不限制内存
查找问题君之redis内存使用状况
#./redis-cli -h 127.0.0.1 -p 6378 # 这个是连接上本机的6378的redis
> info # 查看redis信息
#Server
XXXXXXXXXXXX
#Clients
XXXXXXXXXXXX
#Memory
used_memory:28507480
used_memory_human:27.19M
used_memory_rss:51208192
used_memory_peak:51844256
used_memory_peak_human:49.44M
used_memory_lua:33792
mem_fragmentation_ratio:1.80
mem_allocator:libc
#Persistence
XXXXXXXXXX
#Stats
XXXXXXXXXX
#Replication
XXXXXXXXXX
#CPU
XXXXXXXXXX
#Keyspace
XXXXXXXXXX
介绍Memory的参数信息:
查看了redis使用内存很小,才使用了27.19M,排除了redis的内存使用情况
查找问题君之初步定型问题
使用了speedtest-cli 命令测试了本机的网速情况
speedtest-cli命令介绍:
参考:http://www.linuxde.net/2014/01/15561.html
$ wget https://raw.github.com/sivel/speedtest-cli/master/speedtest_cli.py
$ chmod a+rx speedtest_cli.py
$ sudo mv speedtest_cli.py /usr/local/bin/speedtest-cli
$ sudo chown root:root /usr/local/bin/speedtest-cli
测试结果:
使用这个命令查看本机网络,貌似有问题,于是那了两台机器之间互传了一个较大的文件,查看了速度,经测试速度在5MB-6MB左右,因此排除了网络问题】
查找问题君之数据持久化导
开始认为是持久化导致的磁盘IO飙升问题,于是更改持久化策略
先说一下持久化分为两种方式,第一种为AOF,第二种为save的方式,格式大概为
方式一:
################################ 快照 #################################
#
# 把数据库存到磁盘上:
#
# save <seconds> <changes>
#
# 会在指定秒数和数据变化次数之后把数据库写到磁盘上。
#
# 下面的例子将会进行把数据写入磁盘的操作:
# 900秒(15分钟)之后,且至少1次变更
# 300秒(5分钟)之后,且至少10次变更
# 60秒之后,且至少10000次变更
#
# 注意:你要想不写磁盘的话就把所有 "save" 设置注释掉就行了。
#save 900 1
#save 300 10
#save 60 10000
方式二:
############################## 纯累加模式 ###############################
# 默认情况下,Redis是异步的把数据导出到磁盘上。这种情况下,当Redis挂掉的时候,最新的数据就丢了。
# 如果不希望丢掉任何一条数据的话就该用纯累加模式:一旦开启这个模式,Redis会把每次写入的数据在接收后都写入 appendonly.aof 文件。
# 每次启动时Redis都会把这个文件的数据读入内存里。
#
# 注意,异步导出的数据库文件和纯累加文件可以并存(你得把上面所有"save"设置都注释掉,关掉导出机制)。
# 如果纯累加模式开启了,那么Redis会在启动时载入日志文件而忽略导出的 dump.rdb 文件。
#
# 重要:查看 BGREWRITEAOF 来了解当累加日志文件太大了之后,怎么在后台重新处理这个日志文件。appendonly yes
# 纯累加文件名字(默认:"appendonly.aof")
# appendfilename appendonly.aofappendfilename "appendonly.aof"
# fsync() 请求操作系统马上把数据写到磁盘上,不要再等了。
# 有些操作系统会真的把数据马上刷到磁盘上;有些则要磨蹭一下,但是会尽快去做。
#
# Redis支持三种不同的模式:
#
# no:不要立刻刷,只有在操作系统需要刷的时候再刷。比较快。
# always:每次写操作都立刻写入到aof文件。慢,但是最安全。
# everysec:每秒写一次。折衷方案。
#
# 默认的 "everysec" 通常来说能在速度和数据安全性之间取得比较好的平衡。
# 如果你真的理解了这个意味着什么,那么设置"no"可以获得更好的性能表现(如果丢数据的话,则只能拿到一个不是很新的快照);
# 或者相反的,你选择 "always" 来牺牲速度确保数据安全、完整。
#
# 如果拿不准,就用 "everysec"
# appendfsync always
appendfsync everysec
# appendfsync no
# 如果AOF的同步策略设置成 "always" 或者 "everysec",那么后台的存储进程(后台存储或写入AOF日志)会产生很多磁盘I/O开销。
# 某些Linux的配置下会使Redis因为 fsync() 而阻塞很久。
# 注意,目前对这个情况还没有完美修正,甚至不同线程的 fsync() 会阻塞我们的 write(2) 请求。
#
# 为了缓解这个问题,可以用下面这个选项。它可以在 BGSAVE 或 BGREWRITEAOF 处理时阻止 fsync()。
#
# 这就意味着如果有子进程在进行保存操作,那么Redis就处于"不可同步"的状态。
# 这实际上是说,在最差的情况下可能会丢掉30秒钟的日志数据。(默认Linux设定)
#
# 如果你有延迟的问题那就把这个设为 "yes",否则就保持 "no",这是保存持久数据的最安全的方式。no-appendfsync-on-rewrite yes
# 自动重写AOF文件
#
# 如果AOF日志文件大到指定百分比,Redis能够通过 BGREWRITEAOF 自动重写AOF日志文件。
#
# 工作原理:Redis记住上次重写时AOF日志的大小(或者重启后没有写操作的话,那就直接用此时的AOF文件),
# 基准尺寸和当前尺寸做比较。如果当前尺寸超过指定比例,就会触发重写操作。
#
# 你还需要指定被重写日志的最小尺寸,这样避免了达到约定百分比但尺寸仍然很小的情况还要重写。
#
# 指定百分比为0会禁用AOF自动重写特性。
auto-aof-rewrite-percentage 100
auto-aof-rewrite-min-size 64mb
# lua
lua-time-limit 5000
注掉了从的持久化,主注掉save模式,开启AOF模式,可是io高的问题依旧没有解决,于是乎就有了下文
查找问题君之磁盘IO状况
Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util
sdb 0.00 59.00 574.00 99.00 21272.00 1272.00 33.50 6.02 9.01 1.34 89.90
sda 0.00 0.00 0.00 3.00 0.00 24.00 8.00 0.00 0.00 0.00 0.00
dm-0 0.00 0.00 568.00 158.00 21080.00 1272.00 30.79 6.04 8.38 1.24 89.90
看到这个界面,好像找到了点头绪,服务器的磁盘IO较高,但是小编这里也提出了疑问,redis的数据全部存放到了sdb银盘上,而且redis的程序也都是在sdb上面,那为什么服务器的sda的
IO资源占用如此之高呢?
顺藤摸瓜>>>就从高IO的线索查找问题根源:
检查是什么进程占用了如此高系统盘IO?
iotop
iotop执行命令结果,发现一个占用资源特别高的进程
检查发现,这个进程存在的作用是,当系统的物理内存耗尽时候,系统会激活此进程,以来调用swap分区。
这下有点明白其中的道道了,问题原因大概如下:
检查都有那些系统应用占用了swap分区,编写脚本:
#!/bin/bash
###############################################################################
# 日期 : 2016-09-27
# 作者 : sean
# Email : linux_no1@126.com
# 版本 : 1.0
# 脚本功能 : 列出正在占用swap的进程。
###############################################################################
echo -e "PID\t\tSwap\t\tProc_Name"for pid in `ls -l /proc | grep ^d | awk '{ print $9 }'| grep -v [^0-9]`
# /proc目录下所有以数字为名的目录(进程名是数字才是进程,其他如sys,net等存放的是其他信息)doif [ $pid -eq 1 ];then continue;fi # Do not check init process# 让进程释放swap的方法只有一个:就是重启该进程。或者等其自动释放。# 如果进程会自动释放,那么我们就不会写脚本来找他了,找他都是因为他没有自动释放。# 所以我们要列出占用swap并需要重启的进程,但是init这个进程是系统里所有进程的祖先进程# 重启init进程意味着重启系统,这是万万不可以的,所以就不必检测他了,以免对系统造成影响。grep -q "Swap" /proc/$pid/smaps 2>/dev/null #检查是否占用swap分区if [ $? -eq 0 ];then swap=$(awk '/Swap/{ sum+=$2;} END{ print sum }' /proc/$pid/smaps) #统计占用的swap分区的大小 单位是KB proc_name=$(ps aux | grep -w "$pid" | awk '!/grep/{ for(i=11;i<=NF;i++){ printf("%s ",$i); }}') #取出进程的名字if [ $swap -gt 0 ];then #判断是否占用swap,只有占用才会输出echo -e "$pid\t${swap}\t$proc_name"fifidone | sort -k2 -n | awk -F'\t' '{ if($2<1024)printf("%-10s\t%15sKB\t%s\n",$1,$2,$3);else if($2<1048576)printf("%-10s\t%15.2fMB\t%s\n",$1,$2/1024,$3);elseprintf("%-10s\t%15.2fGB\t%s\n",$1,$2/1048576,$3);}'
执行结果,发现
redis的进程全部存放在了swap分区中,果然是这样。
修改内核参数,合理分配内存使用
A.释放物理内存,并且叫新应用获取物理内存。
参考地址:http://www.cnblogs.com/minideas/p/3796505.html
1.在释放内存之前,检查可用内存多少
free -m
输出结果略
2.手动释放内存
echo 1 > /proc/sys/vm/drop_caches
3.释放完成后,检查可用内存是否进行了释放
free -m
输出结果略
经过上述的三个命令,发现内存确实进行了释放。
4.重启redis服务
5.检查swap分区使用
重启了redis发现内存走的依旧是swap分区,物理内存还有很多可用内存,但是系统为什么分给应用swap分区呢?
B.修改系统内核参数,叫所有的应用尽量使用物理内存,避免使用swap分区。
参考地址:http://davidbj.blog.51cto.com/4159484/1172879/
仔细看,物理内存还有将近1GB没有使用。但是swap已经开始被使用。怀疑是不是swappiness文件的值没有更改。
说明:在centos里面,swappiness的值的大小对如何使用swap分区是有着很大的联系的。swappiness=0的时候表示最大限度使用物理内存,然后才是 swap空间,swappiness=100的时候表示积极的使用swap分区,并且把内存上的数据及时的搬运到swap空间里面。两个极端,对于Centos的默认设置,这个值等于60,建议修改为10。具体这样做:
sysctl vm.swappiness=10 但是这只是临时的修改,如果系统重启会恢复默认的值60,所有还需要做下一步: echo vm.swappiness=10 >> /etc/sysctl.conf
这样就可以了。
最后重新加载swap虚拟内存:
swapoff -a //关闭虚拟内存
swapon -a //开启虚拟内存
但是上面操作后,重启了redis应用,系统依旧分给了redis swap分区。
C. 最后重启服务器,并再次启动redis服务,最后问题得到了解决。swap分区为0了
Tomcat应用报redis超时的故事相关推荐
- 所有的service报红但不报错_从一个应用报错来看centos系统的/tmp目录自动清理规则...
概述 分享最近应用碰到的一个奇怪bug,一开始以为是代码上的问题,找了一段时间发现居然是因为系统的一个自动清理规则导致,下面一起来看看吧~ 一.应用报错: logwire.core.exception ...
- electron + vue /打包linux应用报错记录
1. electron + vue 打包linux应用报错记录 > icon图标导致的报错 ⨯ unknown output format set github.com/develar/app ...
- sanic学习踩坑记录:第一坑——sanic_jinja2应用报错ModuleNotFoundError: No module named ‘AppName‘
刚开始学习使用sanic,发现有一些坑,随手记录一下:以供后来者共同学习,避免踩坑: # 使用的软件版本 python 3.8.10 sanic 21.9.3 sanic-jinja2 0.10.0 ...
- Win7执行应用报CLR20r3错误处理记录
Windows7环境下运行应用报"CLR20r3"错误,错误信息如下: 问题详细信息: 问题签名:问题事件名称: CLR20r3问题签名 01: qbbtools.exe问题签名 ...
- tomcat服务器接口响应超时,Tomcat请求超时
如果您试图阻止请求运行太长时间,那么在Tomcat中设置超时将无济于事.正如克里斯所说,您可以为Tomcat设置全局超时值.但是,从" Apache Tomcat连接器-通用方法超时&quo ...
- tomcat发布应用报错Error starting child
使用tomcat发布应用程序是报错: SEVERE [main] org.apache.catalina.startup.HostConfig.deployDirectory Error deploy ...
- nginx配置ssl后访问部署在tomcat上的应用报304,504错误
我的ssl证书配置在ng上面,后台的应用在tomcat上面,访问应用的时候,报304,504错误 通过下面的方式,问题得以处理,需要在tomcat的server.xml里面添加加上圈红处
- SSM+nginx+tomcat+maven+mysql+redis环境搭建及工程全套配置,实现前后端动静分离
目录 前言 服务器环境搭建 windows开发环境 SSM搭建 加入redis(注解形式) nginx与tomcat关联配置,完成前后端连接 前言 本次采用前后端分离模式,前端以html.css.js ...
- 在Apache Tomcat 7设置redis作为session store
2019独角兽企业重金招聘Python工程师标准>>> redis已经有组件支持直接在tomcat7中设置下将redis作为tomcat默认的session存储器,下面介绍下配置过程 ...
最新文章
- debian安装python3_debian上安装python3.6
- 经典C语言程序100例之九一
- 【CKEditor】上传图片接口接收不到CKEditorFuncNum参数
- 为什么程序员发现不了自己的BUG
- ASP.NET Core中使用GraphQL - 第一章 Hello World
- 针对新手的Java EE7和Maven项目–第8部分
- 【Tensorflow】打印输出tensor张量和变量的方法
- CCNA2.0笔记_ACL
- 前端项目,将package.json数据放到项目某处使用
- sql server根据表中数据生成insert语句
- tensorflow随笔——简单的卷积神经网络分类实例
- Maven压缩插件YUI Compressor使用介绍
- CImage 载入缓存区图像数据
- 基于AP6212实现 Airkiss NDK编程
- 1534 棋子游戏(博弈论)
- 介绍一个牛人的机器学习PPT
- 计算机里pc是什么,什么是pc?pc是什么意思?
- 天文观测理论——已知像素大小、焦距,求像素分辨率
- uoj problem 11 ydc的大树
- vuerouter4报错:Discarded invalid param(s) “name“, “age“ when navigating.