1、问题描述
先说下我们生产环境的部署情况 azkaban-exec部署在prod11、prod12两台机器上,这两台都是物理机,同时还不部署了namenode、resourcemanafer、historyserver、hiverserver、metastore等
正常情况应该是两个azkaban-exec节点都能执行任务,但是昨天发现居然只有一个节点在执行任务
可以通过执行sql语句进行验证:
select * from executors;
+----+------------------------+-------+--------+
| id | host | port | active |
+----+------------------------+-------+--------+
| 36 | hdfs-prod12.yingzi.com | 12321 | 1 |
| 35 | hdfs-prod11.yingzi.com | 12321 | 1 |
+----+------------------------+-------+--------+
#查看2022-02-22 00:00:00以后任务执行情况
select executor_id,count(1),FROM_UNIXTIME(max(update_time)/1000) from execution_flows where executor_id in (35,36) and update_time>=1645459200000 group by executor_id;
+-------------+----------+--------------------------------------+
| executor_id | count(1) | FROM_UNIXTIME(max(update_time)/1000) |
+-------------+----------+--------------------------------------+
| 35 | 41 | 2022-02-22 23:28:19.0980 |
| 36 | 16168 | 2022-02-23 17:38:34.3840 |
+-------------+----------+--------------------------------------+
可以看出prod11最近执行任务的时间是2022-02-22 23:28:19,并且22号一天也只执行了41次
再把时间往前推,发现prod11之前也是有问题的,只偶尔执行极少的任务。
虽然业务没有受到影响,但是全部离线任务都只能在prod12上执行,会导致prod12压力过大
而且会存在单点问题,万一prod12出问题,那离线任务就没法执行,影响业务了
2、发现-解决问题过程
这个问题其实早前就已经有端倪了,从年前开始,生产环境就会断断续续收到prod12的hiverserver2服务监控告警。 不过告警内容只是检测hiveserver2偶尔响应超时,查看应用JVM监控,并没有发现应用有什么异样。 hiverserver2本身是有部署多个节点的,并没有对任务执行产生影响。 而且这个告警很久才发生一次,所以并没有引起我们足够的重视。
2022-02-23凌晨,发生了多次hiverserver2的超时报警,都在prod12这台机 感觉事情没这么简单,于是开始重视起来 比较奇怪的是,hiveserver2也是部署在prod11和prod12节点,为啥都是只有prod12报,prod11从来不报的 对比两台机器的node监控,发现一些问题
prod11 CPU使用率: prod12 CPU使用率: prod11线程数监控: prod12线程数监控: prod11每秒fork进程数: prod12每秒fork进程数:
可以看到:
- CPU使用率prod11只有5左右,prod12峰值则高达60-70
- prod12线程数差不多有prod11的两倍
- 还有每秒种fork的进程数,差别更大:prod11只有30不到,prod12最大都超过200了
这两台部署的服务是相近的,为何会差距这么大呢? 每秒fork的进程数,第一时间想到的就是azkaban 因为azkaban-exec执行任务都是通过调用shell命令的方式,每次shell调用都是fork新的进程
于是对azkaban进行检查,程序本身状态是很健康的。 但是通过sql查询任务执行情况,发现prod11基本不执行任务的 此时基本可以确定是因为任务全部在prod12执行,导致这台机压力过大,进而影响了hiveserver2的响应
至于prod11为什么不执行任务(偶尔执行),则没有太好的思路 只看监控,应用本身是很健康的 于是只能去看azkaban代码,分析可能是哪一环节存在问题,再进行排查
排查了半天,并没有很大进展 尝试重启azkaban服务 没有意外,果然重启并不能解决问题。
还是只能继续啃代码,结合开发环境做实验来进行理解。 终于定位到问题点在哪里。
azkaban默认任务执行采用的推模式,由azkaban-web选择合适的executor,通过调用azkaban-exec http接口的方式,把任务"推"给executor执行 关键的核心就在于选择executor的代码,比较重要的是几个azkaban.executorselector.comparator前缀的配置。 查看生产环境azkaban-web的配置如下:
azkaban.executorselector.comparator.NumberOfAssignedFlowComparator=1
azkaban.executorselector.comparator.Memory=6
azkaban.executorselector.comparator.LastDispatched=1
azkaban.executorselector.comparator.CpuUsage=3
这里几个配置分别指:正在执行的任务数、系统可用内存、最近执行任务时间、CPU使用率等几个指标,配置的数字表示指标权重 大致策略是,把各个executor的指标进行对比,并根据权重求和,最终再进行对比,选择分数最高的那个
这几个指标的默认权重都是1,但是不知道是谁把权重调整成6了,已无从考究。 比较要命的是,prod11的内存占用,大部分时间都高于prod12(虽然实际内存都很充足) 因为内存的权重太高,导致内存基本成了选择executor的决定性因素,所以大部分任务都分发到prod12执行,和事实相符
因为azkaban是直接部署在物理机,混合部署了多个应用,所以单纯的根据内存和CPU来确定executor的优先级,其实是不靠谱的 所以我们决定把Memory和CpuUsage这两个指标去掉 直接注释掉相应的配置然后重启azkaban-web,问题得到解决
执行sql查看重启以后每个小时的任务执行情况:
select t.time_hour,sum(case executor_id when 38 then num else 0 end) num_prod11,sum(case executor_id when 36 then num else 0 end) num_prod12 from
(
select executor_id,FROM_UNIXTIME(update_time/1000,'%Y-%m-%d %H') time_hour,count(1) num from execution_flows where executor_id in (38,36) and update_time>=1645675200000 group by executor_id,FROM_UNIXTIME(update_time/1000,'%Y-%m-%d %H')
)t group by t.time_hour;
+---------------+------------+------------+
| time_hour | num_prod11 | num_prod12 |
+---------------+------------+------------+
| 2022-02-24 12 | 164 | 147 |
| 2022-02-24 13 | 178 | 134 |
| 2022-02-24 14 | 159 | 151 |
| 2022-02-24 15 | 153 | 163 |
| 2022-02-24 16 | 159 | 134 |
+---------------+------------+------------+
可以看到,两个节点都会执行任务了,基本比较平均 偶尔有些差异,推测是任务之间差异,有些大任务执行比较耗时,执行这些大任务的节点,执行的任务数相应也会降低。
3、总结&改进
1、一切的异常现象都是有原因的,后续遇到监控报警一定要重视,探寻背后的真相
2、目前我们大数据的部署模式,基本都是多个应用服务混合部署在一台物理机的,会存在不同进程之间资源竞争,互相影响 尤其像azkaban这种,会有大量短小的子进程,很难进行问题排查 后续增加服务器进程监控,便于观察 同时也要增加对进程的资源管控
3、azkaban需增加任务执行情况的监控,防止后面又出现任务分发不均衡的问题
4、azkaban除了推模式还有拉模式,相对于推,拉模式可能更有优势,后续进行研究
|