记一次Spark sql3.0任务耗时3小时 优化到30分钟总结

1、现象

任务A耗时最近从1个小时逐渐增长为3个小时，导致数据延迟。

2、问题分析

2.1、耗时分析

进入Spark UI界面查看，找到耗时最长的Job, 进入耗时最长的Stage, 观察耗时指标的最大值，中位数，发现一半以上的task任务，耗时都在2-3小时，这是导致整体任务耗时久的主要原因。

2.2、根因分析

进一步查看task的stdout日志，发现频繁有error日志产生，且error日志到下次info日志数据，间隔了5分钟左右。查看其它task也存在一样问题。

2022-08-23 03:56:07, 684 | INFO | Executor task launch worker for task 468.0 in stage 4.0 (TID 3035) | UDF Gener i cUDFFromUtcTimestamp conf get hive. is. time. zone. compatible is true | org. apache. hadoop. hive. ql. udf. generic. Generi cUDFFromlteT
2022-08-23 03:56:07, 701 | INFO | Executor task launch worker for task 468.0 in stage 4.0 (TID 3035) | UDF GenericUDFToUnixTimeStamp conf get hive. is. time. zone. compatible is true | org. apache. hadoop. hive. gl. udf. generic. GenericUDFToUnixTin
2022-08-23 03:56:07, 714 | INFO Executor task launch worker for task 468.0 in stage 4.0 (TID 3035) | UDF GenericUDFToUnixTimeStamp conf get hive. is. time. zone. compatible is true org. apache. hadoop. hive. ql. udf. generic. GenericUDFToUnixTii
2022-08-23 03:56:15,435 | ERROR | Executor task launch worker for task 468.0 in stage 4.0 (TID 3035) | IOException | com. ***. platform. bi. udf. common. GeolpDistrictUDFy3. <init>(GeolpDistrictUDFy3. java: 102)
2022-08-23 03:56:20,208 | ERROR | Executor task launch worker for task 468.0 in stage 4.0 (TID 3035) | IOException | com. ***. platform. bi. udf. common. GeolpDistrictUDFv3. <init>(GeolpDistrictUDFy3. java: 102)
eUZe-Ue-23 Us Ur U4, 592 ERRUR | SIGIERM handler RECEIVED SIGHAL TERM org. apache. spark. util. signalUtils}. panontunpregi sterLogger}eloignalUtils. scala'4s/}
shutdown-hook-O | Finish closing filesystem instance for uri: obs: //obs-onedata-mrsedm3az—dren | org. apache. hadoop. fs. obs. OBSFileSystem. close (OBSFileSystem. java:1727)
2022-08-23 08:07:04,617 | INFO
2022-08-23 08:07:04,617 | INFO | shutdown-hook-O | Finish closing filesystem instance for uri: obs://obs~onedata-mrscommon-dren | org. apache. hadoop. fs. obs. OBSFileSystem. close(OBSFileSystem. java: 1727)
1
2
3
4
5
6
7
8
9

因此猜想是error日志问题导致的问题，进一步定位error日志位置，发现是调用了GeolpDistrictUDFv3这个udf函数报的错误。
该函数功能是ip转国家，且只接受合法ip。 如果是不合法ip，就会报错，且返回NULL。

由于我们底层ip数据量很大，因此怀疑存在不合法ip，导致出现大量报错日志，该步骤存在写入错误日志的IO耗时，从而增加task的耗时。

3、验证

于是查询表中不合法ip记录数，发现存在1600万这种数据，针对不合法ip,我们选择不调用udf函数，直接赋值NULL，从而避免error日志产生。修改如下：

if(user_ip_addr rlike '^(\\d+\\.\\d+\\.\\d+\\.\\d+)$',bicoredata.GeoIpDistrictUDFv2(user_ip_addr,1),null) 
1

4、优化后效果

(1) task日志中无error日志
(2）任务总体耗时从3小时减少到30分钟内。