唯一联合索引插入数据时提示重复条目1. 事故记录 定时任务两小时执行一次(用的Quartz框架),刚上线,前五次是因为使
1. 事故记录
定时任务两小时执行一次(用的Quartz框架),刚上线,前五次是因为使用Apifox手动触发一次,被执行了五次(隔20秒一次,原因未查明)。
$ lz4 -dc rcp_APP_08_15.log.tar.lz4 | tar -xOf - | grep "开始执行定时任务 CheckDeviceUsageJob"
2024-08-15 15:08:43.782 - [APP] - [08d1e5f7bcc937fd:08d1e5f7bcc937fd] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [http-nio-8081-exec-22] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
2024-08-15 15:09:03.787 - [APP] - [d7acdb91e34d99e0:d7acdb91e34d99e0] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [http-nio-8081-exec-4] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
2024-08-15 15:09:23.782 - [APP] - [f552cf142c31eb78:f552cf142c31eb78] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [http-nio-8081-exec-20] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
2024-08-15 15:09:43.783 - [APP] - [8965a13001c969b6:8965a13001c969b6] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [http-nio-8081-exec-11] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
2024-08-15 15:10:03.780 - [APP] - [385c44abeb6c913c:385c44abeb6c913c] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [http-nio-8081-exec-8] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
2024-08-15 16:20:20.031 - [APP] - [6aac551dc3fbb0be:6aac551dc3fbb0be] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [clusteredScheduler_Worker-2] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
2024-08-15 18:20:20.035 - [APP] - [862929c4f76ce8fd:862929c4f76ce8fd] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [clusteredScheduler_Worker-11] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
2024-08-15 20:20:20.021 - [APP] - [7ef6f22c2207e630:7ef6f22c2207e630] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [clusteredScheduler_Worker-10] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
2024-08-15 22:20:20.031 - [APP] - [ba8ce3c248360cfa:ba8ce3c248360cfa] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [clusteredScheduler_Worker-19] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
问题主要出现这前五次上,出现了事务交叉,导致每个都报了重复key的问题(数据库表加了唯一联合索引UK约束)。
第一次:2024-08-15 15:08:43.782 - [APP] - [08d1e5f7bcc937fd:08d1e5f7bcc937fd]
$ lz4 -dc rcp_APP_08_15.log.tar.lz4 | tar -xOf - | grep "08d1e5f7bcc937fd:08d1e5f7bcc937fd"
2024-08-15 15:08:43.782 - [APP] - [08d1e5f7bcc937fd:08d1e5f7bcc937fd] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [http-nio-8081-exec-22] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
2024-08-15 15:10:50.643 - [APP] - [08d1e5f7bcc937fd:08d1e5f7bcc937fd] - [] - [INFO] - [CheckDeviceUsageJob.java:46] - [http-nio-8081-exec-22] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 查询到的新数据列表 deviceUsageEntityList 大小为:181086
2024-08-15 15:11:01.169 - [APP] - [08d1e5f7bcc937fd:08d1e5f7bcc937fd] - [] - [INFO] - [CheckDeviceUsageJob.java:56] - [http-nio-8081-exec-22] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 查询到的旧数据列表 dbDeviceUsageStatisticsList 大小为:0
2024-08-15 15:11:01.169 - [APP] - [08d1e5f7bcc937fd:08d1e5f7bcc937fd] - [] - [INFO] - [CheckDeviceUsageJob.java:121] - [http-nio-8081-exec-22] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 等待更新或插入的 targetList 大小为:181086
第二次:2024-08-15 15:09:03.787 - [APP] - [d7acdb91e34d99e0:d7acdb91e34d99e0]
Duplicate entry '0a61e50420884ebcb0d678f9b98b06ba-3520300000010000000000000277476' for key 'rcp_device_usage_statistics.uk_client_id_eid'
报错后有 LoggingAspect 响应日志,表示是接口触发。
$ lz4 -dc rcp_APP_08_15.log.tar.lz4 | tar -xOf - | grep "d7acdb91e34d99e0:d7acdb91e34d99e0"
2024-08-15 15:09:03.787 - [APP] - [d7acdb91e34d99e0:d7acdb91e34d99e0] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [http-nio-8081-exec-4] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
2024-08-15 15:10:56.064 - [APP] - [d7acdb91e34d99e0:d7acdb91e34d99e0] - [] - [INFO] - [CheckDeviceUsageJob.java:46] - [http-nio-8081-exec-4] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 查询到的新数据列表 deviceUsageEntityList 大小为:181086
2024-08-15 15:11:05.525 - [APP] - [d7acdb91e34d99e0:d7acdb91e34d99e0] - [] - [INFO] - [CheckDeviceUsageJob.java:56] - [http-nio-8081-exec-4] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 查询到的旧数据列表 dbDeviceUsageStatisticsList 大小为:1000
2024-08-15 15:11:05.616 - [APP] - [d7acdb91e34d99e0:d7acdb91e34d99e0] - [] - [INFO] - [CheckDeviceUsageJob.java:94] - [http-nio-8081-exec-4] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待更新流量值的 tempList 大小为:0
2024-08-15 15:11:05.616 - [APP] - [d7acdb91e34d99e0:d7acdb91e34d99e0] - [] - [INFO] - [CheckDeviceUsageJob.java:95] - [http-nio-8081-exec-4] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待新增数据的列表大小为:180086
2024-08-15 15:11:05.617 - [APP] - [d7acdb91e34d99e0:d7acdb91e34d99e0] - [] - [INFO] - [CheckDeviceUsageJob.java:98] - [http-nio-8081-exec-4] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待比对日期的 dbDeviceUsageStatisticsList 大小为:1000
2024-08-15 15:11:05.617 - [APP] - [d7acdb91e34d99e0:d7acdb91e34d99e0] - [] - [INFO] - [CheckDeviceUsageJob.java:121] - [http-nio-8081-exec-4] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 等待更新或插入的 targetList 大小为:180086
2024-08-15 15:11:07.063 - [APP] - [d7acdb91e34d99e0:d7acdb91e34d99e0] - [] - [WARN] - [SqlExceptionHelper.java:137] - [http-nio-8081-exec-4] - logExceptions - org.hibernate.engine.jdbc.spi.SqlExceptionHelper - SQL Error: 1062, SQLState: 23000
2024-08-15 15:11:07.063 - [APP] - [d7acdb91e34d99e0:d7acdb91e34d99e0] - [] - [ERROR] - [SqlExceptionHelper.java:142] - [http-nio-8081-exec-4] - logExceptions - org.hibernate.engine.jdbc.spi.SqlExceptionHelper - Duplicate entry '0a61e50420884ebcb0d678f9b98b06ba-3520300000010000000000000277476' for key 'rcp_device_usage_statistics.uk_client_id_eid'
第三次:2024-08-15 15:09:23.782 - [APP] - [f552cf142c31eb78:f552cf142c31eb78]
Duplicate entry '0a61e50420884ebcb0d678f9b98b06ba-8904903200000100000016592930674' for key 'rcp_device_usage_statistics.uk_client_id_eid'
报错后有 LoggingAspect 响应日志,表示是接口触发。
$ lz4 -dc rcp_APP_08_15.log.tar.lz4 | tar -xOf - | grep "f552cf142c31eb78:f552cf142c31eb78"
2024-08-15 15:09:23.782 - [APP] - [f552cf142c31eb78:f552cf142c31eb78] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [http-nio-8081-exec-20] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
2024-08-15 15:11:21.893 - [APP] - [f552cf142c31eb78:f552cf142c31eb78] - [] - [INFO] - [CheckDeviceUsageJob.java:46] - [http-nio-8081-exec-20] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 查询到的新数据列表 deviceUsageEntityList 大小为:181086
2024-08-15 15:11:30.700 - [APP] - [f552cf142c31eb78:f552cf142c31eb78] - [] - [INFO] - [CheckDeviceUsageJob.java:56] - [http-nio-8081-exec-20] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 查询到的旧数据列表 dbDeviceUsageStatisticsList 大小为:10000
2024-08-15 15:11:30.810 - [APP] - [f552cf142c31eb78:f552cf142c31eb78] - [] - [INFO] - [CheckDeviceUsageJob.java:94] - [http-nio-8081-exec-20] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待更新流量值的 tempList 大小为:0
2024-08-15 15:11:30.811 - [APP] - [f552cf142c31eb78:f552cf142c31eb78] - [] - [INFO] - [CheckDeviceUsageJob.java:95] - [http-nio-8081-exec-20] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待新增数据的列表大小为:171086
2024-08-15 15:11:30.811 - [APP] - [f552cf142c31eb78:f552cf142c31eb78] - [] - [INFO] - [CheckDeviceUsageJob.java:98] - [http-nio-8081-exec-20] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待比对日期的 dbDeviceUsageStatisticsList 大小为:10000
2024-08-15 15:11:30.812 - [APP] - [f552cf142c31eb78:f552cf142c31eb78] - [] - [INFO] - [CheckDeviceUsageJob.java:121] - [http-nio-8081-exec-20] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 等待更新或插入的 targetList 大小为:171086
2024-08-15 15:11:33.099 - [APP] - [f552cf142c31eb78:f552cf142c31eb78] - [] - [WARN] - [SqlExceptionHelper.java:137] - [http-nio-8081-exec-20] - logExceptions - org.hibernate.engine.jdbc.spi.SqlExceptionHelper - SQL Error: 1062, SQLState: 23000
2024-08-15 15:11:33.099 - [APP] - [f552cf142c31eb78:f552cf142c31eb78] - [] - [ERROR] - [SqlExceptionHelper.java:142] - [http-nio-8081-exec-20] - logExceptions - org.hibernate.engine.jdbc.spi.SqlExceptionHelper - Duplicate entry '0a61e50420884ebcb0d678f9b98b06ba-8904903200000100000016592930674' for key 'rcp_device_usage_statistics.uk_client_id_eid'
第四次:2024-08-15 15:09:43.783 - [APP] - [8965a13001c969b6:8965a13001c969b6]
Duplicate entry '505b3e9eed8c41b9ba90c91187593936-8908603420220000102300004680083' for key 'rcp_device_usage_statistics.uk_client_id_eid'
报错后有 LoggingAspect 响应日志,表示是接口触发。
$ lz4 -dc rcp_APP_08_15.log.tar.lz4 | tar -xOf - | grep "8965a13001c969b6:8965a13001c969b6"
2024-08-15 15:09:43.783 - [APP] - [8965a13001c969b6:8965a13001c969b6] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [http-nio-8081-exec-11] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
2024-08-15 15:12:03.875 - [APP] - [8965a13001c969b6:8965a13001c969b6] - [] - [INFO] - [CheckDeviceUsageJob.java:46] - [http-nio-8081-exec-11] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 查询到的新数据列表 deviceUsageEntityList 大小为:181086
2024-08-15 15:12:13.195 - [APP] - [8965a13001c969b6:8965a13001c969b6] - [] - [INFO] - [CheckDeviceUsageJob.java:56] - [http-nio-8081-exec-11] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 查询到的旧数据列表 dbDeviceUsageStatisticsList 大小为:25000
2024-08-15 15:12:13.254 - [APP] - [8965a13001c969b6:8965a13001c969b6] - [] - [INFO] - [CheckDeviceUsageJob.java:94] - [http-nio-8081-exec-11] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待更新流量值的 tempList 大小为:0
2024-08-15 15:12:13.254 - [APP] - [8965a13001c969b6:8965a13001c969b6] - [] - [INFO] - [CheckDeviceUsageJob.java:95] - [http-nio-8081-exec-11] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待新增数据的列表大小为:156086
2024-08-15 15:12:13.255 - [APP] - [8965a13001c969b6:8965a13001c969b6] - [] - [INFO] - [CheckDeviceUsageJob.java:98] - [http-nio-8081-exec-11] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待比对日期的 dbDeviceUsageStatisticsList 大小为:25000
2024-08-15 15:12:13.259 - [APP] - [8965a13001c969b6:8965a13001c969b6] - [] - [INFO] - [CheckDeviceUsageJob.java:121] - [http-nio-8081-exec-11] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 等待更新或插入的 targetList 大小为:156086
2024-08-15 15:12:13.968 - [APP] - [8965a13001c969b6:8965a13001c969b6] - [] - [WARN] - [SqlExceptionHelper.java:137] - [http-nio-8081-exec-11] - logExceptions - org.hibernate.engine.jdbc.spi.SqlExceptionHelper - SQL Error: 1062, SQLState: 23000
2024-08-15 15:12:13.969 - [APP] - [8965a13001c969b6:8965a13001c969b6] - [] - [ERROR] - [SqlExceptionHelper.java:142] - [http-nio-8081-exec-11] - logExceptions - org.hibernate.engine.jdbc.spi.SqlExceptionHelper - Duplicate entry '505b3e9eed8c41b9ba90c91187593936-8908603420220000102300004680083' for key 'rcp_device_usage_statistics.uk_client_id_eid'
第五次:2024-08-15 15:10:03.780 - [APP] - [385c44abeb6c913c:385c44abeb6c913c]
lz4 -dc rcp_APP_08_15.log.tar.lz4 | tar -xOf - | grep "385c44abeb6c913c:385c44abeb6c913c"
2024-08-15 15:10:03.780 - [APP] - [385c44abeb6c913c:385c44abeb6c913c] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [http-nio-8081-exec-8] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
第六次:2024-08-15 16:20:20.031 - [APP] - [6aac551dc3fbb0be:6aac551dc3fbb0be]
及以后都正常了。第六次就把全量数据入库完毕了。
$ lz4 -dc rcp_APP_08_15.log.tar.lz4 | tar -xOf - | grep "6aac551dc3fbb0be:6aac551dc3fbb0be"
2024-08-15 16:20:20.031 - [APP] - [6aac551dc3fbb0be:6aac551dc3fbb0be] - [] - [INFO] - [AbstractQuartzJob.java:50] - [clusteredScheduler_Worker-2] - before - com.redteamobile.venus.job.AbstractQuartzJob - Stopwatch starts in method CheckDeviceUsageJob
2024-08-15 16:20:20.031 - [APP] - [6aac551dc3fbb0be:6aac551dc3fbb0be] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [clusteredScheduler_Worker-2] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
2024-08-15 16:21:34.941 - [APP] - [6aac551dc3fbb0be:6aac551dc3fbb0be] - [] - [INFO] - [CheckDeviceUsageJob.java:46] - [clusteredScheduler_Worker-2] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 查询到的新数据列表 deviceUsageEntityList 大小为:181224
2024-08-15 16:21:39.775 - [APP] - [6aac551dc3fbb0be:6aac551dc3fbb0be] - [] - [INFO] - [CheckDeviceUsageJob.java:56] - [clusteredScheduler_Worker-2] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 查询到的旧数据列表 dbDeviceUsageStatisticsList 大小为:26000
2024-08-15 16:21:40.098 - [APP] - [6aac551dc3fbb0be:6aac551dc3fbb0be] - [] - [INFO] - [CheckDeviceUsageJob.java:94] - [clusteredScheduler_Worker-2] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待更新流量值的 tempList 大小为:813
2024-08-15 16:21:40.098 - [APP] - [6aac551dc3fbb0be:6aac551dc3fbb0be] - [] - [INFO] - [CheckDeviceUsageJob.java:95] - [clusteredScheduler_Worker-2] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待新增数据的列表大小为:155224
2024-08-15 16:21:40.245 - [APP] - [6aac551dc3fbb0be:6aac551dc3fbb0be] - [] - [INFO] - [CheckDeviceUsageJob.java:98] - [clusteredScheduler_Worker-2] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待比对日期的 dbDeviceUsageStatisticsList 大小为:25187
2024-08-15 16:21:40.255 - [APP] - [6aac551dc3fbb0be:6aac551dc3fbb0be] - [] - [INFO] - [CheckDeviceUsageJob.java:121] - [clusteredScheduler_Worker-2] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 等待更新或插入的 targetList 大小为:156037
2024-08-15 16:27:16.133 - [APP] - [6aac551dc3fbb0be:6aac551dc3fbb0be] - [] - [INFO] - [AbstractQuartzJob.java:65] - [clusteredScheduler_Worker-2] - after - com.redteamobile.venus.job.AbstractQuartzJob - Finish performing method CheckDeviceUsageJob, which takes 416101 milliseconds
$ lz4 -dc rcp_APP_08_15.log.tar.lz4 | tar -xOf - | grep "862929c4f76ce8fd:862929c4f76ce8fd"
2024-08-15 18:20:20.034 - [APP] - [862929c4f76ce8fd:862929c4f76ce8fd] - [] - [INFO] - [AbstractQuartzJob.java:50] - [clusteredScheduler_Worker-11] - before - com.redteamobile.venus.job.AbstractQuartzJob - Stopwatch starts in method CheckDeviceUsageJob
2024-08-15 18:20:20.035 - [APP] - [862929c4f76ce8fd:862929c4f76ce8fd] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [clusteredScheduler_Worker-11] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
2024-08-15 18:21:31.710 - [APP] - [862929c4f76ce8fd:862929c4f76ce8fd] - [] - [INFO] - [CheckDeviceUsageJob.java:46] - [clusteredScheduler_Worker-11] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 查询到的新数据列表 deviceUsageEntityList 大小为:182005
2024-08-15 18:21:38.252 - [APP] - [862929c4f76ce8fd:862929c4f76ce8fd] - [] - [INFO] - [CheckDeviceUsageJob.java:56] - [clusteredScheduler_Worker-11] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 查询到的旧数据列表 dbDeviceUsageStatisticsList 大小为:181224
2024-08-15 18:21:38.621 - [APP] - [862929c4f76ce8fd:862929c4f76ce8fd] - [] - [INFO] - [CheckDeviceUsageJob.java:94] - [clusteredScheduler_Worker-11] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待更新流量值的 tempList 大小为:15420
2024-08-15 18:21:38.621 - [APP] - [862929c4f76ce8fd:862929c4f76ce8fd] - [] - [INFO] - [CheckDeviceUsageJob.java:95] - [clusteredScheduler_Worker-11] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待新增数据的列表大小为:781
2024-08-15 18:22:13.797 - [APP] - [862929c4f76ce8fd:862929c4f76ce8fd] - [] - [INFO] - [CheckDeviceUsageJob.java:98] - [clusteredScheduler_Worker-11] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待比对日期的 dbDeviceUsageStatisticsList 大小为:165804
2024-08-15 18:22:13.817 - [APP] - [862929c4f76ce8fd:862929c4f76ce8fd] - [] - [INFO] - [CheckDeviceUsageJob.java:121] - [clusteredScheduler_Worker-11] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 等待更新或插入的 targetList 大小为:16201
2024-08-15 18:22:35.748 - [APP] - [862929c4f76ce8fd:862929c4f76ce8fd] - [] - [INFO] - [AbstractQuartzJob.java:65] - [clusteredScheduler_Worker-11] - after - com.redteamobile.venus.job.AbstractQuartzJob - Finish performing method CheckDeviceUsageJob, which takes 135713 milliseconds
$ lz4 -dc rcp_APP_08_15.log.tar.lz4 | tar -xOf - | grep "7ef6f22c2207e630:7ef6f22c2207e630"
2024-08-15 20:20:20.021 - [APP] - [7ef6f22c2207e630:7ef6f22c2207e630] - [] - [INFO] - [AbstractQuartzJob.java:50] - [clusteredScheduler_Worker-10] - before - com.redteamobile.venus.job.AbstractQuartzJob - Stopwatch starts in method CheckDeviceUsageJob
2024-08-15 20:20:20.021 - [APP] - [7ef6f22c2207e630:7ef6f22c2207e630] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [clusteredScheduler_Worker-10] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
2024-08-15 20:21:38.037 - [APP] - [7ef6f22c2207e630:7ef6f22c2207e630] - [] - [INFO] - [CheckDeviceUsageJob.java:46] - [clusteredScheduler_Worker-10] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 查询到的新数据列表 deviceUsageEntityList 大小为:182491
2024-08-15 20:21:49.800 - [APP] - [7ef6f22c2207e630:7ef6f22c2207e630] - [] - [INFO] - [CheckDeviceUsageJob.java:56] - [clusteredScheduler_Worker-10] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 查询到的旧数据列表 dbDeviceUsageStatisticsList 大小为:182005
2024-08-15 20:21:52.543 - [APP] - [7ef6f22c2207e630:7ef6f22c2207e630] - [] - [INFO] - [CheckDeviceUsageJob.java:94] - [clusteredScheduler_Worker-10] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待更新流量值的 tempList 大小为:22244
2024-08-15 20:21:52.543 - [APP] - [7ef6f22c2207e630:7ef6f22c2207e630] - [] - [INFO] - [CheckDeviceUsageJob.java:95] - [clusteredScheduler_Worker-10] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待新增数据的列表大小为:486
2024-08-15 20:22:43.276 - [APP] - [7ef6f22c2207e630:7ef6f22c2207e630] - [] - [INFO] - [CheckDeviceUsageJob.java:98] - [clusteredScheduler_Worker-10] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待比对日期的 dbDeviceUsageStatisticsList 大小为:159761
2024-08-15 20:22:43.301 - [APP] - [7ef6f22c2207e630:7ef6f22c2207e630] - [] - [INFO] - [CheckDeviceUsageJob.java:121] - [clusteredScheduler_Worker-10] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 等待更新或插入的 targetList 大小为:22730
2024-08-15 20:22:54.288 - [APP] - [7ef6f22c2207e630:7ef6f22c2207e630] - [] - [INFO] - [AbstractQuartzJob.java:65] - [clusteredScheduler_Worker-10] - after - com.redteamobile.venus.job.AbstractQuartzJob - Finish performing method CheckDeviceUsageJob, which takes 154267 milliseconds
$ lz4 -dc rcp_APP_08_15.log.tar.lz4 | tar -xOf - | grep "ba8ce3c248360cfa:ba8ce3c248360cfa"
2024-08-15 22:20:20.031 - [APP] - [ba8ce3c248360cfa:ba8ce3c248360cfa] - [] - [INFO] - [AbstractQuartzJob.java:50] - [clusteredScheduler_Worker-19] - before - com.redteamobile.venus.job.AbstractQuartzJob - Stopwatch starts in method CheckDeviceUsageJob
2024-08-15 22:20:20.031 - [APP] - [ba8ce3c248360cfa:ba8ce3c248360cfa] - [] - [INFO] - [CheckDeviceUsageJob.java:44] - [clusteredScheduler_Worker-19] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 开始执行定时任务 CheckDeviceUsageJob
2024-08-15 22:21:34.728 - [APP] - [ba8ce3c248360cfa:ba8ce3c248360cfa] - [] - [INFO] - [CheckDeviceUsageJob.java:46] - [clusteredScheduler_Worker-19] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 查询到的新数据列表 deviceUsageEntityList 大小为:182788
2024-08-15 22:21:44.756 - [APP] - [ba8ce3c248360cfa:ba8ce3c248360cfa] - [] - [INFO] - [CheckDeviceUsageJob.java:56] - [clusteredScheduler_Worker-19] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 查询到的旧数据列表 dbDeviceUsageStatisticsList 大小为:182491
2024-08-15 22:21:45.076 - [APP] - [ba8ce3c248360cfa:ba8ce3c248360cfa] - [] - [INFO] - [CheckDeviceUsageJob.java:94] - [clusteredScheduler_Worker-19] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待更新流量值的 tempList 大小为:18903
2024-08-15 22:21:45.076 - [APP] - [ba8ce3c248360cfa:ba8ce3c248360cfa] - [] - [INFO] - [CheckDeviceUsageJob.java:95] - [clusteredScheduler_Worker-19] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待新增数据的列表大小为:297
2024-08-15 22:22:22.344 - [APP] - [ba8ce3c248360cfa:ba8ce3c248360cfa] - [] - [INFO] - [CheckDeviceUsageJob.java:98] - [clusteredScheduler_Worker-19] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 待比对日期的 dbDeviceUsageStatisticsList 大小为:163588
2024-08-15 22:22:22.366 - [APP] - [ba8ce3c248360cfa:ba8ce3c248360cfa] - [] - [INFO] - [CheckDeviceUsageJob.java:121] - [clusteredScheduler_Worker-19] - doExecute - com.redteamobile.venus.job.dataUsage.CheckDeviceUsageJob - 等待更新或插入的 targetList 大小为:19200
2024-08-15 22:22:34.248 - [APP] - [ba8ce3c248360cfa:ba8ce3c248360cfa] - [] - [INFO] - [AbstractQuartzJob.java:65] - [clusteredScheduler_Worker-19] - after - com.redteamobile.venus.job.AbstractQuartzJob - Finish performing method CheckDeviceUsageJob, which takes 134217 milliseconds
2. 事故分析
各条日志报的重复 key 并不一样,从日志可以看出,明显出现了交叉事务(前五次任务执行间隔太近了,20秒)。
3. 遗留问题
刚开始怀疑是 MySQL 大小写不敏感造成的唯一键冲突,其实无关,其他场景的话这也是一个排查方向。
唯一联合索引不起作用的时候,可能联合索引中的某个字段为 NULL 了。
问题1:后来发现这个唯一 key 的 eid 最后一位被截断了,和实际数据相比少了一位。这个还待进一步查询资料处理。
问题2:这个为什么会触发五次,间隔 20 秒,是 Apifox 的原因,还是说是手动调用 Quartz 框架的 doExecute 方法导致的,需进一步排查。
问题3:前五次触发中,第一次执行中断原因不明,第二三四次,都是报重复 key 后,有 LoggingAspect 响应日志,表示是接口触发。第五次执行中断原因不明。第六次及之后由 Quartz 框架触发,执行正常。
转载自:https://juejin.cn/post/7403190818629468187