多线程并发

发表于   |   分类于   |  

通过 jmeter 线程组发起并发对接口（插入数据）进行压力测试

  1. 考虑处理方案:
    1. 通过 synchronized 同步互斥锁来控制
    2. 通过 数据库业务唯一键约束，由数据库来控制并发产生的问题
    3. 其他方式，暂时没有思路
  2. 决策
    1. 通过 synchronized 来控制并发，这将大大降低处理性能，使得多线程处理变成队列式依次进行
    2. 经由数据库唯一键约束来控制并发，会出现 org.hibernate.exception.ConstraintViolationException 程序异常，然而，这种性能损耗相对于 synchronized 来讲，还是比较小的，
      在保证处理性能的前提下，选择这种方式无疑要比 synchronized 好很多，而且本身就应该添加的业务唯一键约束，在没有比这更好的处理方案的情况下，选择这种方案更适合。
  3. 行动
    1. 升级数据库（清理脏数据，添加唯一键约束）
    2. 升级程序（容错处理，日志记录）
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
import org.springframework.jdbc.core.JdbcTemplate

private void fixDatas(JdbcTemplate template, Map<String, String> map) {
    if (map == null || map.size() <= 0)
      return;

    Iterator<Entry<String, String>> iterator = map.entrySet().iterator();
    Entry<String, String> entry = null;
    while (iterator.hasNext()) {
      entry = iterator.next();
      debug(MessageFormat.format("{0}:{1}", entry.getKey(), entry.getValue()));
      if (StringUtils.isNotBlank(entry.getKey()) && StringUtils.isNotBlank(entry.getValue()))
        fixProcess(template, entry.getKey(), entry.getValue());
    }
  }

private void fixProcess(JdbcTemplate template, String tableName, String sql) {
LOG.info(MessageFormat.format("======  开始修复 {0} 数据  ======", tableName));
// 检索待修复数据集
List<Object[]> result = loadDataSet(template, sql);

// 清理数据
cleanData(template, result, tableName);
LOG.info(MessageFormat.format("======  已完成修复 {0} 数据  ======", tableName));
}

private List<Object[]> loadDataSet(JdbcTemplate template, String sql) {
// 检索待修复数据集
List<Object[]> result = template.query(sql, new ResultSetExtractor<List<Object[]>>() {
  @Override
  public List<Object[]> extractData(ResultSet rs) throws SQLException, DataAccessException {
	List<Object[]> res = new ArrayList<Object[]>();
	while (rs.next()) {
	  List<Object> singleLine = new ArrayList<Object>();
	  singleLine.add(rs.getString("hst_num"));
	  singleLine.add(rs.getInt("count_res"));
	  res.add(singleLine.toArray(new Object[singleLine.size()]));
	}
	return res;
  }
});

LOG.info("待修复处理数据:{}", JsonSimpleSerializer.serialize(result));
return result;
}

private void cleanData(JdbcTemplate template, List<Object[]> result, String tableName) {
// 清理数据
if (result != null && result.isEmpty() == false) {
  for (int line = 0; line < result.size(); line++) {
	List<String> rows = template.queryForList(MessageFormat
		.format("select uuid from {0} where hst_num = ? ORDER BY {1} asc", tableName,
		  PAY_TRAN_TABLE_NAME.equals(tableName) ? "created" : "createTime"),
	  new Object[]{result.get(line)[0]}, String.class);
	debug(MessageFormat
	  .format("流水记录表 {0} 中重复流水号的 uuid:{1}", tableName, JsonSimpleSerializer.serialize(rows)));
	for (int row = 1; row < rows.size(); row++) {
	  debug(MessageFormat.format("清理流水记录表 {0}  记录为 uuid：{1} 的数据", tableName, rows.get(row)));
	  template.update(MessageFormat.format("DELETE from {0} where uuid = ? ", tableName),
		rows.get(row));
	}
  }
}
}

private void debug(String message) {
if (LOG.isDebugEnabled())
  LOG.debug(message);
}
  • 升级日志 
    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
    121
    122
    123
    124
    125
    126
    127
    128
    129
    130
    131
    132
    133
    134
    135
    136
    137
    138
    139
    140
    141
    142
    143
    144
    145
    146
    147
    148
    149
    150
    151
    2017-01-12 18:36:11,854 [DEBUG] com.hd123.rumba.rdbver.upgrader.UpgraderManager - Call upgrader: com.huanyu.crm.rdb.upgrade.v1.v4.SchemaUpgrader
    2017-01-12 18:36:11,855 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - tran:select hst_num,count(uuid) as count_res  from tran GROUP BY hst_num,tran_status HAVING count(uuid) > 1
    2017-01-12 18:36:11,855 [INFO] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - ======  开始修复 tran 数据  ======
    2017-01-12 18:36:11,855 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing SQL query [select hst_num,count(uuid) as count_res  from tran GROUP BY hst_num,tran_status HAVING count(uuid) > 1]
    2017-01-12 18:36:11,855 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,871 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,876 [INFO] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 待修复处理数据:{"type":"list","value":[{"type":"array","value":[{"type":"string","value":"20170316y001"},{"type":"integer","value":5}]},{"type":"array","value":[{"type":"string","value":"20170316ylj003"},{"type":"integer","value":3}]},{"type":"array","value":[{"type":"string","value":"20170317lq001"},{"type":"integer","value":2}]},{"type":"array","value":[{"type":"string","value":"ylj20170316000"},{"type":"integer","value":2}]}]}
    2017-01-12 18:36:11,903 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
    2017-01-12 18:36:11,905 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [select uuid from tran where hst_num = ? ORDER BY created asc]
    2017-01-12 18:36:11,905 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,925 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,925 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 流水记录表 tran 中重复流水号的 uuid:{"type":"list","value":[{"type":"string","value":"402880905ad60f91015ad683dc060057"},{"type":"string","value":"402880905ad60f91015ad683dc120058"},{"type":"string","value":"402880905ad60f91015ad683dc160059"},{"type":"string","value":"402880905ad60f91015ad683dc19005a"},{"type":"string","value":"402880905ad60f91015ad683dc1c005b"}]}
    2017-01-12 18:36:11,925 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 清理流水记录表 tran  记录为 uuid：402880905ad60f91015ad683dc120058 的数据
    2017-01-12 18:36:11,925 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
    2017-01-12 18:36:11,925 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [DELETE from tran where uuid = ? ]
    2017-01-12 18:36:11,925 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,933 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - SQL update affected 1 rows
    2017-01-12 18:36:11,934 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,934 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 清理流水记录表 tran  记录为 uuid：402880905ad60f91015ad683dc160059 的数据
    2017-01-12 18:36:11,934 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
    2017-01-12 18:36:11,934 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [DELETE from tran where uuid = ? ]
    2017-01-12 18:36:11,934 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,940 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - SQL update affected 1 rows
    2017-01-12 18:36:11,942 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,942 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 清理流水记录表 tran  记录为 uuid：402880905ad60f91015ad683dc19005a 的数据
    2017-01-12 18:36:11,942 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
    2017-01-12 18:36:11,942 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [DELETE from tran where uuid = ? ]
    2017-01-12 18:36:11,942 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,945 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - SQL update affected 1 rows
    2017-01-12 18:36:11,946 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,946 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 清理流水记录表 tran  记录为 uuid：402880905ad60f91015ad683dc1c005b 的数据
    2017-01-12 18:36:11,946 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
    2017-01-12 18:36:11,946 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [DELETE from tran where uuid = ? ]
    2017-01-12 18:36:11,946 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,949 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - SQL update affected 1 rows
    2017-01-12 18:36:11,950 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,950 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
    2017-01-12 18:36:11,950 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [select uuid from tran where hst_num = ? ORDER BY created asc]
    2017-01-12 18:36:11,950 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,952 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,952 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 流水记录表 tran 中重复流水号的 uuid:{"type":"list","value":[{"type":"string","value":"402880905ad60f91015ad664429d003e"},{"type":"string","value":"402880905ad60f91015ad66442a1003f"},{"type":"string","value":"402880905ad60f91015ad66442a40040"}]}
    2017-01-12 18:36:11,952 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 清理流水记录表 tran  记录为 uuid：402880905ad60f91015ad66442a1003f 的数据
    2017-01-12 18:36:11,952 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
    2017-01-12 18:36:11,952 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [DELETE from tran where uuid = ? ]
    2017-01-12 18:36:11,952 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,955 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - SQL update affected 1 rows
    2017-01-12 18:36:11,957 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,957 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 清理流水记录表 tran  记录为 uuid：402880905ad60f91015ad66442a40040 的数据
    2017-01-12 18:36:11,957 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
    2017-01-12 18:36:11,957 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [DELETE from tran where uuid = ? ]
    2017-01-12 18:36:11,957 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,959 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - SQL update affected 1 rows
    2017-01-12 18:36:11,961 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,961 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
    2017-01-12 18:36:11,961 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [select uuid from tran where hst_num = ? ORDER BY created asc]
    2017-01-12 18:36:11,961 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,962 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,962 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 流水记录表 tran 中重复流水号的 uuid:{"type":"list","value":[{"type":"string","value":"402880905ada4434015ada59c42b0019"},{"type":"string","value":"402880905ada4434015ada59c42c001a"}]}
    2017-01-12 18:36:11,962 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 清理流水记录表 tran  记录为 uuid：402880905ada4434015ada59c42c001a 的数据
    2017-01-12 18:36:11,962 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
    2017-01-12 18:36:11,962 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [DELETE from tran where uuid = ? ]
    2017-01-12 18:36:11,962 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,964 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - SQL update affected 1 rows
    2017-01-12 18:36:11,964 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,964 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
    2017-01-12 18:36:11,964 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [select uuid from tran where hst_num = ? ORDER BY created asc]
    2017-01-12 18:36:11,964 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,966 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,966 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 流水记录表 tran 中重复流水号的 uuid:{"type":"list","value":[{"type":"string","value":"402880905ad60f91015ad650a5cd0025"},{"type":"string","value":"402880905ad60f91015ad650a5ef0026"}]}
    2017-01-12 18:36:11,966 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 清理流水记录表 tran  记录为 uuid：402880905ad60f91015ad650a5ef0026 的数据
    2017-01-12 18:36:11,966 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
    2017-01-12 18:36:11,966 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [DELETE from tran where uuid = ? ]
    2017-01-12 18:36:11,966 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,969 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - SQL update affected 1 rows
    2017-01-12 18:36:11,970 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,970 [INFO] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - ======  已完成修复 tran 数据  ======
    2017-01-12 18:36:11,970 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - hst:select hst_num,count(uuid) as count_res from hst GROUP BY hst_num,status HAVING count(uuid) > 1
    2017-01-12 18:36:11,970 [INFO] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - ======  开始修复 hst 数据  ======
    2017-01-12 18:36:11,970 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing SQL query [select hst_num,count(uuid) as count_res from hst GROUP BY hst_num,status HAVING count(uuid) > 1]
    2017-01-12 18:36:11,970 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,977 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,978 [INFO] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 待修复处理数据:{"type":"list","value":[{"type":"array","value":[{"type":"string","value":"20170316y001"},{"type":"integer","value":5}]},{"type":"array","value":[{"type":"string","value":"20170316ylj003"},{"type":"integer","value":3}]},{"type":"array","value":[{"type":"string","value":"20170317lq001"},{"type":"integer","value":2}]},{"type":"array","value":[{"type":"string","value":"ylj20170316000"},{"type":"integer","value":2}]}]}
    2017-01-12 18:36:11,978 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
    2017-01-12 18:36:11,978 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [select uuid from hst where hst_num = ? ORDER BY createTime asc]
    2017-01-12 18:36:11,978 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,981 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,982 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 流水记录表 hst 中重复流水号的 uuid:{"type":"list","value":[{"type":"string","value":"402880905ad60f91015ad683dc24005c"},{"type":"string","value":"402880905ad60f91015ad683dc27005e"},{"type":"string","value":"402880905ad60f91015ad683dc2b0060"},{"type":"string","value":"402880905ad60f91015ad683dc330062"},{"type":"string","value":"402880905ad60f91015ad683dc340064"}]}
    2017-01-12 18:36:11,982 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 清理流水记录表 hst  记录为 uuid：402880905ad60f91015ad683dc27005e 的数据
    2017-01-12 18:36:11,982 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
    2017-01-12 18:36:11,982 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [DELETE from hst where uuid = ? ]
    2017-01-12 18:36:11,982 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,985 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - SQL update affected 1 rows
    2017-01-12 18:36:11,987 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,987 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 清理流水记录表 hst  记录为 uuid：402880905ad60f91015ad683dc2b0060 的数据
    2017-01-12 18:36:11,987 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
    2017-01-12 18:36:11,987 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [DELETE from hst where uuid = ? ]
    2017-01-12 18:36:11,987 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:11,995 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - SQL update affected 1 rows
    2017-01-12 18:36:11,996 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:11,997 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 清理流水记录表 hst  记录为 uuid：402880905ad60f91015ad683dc330062 的数据
    2017-01-12 18:36:11,997 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
    2017-01-12 18:36:11,997 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [DELETE from hst where uuid = ? ]
    2017-01-12 18:36:11,997 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:12,001 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - SQL update affected 1 rows
    2017-01-12 18:36:12,002 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:12,002 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 清理流水记录表 hst  记录为 uuid：402880905ad60f91015ad683dc340064 的数据
    2017-01-12 18:36:12,002 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
    2017-01-12 18:36:12,002 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [DELETE from hst where uuid = ? ]
    2017-01-12 18:36:12,002 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:12,005 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - SQL update affected 1 rows
    2017-01-12 18:36:12,008 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:12,009 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
    2017-01-12 18:36:12,009 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [select uuid from hst where hst_num = ? ORDER BY createTime asc]
    2017-01-12 18:36:12,009 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:12,012 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:12,012 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 流水记录表 hst 中重复流水号的 uuid:{"type":"list","value":[{"type":"string","value":"402880905ad60f91015ad66442a80041"},{"type":"string","value":"402880905ad60f91015ad66442b10043"},{"type":"string","value":"402880905ad60f91015ad66442b20045"}]}
    2017-01-12 18:36:12,012 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 清理流水记录表 hst  记录为 uuid：402880905ad60f91015ad66442b10043 的数据
    2017-01-12 18:36:12,012 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
    2017-01-12 18:36:12,012 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [DELETE from hst where uuid = ? ]
    2017-01-12 18:36:12,012 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:12,016 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - SQL update affected 1 rows
    2017-01-12 18:36:12,017 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:12,017 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 清理流水记录表 hst  记录为 uuid：402880905ad60f91015ad66442b20045 的数据
    2017-01-12 18:36:12,017 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
    2017-01-12 18:36:12,017 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [DELETE from hst where uuid = ? ]
    2017-01-12 18:36:12,017 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:12,021 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - SQL update affected 1 rows
    2017-01-12 18:36:12,023 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:12,023 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
    2017-01-12 18:36:12,023 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [select uuid from hst where hst_num = ? ORDER BY createTime asc]
    2017-01-12 18:36:12,023 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:12,026 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:12,026 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 流水记录表 hst 中重复流水号的 uuid:{"type":"list","value":[{"type":"string","value":"402880905ada4434015ada59c434001b"},{"type":"string","value":"402880905ada4434015ada59c437001d"}]}
    2017-01-12 18:36:12,026 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 清理流水记录表 hst  记录为 uuid：402880905ada4434015ada59c437001d 的数据
    2017-01-12 18:36:12,026 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
    2017-01-12 18:36:12,026 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [DELETE from hst where uuid = ? ]
    2017-01-12 18:36:12,026 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:12,029 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - SQL update affected 1 rows
    2017-01-12 18:36:12,030 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:12,030 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
    2017-01-12 18:36:12,030 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [select uuid from hst where hst_num = ? ORDER BY createTime asc]
    2017-01-12 18:36:12,030 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:12,032 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:12,033 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 流水记录表 hst 中重复流水号的 uuid:{"type":"list","value":[{"type":"string","value":"402880905ad60f91015ad650a60e0027"},{"type":"string","value":"402880905ad60f91015ad650a60f0029"}]}
    2017-01-12 18:36:12,033 [DEBUG] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - 清理流水记录表 hst  记录为 uuid：402880905ad60f91015ad650a60f0029 的数据
    2017-01-12 18:36:12,033 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
    2017-01-12 18:36:12,033 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [DELETE from hst where uuid = ? ]
    2017-01-12 18:36:12,033 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
    2017-01-12 18:36:12,038 [DEBUG] org.springframework.jdbc.core.JdbcTemplate - SQL update affected 1 rows
    2017-01-12 18:36:12,040 [DEBUG] org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
    2017-01-12 18:36:12,040 [INFO] com.huanyu.crm.rdb.upgrade.v1.v4.UpgradePayNotify - ======  已完成修复 hst 数据  ======

多线程并发处理事件

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
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158

线程2 处理日志：

2016-12-23 10:43:55,896 [pool-9-thread-2] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 8eca780c658740b1a499baa1d7074e61 - run
2016-12-23 10:43:55,897 [pool-9-thread-2] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 0639f5184db44f8a9659428a217f930e - handle: test, crm, 402880985ad4ba3c015ad50011720002, com.huanyu.mgate.core.weixin.ActiveCardEvent
2016-12-23 10:43:55,897 [pool-9-thread-2] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 0639f5184db44f8a9659428a217f930e - handle: test, alipass, 402880985ad4ba3c015ad50011720002, com.huanyu.mgate.core.weixin.ActiveCardEvent
2016-12-23 10:43:55,897 [pool-9-thread-2] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 0639f5184db44f8a9659428a217f930e - handle: test, weixin, 402880985ad4ba3c015ad50011720002, com.huanyu.mgate.core.weixin.ActiveCardEvent
2016-12-23 10:43:55,908 [pool-9-thread-2] INFO com.huanyu.weixin.sdk.http.HttpsClient 0639f5184db44f8a9659428a217f930e - Request:
==========================
POST https://api.weixin.qq.com/card/membercard/userinfo/get?access_token=DSJ-g_DErgipWWCqY-cOoicJn-UuwgFbDdZ-3AOCw4uRG6VyjlvXRKVs9lDnQo6hLjRoIlNW06i-UhJKAnmFq7T_apxgI-bpqRfv1V38PlPNe17ETBfXDjSSxQT-RSGcVYEcAKDMPV
{"code":"weixin_code","card_id":"weixin_card_id"}
==========================
2016-12-23 10:43:56,013 [pool-9-thread-2] INFO com.huanyu.weixin.sdk.http.HttpsClient 0639f5184db44f8a9659428a217f930e - Response: 
==========================
200
{"errcode":0,"errmsg":"ok","openid":"weixin_open_id","nickname":"nick_name","membership_number":"weixin_code","bonus":0,"sex":"MALE","user_info":{"common_field_list":[{"name":"USER_FORM_INFO_FLAG_MOBILE","value":"12345678901","value_list":[]}],"custom_field_list":[]},"user_card_status":"NORMAL","has_active":true}
==========================
2016-12-23 10:43:56,130 [pool-9-thread-2] INFO com.huanyu.weixin.sdk.http.HttpClient 0639f5184db44f8a9659428a217f930e - Request:
==========================
GET http://dly-bl.jcrm.test.hd123.cn:9080/jcrm-server-card/rest/mbr/getByMobileNum/12345678901
==========================
2016-12-23 10:43:56,366 [pool-9-thread-2] INFO com.huanyu.weixin.sdk.http.HttpClient 0639f5184db44f8a9659428a217f930e - Response: 
==========================
200
{
  "errorCode" : 0,
  "message" : "ok"
}
==========================
2016-12-23 10:43:56,380 [pool-9-thread-2] INFO com.huanyu.ddps.config.impl.DefaultConfigStore 0639f5184db44f8a9659428a217f930e - 开始监听配置更新，tenantId: test, name: offlinecrm.defaultOperateStore
2016-12-23 10:43:56,407 [pool-9-thread-2] INFO com.huanyu.ddps.config.impl.DefaultConfigStore 0639f5184db44f8a9659428a217f930e - 开始监听配置更新，tenantId: -, name: offlinecrm.paths
2016-12-23 10:43:56,495 [pool-9-thread-2] INFO com.huanyu.mgate.core.weixin.WeixinEventHandler 0639f5184db44f8a9659428a217f930e - 推送给crm：test, json_data
2016-12-23 10:43:57,983 [pool-9-thread-2] INFO com.huanyu.mgate.core.weixin.WeixinEventHandler 0639f5184db44f8a9659428a217f930e - 绑定会员，租户: test, 会员ID: 89638865b0474a9cb5db3aea1b9bd839, 会员号: test_number_1
2016-12-23 10:43:58,000 [pool-9-thread-2] INFO com.huanyu.weixin.sdk.http.HttpsClient 0639f5184db44f8a9659428a217f930e - Request:
==========================
POST https://api.weixin.qq.com/card/code/get?access_token=DSJ-g_DErgipWWCqY-cOoicJn-UuwgFbDdZ-3AOCw4uRG6VyjlvXRKVs9lDnQo6hLjRoIlNW06i-UhJKAnmFq7T_apxgI-bpqRfv1V38PlPNe17ETBfXDjSSxQT-RSGcVYEcAKDMPV
{"check_consume":false,"code":"weixin_code","card_id":"weixin_card_id"}
==========================
2016-12-23 10:43:58,116 [pool-9-thread-2] INFO com.huanyu.weixin.sdk.http.HttpsClient 0639f5184db44f8a9659428a217f930e - Response: 
==========================
200
{"errcode":0,"errmsg":"ok","card":{"card_id":"weixin_card_id","begin_time":0,"end_time":4294967295,"bonus":0,"code":"weixin_code","membership_number":"weixin_code"},"openid":"weixin_open_id","can_consume":true,"user_card_status":"NORMAL"}
==========================
2016-12-23 10:43:58,116 [pool-9-thread-2] INFO com.huanyu.mgate.core.weixin.WeixinEventHandler 0639f5184db44f8a9659428a217f930e - 激活微信会员卡，租户: test, 卡号: weixin_code
2016-12-23 10:43:58,117 [pool-9-thread-2] INFO com.huanyu.weixin.sdk.http.HttpsClient 0639f5184db44f8a9659428a217f930e - Request:
==========================
POST https://api.weixin.qq.com/card/membercard/activate?access_token=DSJ-g_DErgipWWCqY-cOoicJn-UuwgFbDdZ-3AOCw4uRG6VyjlvXRKVs9lDnQo6hLjRoIlNW06i-UhJKAnmFq7T_apxgI-bpqRfv1V38PlPNe17ETBfXDjSSxQT-RSGcVYEcAKDMPV
{"membership_number":"test_number_1","code":"weixin_code","card_id":"weixin_card_id"}
==========================
2016-12-23 10:43:58,228 [pool-9-thread-2] INFO com.huanyu.weixin.sdk.http.HttpsClient 0639f5184db44f8a9659428a217f930e - Response: 
==========================
200
{"errcode":0,"errmsg":"ok"}
==========================
2016-12-23 10:43:58,229 [pool-9-thread-2] INFO com.huanyu.mgate.core.PublishServiceImpl 0639f5184db44f8a9659428a217f930e - mgate-crmService-queryAccount：租户Id:test,查询类型:crm_mbr_id,查询码:test_number_1
2016-12-23 10:43:58,427 [pool-9-thread-2] WARN com.huanyu.mgate.core.weixin.WeixinEventHandler 0639f5184db44f8a9659428a217f930e - 初始化会员weixin_code微信积分账户,积分数:0.00
2016-12-23 10:43:58,428 [pool-9-thread-2] INFO com.huanyu.weixin.sdk.http.HttpsClient 0639f5184db44f8a9659428a217f930e - Request:
==========================
POST https://api.weixin.qq.com/card/membercard/updateuser?access_token=DSJ-g_DErgipWWCqY-cOoicJn-UuwgFbDdZ-3AOCw4uRG6VyjlvXRKVs9lDnQo6hLjRoIlNW06i-UhJKAnmFq7T_apxgI-bpqRfv1V38PlPNe17ETBfXDjSSxQT-RSGcVYEcAKDMPV
{"record_bonus":"积分更新","notify_optional":{"is_notify_bonus":true},"bonus":0,"code":"weixin_code","card_id":"weixin_card_id"}
==========================
2016-12-23 10:43:58,619 [pool-9-thread-2] INFO com.huanyu.weixin.sdk.http.HttpsClient 0639f5184db44f8a9659428a217f930e - Response: 
==========================
200
{"errcode":-1,"errmsg":"system error hint: [7OsAaA0238e503]"}
==========================
2016-12-23 10:43:58,621 [pool-9-thread-2] INFO com.huanyu.mgate.core.weixin.WeixinEventHandler 0639f5184db44f8a9659428a217f930e - 初始化会员test_number_1微信积分账户失败
java.lang.Exception: 微信系统繁忙，请稍候再试(-1, system error hint: [7OsAaA0238e503])
        at com.huanyu.weixin.sdk.WeixinClient.checkResult(WeixinClient.java:49)
        at com.huanyu.weixin.sdk.cardcode.CardCodeClient.updateScore(CardCodeClient.java:181)
        at com.huanyu.mgate.core.weixin.WeixinEventHandler.activateBycrmNo(WeixinEventHandler.java:312)
        at com.huanyu.mgate.core.weixin.WeixinEventHandler.handleActive(WeixinEventHandler.java:261)
        at com.huanyu.mgate.core.weixin.WeixinEventHandler.activateCard(WeixinEventHandler.java:195)
        at com.huanyu.mgate.core.weixin.WeixinEventHandler.handle(WeixinEventHandler.java:109)
        at com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher$HandleTask.run(MultiTenantEventDispatcher.java:264)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:745)
2016-12-23 10:43:58,651 [pool-9-thread-2] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 0639f5184db44f8a9659428a217f930e - test, weixin 处理 com.huanyu.mgate.core.weixin.ActiveCardEvent 耗时 2754 ms
2016-12-23 10:43:58,651 [pool-9-thread-2] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 0639f5184db44f8a9659428a217f930e - handle: test, MerchantAcceptOrder, 402880985ad4ba3c015ad50011720002, com.huanyu.mgate.core.weixin.ActiveCardEvent
2016-12-23 10:43:58,651 [pool-9-thread-2] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 0639f5184db44f8a9659428a217f930e - handle: test, alimerchantupdate, 402880985ad4ba3c015ad50011720002, com.huanyu.mgate.core.weixin.ActiveCardEvent
2016-12-23 10:43:58,651 [pool-9-thread-2] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 0639f5184db44f8a9659428a217f930e - handle: test, feifanMemberAsyncRegister, 402880985ad4ba3c015ad50011720002, com.huanyu.mgate.core.weixin.ActiveCardEvent
2016-12-23 10:43:58,651 [pool-9-thread-2] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 0639f5184db44f8a9659428a217f930e - 删除事件：402880985ad4ba3c015ad50011720002



线程3 处理日志：

2016-12-23 10:43:57,202 [pool-9-thread-3] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 037e8b865132482d9be1eaf104042236 - run
2016-12-23 10:43:57,203 [pool-9-thread-3] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 6969ef8818c34b34aeb86ea755f21e52 - handle: test, crm, 402880985ad4ba3c015ad50011720002, com.huanyu.mgate.core.weixin.ActiveCardEvent
2016-12-23 10:43:57,203 [pool-9-thread-3] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 6969ef8818c34b34aeb86ea755f21e52 - handle: test, alipass, 402880985ad4ba3c015ad50011720002, com.huanyu.mgate.core.weixin.ActiveCardEvent
2016-12-23 10:43:57,203 [pool-9-thread-3] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 6969ef8818c34b34aeb86ea755f21e52 - handle: test, weixin, 402880985ad4ba3c015ad50011720002, com.huanyu.mgate.core.weixin.ActiveCardEvent
2016-12-23 10:43:57,218 [DDPS-Scheduler-Thread-10] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher fe82751489dd4d6eb4c39c92cad9a012 - 租户 test 共找到 1 个事件，耗时：16 ms
2016-12-23 10:43:57,219 [DDPS-Scheduler-Thread-10] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher fe82751489dd4d6eb4c39c92cad9a012 - 忽略: 402880985ad4ba3c015ad50011720002
2016-12-23 10:43:57,219 [DDPS-Scheduler-Thread-10] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher fe82751489dd4d6eb4c39c92cad9a012 - 跳过当前页，时间片+1
2016-12-23 10:43:57,219 [pool-9-thread-3] INFO com.huanyu.weixin.sdk.http.HttpsClient 6969ef8818c34b34aeb86ea755f21e52 - Request:
==========================
POST https://api.weixin.qq.com/card/membercard/userinfo/get?access_token=DSJ-g_DErgipWWCqY-cOoicJn-UuwgFbDdZ-3AOCw4uRG6VyjlvXRKVs9lDnQo6hLjRoIlNW06i-UhJKAnmFq7T_apxgI-bpqRfv1V38PlPNe17ETBfXDjSSxQT-RSGcVYEcAKDMPV
{"code":"weixin_code","card_id":"weixin_card_id"}
==========================
2016-12-23 10:43:57,221 [DDPS-Scheduler-Thread-10] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher fe82751489dd4d6eb4c39c92cad9a012 - 租户 test 共找到 0 个事件，耗时：2 ms
2016-12-23 10:43:57,344 [pool-9-thread-3] INFO com.huanyu.weixin.sdk.http.HttpsClient 6969ef8818c34b34aeb86ea755f21e52 - Response: 
==========================
200
{"errcode":0,"errmsg":"ok","openid":"weixin_open_id","nickname":"nick_name","membership_number":"weixin_code","bonus":0,"sex":"MALE","user_info":{"common_field_list":[{"name":"USER_FORM_INFO_FLAG_MOBILE","value":"12345678901","value_list":[]}],"custom_field_list":[]},"user_card_status":"NORMAL","has_active":true}
==========================
2016-12-23 10:43:57,421 [pool-9-thread-3] INFO com.huanyu.weixin.sdk.http.HttpClient 6969ef8818c34b34aeb86ea755f21e52 - Request:
==========================
GET http://dly-bl.jcrm.test.hd123.cn:9080/jcrm-server-card/rest/mbr/getByMobileNum/12345678901
==========================
2016-12-23 10:43:57,464 [pool-9-thread-3] INFO com.huanyu.weixin.sdk.http.HttpClient 6969ef8818c34b34aeb86ea755f21e52 - Response: 
==========================
200
{
  "errorCode" : 0,
  "message" : "ok"
}
==========================
2016-12-23 10:43:57,477 [pool-9-thread-3] INFO com.huanyu.mgate.core.weixin.WeixinEventHandler 6969ef8818c34b34aeb86ea755f21e52 - 推送给crm：test, json_data
2016-12-23 10:43:58,384 [pool-9-thread-3] INFO com.huanyu.mgate.core.weixin.WeixinEventHandler 6969ef8818c34b34aeb86ea755f21e52 - 绑定会员，租户: test, 会员ID: 89638865b0474a9cb5db3aea1b9bd839, 线下会员号: test_number_2
2016-12-23 10:43:58,403 [pool-9-thread-3] INFO com.huanyu.weixin.sdk.http.HttpsClient 6969ef8818c34b34aeb86ea755f21e52 - Request:
==========================
POST https://api.weixin.qq.com/card/code/get?access_token=DSJ-g_DErgipWWCqY-cOoicJn-UuwgFbDdZ-3AOCw4uRG6VyjlvXRKVs9lDnQo6hLjRoIlNW06i-UhJKAnmFq7T_apxgI-bpqRfv1V38PlPNe17ETBfXDjSSxQT-RSGcVYEcAKDMPV
{"check_consume":false,"code":"weixin_code","card_id":"weixin_card_id"}
==========================
2016-12-23 10:43:58,482 [pool-9-thread-3] INFO com.huanyu.weixin.sdk.http.HttpsClient 6969ef8818c34b34aeb86ea755f21e52 - Response: 
==========================
200
{"errcode":0,"errmsg":"ok","card":{"card_id":"weixin_card_id","begin_time":0,"end_time":4294967295,"bonus":0,"code":"weixin_code","membership_number":"test_number_1"},"openid":"weixin_open_id","can_consume":true,"user_card_status":"NORMAL"}
==========================
2016-12-23 10:43:58,483 [pool-9-thread-3] INFO com.huanyu.mgate.core.weixin.WeixinEventHandler 6969ef8818c34b34aeb86ea755f21e52 - 激活微信会员卡，租户: test, 卡号: weixin_code
2016-12-23 10:43:58,483 [pool-9-thread-3] INFO com.huanyu.weixin.sdk.http.HttpsClient 6969ef8818c34b34aeb86ea755f21e52 - Request:
==========================
POST https://api.weixin.qq.com/card/membercard/activate?access_token=DSJ-g_DErgipWWCqY-cOoicJn-UuwgFbDdZ-3AOCw4uRG6VyjlvXRKVs9lDnQo6hLjRoIlNW06i-UhJKAnmFq7T_apxgI-bpqRfv1V38PlPNe17ETBfXDjSSxQT-RSGcVYEcAKDMPV
{"membership_number":"test_number_2","code":"weixin_code","card_id":"weixin_card_id"}
==========================
2016-12-23 10:43:58,617 [pool-9-thread-3] INFO com.huanyu.weixin.sdk.http.HttpsClient 6969ef8818c34b34aeb86ea755f21e52 - Response: 
==========================
200
{"errcode":0,"errmsg":"ok"}
==========================
2016-12-23 10:43:58,618 [pool-9-thread-3] INFO com.huanyu.mgate.core.PublishServiceImpl 6969ef8818c34b34aeb86ea755f21e52 - mgate-crmService-queryAccount：租户Id:test,查询类型:crm_mbr_id,查询码:test_number_2
2016-12-23 10:43:58,733 [pool-9-thread-3] WARN com.huanyu.mgate.core.weixin.WeixinEventHandler 6969ef8818c34b34aeb86ea755f21e52 - 初始化会员weixin_code微信积分账户,积分数:0.00
2016-12-23 10:43:58,734 [pool-9-thread-3] INFO com.huanyu.weixin.sdk.http.HttpsClient 6969ef8818c34b34aeb86ea755f21e52 - Request:
==========================
POST https://api.weixin.qq.com/card/membercard/updateuser?access_token=DSJ-g_DErgipWWCqY-cOoicJn-UuwgFbDdZ-3AOCw4uRG6VyjlvXRKVs9lDnQo6hLjRoIlNW06i-UhJKAnmFq7T_apxgI-bpqRfv1V38PlPNe17ETBfXDjSSxQT-RSGcVYEcAKDMPV
{"record_bonus":"积分更新","notify_optional":{"is_notify_bonus":true},"bonus":0,"code":"weixin_code","card_id":"weixin_card_id"}
==========================
2016-12-23 10:43:58,850 [pool-9-thread-3] INFO com.huanyu.weixin.sdk.http.HttpsClient 6969ef8818c34b34aeb86ea755f21e52 - Response: 
==========================
200
{"errcode":0,"errmsg":"ok","result_bonus":0,"result_balance":0,"openid":"weixin_open_id"}
==========================
2016-12-23 10:43:58,879 [pool-9-thread-3] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 6969ef8818c34b34aeb86ea755f21e52 - test, weixin 处理 com.huanyu.mgate.core.weixin.ActiveCardEvent 耗时 1676 ms
2016-12-23 10:43:58,879 [pool-9-thread-3] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 6969ef8818c34b34aeb86ea755f21e52 - handle: test, MerchantAcceptOrder, 402880985ad4ba3c015ad50011720002, com.huanyu.mgate.core.weixin.ActiveCardEvent
2016-12-23 10:43:58,879 [pool-9-thread-3] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 6969ef8818c34b34aeb86ea755f21e52 - handle: test, alimerchantupdate, 402880985ad4ba3c015ad50011720002, com.huanyu.mgate.core.weixin.ActiveCardEvent
2016-12-23 10:43:58,879 [pool-9-thread-3] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 6969ef8818c34b34aeb86ea755f21e52 - handle: test, feifanMemberAsyncRegister, 402880985ad4ba3c015ad50011720002, com.huanyu.mgate.core.weixin.ActiveCardEvent
2016-12-23 10:43:58,880 [pool-9-thread-3] INFO com.huanyu.multitenant.cqrs.event.MultiTenantEventDispatcher 6969ef8818c34b34aeb86ea755f21e52 - 删除事件：402880985ad4ba3c015ad50011720002
  1. 分析日志
    由上述日志分析可见，数据库事件：402880985ad4ba3c015ad50011720002 经由多租户事件分发器：MultiTenantEventDispatcher 分发给多个事件监听处理器时，
    并发产生了两个线程（线程：pool-9-thread-3 和 线程：pool-9-thread-2）同时处理一个事件,业务关键在于 推送给crm：test, json_data 这一处，这里将
    导致将本系统同一份会员数据（同一个会员数据并发同步推送给crm系统）并发同步给crm系统，导致crm系统产生了两个会员（test_number_1 和 test_number_2）。
  2. 为了解决这种并发场景下的问题产生，需要给同步crm系统这块添加同步互斥锁，因为这是事件处理，性能可以适当降低要求，因此，使用 synchronized 来控制并发。

参考资料

Java 多线程 并发编程

JAVA多线程与并发学习总结

SQL 索引最左前缀原理

MySQL索引背后的数据结构及算法原理-最左前缀原理与相关优化

数据库索引的实现原理及查询优化

50种方法优化SQL Server