J~杰's Blog

人生就一条路,走一步有一步的景观

0%

背景

前几周给insgin团队业做跨机房数据迁移过程中,出现了一系列的数据,主要问题如下:

  1. 部分表未同步/增量丢失问题

    那有些人可能会问为什么不是全量迁移导致数据不一致问题?那是因为我们的数据迁移操作流程,是增量数据和全量数据同时开启更新的,当全量迁移完成时候,我们通过增量通道的偏移量追赶到最新binlog偏移量时候,会触发全量数据校验过程,在校验完成一致后,我们会修复不一致的数据,直到数据准实时一致。数据修复完成后,接下来就是每天数据校验,我们会每天晚上自动开启数据校验流程,然后持续观察数据是否一致。我们出现的现象就是某几张表一致增量丢失现象。

  2. 跨机房传输RPC是采用Http协议多线程下载问题,下载过程中出现pb反序列化问题和下载502问题;

    pb反序列化问题主要是2.6版本的pb反序列化有大小64m限制,由于某些表存在大字段问题,批量读取binlog可能导致序列化生成的文件过大导致反序列化问题。下载502报错采用多线程下载器aria2c在下载文件比较大的情况下经常出现下载失败问题。

  3. 数据同步更新时间不一致问题;

    发现更新频繁的表经常出现更新时间不一致问题。

  4. 数据校验出现超时校验导致校验失败问题;

    某一些表,数据量在50w左右,但是出现了校验超时失败问题。

原因

增量丢失问题

针对2张表增量丢失更新问题,我们差不多定位了1周左右,中间连周末都去加班找问题了。由于线下环境一直模拟不出来问题,线上由于otter定于的表差不多400多张,同步量还是挺大的,debug日志也不好开启。所以最终我们只能通过针对问题表的日志输出具体canal解析到的binlog信息。从SelectTask开始加日志,到MessageParse加日志,最终定位到,出问题的binlog信息没有rowchange信息,导致无法解析到数据变更前和变更后的信息,然后通过binlog的偏移量去查mysql的binlog信息,发现给binlog信息居然真的只有sql语句,没有变更前和变更后的数据。

com.alibaba.otter.node.etl.select.selector.MessageParser#internParse(com.alibaba.otter.shared.common.model.config.pipeline.Pipeline, com.alibaba.otter.canal.protocol.CanalEntry.Entry)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
 private List<EventData> internParse(Pipeline pipeline, Entry entry) {
RowChange rowChange = null;
try {
rowChange = RowChange.parseFrom(entry.getStoreValue());
} catch (Exception e) {
throw new SelectException("parser of canal-event has an error , data:" + entry.toString(), e);
}

// //线下环境
// if(19 == pipeline.getId() && ("global_drug_relate_indication".equalsIgnoreCase(entry.getHeader().getTableName())
// || "drug_indications_relation".equalsIgnoreCase(entry.getHeader().getTableName()) )) {
//
// parseFromDesc(entry);
// logger.warn("binlogdebug-interparse rowChange object:{}", rowChange);
// }
// //线上环境
// if(23 == pipeline.getId() && ("global_drug_relate_indication".equalsIgnoreCase(entry.getHeader().getTableName())
// || "drug_indications_relation".equalsIgnoreCase(entry.getHeader().getTableName()) )) {
//
// logger.warn("binlogdebug-interparse entryposition:{}", entry.getHeader().getLogfileOffset());
//
//
// if (null == rowChange.getRowDatasList() || rowChange.getRowDatasList().size() == 0) {
// logger.warn("binlogdebug-interparse storeValue parseFrom(), dataList of rowChange is null");
// logger.warn("binlogdebug-interparse rowChange object:{}", rowChange);
// parseFromDesc(entry);
// } else {
// logger.warn("binlogdebug-interparse storeValue parseFrom(), dataList of rowChange is not null, rowDatasList: {}", rowChange.getRowDatasList());
// }
// }

if (rowChange == null) {
return null;
}

String schemaName = entry.getHeader().getSchemaName();
String tableName = entry.getHeader().getTableName();
EventType eventType = EventType.valueOf(rowChange.getEventType().name());

// 处理下DDL操作
if (eventType.isQuery()) {
// 直接忽略query事件
return null;
}

// 首先判断是否为系统表
if (StringUtils.equalsIgnoreCase(pipeline.getParameters().getSystemSchema(), schemaName)) {
// do noting
if (eventType.isDdl()) {
return null;
}

if (StringUtils.equalsIgnoreCase(pipeline.getParameters().getSystemDualTable(), tableName)) {
// 心跳表数据直接忽略
return null;
}
} else {
if (eventType.isDdl()) {
boolean notExistReturnNull = false;
if (eventType.isRename()) {
notExistReturnNull = true;
}

DataMedia dataMedia = ConfigHelper.findSourceDataMedia(pipeline,
schemaName,
tableName,
notExistReturnNull);
// 如果EventType是CREATE/ALTER,需要reload
// DataMediaInfo;并且把CREATE/ALTER类型的事件丢弃掉.
if (dataMedia != null && (eventType.isCreate() || eventType.isAlter() || eventType.isRename())) {
DbDialect dbDialect = dbDialectFactory.getDbDialect(pipeline.getId(),
(DbMediaSource) dataMedia.getSource());
dbDialect.reloadTable(schemaName, tableName);// 更新下meta信息
}

// if(23 == pipeline.getId() && ("global_drug_relate_indication".equalsIgnoreCase(entry.getHeader().getTableName())
// || "drug_indications_relation".equalsIgnoreCase(entry.getHeader().getTableName()) )) {
// logger.warn("binlogdebug-interparse ddlSync return");
// }

boolean ddlSync = pipeline.getParameters().getDdlSync();

if (ddlSync) {
// 处理下ddl操作
EventData eventData = new EventData();
eventData.setSchemaName(schemaName);
eventData.setTableName(tableName);
eventData.setEventType(eventType);
eventData.setExecuteTime(entry.getHeader().getExecuteTime());
eventData.setSql(rowChange.getSql());
eventData.setDdlSchemaName(rowChange.getDdlSchemaName());
eventData.setTableId(dataMedia.getId());
return Arrays.asList(eventData);
} else {
return null;
}
}
}

List<EventData> eventDatas = new ArrayList<>();
for (RowData rowData : rowChange.getRowDatasList()) {
// if(23 == pipeline.getId() && ("global_drug_relate_indication".equalsIgnoreCase(entry.getHeader().getTableName())
// || "drug_indications_relation".equalsIgnoreCase(entry.getHeader().getTableName()) )) {
// logger.warn("binlogdebug-interparse internParse execute start");
// }

EventData eventData = internParse(pipeline, entry, rowChange, rowData);

// if(23 == pipeline.getId() && ("global_drug_relate_indication".equalsIgnoreCase(entry.getHeader().getTableName())
// || "drug_indications_relation".equalsIgnoreCase(entry.getHeader().getTableName()) )) {
// logger.warn("binlogdebug-interparse internParse execute end, eventData: {}", eventData);
// }

if (eventData != null) {
eventDatas.add(eventData);
}
}

return eventDatas;
}

这下开始茫然了,DBA那边查看binlog format确实是row模式,但是只有几张表出现这个问题。然后通过分析DBA修改binlog-format的操作过程,发现DBA原来是修改global session方式去修改配置,这种操作理论上是需要业务方重启业务的,然后咨询了业务放是否有无重启业务,发现数据迁移的数据库有好几个应用在用,业务方均没有主动重启。这才确定了应该是没有重启导致的问题。但是为什么只有几张表才出现这个现象呢,涉及数据迁移的几个库涉及到了好几个业务应用,php应用的数据库连接池每天会重连,但是java应用是有连接池的,数据库连接没有重连导致部分连接format未生效。

pb反序列化失败问题

通过阅读pb的源码,发现新版本已经调整了这个限制大小,所以我们通过升级pb即可解决。

aria2c下载502问题

针对数据传输失败问题,查看了aria2c的github的issue,发现有些开发者也出现了这个问题,推荐调整多线程下载的线程数和重试次数可以降低报错。最终我们通过优化参数和调整canal的读取binlog的读取时间和读取大小限制来降低生成文件的大小,但是由于canal调整的参数如果读取大小设置为10,并不能精准的限制大小,只能大概可以减低读取的binlog数量。所以后期我们计划搞一个可以动态根据吞吐量来自动调整canal限制。

增量同步更新时间不一致问题

该问题定位到是由于数据更新频率太快的原因导致的,比如源库在同一时间新增一条数据,又马上对该数据更新,导致canal解析到更新时间字段为没有update,然后同步的时候去除了该更新时间字段,但是该字段又配置了自动更新,导致目标库更新的时候数据库主动将更新时间字段更新了,最终出现的更新时间不一致的问题。虽然otter本身是为了节省同步的数据量,但是由于我们公司需要对数据强一致要求,我们这边就改造了判断时间类型,强制同步。

com.alibaba.otter.node.etl.select.selector.MessageParser#internParse(com.alibaba.otter.shared.common.model.config.pipeline.Pipeline, com.alibaba.otter.canal.protocol.CanalEntry.Entry, com.alibaba.otter.canal.protocol.CanalEntry.RowChange, com.alibaba.otter.canal.protocol.CanalEntry.RowData)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
for (Column column : afterColumns) {
if (isKey(tableHolder, tableName, column)) {
// 获取变更后的主键
keyColumns.put(column.getName(), copyEventColumn(column, true, tableHolder));
} else if (needAllColumns || entry.getHeader().getSourceType() == CanalEntry.Type.ORACLE
|| column.getUpdated() || (!StringUtils.isEmpty(column.getMysqlType()) && "datetime".equalsIgnoreCase(column.getMysqlType()))) {
// 在update操作时,oracle和mysql存放变更的非主键值的方式不同,oracle只有变更的字段;
// mysql会把变更前和变更后的字段都发出来,只需要取有变更的字段.
// 如果是oracle库,after里一定为对应的变更字段
// 增加如果字段类型是datetime,

boolean isUpdate = true;
if (entry.getHeader().getSourceType() == CanalEntry.Type.MYSQL) {
// mysql的after里部分数据为未变更,oracle里after里为变更字段
isUpdate = column.getUpdated();
if(!StringUtils.isEmpty(column.getMysqlType()) && "datetime".equalsIgnoreCase(column.getMysqlType())){
isUpdate = true;
}
}

notKeyColumns.put(column.getName(), copyEventColumn(column, isRowMode || isUpdate, tableHolder));// 如果是rowMode,所有字段都为updated
}
}

总结

针对这次数据迁移出现的问题,增量丢失数据闹了一个大乌龙,经过这次事件,让我们对我们的数据迁移平台更加有信心保证数据安全和高效传输。目前跨机房问题我们差不多有1-3s的同步延时问题,这块计划考虑增加grpc协议优化传输性能问题。

由于定制的Otter出现增量丢数据的问题,底层用到了canal,用来解析binlog数据,这篇文章就详细的讲些binlog相关的知识点。

Mysql 日志概述

MySQL中有六种日志文件,分别是:重做日志(redo log)、回滚日志(undo log)、二进制日志(bin log)、错误日志(error log)、慢查询日志(slow query log)、一般查询日志(general log),中继日志(relay log)。
其中bin log和undo log与事务操作息息相关,bin log也与事务操作有一定的关系,这三种日志,对理解MySQL中的事务操作有着重要的意义。

Binlog

是什么

由Mysql的Server层实现,是逻辑日志,记录的是sql语句的原始逻辑,比如”给 ID=2 这一行的C字段加1”。

怎么工作的

binlog会写入指定大小的物理文件中,是追加写入的,当前文件写满则会创建新的文件写入。

产生:事务提交的时候,一次性将事务中的sql语句,按照一定的格式记录到binlog中。
清理:可设置参数expire_logs_days,在生成时间超过配置的天数之后,会被自动删除。

做什么用的

  1. 用于复制,在主从复制中,从库利用主库上的binlog进行重播(执行日志中记录的修改逻辑),实现主从同步。

  2. 用于数据库的基于时间点的还原。

3种模式

  1. statement:基于SQL语句的模式,某些语句中含有一些函数,例如 UUID,NOW 等在复制过程可能导致数据不一致甚至出错。

  2. row:基于行的模式,记录的是行的变化,很安全。但是 binlog 的磁盘占用会比其他两种模式大很多,在一些大表中清除大量数据时在 binlog 中会生成很多条语句,可能导致从库延迟变大。

  3. mixed:混合模式,根据语句来选用是 statement 还是 row 模式。表结构变更使用 statement 模式来记录,如果 SQL 语句是 update 或者 delete 语句,那么使用row模式。

Redolog

是什么

由引擎层的InnoDB引擎实现,是物理日志,记录的是物理数据页修改的信息,比如”某个数据页上内容发生了哪些改动”

怎么工作的

原理:当一条数据需要更新时,InnoDB会先将更新操作记录到rodolog中,并更新到内存中,这个更新就算是完成了。InnoDB引擎会在mysql空闲时将这些更新操作更新到磁盘中(数据文件)。
(这个就是MySql经常说到的WAL技术,Write-Ahead Logging ,关键点是先写日志,再写磁盘)

存储:redolog是顺序写入指定大小的物理文件中的。是循环写入的,当文件快写满时,会边擦除边刷磁盘,即擦除日志记录(redolog file)并将数据刷到磁盘中。

做什么用的

  1. 提供crash-safe 能力(崩溃恢复),确保事务的持久性。
    数据库突然崩溃,有些数据并未刷到数据文件中,当重启MySQL数据库,会从redolog中未刷到磁盘的数据刷到磁盘中。

  2. 利用WAL技术推迟物理数据页的刷新,从而提升数据库吞吐,有效降低了访问时延。

Undolog

是什么

由引擎层的InnoDB引擎实现,是逻辑日志,记录数据修改被修改前的值,比如”把Name=’B’ 修改为Name = ‘B2’ ,那么undo日志就会用来存放Name=’B’的记录”

怎么工作的

当一条数据需要更新前,会先把修改前的记录存储在undolog中,如果这个修改出现异常,,则会使用undo日志来实现回滚操作,保证事务的一致性。

当事务提交之后,undo log并不能立马被删除,而是会被放到待清理链表中,待判断没有事物用到该版本的信息时才可以清理相应undolog。

做什么用的

保存了事务发生之前的数据的一个版本,用于回滚,同时可以提供多版本并发控制下的读(MVCC),也即非锁定读

总结

3种日志在事物执行过程中的工作,执行sql如下:

1
2
3
4
BEGIN;
update name = 'wk' from user where id = 1;
update name = 'river' from user where id = 2;
Commit;

A. 将id=1的行name的值读取到内存中
B. 记录id=1的行name=ken到undo log
C. 修改name=wk
D. 记录相应数据页的修改到redo log,并更新内存中的数据
E. 将id=2的行name的值读取到内存中
F. 记录id=2的行name=lj到undo log
G. 修改name=lj
H. 记录相应数据页的修改到redo log,并更新内存中的数据
I. 记录事务中所有SQL的逻辑操作到bin log
J. 提交事务
K. MySql服务器空闲时,把redo log中的物理数据页刷到磁盘数据文件中

特性

  1. 保证原子性:更新数据前,记录undo log,为保证在更新数据时发生异常导致更新失败,这时可以使用undo log对数据进行回滚(回滚内存中的数据,并会在redo log中记录回滚操作)

  2. 保证持久性:每更新数据后,记录redo log,为防止服务器突然宕机,导致没有把数据刷到磁盘中,每次重启MySql服务器都会从redo log将脏页(未能及时写到磁盘的数据页)刷到磁盘

  3. 两阶段提交,保证数据的一致性:
    先写redo log,再写bin log,完成后才能认为事务是完整的。从库主要通过bin log进行同步,但如果服务器异常宕机,可能会造成主从数据不一致的情况。

    a. 写完redo log宕机,bin log还没写
    因为两阶段提交机制,MySql会判断redo log 和 bin log是否都完整,如果不完整,则认为事务未提交,在从redo log 刷数据时,就不会刷未提交的事务的数据

    b. 在写bin log的中途宕机
    已经写了部分的bin log,但是没有写完整(binlog 是否完整会有一个标识符标识),仍然认为事务未提交。崩溃恢复和主从复制时,都不会使用未提交的数据,从而实现数据的一致性。

    c. bin log写完了,但未提交事务
    两阶段提交机制认为,只要redo log和bin log都是完整的,则可以认为事务提交了。

Read more »

线上故障主要会包括 cpu磁盘内存以及 网络 问题,而大多数故障可能会包含不止一个层面的问题,所以进行排查时候尽量四个方面依次排查一遍。同时例如 jstackjmap 等工具也是不囿于一个方面的问题的,基本上出问题就是 df、free、top 三连,然后依次 jstack、jmap 伺候,具体问题具体分析即可。

CPU相关

使用jstack分析cpu问题

我们先用ps命令找到对应进程的 pid(如果你有好几个目标进程,可以先用top看一下哪个占用比较高)。接着用top -H -p pid来找到cpu使用率比较高的一些线程

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
pangpeijie@mt1:~$ top -H -p 308929
top - 15:22:53 up 30 days, 18:06, 2 users, load average: 9.25, 8.29, 9.27
Threads: 30 total, 5 running, 25 sleeping, 0 stopped, 0 zombie
%Cpu0 : 69.1 us, 5.7 sy, 0.0 ni, 24.5 id, 0.0 wa, 0.0 hi, 0.7 si, 0.0 st
%Cpu1 : 71.8 us, 4.4 sy, 0.0 ni, 23.5 id, 0.0 wa, 0.0 hi, 0.3 si, 0.0 st
%Cpu2 : 69.6 us, 6.7 sy, 0.0 ni, 23.1 id, 0.0 wa, 0.0 hi, 0.7 si, 0.0 st
%Cpu3 : 73.1 us, 4.7 sy, 0.0 ni, 21.5 id, 0.0 wa, 0.0 hi, 0.7 si, 0.0 st
%Cpu4 : 72.5 us, 4.7 sy, 0.0 ni, 22.4 id, 0.0 wa, 0.0 hi, 0.3 si, 0.0 st
%Cpu5 : 73.0 us, 4.7 sy, 0.0 ni, 21.7 id, 0.0 wa, 0.0 hi, 0.7 si, 0.0 st
%Cpu6 : 72.8 us, 4.7 sy, 0.0 ni, 22.5 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
%Cpu7 : 72.7 us, 4.7 sy, 0.0 ni, 22.2 id, 0.0 wa, 0.0 hi, 0.3 si, 0.0 st
KiB Mem : 19531248 total, 10154676 free, 6357936 used, 3018636 buff/cache
KiB Swap: 0 total, 0 free, 0 used. 13173312 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
308942 pangpei+ 20 0 8223248 170836 18684 S 36.0 0.9 0:12.55 MultiStageCopro
308949 pangpei+ 20 0 8223248 170836 18684 R 36.0 0.9 0:10.56 MultiStageCopro
308950 pangpei+ 20 0 8223248 170836 18684 R 35.3 0.9 0:10.33 MultiStageCopro
308953 pangpei+ 20 0 8223248 170836 18684 S 33.3 0.9 0:10.43 MultiStageCopro
308952 pangpei+ 20 0 8223248 170836 18684 S 32.3 0.9 0:10.41 MultiStageCopro
308958 pangpei+ 20 0 8223248 170836 18684 S 32.3 0.9 0:10.26 MultiStageCopro
308944 pangpei+ 20 0 8223248 170836 18684 S 32.0 0.9 0:10.49 MultiStageCopro
308946 pangpei+ 20 0 8223248 170836 18684 R 32.0 0.9 0:10.38 MultiStageCopro
308954 pangpei+ 20 0 8223248 170836 18684 S 31.7 0.9 0:10.25 MultiStageCopro
308945 pangpei+ 20 0 8223248 170836 18684 R 30.7 0.9 0:10.34 MultiStageCopro
308955 pangpei+ 20 0 8223248 170836 18684 S 30.3 0.9 0:10.06 MultiStageCopro
308943 pangpei+ 20 0 8223248 170836 18684 S 29.7 0.9 0:10.22 MultiStageCopro
308956 pangpei+ 20 0 8223248 170836 18684 R 29.7 0.9 0:10.08 MultiStageCopro
308951 pangpei+ 20 0 8223248 170836 18684 S 29.3 0.9 0:10.55 MultiStageCopro
308948 pangpei+ 20 0 8223248 170836 18684 S 29.0 0.9 0:10.21 MultiStageCopro
308957 pangpei+ 20 0 8223248 170836 18684 S 27.0 0.9 0:10.18 MultiStageCopro
308947 pangpei+ 20 0 8223248 170836 18684 S 26.0 0.9 0:10.10 MultiStageCopro
308941 pangpei+ 20 0 8223248 170836 18684 S 7.0 0.9 0:02.89 MultiStageCopro
308939 pangpei+ 20 0 8223248 170836 18684 S 3.3 0.9 0:03.02 destination = e
308931 pangpei+ 20 0 8223248 170836 18684 S 0.3 0.9 0:00.13 VM Thread
308929 pangpei+ 20 0 8223248 170836 18684 S 0.0 0.9 0:00.00 java
308930 pangpei+ 20 0 8223248 170836 18684 S 0.0 0.9 0:00.53 java
308932 pangpei+ 20 0 8223248 170836 18684 S 0.0 0.9 0:00.00 Reference Handl
308933 pangpei+ 20 0 8223248 170836 18684 S 0.0 0.9 0:00.00 Finalizer
308934 pangpei+ 20 0 8223248 170836 18684 S 0.0 0.9 0:00.00 Signal Dispatch
308935 pangpei+ 20 0 8223248 170836 18684 S 0.0 0.9 0:04.44 C2 CompilerThre
308936 pangpei+ 20 0 8223248 170836 18684 S 0.0 0.9 0:01.17 C1 CompilerThre
308937 pangpei+ 20 0 8223248 170836 18684 S 0.0 0.9 0:00.00 Service Thread
308938 pangpei+ 20 0 8223248 170836 18684 S 0.0 0.9 0:00.01 VM Periodic Tas
308940 pangpei+ 20 0 8223248 170836 18684 S 0.0 0.9 0:00.00 destination = e

然后将占用最高的pid转换为16进制printf '%x\n' pid得到nid

1
2
pangpeijie@mt1: printf ‘%x\n308953
4b6d9n

接着直接在jstack中找到相应的堆栈信息`jstack pid |grep ‘nid’

1
2
pangpeijie@mt1:~$ sudo -u www-data  /usr/lib/jvm/java-8-openjdk-amd64/bin/jstack 1266021|grep "0x1351aa"
"NettyServerBoss-1-1" #33 daemon prio=5 os_prio=0 tid=0x00007efbaa98a800 nid=0x1351aa runnable [0x00007efba2dad000]

可以看到我们已经找到了nid为0x42的堆栈信息。

统计线程状态

当然更常见的是我们对整个jstack文件进行分析,通常我们会比较关注WAITING和TIMED_WAITING的部分,BLOCKED就不用说了。我们可以使用命令cat jstack.log | grep "java.lang.Thread.State" | sort -nr | uniq -c来对jstack的状态有一个整体的把握,如果WAITING 之类的特别多,那么多半是有问题啦。

1
2
3
4
5
6
7
8
pangpeijie@mt1:~$ sudo -u www-data  /usr/lib/jvm/java-8-openjdk-amd64/bin/jstack 1266021 | grep "java.lang.Thread.State" | sort -nr | uniq -c
263 java.lang.Thread.State: WAITING (parking)
2 java.lang.Thread.State: WAITING (on object monitor)
4 java.lang.Thread.State: TIMED_WAITING (sleeping)
16 java.lang.Thread.State: TIMED_WAITING (parking)
3 java.lang.Thread.State: TIMED_WAITING (on object monitor)
32 java.lang.Thread.State: RUNNABLE
1 java.lang.Thread.State: BLOCKED (on object monitor)

频繁gc

当然我们还是会使用jstack来分析问题,但有时候我们可以先确定下gc是不是太频繁,使用jstat -gc pid 1000命令来对gc分代变化情况进行观察,1000表示采样间隔(ms),S0C/S1C、S0U/S1U、EC/EU、OC/OU、MC/MU分别代表两个Survivor区、Eden区、老年代、元数据区的容量和使用量。YGC/YGT、FGC/FGCT、GCT则代表YoungGc、FullGc的耗时和次数以及总耗时。如果看到gc比较频繁,再针对gc方面做进一步分析。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
jstat -gc 308929 1000
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
10240.0 10240.0 0.0 249.5 81920.0 1627.6 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 1644.4 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 9778.9 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 9778.9 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 17880.8 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 17894.2 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 17894.2 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 24394.5 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 24410.3 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 24425.1 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 33763.8 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 33763.8 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 33780.7 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 39013.0 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 39013.0 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 39026.1 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 48357.7 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 48542.8 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 48542.8 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 50558.9 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 51712.9 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 55216.5 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 64732.6 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 64732.6 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 66789.8 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 71665.8 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 71665.8 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 77737.3 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285
10240.0 10240.0 0.0 249.5 81920.0 77737.3 204800.0 4290.4 18048.0 17467.9 2176.0 2022.8 165 0.285 0 0.000 0.285

上下文切换

针对频繁上下文问题,我们可以使用vmstat命令来进行查看

1
2
3
4
pangpeijie@mt1:~$  pangpeijie@mdw1:~/jdk1.8.0_261/bin$ vmstat
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
28 0 0 9226900 0 3907432 0 0 2777 5668 0 0 9 4 86 1 0

cs(context switch)一列则代表了上下文切换的次数。如果我们希望对特定的pid进行监控那么可以使用 pidstat -w pid命令,cswch和nvcswch表示自愿及非自愿切换。

Read more »

问题来源

在使用otter数据同步项目的时候,由于业务方使用了XA事物,预发环境又是mysql5.7版本,导致XA命令不支持,当改造完otter支持XA命令解析测试的时候,测试发现XA的Rollback数据居然也同步成功了,最终定位到原来mysql在5.7版本之后,增加了在XA Prepare之后就会将binlog生成,发生XA Rollback只是发送命令,无法得知需要更新的数据信息,这就导致到otter数据不一致问题。以下是整理的关于mysql 5.7关于XA的知识点。

什么是XA

XA(分布式事务)规范主要定义了(全局)事务管理器(TM: Transaction Manager)和(局部)资源管理器(RM: Resource Manager)之间的接口。XA为了实现分布式事务,将事务的提交分成了两个阶段:也就是2PC (tow phase commit),XA协议就是通过将事务的提交分为两个阶段来实现分布式事务。

两阶段
1)prepare 阶段
事务管理器向所有涉及到的数据库服务器发出prepare”准备提交”请求,数据库收到请求后执行数据修改和日志记录等处理,处理完成后只是把事务的状态改成”可以提交”,然后把结果返回给事务管理器。即:为prepare阶段,TM向RM发出prepare指令,RM进行操作,然后返回成功与否的信息给TM。
2)commit 阶段
事务管理器收到回应后进入第二阶段,如果在第一阶段内有任何一个数据库的操作发生了错误,或者事务管理器收不到某个数据库的回应,则认为事务失败,回撤所有数据库的事务。数据库服务器收不到第二阶段的确认提交请求,也会把”可以提交”的事务回撤。如果第一阶段中所有数据库都提交成功,那么事务管理器向数据库服务器发出”确认提交”请求,数据库服务器把事务的”可以提交”状态改为”提交完成”状态,然后返回应答。即:为事务提交或者回滚阶段,如果TM收到所有RM的成功消息,则TM向RM发出提交指令;不然则发出回滚指令。

外部与内部XA
MySQL中的XA实现分为:外部XA和内部XA。前者是指我们通常意义上的分布式事务实现;后者是指单台MySQL服务器中,Server层作为TM(事务协调者,通常由binlog模块担当),而服务器中的多个数据库实例作为RM,而进行的一种分布式事务,也就是MySQL跨库事务;也就是一个事务涉及到同一条MySQL服务器中的两个innodb数据库(目前似乎只有innodb支持XA)。内部XA也可以用来保证redo和binlog的一致性问题。

2.2. redo与binlog的一致性问题
我们MySQL为了兼容其它非事务引擎的复制,在server层面引入了 binlog, 它可以记录所有引擎中的修改操作,因而可以对所有的引擎使用复制功能; 然而这种情况会导致redo log与binlog的一致性问题;MySQL通过内部XA机制解决这种一致性的问题。
第一阶段:InnoDB prepare, write/sync redo log;binlog不作任何操作;
第二阶段:包含两步,1> write/sync Binlog; 2> InnoDB commit (commit in memory);
当然在5.6之后引入了组提交的概念,可以在IO性能上进行一些提升,但总体的执行顺序不会改变。
当第二阶段的第1步执行完成之后,binlog已经写入,MySQL会认为事务已经提交并持久化了(在这一步binlog就已经ready并且可以发送给订阅者了)。在这个时刻,就算数据库发生了崩溃,那么重启MySQL之后依然能正确恢复该事务。在这一步之前包含这一步任何操作的失败都会引起事务的rollback。
第二阶段的第2大部分都是内存操作,比如释放锁,释放mvcc相关的read view等等。MySQL认为这一步不会发生任何错误,一旦发生了错误那就是数据库的崩溃,MySQL自身无法处理。这个阶段没有任何导致事务rollback的逻辑。在程序运行层面,只有这一步完成之后,事务导致变更才能通过API或者客户端查询体现出来。

Read more »

问题描述

最近业务团队预发使用平台redis框架包(redis客户端使用lettuce,超时时间配置为5s)的时候经常出现命令超时问题。

报错日志,issue地址

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
Sep  2 17:04:07 live-uat dxy-live-extensions-uat[117]: 2020-09-02 17:04:07.029 dxy-live-extensions [lettuce-epollEventLoop-5-1] ERROR c.d.redis.lock.RedisDistributedLock - set redis occured an exception:Redis command timed out; nested exception is io.lettuce.core.RedisCommandTimeoutException: Command timed out
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: org.springframework.dao.QueryTimeoutException: Redis command timed out; nested exception is io.lettuce.core.RedisCommandTimeoutException: Command timed out
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.connection.lettuce.LettuceExceptionConverter.convert(LettuceExceptionConverter.java:70)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.connection.lettuce.LettuceExceptionConverter.convert(LettuceExceptionConverter.java:41)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.PassThroughExceptionTranslationStrategy.translate(PassThroughExceptionTranslationStrategy.java:44)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.FallbackExceptionTranslationStrategy.translate(FallbackExceptionTranslationStrategy.java:42)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.connection.lettuce.LettuceConnection.convertLettuceAccessException(LettuceConnection.java:257)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.connection.lettuce.LettuceScriptingCommands.convertLettuceAccessException(LettuceScriptingCommands.java:236)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.connection.lettuce.LettuceScriptingCommands.evalSha(LettuceScriptingCommands.java:195)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.connection.DefaultedRedisConnection.evalSha(DefaultedRedisConnection.java:1240)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at java.lang.reflect.Method.invoke(Method.java:498)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.core.CloseSuppressingInvocationHandler.invoke(CloseSuppressingInvocationHandler.java:61)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at com.sun.proxy.$Proxy169.evalSha(Unknown Source)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.core.script.DefaultScriptExecutor.eval(DefaultScriptExecutor.java:77)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.core.script.DefaultScriptExecutor.lambda$execute$0(DefaultScriptExecutor.java:68)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:224)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:184)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:171)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.core.script.DefaultScriptExecutor.execute(DefaultScriptExecutor.java:58)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.core.script.DefaultScriptExecutor.execute(DefaultScriptExecutor.java:52)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:346)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at com.dxy.redis.lock.RedisDistributedLock.redisLock(RedisDistributedLock.java:121)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at com.dxy.redis.lock.RedisDistributedLock.doLock(RedisDistributedLock.java:92)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at com.dxy.redis.lock.AbstractDistributedLock.lock(AbstractDistributedLock.java:46)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at com.dxy.redis.util.RedisLockUtils.tryLock(RedisLockUtils.java:64)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at com.dxy.listener.AbstractMessageListener.tryLock(AbstractMessageListener.java:21)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at com.dxy.listener.LiveInfoChangeMessageListener.onMessage(LiveInfoChangeMessageListener.java:34)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.connection.lettuce.LettuceMessageListener.message(LettuceMessageListener.java:43)
Sep 2 17:04:07 live-uat dxy-live-extensions-uat[117]: #011at org.springframework.data.redis.connection.lettuce.LettuceMessageListener.message(LettuceMessageListener.java:29)

Read more »

[1] 强制 [2] 推荐 [3] 参考

使用规范

  1. [2] 冷热数据区分

    虽然 Redis支持持久化,但将所有数据存储在 Redis 中,成本非常昂贵。建议将热数据 (如 QPS超过 5k) 的数据加载到 Redis 中。低频数据可存储在 Mysql、 ElasticSearch中。

  2. [2] 业务数据分离

    不要将不相关的数据业务都放到一个 Redis中。一方面避免业务相互影响,另一方面避免单实例膨胀,并能在故障时降低影响面,快速恢复。

  3. [2] 缓存不能有中间态

    缓存应该仅作缓存用,去掉后业务逻辑不应发生改变,万不可切入到业务里。第一,缓存的高可用会影响业务;第二,产生深耦合会发生无法预料的效果;第三,会对维护行产生肤效果。

Key设计规范

  1. [2] 可读性和可管理性:以英文冒号分隔key,前缀概念的范围的返回从大到小,从不变到可变,从变化幅度小到变化幅度大。

    例如:yoga:user:1,表示 yoga:user:{userID},即瑜伽子系统ID=1的用户信息。

  2. [2] 简洁性:保证语义的前提下,控制key的长度,当key较长时,内存占用也不容忽视。

    例如:user:{uid}:friends:messages:{mid}可简化为 u:{uid}:f:m:{mid}

  3. [1] 不包含特殊字符,只使用字母数字。

反例:包含空格、换行、单双引号以及其他转义字符

Value设计规范

  1. [1] 拒绝bigkey(防止网卡流量、慢查询)

    string类型控制在10K以内,hash、list、set、zset元素个数不要超过5000。

    反例:一个包含200万个元素的list。

    非字符串的bigkey,不要使用del删除,使用hscan、sscan、zscan方式渐进式删除,同时要注意防止bigkey过期时间自动删除问题(例如一个200万的zset设置1小时过期,会触发del操作,造成阻塞,而且该操作不会不出现在慢查询中(latency可查)).

  2. [2] 选择适合的数据类型。

    例如:实体类型(要合理控制和使用数据结构内存编码优化配置,例如ziplist,但也要注意节省内存和性能之间的平衡)

    反例:
    set user:1:name tom
    set user:1:age 19
    set user:1:favor football

    正例:
    hmset user:1 name tom age 19 favor football

  3. [2] 控制key的生命周期,redis不是垃圾桶。

    建议使用expire设置过期时间(条件允许可以打散过期时间,防止集中过期),不过期的数据重点关注idletime。
    作为缓存使用的 Key,必须要设置失效时间。失效时间并不是越长越好,请根据业务性质进行设置。注意,失效时间的单位有的是秒,有的是毫秒,这个很多同学不注意容易搞错。

Read more »

1. 缩短键值对的存储长度

键值对的长度是和性能成反比的,比如我们来做一组写入数据的性能测试,执行结果如下:

image

从以上数据可以看出,在 key 不变的情况下,value 值越大操作效率越慢,因为 Redis 对于同一种数据类型会使用不同的内部编码进行存储,比如字符串的内部编码就有三种:int(整数编码)、raw(优化内存分配的字符串编码)、embstr(动态字符串编码),这是因为 Redis 的作者是想通过不同编码实现效率和空间的平衡,然而数据量越大使用的内部编码就越复杂,而越是复杂的内部编码存储的性能就越低。

这还只是写入时的速度,当键值对内容较大时,还会带来另外几个问题:

  • 内容越大需要的持久化时间就越长,需要挂起的时间越长,Redis 的性能就会越低;
  • 内容越大在网络上传输的内容就越多,需要的时间就越长,整体的运行速度就越低;
  • 内容越大占用的内存就越多,就会更频繁的触发内存淘汰机制,从而给 Redis 带来了更多的运行负担。

因此在保证完整语义的同时,我们要尽量的缩短键值对的存储长度,必要时要对数据进行序列化和压缩再存储,以 Java 为例,序列化我们可以使用 protostuff 或 kryo,压缩我们可以使用 snappy。

2. 使用 lazy free 特性

lazy free 特性是 Redis 4.0 新增的一个非常使用的功能,它可以理解为惰性删除或延迟删除。意思是在删除的时候提供异步延时释放键值的功能,把键值释放操作放在 BIO(Background I/O) 单独的子线程处理中,以减少删除删除对 Redis 主线程的阻塞,可以有效地避免删除 big key 时带来的性能和可用性问题。

lazy free 对应了 4 种场景,默认都是关闭的:

1
2
3
4
lazyfree-lazy-eviction no
lazyfree-lazy-expire no
lazyfree-lazy-server-del no
slave-lazy-flush no

它们代表的含义如下:

  • lazyfree-lazy-eviction:表示当 Redis 运行内存超过 maxmeory 时,是否开启 lazy free 机制删除;
  • lazyfree-lazy-expire:表示设置了过期时间的键值,当过期之后是否开启 lazy free 机制删除;
  • lazyfree-lazy-server-del:有些指令在处理已存在的键时,会带有一个隐式的 del 键的操作,比如 rename 命令,当目标键已存在,Redis 会先删除目标键,如果这些目标键是一个 big key,就会造成阻塞删除的问题,此配置表示在这种场景中是否开启 lazy free 机制删除;
  • slave-lazy-flush:针对 slave(从节点) 进行全量数据同步,slave 在加载 master 的 RDB 文件前,会运行 flushall 来清理自己的数据,它表示此时是否开启 lazy free 机制删除。

建议开启其中的 lazyfree-lazy-eviction、lazyfree-lazy-expire、lazyfree-lazy-server-del 等配置,这样就可以有效的提高主线程的执行效率。

Read more »

KMP算法

字符串匹配的KMP算法原理

题目

深度优先搜索(DFS)

深度优先搜索算法(Depth-First-Search),是搜索算法的一种。它沿着树的深度遍历树的节点,尽可能深的搜索树的分支。当节点v的所有边都己被探寻过,搜索将回溯到发现节点v的那条边的起始节点。这一过程一直进行到已发现从源节点可达的所有节点为止。如果还存在未被发 现的节点,则选择其中一个作为源节点并重复以上过程,整个进程反复进行直到所有节点都被访问为止。
深度优先搜索是图论中的经典算法,利用深度优先搜索算法可以产生目标图的相应拓扑排序表,利用拓扑排序表可以方便的解决很多相关的图论问题,如最大路径问题等等。一般用堆数据结构来辅助实现DFS算法。

深度优先遍历图算法步骤:

  1. 访问顶点v;
  2. 依次从v的未被访问的邻接点出发,对图进行深度优先遍历;直至图中和v有路径相通的顶点都被访问;
  3. 若此时图中尚有顶点未被访问,则从一个未被访问的顶点出发,重新进行深度优先遍历,直到图中所有顶点均被访问过为止。

题目

Read more »

知识图谱

面试题

  1. 网络模型是什么?
  2. 说说TCP协议的三次握手?
  3. 说说TCP协议的四次挥手?
  4. 为什么需要三次握手才能建立连接?
  5. SYN洪水攻击防护?
  6. 建立连接后,Client出现故障怎么办?
  7. 为什么会有TIME_WAIT状态?
  8. 为什么需要四次挥手才能断开连接?
  9. 服务器出现大量CLOST_WAIT状态的原因?
  10. UDP和TCP的区别?
  11. 说说TCP协议的滑动窗口?
  12. 浏览器中输入url,按下回车经过的过程?
  13. Get和Post的区别?
  14. Cookies和Session的区别?
  15. http和http的区别?