最近在项目中使用了redis结合spring cache一起作了一个缓存,并使用了订阅功能来达到进程间的数据同步。但在测试使用过程中,发现第二天一来,本来应该工作的订阅同步并不能进行。当时没在意,简单重启了事。但后来发现,每天早上相应的同步都不能进行,并且经测试。每个进程的同步都不进行,感觉是redis的订阅出问题了。
1. 验证问题
表现出来就是A程序修改了数据,B程序并没有识别到这次更新。那么就先尝试手动在redis中进行相应的set操作,因为订阅的是redis的空间事件,即key space event. 在控制台单独连接redis,执行相应的set 命令,在B程序中并没有任何表示。
怀疑是不是redis的发布订阅出问题了,就另开终端,手动地进行订阅,一切正常。
初步确定是程序出问题了。
2. 查看程序
把进程的stack打印一份,查看里面的线程信息,发现并没有redisson的线程信息。一般来说,没收到消息也可能是线程内阻塞了,但是直接就没有相应的线程,这就有问题了。
怀疑是不是相应的连接被断开之后就没有再连,也可能是redis server被重启了。
重新连接redis,使用status查看相应的状态,显示server端并没有重启过,其运行时间长达X天,即没有间断过。
回过来再看相应的redisson程序,里面有一个watch dog,是负责连接断开重连的。即如果连接被断掉了,它会尝试重连,但每一次的重连都会迟后一定时间,如 1 2 4 8 秒这样。这也是为什么要看stack的原因。简单看了下watchdog的实现,表示并没有明显的问题(或者就没问题)。
进一步怀疑是不是出现了某个异常,导致相应的watchdog重连直接被中断了。比如Error级错误。将相应的日志拉下来一份,因为一晚上都没人操作,日志信息本身也很少。直接在里面使用grep Exception查找日志信息,但一切也很正常,甚至没有异常发生。
再重新查看了redisson的源码,里面使用netty的channelInActive来进行重连尝试。在本地测试了一下这个机制,redis重启或者断开连接,它都能检测到。开始怀疑是不是日志信息不全,被吞掉了。重新调整日志级别,将redisson和netty的级别调到TRACE级别,结果中午过去一会,再回来看。相应的连接又不见了,订阅又不能正常工作。查看了日志,里面也没有任何信息,因为这期间无任何操作。