Shulou(Shulou.com)06/01 Report--

This article focuses on "how to use AWK to organize KyLin logs". Interested friends may wish to have a look at it. The method introduced in this paper is simple, fast and practical. Let's let the editor take you to learn how to use AWK to organize KyLin logs.

We need to parse the Kylin log to get the relevant information about the query.

But Kylin logs are written concurrently, that is, in the case of concurrency, the query logs will cross.

In addition, the rows summarized by Kylin need to be extracted

Finally, for lines involving SQL, you need to merge multiple lines into one line.

The original KyLin log is as follows

2018-06-22 18 431d-bd75-bef0dae0bf57 1715 05341 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] service.QueryService:428: Using project: h_test

2018-06-22 18 431d-bd75-bef0dae0bf57 1715 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 431d-bd75-bef0dae0bf57 1715 05345 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] service.QueryService:893: Setting current statement's max rows to 0

2018-06-22 18 431d-bd75-bef0dae0bf57 1715 05360 INFO [name-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 431d-bd75-bef0dae0bf57 17 431d-bd75-bef0dae0bf57 05361 INFO [name-431d-bd75-bef0dae0bf57-144391] routing.QueryRouter:51: Applying rule: class org.apache.kylin.query.routing.rules.RemoveBlackoutRealizationsRule, realizations before: [CubeT_1 [name = name]], realizations after: [name = CubeT_1]]

2018-06-22 18 431d-bd75-bef0dae0bf57 17 431d-bd75-bef0dae0bf57 05361 INFO [name-431d-bd75-bef0dae0bf57-144391] routing.QueryRouter:51: Applying rule: class org.apache.kylin.query.routing.rules.RemoveUncapableRealizationsRule, realizations before: [CubeT_1 [name = name]], realizations after: [name = CubeT_1]]

2018-06-22 18 431d-bd75-bef0dae0bf57 1705361 INFO [name-431d-bd75-bef0dae0bf57-144391] rules.RealizationSortRule:40: cube [name = CubeT_1] priority 1 cost 14200.

2018-06-22 18 INFO 1715 05362 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] routing.QueryRouter:51: Applying rule: class org.apache.kylin.query.routing.rules.RealizationSortRule, realizations before: [CubeT_1 [name = CubeT_1]], realizations after: [name = CubeT_1]]

2018-06-22 18 431d-bd75-bef0dae0bf57 1705362 INFO [name-431d-bd75-bef0dae0bf57-144391] routing.QueryRouter:75: The realizations remaining: [name = CubeT_1]], and the final chosen one for current olap context 0 is cube [name = CubeT_1]

2018-06-22 18 431d-bd75-bef0dae0bf57 1705373 DEBUG [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] enumerator.OLAPEnumerator:108: query storage...

2018-06-22 18 431d-bd75-bef0dae0bf57 1715 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 431d-bd75-bef0dae0bf57 1705373 DEBUG [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] gtrecord.GTCubeStorageQueryBase:308: Does not need storage aggregation

2018-06-22 18 431d-bd75-bef0dae0bf57 1715 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] gtrecord.GTCubeStorageQueryBase:579: exactAggregation is true, cuboid id is

2018-06-22 18 431d-bd75-bef0dae0bf57 1715 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] gtrecord.GTCubeStorageQueryBase:289: Filter column set for query: []

2018-06-22 18 431d-bd75-bef0dae0bf57 1705374 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] gtrecord.GTCubeStorageQueryBase:298: Filter mask is: 0

2018-06-22 18 431d-bd75-bef0dae0bf57 1715 05375 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 431d-bd75-bef0dae0bf57 1715 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 INFO 1715 05375 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 431d-bd75-bef0dae0bf57 1715 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] gtrecord.CubeSegmentScanner:56: Init CubeSegmentScanner for segment FULL_BUILD

2018-06-22 18 431d-bd75-bef0dae0bf57 1705376 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 431d-bd75-bef0dae0bf57 1705376 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] v2.CubeHBaseEndpointRPC:152: Serialized scanRequestBytes 1460 bytes, rawScanBytesString 56 bytes

2018-06-22 18 INFO 1715 05377 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 431d-bd75-bef0dae0bf57 1715 05377 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\ xFF\ X00\ xFF\ xFF \ xFF\ X00 (\ X00\ X01\ xFF\ X00) No Fuzzy Key

2018-06-22 18 431d-bd75-bef0dae0bf57 1715 05377 DEBUG [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] v2.CubeHBaseEndpointRPC:159: Submitting rpc to 1 shards starting from shard 0, scan range count 1

INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] common.KylinConfig:319: Loading kylin-defaults.properties from filebank OptGap OptGap SoftUnip Kylinlyk 2.3.0 LIBBUBLING WEBBUBUBUBUBUBUBUBUBUBUBUBUBUBUBUBUBUBUR

2018-06-22 18 431d-bd75-bef0dae0bf57 1715 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 431d-bd75-bef0dae0bf57 1715 05385 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 431d-bd75-bef0dae0bf57 1715 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] gtrecord.SequentialCubeTupleIterator:73: Using Iterators.concat to merge segment results

2018-06-22 18 431d-bd75-bef0dae0bf57 1715 DEBUG [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] enumerator.OLAPEnumerator:120: return TupleIterator...

2018-06-22 18 v2.CubeHBaseEndpointRPC:217 1715 05387 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 v2.CubeHBaseEndpointRPC:284 175393 INFO [kylin-coproc--pool2-t1175] v2.CubeHBaseEndpointRPC:284: EndpointRPC returned from HTable KYLIN_D52DC4HQKR Shard\ x4B\ x59\ x4C\ x49\ x4e\ x5F\ x44\ x35\ x44\ x43\ x34\ x48\ x51\ x52\ x2C\ x31\ x32\ x34\ x34\ x30\ x39\ x36\ x2E\ x30\ x62\ x32\ x39\ x38\ x62\ x33\ x31\ x37 \ x30\ x39\ x33\ x37\ x36\ x63\ x34\ x32\ x38\ x34\ x64\ x31\ x66\ 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: 56.56204083 billion, server swap mem left:3.3554427904E10.Etc message: start latency: 8801, agg done@2,compress done@2,server stats done@2, debugGitTag:1179ee72d0a2a2c629a649751ef43ae9e82dc87a;.Normal Complete: true.Compressed row size: 265

2018-06-22 18 util.CompressionUtils:67 1705393 DEBUG [kylin-coproc--pool2-t1175] util.CompressionUtils:67: Original: 265 bytes. Decompressed: 700 bytes. Time: 0

2018-06-22 18 431d-bd75-bef0dae0bf57 1715 05393 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 431d-bd75-bef0dae0bf57 1715 05394 INFO [Query 1235b6a5-ae41-431d-bd75-bef0dae0bf57-144391] service.QueryService:1068: Processed rows for each storageContext: 70

2018-06-22 18 431d-bd75-bef0dae0bf57 1715 05394 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 431d-bd75-bef0dae0bf57 1715 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 431d-bd75-bef0dae0bf57 1705395 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 service.QueryService:428 1714 14141 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] service.QueryService:428: Using project: h_test

2018-06-22 18 service.QueryService:429 1714 14141 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 service.QueryService:646 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 routing.QueryRouter:58 1715 14164 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 INFO 1715 14164 INFO [name] routing.QueryRouter:51: Applying rule: class org.apache.kylin.query.routing.rules.RemoveBlackoutRealizationsRule, realizations before: [name = CubeT_1]], realizations after: [CubeT_1 [name = name]]

2018-06-22 18 routing.QueryRouter:51 1715 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 rules.RealizationSortRule:40 1715 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] rules.RealizationSortRule:40: cube [name = CubeT_1] priority 1 cost 14200.

2018-06-22 18 routing.QueryRouter:51 1715 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 INFO 17 routing.QueryRouter:75 14165 [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] routing.QueryRouter:75: The realizations remaining: [name = CubeT_1]], and the final chosen one for current olap context 0 is cube [name = CubeT_1]

2018-06-22 18 enumerator.OLAPEnumerator:108 17 14 176 DEBUG [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] enumerator.OLAPEnumerator:108: query storage...

2018-06-22 18 cube.RawQueryLastHacker:43 1717 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 gtrecord.GTCubeStorageQueryBase:308 17 14 17 DEBUG [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] gtrecord.GTCubeStorageQueryBase:308: Does not need storage aggregation

2018-06-22 18 gtrecord.GTCubeStorageQueryBase:579 1717 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] gtrecord.GTCubeStorageQueryBase:579: exactAggregation is true, cuboid id is

2018-06-22 18 gtrecord.GTCubeStorageQueryBase:289 17 14 178 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] gtrecord.GTCubeStorageQueryBase:289: Filter column set for query: []

2018-06-22 18 gtrecord.GTCubeStorageQueryBase:298 17 14 178 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] gtrecord.GTCubeStorageQueryBase:298: Filter mask is: 0

2018-06-22 18 at level 1715 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 gtrecord.GTCubeStorageQueryBase:463 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 gtrecord.GTCubeStorageQueryBase:170 1715 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 gtrecord.CubeSegmentScanner:56 17 14 179 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] gtrecord.CubeSegmentScanner:56: Init CubeSegmentScanner for segment FULL_BUILD

2018-06-22 18 v2.CubeHBaseRPC:315 1715 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 v2.CubeHBaseEndpointRPC:152 1718 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] v2.CubeHBaseEndpointRPC:152: Serialized scanRequestBytes 1460 bytes, rawScanBytesString 56 bytes

2018-06-22 18 v2.CubeHBaseEndpointRPC:154 1718 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 v2.CubeHBaseRPC:288 1715 14181 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\ xFF\ X00\ xFF\ xFF \ xFF\ X00 (\ X00\ X01\ xFF\ X00) No Fuzzy Key

2018-06-22 18 v2.CubeHBaseEndpointRPC:159 1718 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 1818 INFO 14182 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] common.KylinConfig:319: Loading kylin-defaults.properties from fileGroupe OptUnip SoftUnip SoftUniverse Kylinwashi 2.3.0WEBINFActionWEBINFActionLIBUBUBUBUBUBUBUR Corel commonly2.3.0.jarbank Universe Kylintel defaults.properties

2018-06-22 18 common.KylinConfig:278 1718 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 common.BackwardCompatibilityConfig:93 1715 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 gtrecord.SequentialCubeTupleIterator:73 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 enumerator.OLAPEnumerator:120 17 14 190 DEBUG [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] enumerator.OLAPEnumerator:120: return TupleIterator...

2018-06-22 18 v2.CubeHBaseEndpointRPC:217 1715 14190 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 v2.CubeHBaseEndpointRPC:284 INFO [kylin-coproc--pool2-t1176] v2.CubeHBaseEndpointRPC:284: EndpointRPC returned from HTable KYLIN_D52DC4HQKR Shard\ x4B\ x59\ x4C\ x49\ x4e\ x5F\ x44\ x35\ x43\ x34\ x48\ x51\ x52\ x2C\ x31\ x35\ x34\ x34\ x30\ x39\ x36\ x36\ x2E\ x30\ x62\ x32\ x38\ x62\ x33\ x31\ x37 \ x30\ x39\ x33\ x37\ x36\ x63\ x34\ x32\ x38\ x34\ x64\ x31\ x66\ 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: 56.55954637 billion, server swap mem left:3.3554427904E10.Etc message: start latency: 8802 debugGitTag:1179ee72d0a2a2c629a649751ef43ae9e82dc87a;.Normal Complete done@3,compress done@3,server stats done@3, debugGitTag:1179ee72d0a2a2c629a649751ef43ae9e82dc87a;.Normal Complete: true.Compressed row size: 265

2018-06-22 18 util.CompressionUtils:67 17 14 198 DEBUG [kylin-coproc--pool2-t1176] util.CompressionUtils:67: Original: 265 bytes. Decompressed: 700 bytes. Time: 0

2018-06-22 18 partition results out of 17 gtrecord.SortMergedPartitionResultIterator:76 14198 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 service.QueryService:1068 17 14 199 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] service.QueryService:1068: Processed rows for each storageContext: 70

2018-06-22 18 service.QueryService:510 1715 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 util.CheckUtil:35 1715 DEBUG [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402] util.CheckUtil:35: 62 (threshold 2000), scan count: 70 (threshold 10240), scan bytes: 3430 (threshold 1048576)

2018-06-22 18 service.QueryService:328 17 service.QueryService:328 14 200 INFO [Query 2b31728e-585f-437e-ac9e-b04aaea8637c-149402]:

= = [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] =

Save the above log as test.log

Then run the following 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 ($0gamma rowdata, ":");}

/ ^ SQL:/ {s=trim ($0); next;}

/ ^ User:/ {print "19700101 000000000 INFO [Query" trim (rowdata [2]) "" s = ""; print $0;}

/ ^ = / {delete rowdata;}

{

If (rowdata [2]! = "")

If (slots = "") s = (s "" trim ($0))

Else

Print "19700101 000000000 INFO [Query" trim (rowdata [2]) "$0

Else gsub ("[,: -]", ", $1); gsub (" [,: -] ", $2); $5=substr ($5d0d0, 36); print ($0)

}

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

First define three functions of trim rtrim ltrim

If it starts with QueryId, it is the first line of the summary of kylin. Extract QueryId.

If it starts with SQL:, save the SQL text in the s variable, mainly by merging multiple lines into one line

If it starts with User:, it means that the SQL segment ends, because the next paragraph of the SQL section is the User segment. First print the SQL text saved in the variable s, and then print the User segment line. When printing text, the date and time use the default value, and patchwork format, the QueryId will also be printed out, which is convenient for subsequent grouping and sorting.

If it starts with = and indicates a delimited line, the saved queryId information is deleted.

Then determine whether it is a summary bank, rowdata [2] is valuable, it is a summary bank. Summary bank has two cases, one is multi-line SQL, in this case, just save the sql to the variable s and wait to the User section before output. Another case is the ordinary summary line, in which the default value is spliced and output. If it is a log line, underscore the date and time and remove the colon so that it can be sorted as a number.

Grep "\ [Query" filters log information that has nothing to do with the query

Sort is sorted by the fifth column queryid, and then by date and time.

In this way, the concurrent kylin logs are sequenced to facilitate subsequent information extraction.

At this point, I believe you have a deeper understanding of "how to use AWK to organize KyLin logs". You might as well do it in practice. Here is the website, more related content can enter the relevant channels to inquire, follow us, continue to learn!

Welcome to subscribe "Shulou Technology Information " to get latest news, interesting things and hot topics in the IT industry, and controls the hottest and latest Internet news, technology news and IT industry trends.