问题描述某产品线应用[A]收到应用[B]发送给MQ的消息，经过业务逻辑处理后，得到的数据存储在数据库中。最近发现应用[A]数据库表中的某些记录的时间比应用[B]数据库表中相应记录的时间短8小时。产品线反映，此类异常数据是线上间歇性产生的。异常数据量不清楚，估计不会太多。分析过程相差整整8个小时。最有可能想到的是时区问题，但是分析问题还是要搞清楚怎么发现问题，发现问题的时间，问题前后的系统变化，量异常数据，以及影响范围（应用有问题或者本地有问题），异常数据是否有规律性，如何与相关系统进行交互等基本情况，这些是最基本也是最重要的依据判断。分析数据寻找规律[B]应用数据准确，通过比对找出[A]应用异常数据不同维度的统计信息。例如：异常数据的条数是按机构按时间（按天、按小时）统计的。根据这个统计信息，可以判断系统什么时候开始出现问题以及逐渐变化的过程（是逐渐恶化还是在某个时间突然恶化），这就是产品线应该做的事情问题发现了，可惜一直没有做；异常数据估计不小，每天上百万量级。通过异常数据中的订单ID，可以到系统中调取订单从处理开始到处理结束的所有日志（入口参数、处理过程中的参数等）。通过日志可以分析出是哪台机器出了问题。一旦确定了机器，就会更有针对性（应用有180个ECS在线）。通过日志，您也可以尝试在离线环境下通过模拟播放来重现问题。由于缺乏类似SLS的产品，目前的日志分析比较费力且效率低下，而且分析结果不够清晰，这也是本次分析问题比较遗憾的地方。为了便于系统交互流程图的表达和理解，下面仅对涉及时间的输入参数和操作进行逻辑抽象。系统交互关系查看MQ消息，发现日志中异常数据对应的MQ消息消息，timestamp字段值正确。确认时区配置操作系统时钟正常：查看应用180ECS系统时间是否同步，Linux命令：date操作系统时区正常：查看/etc/localtime正常timedatectl，发现有警告机，经数据确认，不是造成时间不一致的原因是正常的。WarningJVM时区配置正常（可用以下两种检查方式）：jinfo|grepuser.timezoneuser.timezone:PRCarthas:syspropuser.timezoneuser.timezone:PRCDRDS、RDS时区配置正常，数据库负责同学查看应用代码逻辑数据库。两个时间字段对应的类型为：datetime排除其他不相关的逻辑，时间字段的处理逻辑可以用如下代码表示：应用代码逻辑数据库表：代码审核后的表结构（没有专门的时间转换逻辑），并没有找出问题所在！这里的datetime和timestamp有比较关键的知识点，需要注意：datetime和timestamp是如何转换和存储的，例子解释如下：MySQLServer中datetime字段存储的就是取出来的【datetime示例1]：JVM为UTC+8，MySQL服务器session为UTC+0，JVM客户端原始时间为（UTC+8）：2022-10-1610:00:00MySQLJDBCDriver发送给的时间MySQL服务器为：2022-10-1602:00:00（时间由UTC+8转换为UTC+0）MySQL服务器最终存储时间：2022-10-1602:00:00JVM客户端查看时间来自数据库：2022-10-1602:00:00[datetimeexample2]:JVM是UTC+8，MySQL的initialserversession是UTC+0，MySQLJDBCDriver配置的是UTC+1，原始时间JVM客户端为（UTC+8）：2022-10-1610:00:00MySQLJDBCDriver发送给MySQL服务器的时间为：2022-10-1603:00:00（时间由UTC转换而来+8到UTC+1）MySQL服务器最终入库时间为：2022-10-1603:00:00JVM客户端从数据库中checkout的时间为：2022-10-1603:00:00由上可知可以看出datetime最后存储的时间与MySQLJDBCDriverSession配置的时区直接相关；timestamp字段存储MySQLServer中的UTC时间【时间戳示例1】：JVM为UTC+8，MySQL服务器session为UTC+0，JVM客户端原始时间为（UTC+8）：2022-10-1610:00:00MySQLJDBCDriver向MySQL服务器发送时间：2022-10-1602:00:00（时间由UTC+8转换为UTC+0）MySQL服务器最终存储的时间为：2022-10-1602:00:00(无需转换)从MySQLServer检索到服务器会话的时间为：2022-10-1602:00:00(无需转换)MySQLJDBCDriver在JVM时间中解析的时间时区为：2022-10-1610:00:00（时间由UTC+0转换为UTC+8）。另一台机器的JVM时区为UTC+9，MySQLJDBCDriver在JVM中解析时间为：2022-10-1611:00:00（时间由UTC+0转换为UTC+9）【时间戳示例2】：JVM为UTC+8，MySQL初始服务器会话为UTC+0，MySQLJDBCDriver配置为UTC+1。JVM客户端原始时间为（UTC+8）：2022-10-1610:00:00MySQLJDBCDriver发送给MySQL服务器的时间为：2022-10-1603:00:00（时间由UTC+8转换为UTC+1决定）最后存储的MySQLServertimeis:2022-10-1602:00:00(时间由UTC+1转换为UTC+0)从MySQLServer获取的serversession时间为：2022-10-1603:00:00（MySQL内部转换，由UTC+0转换为UTC+1）MySQLJDBCDriver在JVM时区解析的时间为：2022-10-1610:00:00（时间由UTC+1转换为UTC+8）另一台机器JVM的时区为UTC+9，JVM中MySQLJDBCDriver解析出来的时间为：2022-10-1611:00:00（时间由UTC+1转换为UTC+9).上面查看JVM运行时的时区JVM时区配置属性user.timezone:PRC是正常的，我们也查看了几台机器的TimeZone.getDefault()也正常：user.timezone查看TimeZone比较麻烦。getDefault()由于有180台机器在线。因此，我们并没有对每一台机器都进行检查（这也是导致我们走了弯路的一步）。在检查应用程序的同时，我们检查了下游的DRDSSQL日志。通过对比异常数据，我们在DRDSSQL日志中找到了错误的SQL日志：，其实是0时区：user.timezone-GMT然后我查了一下在这台ECS上处理的所有数据都存在时区错误的情况。之后在应用代码中搜索[TimeZone.setDefault]，发现是这样的代码：异常代码终于和产品线沟通了，偶尔会调出这段代码（反正这两行代码是有问题的）。异常场景回放异常场景后【5．业务运营】上图中，我们的数据开始出现异常。由于[5。业务运营】是即将下线的功能，后台服务器数量比较多，没有造成大范围数据异常。解决BUG修复对于需要单独格式化时间的场景，可以为单独的DateFormat设置时区信息，示例：DateFormat示例时区配置监控&告警定时采集时区配置（操作系统ORJVM系统配置ORJVM运行时区）信息。异常数据及时报警。
