导航：首页 > 服务器 >

如何使用AWK规整KyLin日志

发表于：2025-12-01 作者：千家信息网编辑

千家信息网最后更新 2025年12月01日，本篇内容主要讲解"如何使用AWK规整KyLin日志"，感兴趣的朋友不妨来看看。本文介绍的方法操作简单快捷，实用性强。下面就让小编来带大家学习"如何使用AWK规整KyLin日志"吧!我们需要解析Kyli

千家信息网最后更新 2025年12月01日如何使用AWK规整KyLin日志

本篇内容主要讲解"如何使用AWK规整KyLin日志"，感兴趣的朋友不妨来看看。本文介绍的方法操作简单快捷，实用性强。下面就让小编来带大家学习"如何使用AWK规整KyLin日志"吧!

我们需要解析Kylin的日志,获取查询的相关信息.
但是Kylin的日志是并发写的,也就是并发情况下,查询日志会有交叉。
另外,Kylin汇总的行需要提取出来
最后,涉及SQL的行，需要把多行合并为一行。

KyLin原始日志如下

2018-06-22 18:17:05,341 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] service.QueryService:428 : Using project: h_test
2018-06-22 18:17:05,342 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] service.QueryService:429 : The original query: SELECT
O_M_T_STUDENT.USER_NAME as O_M_T_STUDENT_USER_NAME
,O_M_T_STUDENT.CITY as O_M_T_STUDENT_CITY
,O_M_T_STUDENT.ID as O_M_T_STUDENT_ID
,O_M_T_STUDENT.SEX as O_M_T_STUDENT_SEX
,O_M_T_STUDENT.PROVINCE as O_M_T_STUDENT_PROVINCE
,O_M_T_SCORE.USER_ID as O_M_T_SCORE_USER_ID
,O_M_T_SCORE.SUBJECT_ID as O_M_T_SCORE_SUBJECT_ID
,O_M_T_SUBJECT.ID as O_M_T_SUBJECT_ID
,O_M_T_SUBJECT.SUBJECT_NAME as O_M_T_SUBJECT_SUBJECT_NAME
,O_M_T_SCORE.SCORE as O_M_T_SCORE_SCORE
FROM ODS.O_M_T_SCORE as O_M_T_SCORE
LEFT JOIN ODS.O_M_T_STUDENT as O_M_T_STUDENT
ON O_M_T_SCORE.USER_ID = O_M_T_STUDENT.ID
LEFT JOIN ODS.O_M_T_SUBJECT as O_M_T_SUBJECT
ON O_M_T_SCORE.SUBJECT_ID = O_M_T_SUBJECT.ID
WHERE 1=1 LIMIT 5000
2018-06-22 18:17:05,345 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] service.QueryService:893 : Setting current statement's max rows to 0
2018-06-22 18:17:05,360 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] routing.QueryRouter:58 : Find candidates by table ODS.O_M_T_SCORE and project=h_test : CUBE[name=CubeT_1]
2018-06-22 18:17:05,361 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] routing.QueryRouter:51 : Applying rule: class org.apache.kylin.query.routing.rules.RemoveBlackoutRealizationsRule, realizations before: [CUBE[name=CubeT_1]], realizations after: [CUBE[name=CubeT_1]]
2018-06-22 18:17:05,361 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] routing.QueryRouter:51 : Applying rule: class org.apache.kylin.query.routing.rules.RemoveUncapableRealizationsRule, realizations before: [CUBE[name=CubeT_1]], realizations after: [CUBE[name=CubeT_1]]
2018-06-22 18:17:05,361 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] rules.RealizationSortRule:40 : CUBE[name=CubeT_1] priority 1 cost 14200.
2018-06-22 18:17:05,362 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] routing.QueryRouter:51 : Applying rule: class org.apache.kylin.query.routing.rules.RealizationSortRule, realizations before: [CUBE[name=CubeT_1]], realizations after: [CUBE[name=CubeT_1]]
2018-06-22 18:17:05,362 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] routing.QueryRouter:75 : The realizations remaining: [CUBE[name=CubeT_1]],and the final chosen one for current olap context 0 is CUBE[name=CubeT_1]
2018-06-22 18:17:05,373 DEBUG [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] enumerator.OLAPEnumerator:108 : query storage...
2018-06-22 18:17:05,373 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] cube.RawQueryLastHacker:43 : No group by and aggregation found in this query, will hack some result for better look of output...
2018-06-22 18:17:05,373 DEBUG [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] gtrecord.GTCubeStorageQueryBase:308 : Does not need storage aggregation
2018-06-22 18:17:05,374 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] gtrecord.GTCubeStorageQueryBase:579 : exactAggregation is true, cuboid id is 511
2018-06-22 18:17:05,374 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] gtrecord.GTCubeStorageQueryBase:289 : Filter column set for query: []
2018-06-22 18:17:05,374 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] gtrecord.GTCubeStorageQueryBase:298 : Filter mask is: 0
2018-06-22 18:17:05,375 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] storage.StorageContext:165 : Enabling limit push down: 5000 at level: LIMIT_ON_SCAN
2018-06-22 18:17:05,375 DEBUG [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] gtrecord.GTCubeStorageQueryBase:463 : Aggregate partition results is not beneficial because no storage aggregation
2018-06-22 18:17:05,375 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] gtrecord.GTCubeStorageQueryBase:170 : Cuboid identified: cube=CubeT_1, cuboidId=511, groupsD=[ODS.O_M_T_STUDENT.CITY, ODS.O_M_T_STUDENT.ID, ODS.O_M_T_SUBJECT.ID, ODS.O_M_T_SCORE.SUBJECT_ID, ODS.O_M_T_STUDENT.USER_NAME, ODS.O_M_T_SCORE.USER_ID, ODS.O_M_T_SUBJECT.SUBJECT_NAME, ODS.O_M_T_STUDENT.SEX, ODS.O_M_T_STUDENT.PROVINCE], filterD=[], limitPushdown=5000, limitLevel=LIMIT_ON_SCAN, storageAggr=false
2018-06-22 18:17:05,375 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] gtrecord.CubeSegmentScanner:56 : Init CubeSegmentScanner for segment FULL_BUILD
2018-06-22 18:17:05,376 DEBUG [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] v2.CubeHBaseRPC:315 : hbase.rpc.timeout = 60000 ms, use 54000 ms as timeout for coprocessor
2018-06-22 18:17:05,376 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] v2.CubeHBaseEndpointRPC:152 : Serialized scanRequestBytes 1460 bytes, rawScanBytesString 56 bytes
2018-06-22 18:17:05,377 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] v2.CubeHBaseEndpointRPC:154 : The scan 7b4870f for segment CubeT_1[FULL_BUILD] is as below with 1 separate raw scans, shard part of start/end key is set to 0
2018-06-22 18:17:05,377 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] v2.CubeHBaseRPC:288 : Visiting hbase table KYLIN_D52DC4HQKR: cuboid exact match, from 511 to 511 Start: \x00\x00\x00\x00\x00\x00\x00\x00\x01\xFF\x00\x00\x00\x00\x00\x00\x00\x00\x00 (\x00\x00\x00\x00\x00\x00\x00\x00\x01\xFF\x00\x00\x00\x00\x00\x00\x00\x00\x00) Stop: \x00\x00\x00\x00\x00\x00\x00\x00\x01\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\x00 (\x00\x00\x00\x00\x00\x00\x00\x00\x01\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\x00), No Fuzzy Key
2018-06-22 18:17:05,377 DEBUG [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] v2.CubeHBaseEndpointRPC:159 : Submitting rpc to 1 shards starting from shard 0, scan range count 1
2018-06-22 18:17:05,378 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] common.KylinConfig:319 : Loading kylin-defaults.properties from file:/opt/soft/apache-kylin-2.3.0-bin/tomcat/webapps/kylin/WEB-INF/lib/kylin-core-common-2.3.0.jar!/kylin-defaults.properties
2018-06-22 18:17:05,385 DEBUG [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] common.KylinConfig:278 : KYLIN_CONF property was not set, will seek KYLIN_HOME env variable
2018-06-22 18:17:05,385 WARN [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] common.BackwardCompatibilityConfig:93 : Config 'kylin.job.mr.lib.dir' is deprecated, use 'kylin.engine.mr.lib-dir' instead
2018-06-22 18:17:05,386 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] gtrecord.SequentialCubeTupleIterator:73 : Using Iterators.concat to merge segment results
2018-06-22 18:17:05,386 DEBUG [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] enumerator.OLAPEnumerator:120 : return TupleIterator...
2018-06-22 18:17:05,387 INFO [kylin-coproc--pool2-t1175] v2.CubeHBaseEndpointRPC:217 : Query-1235b6a5-ae41-431d-bd75-bef0dae0bf57: send request to the init region server tjtx-89-89.58os.org on table KYLIN_D52DC4HQKR
2018-06-22 18:17:05,393 INFO [kylin-coproc--pool2-t1175] v2.CubeHBaseEndpointRPC:284 : Endpoint RPC returned from HTable KYLIN_D52DC4HQKR Shard \x4B\x59\x4C\x49\x4E\x5F\x44\x35\x32\x44\x43\x34\x48\x51\x4B\x52\x2C\x2C\x31\x35\x32\x35\x34\x32\x34\x30\x39\x37\x36\x39\x36\x2E\x30\x62\x32\x39\x38\x62\x64\x33\x31\x37\x30\x39\x33\x37\x36\x63\x34\x32\x38\x34\x64\x31\x37\x66\x33\x33\x34\x39\x66\x62\x63\x63\x2E on host: tjtx-89-89.58os.org.Total scanned row: 70. Total scanned bytes: 3430. Total filtered row: 0. Total aggred row: 0. Time elapsed in EP: 2(ms). Server CPU usage: 0.01470260637112943, server physical mem left: 5.6562040832E10, server swap mem left:3.3554427904E10.Etc message: start latency: 8@1,agg done@2,compress done@2,server stats done@2, debugGitTag:1179ee72d0a2a2c629a649751ef43ae9e82dc87a;.Normal Complete: true.Compressed row size: 265
2018-06-22 18:17:05,393 DEBUG [kylin-coproc--pool2-t1175] util.CompressionUtils:67 : Original: 265 bytes. Decompressed: 700 bytes. Time: 0
2018-06-22 18:17:05,393 DEBUG [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] gtrecord.SortMergedPartitionResultIterator:76 : Using SortMergedPartitionResultIterator to merge 1 partition results out of 1 partitions
2018-06-22 18:17:05,394 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] service.QueryService:1068 : Processed rows for each storageContext: 70
2018-06-22 18:17:05,394 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] service.QueryService:510 : Stats of SQL response: isException: false, duration: 55, total scan count 70
2018-06-22 18:17:05,394 DEBUG [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] util.CheckUtil:35 : query is too lightweight with duration: 55 (threshold 2000), scan count: 70 (threshold 10240), scan bytes: 3430 (threshold 1048576)
2018-06-22 18:17:05,395 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] service.QueryService:328 :
==========================[QUERY]===============================
Query Id: 1235b6a5-ae41-431d-bd75-bef0dae0bf57
SQL: SELECT
O_M_T_STUDENT.USER_NAME as O_M_T_STUDENT_USER_NAME
,O_M_T_STUDENT.CITY as O_M_T_STUDENT_CITY
,O_M_T_STUDENT.ID as O_M_T_STUDENT_ID
,O_M_T_STUDENT.SEX as O_M_T_STUDENT_SEX
,O_M_T_STUDENT.PROVINCE as O_M_T_STUDENT_PROVINCE
,O_M_T_SCORE.USER_ID as O_M_T_SCORE_USER_ID
,O_M_T_SCORE.SUBJECT_ID as O_M_T_SCORE_SUBJECT_ID
,O_M_T_SUBJECT.ID as O_M_T_SUBJECT_ID
,O_M_T_SUBJECT.SUBJECT_NAME as O_M_T_SUBJECT_SUBJECT_NAME
,O_M_T_SCORE.SCORE as O_M_T_SCORE_SCORE
FROM ODS.O_M_T_SCORE as O_M_T_SCORE
LEFT JOIN ODS.O_M_T_STUDENT as O_M_T_STUDENT
ON O_M_T_SCORE.USER_ID = O_M_T_STUDENT.ID
LEFT JOIN ODS.O_M_T_SUBJECT as O_M_T_SUBJECT
ON O_M_T_SCORE.SUBJECT_ID = O_M_T_SUBJECT.ID
WHERE 1=1 LIMIT 5000
User: ADMIN
Success: true
Duration: 0.056
Project: h_test
Realization Names: [CUBE[name=CubeT_1]]
Cuboid Ids: [511]
Total scan count: 70
Total scan bytes: 3430
Result row count: 70
Accept Partial: false
Is Partial Result: false
Hit Exception Cache: false
Storage cache used: false
Is Query Push-Down: false
Is Prepare: false
Trace URL: null
Message: null
==========================[QUERY]===============================

2018-06-22 18:17:14,141 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] service.QueryService:428 : Using project: h_test
2018-06-22 18:17:14,141 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] service.QueryService:429 : The original query: SELECT
O_M_T_STUDENT.USER_NAME as O_M_T_STUDENT_USER_NAME
,O_M_T_STUDENT.CITY as O_M_T_STUDENT_CITY
,O_M_T_STUDENT.ID as O_M_T_STUDENT_ID
,O_M_T_STUDENT.SEX as O_M_T_STUDENT_SEX
,O_M_T_STUDENT.PROVINCE as O_M_T_STUDENT_PROVINCE
,O_M_T_SCORE.USER_ID as O_M_T_SCORE_USER_ID
,O_M_T_SCORE.SUBJECT_ID as O_M_T_SCORE_SUBJECT_ID
,O_M_T_SUBJECT.ID as O_M_T_SUBJECT_ID
,O_M_T_SUBJECT.SUBJECT_NAME as O_M_T_SUBJECT_SUBJECT_NAME
,O_M_T_SCORE.SCORE as O_M_T_SCORE_SCORE
FROM ODS.O_M_T_SCORE as O_M_T_SCORE
LEFT JOIN ODS.O_M_T_STUDENT as O_M_T_STUDENT
ON O_M_T_SCORE.USER_ID = O_M_T_STUDENT.ID
LEFT JOIN ODS.O_M_T_SUBJECT as O_M_T_SUBJECT
ON O_M_T_SCORE.SUBJECT_ID = O_M_T_SUBJECT.ID
WHERE 1=1
2018-06-22 18:17:14,145 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] service.QueryService:646 : The corrected query: SELECT
O_M_T_STUDENT.USER_NAME as O_M_T_STUDENT_USER_NAME
,O_M_T_STUDENT.CITY as O_M_T_STUDENT_CITY
,O_M_T_STUDENT.ID as O_M_T_STUDENT_ID
,O_M_T_STUDENT.SEX as O_M_T_STUDENT_SEX
,O_M_T_STUDENT.PROVINCE as O_M_T_STUDENT_PROVINCE
,O_M_T_SCORE.USER_ID as O_M_T_SCORE_USER_ID
,O_M_T_SCORE.SUBJECT_ID as O_M_T_SCORE_SUBJECT_ID
,O_M_T_SUBJECT.ID as O_M_T_SUBJECT_ID
,O_M_T_SUBJECT.SUBJECT_NAME as O_M_T_SUBJECT_SUBJECT_NAME
,O_M_T_SCORE.SCORE as O_M_T_SCORE_SCORE
FROM ODS.O_M_T_SCORE as O_M_T_SCORE
LEFT JOIN ODS.O_M_T_STUDENT as O_M_T_STUDENT
ON O_M_T_SCORE.USER_ID = O_M_T_STUDENT.ID
LEFT JOIN ODS.O_M_T_SUBJECT as O_M_T_SUBJECT
ON O_M_T_SCORE.SUBJECT_ID = O_M_T_SUBJECT.ID
WHERE 1=1
LIMIT 50000
2018-06-22 18:17:14,164 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] routing.QueryRouter:58 : Find candidates by table ODS.O_M_T_SCORE and project=h_test : CUBE[name=CubeT_1]
2018-06-22 18:17:14,164 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] routing.QueryRouter:51 : Applying rule: class org.apache.kylin.query.routing.rules.RemoveBlackoutRealizationsRule, realizations before: [CUBE[name=CubeT_1]], realizations after: [CUBE[name=CubeT_1]]
2018-06-22 18:17:14,165 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] routing.QueryRouter:51 : Applying rule: class org.apache.kylin.query.routing.rules.RemoveUncapableRealizationsRule, realizations before: [CUBE[name=CubeT_1]], realizations after: [CUBE[name=CubeT_1]]
2018-06-22 18:17:14,165 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] rules.RealizationSortRule:40 : CUBE[name=CubeT_1] priority 1 cost 14200.
2018-06-22 18:17:14,165 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] routing.QueryRouter:51 : Applying rule: class org.apache.kylin.query.routing.rules.RealizationSortRule, realizations before: [CUBE[name=CubeT_1]], realizations after: [CUBE[name=CubeT_1]]
2018-06-22 18:17:14,165 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] routing.QueryRouter:75 : The realizations remaining: [CUBE[name=CubeT_1]],and the final chosen one for current olap context 0 is CUBE[name=CubeT_1]
2018-06-22 18:17:14,176 DEBUG [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] enumerator.OLAPEnumerator:108 : query storage...
2018-06-22 18:17:14,177 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] cube.RawQueryLastHacker:43 : No group by and aggregation found in this query, will hack some result for better look of output...
2018-06-22 18:17:14,177 DEBUG [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] gtrecord.GTCubeStorageQueryBase:308 : Does not need storage aggregation
2018-06-22 18:17:14,177 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] gtrecord.GTCubeStorageQueryBase:579 : exactAggregation is true, cuboid id is 511
2018-06-22 18:17:14,178 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] gtrecord.GTCubeStorageQueryBase:289 : Filter column set for query: []
2018-06-22 18:17:14,178 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] gtrecord.GTCubeStorageQueryBase:298 : Filter mask is: 0
2018-06-22 18:17:14,178 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] storage.StorageContext:165 : Enabling limit push down: 50000 at level: LIMIT_ON_SCAN
2018-06-22 18:17:14,178 DEBUG [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] gtrecord.GTCubeStorageQueryBase:463 : Aggregate partition results is not beneficial because no storage aggregation
2018-06-22 18:17:14,179 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] gtrecord.GTCubeStorageQueryBase:170 : Cuboid identified: cube=CubeT_1, cuboidId=511, groupsD=[ODS.O_M_T_STUDENT.CITY, ODS.O_M_T_STUDENT.ID, ODS.O_M_T_SUBJECT.ID, ODS.O_M_T_SCORE.SUBJECT_ID, ODS.O_M_T_STUDENT.USER_NAME, ODS.O_M_T_SCORE.USER_ID, ODS.O_M_T_SUBJECT.SUBJECT_NAME, ODS.O_M_T_STUDENT.SEX, ODS.O_M_T_STUDENT.PROVINCE], filterD=[], limitPushdown=50000, limitLevel=LIMIT_ON_SCAN, storageAggr=false
2018-06-22 18:17:14,179 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] gtrecord.CubeSegmentScanner:56 : Init CubeSegmentScanner for segment FULL_BUILD
2018-06-22 18:17:14,180 DEBUG [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] v2.CubeHBaseRPC:315 : hbase.rpc.timeout = 60000 ms, use 54000 ms as timeout for coprocessor
2018-06-22 18:17:14,181 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] v2.CubeHBaseEndpointRPC:152 : Serialized scanRequestBytes 1460 bytes, rawScanBytesString 56 bytes
2018-06-22 18:17:14,181 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] v2.CubeHBaseEndpointRPC:154 : The scan 31d3d2c8 for segment CubeT_1[FULL_BUILD] is as below with 1 separate raw scans, shard part of start/end key is set to 0
2018-06-22 18:17:14,181 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] v2.CubeHBaseRPC:288 : Visiting hbase table KYLIN_D52DC4HQKR: cuboid exact match, from 511 to 511 Start: \x00\x00\x00\x00\x00\x00\x00\x00\x01\xFF\x00\x00\x00\x00\x00\x00\x00\x00\x00 (\x00\x00\x00\x00\x00\x00\x00\x00\x01\xFF\x00\x00\x00\x00\x00\x00\x00\x00\x00) Stop: \x00\x00\x00\x00\x00\x00\x00\x00\x01\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\x00 (\x00\x00\x00\x00\x00\x00\x00\x00\x01\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF\x00), No Fuzzy Key
2018-06-22 18:17:14,182 DEBUG [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] v2.CubeHBaseEndpointRPC:159 : Submitting rpc to 1 shards starting from shard 0, scan range count 1
2018-06-22 18:17:14,182 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] common.KylinConfig:319 : Loading kylin-defaults.properties from file:/opt/soft/apache-kylin-2.3.0-bin/tomcat/webapps/kylin/WEB-INF/lib/kylin-core-common-2.3.0.jar!/kylin-defaults.properties
2018-06-22 18:17:14,188 DEBUG [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] common.KylinConfig:278 : KYLIN_CONF property was not set, will seek KYLIN_HOME env variable
2018-06-22 18:17:14,189 WARN [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] common.BackwardCompatibilityConfig:93 : Config 'kylin.job.mr.lib.dir' is deprecated, use 'kylin.engine.mr.lib-dir' instead
2018-06-22 18:17:14,190 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] gtrecord.SequentialCubeTupleIterator:73 : Using Iterators.concat to merge segment results
2018-06-22 18:17:14,190 DEBUG [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] enumerator.OLAPEnumerator:120 : return TupleIterator...
2018-06-22 18:17:14,190 INFO [kylin-coproc--pool2-t1176] v2.CubeHBaseEndpointRPC:217 : Query-2b31728e-585f-437e-ac9e-b04aaea8637c: send request to the init region server tjtx-89-89.58os.org on table KYLIN_D52DC4HQKR
2018-06-22 18:17:14,198 INFO [kylin-coproc--pool2-t1176] v2.CubeHBaseEndpointRPC:284 : Endpoint RPC returned from HTable KYLIN_D52DC4HQKR Shard \x4B\x59\x4C\x49\x4E\x5F\x44\x35\x32\x44\x43\x34\x48\x51\x4B\x52\x2C\x2C\x31\x35\x32\x35\x34\x32\x34\x30\x39\x37\x36\x39\x36\x2E\x30\x62\x32\x39\x38\x62\x64\x33\x31\x37\x30\x39\x33\x37\x36\x63\x34\x32\x38\x34\x64\x31\x37\x66\x33\x33\x34\x39\x66\x62\x63\x63\x2E on host: tjtx-89-89.58os.org.Total scanned row: 70. Total scanned bytes: 3430. Total filtered row: 0. Total aggred row: 0. Time elapsed in EP: 3(ms). Server CPU usage: 0.013044872937234914, server physical mem left: 5.6559546368E10, server swap mem left:3.3554427904E10.Etc message: start latency: 8@2,agg done@3,compress done@3,server stats done@3, debugGitTag:1179ee72d0a2a2c629a649751ef43ae9e82dc87a;.Normal Complete: true.Compressed row size: 265
2018-06-22 18:17:14,198 DEBUG [kylin-coproc--pool2-t1176] util.CompressionUtils:67 : Original: 265 bytes. Decompressed: 700 bytes. Time: 0
2018-06-22 18:17:14,198 DEBUG [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] gtrecord.SortMergedPartitionResultIterator:76 : Using SortMergedPartitionResultIterator to merge 1 partition results out of 1 partitions
2018-06-22 18:17:14,199 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] service.QueryService:1068 : Processed rows for each storageContext: 70
2018-06-22 18:17:14,200 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] service.QueryService:510 : Stats of SQL response: isException: false, duration: 62, total scan count 70
2018-06-22 18:17:14,200 DEBUG [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] util.CheckUtil:35 : query is too lightweight with duration: 62 (threshold 2000), scan count: 70 (threshold 10240), scan bytes: 3430 (threshold 1048576)
2018-06-22 18:17:14,200 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] service.QueryService:328 :
==========================[QUERY]===============================
Query Id: 2b31728e-585f-437e-ac9e-b04aaea8637c
SQL: SELECT
O_M_T_STUDENT.USER_NAME as O_M_T_STUDENT_USER_NAME
,O_M_T_STUDENT.CITY as O_M_T_STUDENT_CITY
,O_M_T_STUDENT.ID as O_M_T_STUDENT_ID
,O_M_T_STUDENT.SEX as O_M_T_STUDENT_SEX
,O_M_T_STUDENT.PROVINCE as O_M_T_STUDENT_PROVINCE
,O_M_T_SCORE.USER_ID as O_M_T_SCORE_USER_ID
,O_M_T_SCORE.SUBJECT_ID as O_M_T_SCORE_SUBJECT_ID
,O_M_T_SUBJECT.ID as O_M_T_SUBJECT_ID
,O_M_T_SUBJECT.SUBJECT_NAME as O_M_T_SUBJECT_SUBJECT_NAME
,O_M_T_SCORE.SCORE as O_M_T_SCORE_SCORE
FROM ODS.O_M_T_SCORE as O_M_T_SCORE
LEFT JOIN ODS.O_M_T_STUDENT as O_M_T_STUDENT
ON O_M_T_SCORE.USER_ID = O_M_T_STUDENT.ID
LEFT JOIN ODS.O_M_T_SUBJECT as O_M_T_SUBJECT
ON O_M_T_SCORE.SUBJECT_ID = O_M_T_SUBJECT.ID
WHERE 1=1
User: ADMIN
Success: true
Duration: 0.062
Project: h_test
Realization Names: [CUBE[name=CubeT_1]]
Cuboid Ids: [511]
Total scan count: 70
Total scan bytes: 3430
Result row count: 70
Accept Partial: true
Is Partial Result: false
Hit Exception Cache: false
Storage cache used: false
Is Query Push-Down: false
Is Prepare: false
Trace URL: null
Message: null
==========================[QUERY]===============================

将上述的日志保存为 test.log
然后运行如下awk
time awk '
function ltrim(s) { sub(/^[ \t\r\n]+/, "", s); return s }
function rtrim(s) { sub(/[ \t\r\n]+$/, "", s); return s }
function trim(s) { return rtrim(ltrim(s)); }
/^Query Id:/{split($0,rowdata,":");}
/^SQL:/{s=trim($0);next;}
/^User:/{print "19700101 000000000 INFO [Query "trim(rowdata[2])" "s;s="";print $0;}
/^==========================/{delete rowdata;}
{
if(rowdata[2]!="")
if(s!="") s=(s" "trim($0))
else
print "19700101 000000000 INFO [Query "trim(rowdata[2])" "$0;
else gsub("[,:-]","",$1);gsub("[,:-]","",$2);$5=substr($5,0,36);print ($0);
}

' test.log | grep "\\[Query" | sort -k5,5 -k2n,2 -k3n,3 > t1.txt

首先定义 trim rtrim ltrim 三个函数

如果是Query Id 开头,说明是kylin的汇总第一行,提取QueryId

如果是SQL:开头,则将SQL文本保存在 s变量中,主要是多行合并为一行

如果是User:开头,则说明 SQL段结束,因为SQL段的下一段就是 User段.先打印保存在变量s中的SQL文本,然后打印User段本行.在打印文本的时候,日期时间采用默认值,并且拼凑格式,将QueryId也打印出来,这方便后续的分组和排序.

如果是 =========开头,说明是分隔符行,则删除保存的queryId信息.

然后判断是否是汇总行,rowdata[2]有值，则说明是汇总行.汇总行有两种情况，一种情况是多行的SQL，这种情况只是把sql保存到变量s,等待到User段再输出.另外一种情况是普通的汇总行,这种情况拼接默认值后输出.如果是日志行,则将日期时间的下划线，冒号去掉,以便作为数字排序.

grep "\\[Query" 则过滤与查询无关的日志信息

sort 先按照第五列 queryid排序后,再按照日期，时间排序.

这样并发的kylin日志,就顺序化了,方便后续的信息提取.