# 075. 将缓存预热解决方案的代码运行后观察效果以及调试和修复所有的 bug
本章节，视频中花费了一小时的时间调流程，出现 bug 的地方是 topn 算法有问题 和 zk 写数据没有先创建节点导致的。还有一部分是日志打的不如意；
这些 bug 导致该视频耗时 50 多分钟，幸好，本人前面的笔记，topn 写完是调试过的，所以问题不大
本章就是来测试之前的整个流程：
- 提交 HotProductTopology 到 storm 集群中
- 访问 ngxin 分发服务，让访问日志到达 kafka 中
- 观察 HotProductTopology 统计日志
- 通过 zkCli.sh 查看对应节点数据是否正常
- 重启动缓存服务，触发缓存预热，查看缓存预热日志是否正常
由于 nginx 分发层的逻辑是需要调用缓存服务的， 而之前缓存预热的是放在了项目启动时，所以这里还是按照视频中把缓存预热入口， 卸载一个 controller 中，方便这里测试
# 运行 HotProductTopology 并观察日志
打包的时候报错
Errors occurred while build effective model from E:\SoftwareDevelop\Repository\caches\modules-2\files-2.1\log4j\log4j\1.2.15\a09f05bb79a0acabbe979f67ed4fbbbc07a368c1\log4j-1.2.15.pom:
'build.plugins.plugin[io.spring.gradle.dependencymanagement.org.apache.maven.plugins:maven-antrun-plugin].dependencies.dependency.scope' for junit:junit:jar must be one of [compile, runtime, system]
but is 'test'. in log4j:log4j:1.2.15
1
2
3
4
2
3
4
运行依赖检查
H:\dev\project\mrcode\cache-pdp\eshop-storm>gradle dependencyInsight --dependency jmxtools
\--- log4j:log4j:1.2.15
+--- com.101tec:zkclient:0.3
| \--- org.apache.kafka:kafka_2.9.2:0.8.1.1
| \--- compileClasspath
\--- org.apache.zookeeper:zookeeper:3.4.5
+--- compileClasspath
+--- org.apache.kafka:kafka_2.9.2:0.8.1.1 (*)
\--- com.101tec:zkclient:0.3 (*)
1
2
3
4
5
6
7
8
9
10
11
2
3
4
5
6
7
8
9
10
11
发现还依赖了 log4j，之前排除了一个，看来是引入了 zk 引起的传递依赖，需要再排除下
compile ('org.apache.kafka:kafka_2.9.2:0.8.1.1'){
exclude group: 'org.slf4j', module: 'slf4j-log4j12'
exclude group: 'log4j', module: 'log4j'
}
compile ('org.apache.zookeeper:zookeeper:3.4.5'){
exclude group: 'org.slf4j', module: 'slf4j-log4j12'
exclude group: 'log4j', module: 'log4j'
}
1
2
3
4
5
6
7
8
2
3
4
5
6
7
8
storm jar eshop-storm-1.0.0.jar cn.mrcode.cachepdp.eshop.storm.HotProductTopology HotProductTopology
1
启动后发现卡主了
[root@eshop-cache01 storm]# storm jar eshop-storm-1.0.0.jar cn.mrcode.cachepdp.eshop.storm.HotProductTopology HotProductTopologyxxxxxx-Dstorm.dependency.jars= -Dstorm.dependency.artifacts={} cn.mrcode.cachepdp.eshop.storm.HotProductTopology HotProductTopology
watch event：SyncConnected
zookeeper 已连接
就卡在这个地方了
1
2
3
4
2
3
4
在本地启动发现同样被卡在这个地方；最后发现只要 new ZooKeeper 的时候使用 内部类 匿名内部类 new Watcher()，就会卡主，而使用拉姆达表达式就不会，不知道是怎么回事；看了视频中的代码之后，最终测试出，问题出在单例的获取上，只能使用静态内部类的方式 延迟获取实例，直接一上来就 new 就会卡主；最终修改为下面这样了
package cn.mrcode.cachepdp.eshop.storm;
import org.apache.zookeeper.CreateMode;
import org.apache.zookeeper.KeeperException;
import org.apache.zookeeper.WatchedEvent;
import org.apache.zookeeper.Watcher;
import org.apache.zookeeper.ZooDefs;
import org.apache.zookeeper.ZooKeeper;
import org.apache.zookeeper.data.Stat;
import java.io.IOException;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.TimeUnit;
/**
* ${todo}
*
* @author : zhuqiang
* @date : 2019/5/7 22:37
*/
public class ZooKeeperSession {
private ZooKeeper zookeeper;
private CountDownLatch connectedSemaphore = new CountDownLatch(1);
private ZooKeeperSession() {
String connectString = "192.168.99.170:2181,192.168.99.171:2181,192.168.99.172:2181";
int sessionTimeout = 5000;
try {
// 异步连接，所以需要一个 org.apache.zookeeper.Watcher 来通知
// 由于是异步，利用 CountDownLatch 来让构造函数等待
zookeeper = new ZooKeeper(connectString, sessionTimeout, new Watcher() {
@Override
public void process(WatchedEvent event) {
Watcher.Event.KeeperState state = event.getState();
System.out.println("watch event：" + state);
if (state == Watcher.Event.KeeperState.SyncConnected) {
System.out.println("zookeeper 已连接");
connectedSemaphore.countDown();
}
}
});
} catch (IOException e) {
e.printStackTrace();
}
try {
connectedSemaphore.await();
} catch (InterruptedException e) {
e.printStackTrace();
}
System.out.println("zookeeper 初始化成功");
}
/**
* 获取分布式锁
*/
public void acquireDistributedLock(String path) {
byte[] data = "".getBytes();
try {
// 创建一个临时节点，后面两个参数一个安全策略，一个临时节点类型
// EPHEMERAL：客户端被断开时，该节点自动被删除
zookeeper.create(path, data, ZooDefs.Ids.OPEN_ACL_UNSAFE, CreateMode.EPHEMERAL);
System.out.println("获取锁成功 [path=" + path + "]");
} catch (Exception e) {
e.printStackTrace();
// 如果锁已经被创建，那么将异常
// 循环等待锁的释放
int count = 0;
while (true) {
try {
TimeUnit.MILLISECONDS.sleep(20);
// 休眠 20 毫秒后再次尝试创建
zookeeper.create(path, data, ZooDefs.Ids.OPEN_ACL_UNSAFE, CreateMode.EPHEMERAL);
} catch (Exception e1) {
// e1.printStackTrace();
count++;
continue;
}
System.out.println("获取锁成功 [path=" + path + "] 尝试了 " + count + " 次.");
break;
}
}
}
/**
* 释放分布式锁
*/
public void releaseDistributedLock(String path) {
try {
zookeeper.delete(path, -1);
} catch (InterruptedException e) {
e.printStackTrace();
} catch (KeeperException e) {
e.printStackTrace();
}
}
/**
* 写节点数据
*/
public void setNodeData(String path, String data) {
try {
Stat exists = zookeeper.exists(path, false);
if (exists == null) {
// 节点不存，先创建 PERSISTENT 持久连接
zookeeper.create(path, data.getBytes(), ZooDefs.Ids.OPEN_ACL_UNSAFE, CreateMode.PERSISTENT);
return;
}
zookeeper.setData(path, data.getBytes(), -1);
} catch (KeeperException e) {
e.printStackTrace();
} catch (InterruptedException e) {
e.printStackTrace();
}
}
public String getNodeData(String path) {
try {
return new String(zookeeper.getData(path, false, new Stat()));
} catch (KeeperException e) {
e.printStackTrace();
} catch (InterruptedException e) {
e.printStackTrace();
}
return null;
}
/**
* 封装单例的静态内部类
*
* @author Administrator
*/
private static class Singleton {
private static ZooKeeperSession instance;
static {
instance = new ZooKeeperSession();
}
public static ZooKeeperSession getInstance() {
return instance;
}
}
/**
* 获取单例
*/
public static ZooKeeperSession getInstance() {
return Singleton.getInstance();
}
public static void main(String[] args) throws InterruptedException {
ZooKeeperSession instance = ZooKeeperSession.getInstance();
}
}
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
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
# 测试流程
经过几个小时的折腾，代码层面的问题解决之后，提交到了 storm 中；
在后端服务未启动的情况下访问 :http://eshop-cache03/product?method=product&productId=1&shopId=1
浏览器中会显示 500 错误，是因为 kafka 访问日志上报了，但是后面的逻辑去 缓存服务获取 缓存连接不上缓存服务，导致 500 错误。
这个时候查看一下 storm 日志，发现正常在统计了
然后启动缓存服务，触发缓存预热任务
获取锁成功 [path=/hot-product-task-lock-5]
at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151)
at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1180)
预热缓存信息：ProductInfo{id=1, name='iphone7手机', price=5599.0, pictureList='a.jpg,b.jpg', specification='iphone7的规格', service='iphone7的售后服务', color='红色,白色,黑色', size='5.5', shopId=1, modifyTime=Mon May 13 22:00:00 CST 2019}
at cn.mrcode.cachepdp.eshop.cache.ZooKeeperSession.getNodeData(ZooKeeperSession.java:178)
at cn.mrcode.cachepdp.eshop.cache.prewarm.CachePrewarmThread.run(CachePrewarmThread.java:42)
预热缓存信息：ProductInfo{id=3, name='iphone7手机', price=5599.0, pictureList='a.jpg,b.jpg', specification='iphone7的规格', service='iphone7的售后服务', color='红色,白色,黑色', size='5.5', shopId=1, modifyTime=Mon May 13 22:00:00 CST 2019}
获取锁成功 [path=/hot-product-task-lock-5]
1
2
3
4
5
6
7
8
9
10
2
3
4
5
6
7
8
9
10
从日志看来，的确从 zk 获取到了日志信息，
# storm 进程老是消失问题
# 重启发现一会就进程又没有了
storm supervisor >/dev/null 2>&1 &
# 最后通过 storm supervisor 启动，查看打印的日志
# 发现是加载了 storm-core-1.1.0.jar 的 jar 包，报错 log4j 日志问题
# 可能这个包是之前的，不知道为什么没有更新到
# 手动删除该 jar 包
rm -rf /usr/local/storm/lib/storm-core-1.1.0.jar
# 重启 storm 相关进程
storm supervisor >/dev/null 2>&1 &
storm logviewer > /dev/null 2>&1 &
1
2
3
4
5
6
7
8
9
10
11
2
3
4
5
6
7
8
9
10
11
能正常启动了；特别注意一件事情，在分布式系统中，记得同步时间， 因为学习这个课程是断断续续的，休眠之后，时间就停止了。
# 本节总结
血的教训，视频中花费了 1 小时时间调试 bug。 而我则花费了 4 个小时。问题总结如下：
- topn 算法部分写完自己本地测试过了
- 但是后续的 zk 分段存储和商品预热写完没有在本地测试，导致 zk 初始化在不同 jdk 版本下出现问题。
- storm 打包排除日志文件有点变态，很不方便
- storm 服务器时间不同步
- zk 操作在这个代码中很粗糙，哪里都在打印异常。所以这里主要还是学习思想，而不是代码
最后还好，自己坚持把这个流程跑通了。