[阿里云][日志服务][数据加工][数据分析]基于日志服务数据加工分析Java异常日志

秒速五厘米 2023-02-18 15:26 41阅读 0赞

## 1. 本文要点(regex\_findall()、e\_regex()、e\_output()专题)： ##

*  正则解析复杂异常日志（一次性解析不出全部格式异常日志怎么办？）
 *  根据不同产品的Exception做数据清洗以及多目标分发
 *  对不同的产品的异常日志做数据分析

## 2. 背景 ##

**业务背景：**  
采集并脱敏了整个5月份的项目异常日志，准备使用日志服务数据加工做数据清洗以及分析。本案例是基于使用阿里云相关产品(OSS，RDS，SLS等)的SDK展开自身业务。  
**业务需求：**  
需要对异常日志做解析，将原始日志中时间、错误码、错误信息、状态码、产品信息、请求方法、出错行号提取出来。然后根据提取出来的不同产品信息做多目标分发处理。对清洗后的数据做异常日志数据分析。

## 3. 案例总体流程 ##

本案例中的所有异常日志全部是通过使用日志服务SDK上传到cloud\_product\_error\_log的logstore中，然后再经过数据加工清洗数据后投递到各自产品的logstore中，最后针对各个产品的异常日志做分析。具体流程如下：  
![undefined][]

## 4. 原始日志样例 ##

![undefined][undefined 1]  
原始日志中只有错误日志信息message，需要将其message中的一些重要信息解析出来。

## 5. 加工需求 ##

(1) 将message错误信息中的时间、错误码、状态码、产品信息、错误码信息、请求方法、出错行号提取出来  
(2) 根据提取出的产品信息对清洗后的数据进行多目标分发

具体需求流程如下图所示：  
![undefined][undefined 2]

## 6. 对异常日志数据进行解析和投递 ##

### 6.1 加工逻辑分析 ###

下图展示的是如何从原始异常日志经过数据加工得到解析后的日志信息（原始日志形式，预期日志形式），然后投递到不同logstore中，最后对不同产品的异常日志做数据分析。本案例中只对**SLS异常日志和OSS异常日志**做加工分析。  
![undefined][undefined 3]

### 6.2 加工操作 ###

经过以上对异常日志的分析以及加工流程的剖析，此时我们可以对异常日志加工进行实操（对于不熟悉如何使用日志服务数据加工的同学可以参考[基于日志服务(SLS)实现电商数据加工与分析][SLS]）。以下是具体的加工语法:

e_switch(
    	regex_match(v("message"), r"LogException"),e_compose(e_regex("message", "(?P<data_time>\S+\s\S+)\s(?P<error_code>[a-zA-Z]+)\s(?P<status>[0-9]+)\scom\.aliyun\.openservices\.log\.exception\.(?P<product_exception>[a-zA-Z]+)\:(?P<error_message>[a-zA-Z0-9:,\-\s]+)\.(\s+\S+\s\S+){5}\s+\S+\scom\.aliyun\.openservices\.log\.Client\.(?P<method>[a-zA-Z]+)\S+\s+\S+\stransformEvent\.main\(transformEvent\.java\:(?P<error_line>[0-9]+)\)"),e_drop_fields("message"),e_output("sls-error")),
    	regex_match(v("message"), r"OSSException"),e_compose(e_regex("message", "(?P<data_time>\S+\s\S+)\scom\.aliyun\.oss\.(?P<product_exception>[a-zA-Z]+)\:(?P<error_message>[a-zA-Z0-9,\s]+)\.\n\[ErrorCode\]\:\s(?P<error_code>[a-zA-Z]+)\n\[RequestId\]\:\s(?P<request_id>[a-zA-Z0-9]+)\n\[HostId\]\:\s(?P<host_id>[a-zA-Z-.]+)\n\S+\n\S+(\s\S+){3}\n\s+\S+\s+(.+)(\s+\S+){24}\scom\.aliyun\.oss\.OSSClient\.(?P<method>[a-zA-Z]+)\S+\s+\S+\stransformEvent\.main\(transformEvent\.java:(?P<error_line>[0-9]+)\)"),e_drop_fields("message"),e_output("oss-error"))
    )

点击预览效果如下所示：  
![undefined][undefined 4]  
上图表面加工语法能够正常解析异常日志，接下来需要进行保存加工任务操作。具体加工配置如下图：  
![undefined][undefined 5]  
**注意：**  
以上语法中的e\_output中的name参数需要与加工配置规则中的目标名称一一对应。更多用法请参考[e\_output语法注意事项][e_output]

### 6.3 语法详解 ###

其中涉及到的正则语法分组相关知识请移步[正则表达式-分组][-]  
(1) 首先使用regex\_match函数匹配出此条日志中是否有LogException如果匹配上则走解析sls异常日志的规则分支，如果匹配上OSSException则走解析OSS异常日志的规则分支。  
(2) 其次使用e\_regex正则解析函数解析相应的异常日志。  
(3) 最后删除原字段message信息，并投递到相应产品的logstore中。

其中本案例中正则解析日志详解是以解析SLS异常日志为例，具体如下  
![undefined][undefined 6]

## 7. 数据加工诊断 ##

当我们在解析日志的时候，时常会遇到一次性解析不出全部格式异常日志的情况。并且在加工预览页面只会预览一定量的数据，因此在加工预览页面不一定会提示出该正则解析不出的日志的情况。  
综上，我们可以通过查看**数据加工概览**（具体如何查看请参考[加工概览][SLS]）的方式查到具体是那一条日志没有解析出来，然后再调整我们的正则表达式。解析失败样例，如下图所示：  
![undefined][undefined 7]  
具体**异常详情的logging**如下：

{ 
        "message": "transform_regex: field value \"2020-05-04 08:45:07 ServerBusy 505 com.aliyun.openservices.log.exception.LogException:The server is busy, please try again later.\n at com.aliyun.openservices.log.Client.ErrorCheck(Client.java:2161)\n at com.aliyun.openservices.log.Client.SendData(Client.java:2312)\n at com.aliyun.openservices.log.Client.CreateConsumerGroup(Client.java:2190)\n at com.aliyun.openservices.log.Client.SendData(Client.java:2265)\n at com.aliyun.openservices.log.Client.GetCursor(Client.java:1123)\n at com.aliyun.openservices.log.Client.CreateConsumerGroup(Client.java:1100)\n at transformEvent.main(transformEvent.java:1950)\" cannot extract value with config \"(?P<data_time>\\S+\\s\\S+)\\s(?P<error_code>[a-zA-Z]+)\\s(?P<status>[0-9]+)\\scom\\.aliyun\\.openservices\\.log\\.exception\\.(?P<__topic__>[a-zA-Z]+)\\:(?P<error_message>[a-zA-Z0-9\\s:-]+)\\.(\\s+\\S+\\s\\S+){5}\\s+\\S+\\scom\\.aliyun\\.openservices\\.log\\.Client\\.(?P<method>[a-zA-Z]+)\\S+\\s+\\S+\\stransformEvent\\.main\\(transformEvent\\.java\\:(?P<error_line>[0-9]+)\\)\"",
        "processName": "MainProcess",
        "process": "1",
        "thread": "139873923098368",
        "levelname": "WARNING",
        "module": "regex_impl",
        "threadName": "ThreadPoolExecutor-0_1",
        "funcName": "__call__"
    }

从以上图例和具体信息可以看到，如果**正则解析失败会报WARNING级别日志**。此时的加工处理规则是跳过加工失败的日志继续往下加工，此过程中并不会影响到整个加工任务的执行（**只有ERROR级别的会影响到整个加工任务的消费**）。  
接下来主要关注message中的日志信息，看具体是那条日志或者那一类异常日志导致现有的正则规则加工失败。  
其message中的解析失败的日志和正则（logging中的正则表达式需要自己去掉多加的转义反斜杠）。

"""解析失败日志"""
    2020-05-04 08:45:07 ServerBusy 505 com.aliyun.openservices.log.exception.LogException:The server is busy, please try again later.\n    at com.aliyun.openservices.log.Client.ErrorCheck(Client.java:2161)\n    at com.aliyun.openservices.log.Client.SendData(Client.java:2312)\n    at com.aliyun.openservices.log.Client.CreateConsumerGroup(Client.java:2190)\n    at com.aliyun.openservices.log.Client.SendData(Client.java:2265)\n    at com.aliyun.openservices.log.Client.GetCursor(Client.java:1123)\n    at com.aliyun.openservices.log.Client.CreateConsumerGroup(Client.java:1100)\n    at transformEvent.main(transformEvent.java:1950)
    """正则表达式"""
    (?P<data_time>\S+\s\S+)\s(?P<error_code>[a-zA-Z]+)\s(?P<status>[0-9]+)\scom\.aliyun\.openservices\.log\.exception\.(?P<product_exception>[a-zA-Z]+)\:(?P<error_message>[a-zA-Z0-9\s:-]+)\.(\s+\S+\s\S+){ 5}\s+\S+\scom\.aliyun\.openservices\.log\.Client\.(?P<method>[a-zA-Z]+)\S+\s+\S+\stransformEvent\.main\(transformEvent\.java\:(?P<error_line>[0-9]+)\)

经过一步一步的查找验证，得出在解析error\_message中缺少了对有逗号情景的解析，因此此地方正则需要改善，具体改善如下：

"""解析失败error_message正则"""
    (?P<error_message>[a-zA-Z0-9\s:-]+)
    """完善后解析error_message正则"""
    (?P<error_message>[a-zA-Z0-9:,\-\s]+)

综上，经过我们不断的完善正则表达式，目前是能够成功解析各个不同类型的异常日志。接下来我们将进入数据分析阶段。

## 8. 异常日志数据分析 ##

下图是通过sql查询所展示数据仪表大盘：  
![undefined][undefined 8]  
基于加工后的异常日志（以SLS错误日志为例分析），在这里我们的需求有以下几方面：  
(1) 各个方法异常统计  
(2) 各个方法异常占比统计图  
(3) PutLogs错误信息  
(4) 各个方法调用报错每日level气泡图  
(5) 各个ErrorCode统计分析  
(6) 各个方法报错时间轴

### 8.1 各个方法异常统计和各个方法异常占比统计图 ###

为了方便查看那个方法出现错误次数最高和帮助我们定位业务调用的具体方法，因此我们先对各个方法出现的异常情况做一个统计。

* | SELECT COUNT(method) as m_ct, method GROUP BY method

这条语句表示的是统计每个调用方法出现异常的数量。  
下图表示的是在查询框里输入以上sql分析语句之后进入统计图表，然后点击条形图进行配置，method为X轴，m\_ct为Y轴。  
![undefined][undefined 9]  
通过上图分析可知总体情况，PutLogs调用出现异常的次数最多，其中GetCursor和DeleteConsumerGroup是出现异常的次数是最少的。  
此外，为了方便我们查看各个方法异常占比情况，我们可以基于以上的SQL做一个占比统计图，点击漏斗图，然后以method为分组列，m\_ct为数值列具体操作如下。  
![undefined][undefined 10]

### 8.2 PutLogs错误信息 ###

为了方便我们查看哪一类的错误信息是占比最大，帮助我们分析：  
(1) 需要自身业务需要改进的  
(2) 需要SLS帮忙调整的（如调整quota）  
(3) 需要深入项目中具体排查错误的（具体的error line）

* | SELECT error_message,COUNT(error_message) as ct_msg, method WHERE method LIKE 'PutLogs' GROUP BY error_message,method

点击矩形树图，然后以error\_message为分类和ct\_msg为数值列。  
![undefined][undefined 11]  
从上图中我们可知:  
(1) consumer group already exist、consumer group not exist、Logs must be less than or equal to 3 MB and 4096 entries等这些都是属于需要在项目中具体排查的错误  
(2) Read/ Write quota is exceeded这些是需要SLS调整quota的  
(3) 还有一些是需要调整自身业务的比如logstore/ project not exist看是否是因为一些业务原因而导致这些project被取消等等。

### 8.3 各个方法调用报错每日level气泡图 ###

为了方面我们查看每一天的各个调用方法出错频次，我们需要有一个直观的图来查看每一天的调用出错程度，这样我们可以更加直观的去看某一天的具体调用出错细节。

* | select date_format(data_time, '%Y-%m-%d') as day,COUNT(method) as count_method, case 
    when method = 'PullLogs' and COUNT(method) > 21800 then 3 when method = 'PullLogs' and COUNT(method)>21400 then 2 when method = 'PullLogs' and COUNT(method)>21100 then 1 
    when method = 'CreateConsumerGroup' and COUNT(method) > 21900 then 3
    when method = 'CreateConsumerGroup' and COUNT(method) > 21700 then 2 when method = 'CreateConsumerGroup' and COUNT(method) > 21550 then 1 
    when method = 'PutLogs' and COUNT(method)>43900 then 3 when method = 'PutLogs' and COUNT(method)>43300 then 2 when method = 'PutLogs' and COUNT(method)>42900 then 1 
    when method = 'DeleteConsumerGroup' and COUNT(method)>7440 then 3 when method = 'DeleteConsumerGroup' and COUNT(method)>7330 then 2 when method = 'DeleteConsumerGroup' and COUNT(method)>7320 then 1 
    when method = 'GetCursor' and COUNT(method)>7350 then 3 when method = 'GetCursor' and COUNT(method)>7200 then 2 when method = 'GetCursor' and COUNT(method)>7150 then 1
    else 0 end as level,  method group by day, method ORDER BY day asc

其中如果一天PullLogs出错次数大于21800则属于level3级别的，大于21400则属于level2级别，大于21100则属于level1，否则属于level0，然后再跟据每一天每个方法做聚合操作。  
点击气泡图，其中以day为X轴，method为Y轴。  
![undefined][undefined 12]  
从上图中可以明显的知道每一天的每个方法的出现异常的level值，针对某一天level值高的可以对其做具体的错误查看到底是什么原因引起的。

### 8.4 各个ErrorCode统计分析 ###

统计各个error\_code出现的错误次数，能够更好的帮助我们查看哪些是因为ServerBusy，哪些是因为ParameterInvalid等不同的原因引起的异常，从而更好的定位异常原因。

* | SELECT error_code,COUNT(error_code) as count_code GROUP BY error_code

点击折线图，以error\_code为X轴，以count\_code为Y轴  
![undefined][undefined 13]  
基于上图可知WriteQuotaExceed出现异常次数最多，可以查查那个project下的logstore被限制，然后咨询相关的产品技术支持。

### 8.5 各个方法报错时间轴 ###

设置报错时间轴，可以实时的查看调用接口异常信息。

* | SELECT date_format(data_time, '%Y-%m-%d %H:%m:%s') as date_time,status,product_exception,error_line, error_message,method ORDER BY date_time desc

![undefined][undefined 14]  
基于上图所示，我们可以对重要的接口出现异常做标注高亮显示，以便我们能够快速识别出重要接口异常情况。

## 9. 总结 ##

对于其他的产品的异常日志，我们也可以使用同样的方法加工清洗投递，然后SQL分析自己所关心的业务指标。

[undefined]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9pbnRyYW5ldHByb3h5LmFsaXBheS5jb20vc2t5bGFyay9sYXJrLzAvMjAyMC9wbmcvMjA4MjMwLzE1OTE4NzQ5NTI0NDMtNDU5YTVmZmEtNzYxYi00ODQ3LWFiMzItNjllN2UwMzkzNjg4LnBuZw?x-oss-process=image/format,png
[undefined 1]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9pbnRyYW5ldHByb3h5LmFsaXBheS5jb20vc2t5bGFyay9sYXJrLzAvMjAyMC9wbmcvMjA4MjMwLzE1OTE5MzQ3ODk3MzktZDM0ZTUzM2UtMGZlNy00ODJhLTgwZGItZmQ5OWZlYmE3NGNhLnBuZw?x-oss-process=image/format,png
[undefined 2]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9pbnRyYW5ldHByb3h5LmFsaXBheS5jb20vc2t5bGFyay9sYXJrLzAvMjAyMC9wbmcvMjA4MjMwLzE1OTIyMDMwMDQxNTktOTM4ZGU0OWQtNWU3Ny00NWNkLWJlMDMtNzZiN2Y5NThmMzlkLnBuZw?x-oss-process=image/format,png
[undefined 3]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9pbnRyYW5ldHByb3h5LmFsaXBheS5jb20vc2t5bGFyay9sYXJrLzAvMjAyMC9wbmcvMjA4MjMwLzE1OTE5MzUyNzk3NzQtNzQ1ZGMxYWEtMmQ2OS00MjFhLTliMTgtMDg0MWNmZDdlODQ0LnBuZw?x-oss-process=image/format,png
[SLS]: https://yq.aliyun.com/articles/726073?spm=a2c4e.11163080.searchblog.23.40772ec1U6n69b
[undefined 4]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9pbnRyYW5ldHByb3h5LmFsaXBheS5jb20vc2t5bGFyay9sYXJrLzAvMjAyMC9wbmcvMjA4MjMwLzE1OTE5NDM1NzYwNDctYWVkNzVkN2EtOWI3My00ZDgxLWFlZDMtOWY3OWUwYTczMjM2LnBuZw?x-oss-process=image/format,png
[undefined 5]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9pbnRyYW5ldHByb3h5LmFsaXBheS5jb20vc2t5bGFyay9sYXJrLzAvMjAyMC9wbmcvMjA4MjMwLzE1OTE5NDQyNjU2NDQtYmEwNTI5MGMtNjFiYS00ODY3LTk1NGUtNDE2NGNkNzdkNTBkLnBuZw?x-oss-process=image/format,png
[e_output]: https://help.aliyun.com/document_detail/125484.html?spm=a2c4g.11186623.2.14.101863304JzxcS#title-9em-83k-feg
[-]: https://help.aliyun.com/document_detail/129386.html?spm=a2c4g.11186623.6.937.6db84514toi5A6#title-5oi-2m0-9wo
[undefined 6]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9pbnRyYW5ldHByb3h5LmFsaXBheS5jb20vc2t5bGFyay9sYXJrLzAvMjAyMC9wbmcvMjA4MjMwLzE1OTI0Njk1NzM0MTEtY2I2MzVjYWEtNDZjZC00Y2RhLTg0NTctNzY3NzE4YmM5M2NlLnBuZw?x-oss-process=image/format,png
[undefined 7]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9pbnRyYW5ldHByb3h5LmFsaXBheS5jb20vc2t5bGFyay9sYXJrLzAvMjAyMC9wbmcvMjA4MjMwLzE1OTE5NTI5Njg0NzMtYzBmODU2ZGUtYjE4ZC00ZTliLThkMWEtZjA2YTdkMTBjMmQ5LnBuZw?x-oss-process=image/format,png
[undefined 8]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9pbnRyYW5ldHByb3h5LmFsaXBheS5jb20vc2t5bGFyay9sYXJrLzAvMjAyMC9wbmcvMjA4MjMwLzE1OTIyMDUyODUxMTYtNzg5YzRiOGMtODBlYS00ZmMyLWFmODMtMTVmNDFlZWNlOWIwLnBuZw?x-oss-process=image/format,png
[undefined 9]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9pbnRyYW5ldHByb3h5LmFsaXBheS5jb20vc2t5bGFyay9sYXJrLzAvMjAyMC9wbmcvMjA4MjMwLzE1OTIxOTA2OTQzMzktMzU1OGI1YzEtM2E1OC00ZGZkLThkMjItM2JjN2UyYmYxNDUxLnBuZw?x-oss-process=image/format,png
[undefined 10]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9pbnRyYW5ldHByb3h5LmFsaXBheS5jb20vc2t5bGFyay9sYXJrLzAvMjAyMC9wbmcvMjA4MjMwLzE1OTIxOTEyMjk4MDgtZWE5OGMwNDgtOGNjNC00MjI4LTg0ZGEtMmUyM2E4ODM3NjEyLnBuZw?x-oss-process=image/format,png
[undefined 11]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9pbnRyYW5ldHByb3h5LmFsaXBheS5jb20vc2t5bGFyay9sYXJrLzAvMjAyMC9wbmcvMjA4MjMwLzE1OTIxOTE4ODExNjUtYjk3YTBkYTctYjBiYi00N2Y3LTgxOGMtODAwYmE1ZTY2YWIwLnBuZw?x-oss-process=image/format,png
[undefined 12]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9pbnRyYW5ldHByb3h5LmFsaXBheS5jb20vc2t5bGFyay9sYXJrLzAvMjAyMC9wbmcvMjA4MjMwLzE1OTIxOTM1MTg3NjQtNzlmMzA5YWMtNzU4OS00NTZhLTllMjctNDI0MzIyYWVmZjJiLnBuZw?x-oss-process=image/format,png
[undefined 13]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9pbnRyYW5ldHByb3h5LmFsaXBheS5jb20vc2t5bGFyay9sYXJrLzAvMjAyMC9wbmcvMjA4MjMwLzE1OTIxOTQyNTMwNDgtMGZiOWE3ZjYtNjEwMy00Mjc0LTkwNzItN2U5ZjFlNTVlNWRjLnBuZw?x-oss-process=image/format,png
[undefined 14]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9pbnRyYW5ldHByb3h5LmFsaXBheS5jb20vc2t5bGFyay9sYXJrLzAvMjAyMC9wbmcvMjA4MjMwLzE1OTIyMDE1MzA0MDgtZWVkYWVlMGEtYzgxMC00ZWQ2LWE4ODEtMDZmYjdiZDUzMDZlLnBuZw?x-oss-process=image/format,png