9134

Build # 9134

Build Type

push

jenkins

Committed by GitHub

Commit Message

<a href="https://github.com/apache/carbondata/commit/<a class=hub.com/apache/carbondata/commit/<a class="double-link" href="https://git"><a class=hub.com/apache/carbondata/commit/<a class="double-link" href="https://git"><a class=hub.com/apache/carbondata/commit/<a class="double-link" href="https://git"><a class=hub.com/apache/carbondata/commit/040104a1c25e728abef88554c211665ba455af8f">040104a1c">&lt;a href=&quot;https://github.com/apache/carbondata/commit/</a><a class="double-link" href="https://github.com/apache/carbondata/commit/&lt;a class=&quot;double-link&quot; href=&quot;https://git">&lt;a class=</a>hub.com/apache/carbondata/commit/&lt;a class=&quot;double-link&quot; href=&quot;https://git">&lt;a class=</a>hub.com/apache/carbondata/commit/&lt;a class=&quot;double-link&quot; href=&quot;https://git">&lt;a class=</a>hub.com/apache/carbondata/commit/&lt;a class=&quot;double-link&quot; href=&quot;https://git">&lt;a class=</a>hub.com/apache/carbondata/commit/040104a1c25e728abef88554c211665ba455af8f">040104a1c</a><a href="https://github.com/apache/carbondata/commit/040104a1c25e728abef88554c211665ba455af8f">&quot;&gt;&amp;lt;a href=&amp;quot;https://github.com/apache/carbondata/commit/&lt;/a&gt;&lt;a class=&quot;double-link&quot; href=&quot;https://github.com/apache/carbondata/commit/&amp;lt;a class=&amp;quot;double-link&amp;quot; href=&amp;quot;https://git&quot;&gt;&amp;lt;a class=&lt;/a&gt;hub.com/apache/carbondata/commit/&amp;lt;a class=&amp;quot;double-link&amp;quot; href=&amp;quot;https://git&quot;&gt;&amp;lt;a class=&lt;/a&gt;hub.com/apache/carbondata/commit/&amp;lt;a class=&amp;quot;double-link&amp;quot; href=&amp;quot;https://git&quot;&gt;&amp;lt;a class=&lt;/a&gt;hub.com/apache/carbondata/commit/&amp;lt;a class=&amp;quot;double-link&amp;quot; href=&amp;quot;https://git&quot;&gt;&amp;lt;a class=&lt;/a&gt;hub.com/apache/carbondata/commit/040104a1c25e728abef88554c211665ba455af8f&quot;&gt;040104a1c&lt;/a&gt;&lt;a href=&quot;https://github.com/apache/carbondata/commit/040104a1c25e728abef88554c211665ba455af8f&quot;&gt;&amp;quot;&amp;gt;&amp;amp;lt;a href=&amp;amp;quot;https://github.com/apache/carbondata/commit/&amp;lt;/a&amp;gt;&amp;lt;a class=&amp;quot;double-link&amp;quot; href=&amp;quot;https://github.com/apache/carbondata/commit/&amp;amp;lt;a ... (continued)

Run Details

53 of 53 new or added lines in 8 files covered. (100.0%)

57984 of 75159 relevant lines covered (77.15%)

1.03 hits per line

Source File
Press 'n' to go to next uncovered line, 'b' for previous

93.96

/integration/spark-common/src/main/scala/org/apache/spark/sql/profiler/ProfilerLogger.scala

/*
 * Licensed to the Apache Software Foundation (ASF) under one or more
 * contributor license agreements.  See the NOTICE file distributed with
 * this work for additional information regarding copyright ownership.
 * The ASF licenses this file to You under the Apache License, Version 2.0
 * (the "License"); you may not use this file except in compliance with
 * the License.  You may obtain a copy of the License at
 *
 *    http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */

package org.apache.spark.sql.profiler

import java.lang.{StringBuilder => JavaStringBuilder}
import java.sql.Timestamp
import java.text.SimpleDateFormat
import java.util
import java.util.Comparator

import scala.collection.mutable.ArrayBuffer

import org.apache.carbondata.common.logging.LogServiceFactory
import org.apache.carbondata.core.stats.TaskStatistics
import org.apache.carbondata.core.util.CarbonUtil

/**
 * the util of profiler logger
 */
private[profiler] object ProfilerLogger {

  val LOGGER = LogServiceFactory.getLogService(this.getClass.getCanonicalName)

  lazy val simpleDateFormat = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS")

  // format timestamp value
  def format(time: Long): String = this.synchronized {
    if (time < 0) {
      ""
    } else {
      val timestamp = new Timestamp(time)
      simpleDateFormat.format(timestamp)
    }
  }

  def logStatementSummary(statementId: Long, messages: ArrayBuffer[ProfilerMessage]): Unit = {
    LOGGER.info(new StatementSummary(statementId, messages).toString)
  }

  def logExecutionSummary(executionId: Long, messages: ArrayBuffer[ProfilerMessage]): Unit = {
    LOGGER.info(new ExecutionSummary(executionId, messages).toString)
  }
}

/**
 * summarize the statement information
 */
private[profiler] class StatementSummary(
    statementId: Long,
    messages: ArrayBuffer[ProfilerMessage]
) {

  private var sqlText: String = ""

  private var isCommand = false

  private var startTime: Long = -1

  private var parserEnd: Long = -1

  private var analyzerEnd: Long = -1

  private var optimizerStart: Long = -1

  private var optimizerEnd: Long = -1

  private var optimizerTaken: Long = -1

  private var endTime: Long = -1

  // summarize the messages
  messages.foreach {
    case sqlStart: SQLStart =>
      sqlText = sqlStart.sqlText.trim
      isCommand = sqlStart.isCommand
      startTime = sqlStart.startTime
      parserEnd = sqlStart.parseEnd
      analyzerEnd = sqlStart.analyzerEnd
      endTime = sqlStart.endTime
    case optimizer: Optimizer =>
      optimizerTaken = optimizer.timeTaken
      optimizerStart = optimizer.startTime
      optimizerEnd = optimizerStart + optimizerTaken
  }

  private def totalTaken: Long = endTime - startTime

  private def parserTaken: Long = parserEnd - startTime

  private def analyzerTaken: Long = analyzerEnd - parserEnd

  private def parserToOptimizer: Long = optimizerEnd - startTime

  private def commandTaken: Long = endTime - analyzerEnd

  override def toString: String = {
    if (isCommand) {
      buildForComand()
    } else {
      buildForQuery()
    }
  }

  /**
   * for example
   * [statement id]: 1
   * [sql text]:
   * +-----------------------------------------------------------+
   * |CREATE TABLE carbon_table(                                 |
   * | shortField SHORT,                                         |
   * | intField INT,                                             |
   * | bigintField LONG,                                         |
   * | doubleField DOUBLE,                                       |
   * | stringField STRING,                                       |
   * | timestampField TIMESTAMP,                                 |
   * | decimalField DECIMAL(18,2),                               |
   * | dateField DATE,                                           |
   * | charField CHAR(5),                                        |
   * | floatField FLOAT                                          |
   * | )                                                         |
   * | STORED BY 'carbondata'                                    |
   * | TBLPROPERTIES('DICTIONARY_INCLUDE'='dateField, charField')|
   * +-----------------------------------------------------------+
   * [start time]: 2018-03-22 17:12:18.310
   * [driver side total taken]: 1255 ms
   *   |__ 1.parser taken: 203 ms
   *   |__ 2.analyzer taken: 1 ms
   *   |__ 3.execution taken: 1051 ms
   *   |__ ...
   */
  private def buildForComand(): String = {
    val builder = new JavaStringBuilder(1000)
    builder.append(s"\n[statement id]: ${ statementId }")
    builder.append(s"\n[sql text]:\n")
    CarbonUtil.logTable(builder, sqlText, "")
    builder.append(s"\n[start time]: ${ ProfilerLogger.format(startTime) }\n")
    builder.append(s"[driver side total taken]: $totalTaken ms\n")
    builder.append(s"  |__ 1.parser taken: $parserTaken ms\n")
    builder.append(s"  |__ 2.analyzer taken: $analyzerTaken ms\n")
    builder.append(s"  |__ 3.execution taken: $commandTaken ms")
    builder.toString
  }

  /**
   * for example
   * [statement id]: 4
   * [sql text]:
   * +--------------------------------------------------+
   * |SELECT charField, stringField, intField           |
   * | FROM carbon_table                                |
   * | WHERE stringfield = 'spark' AND decimalField > 40|
   * +--------------------------------------------------+
   * [start time]: 2018-03-22 17:12:22.001
   * [driver side total taken]: 476ms
   * |__ 1.parser taken: 82 ms
   * |__ 2.analyzer taken: 195 ms
   * |__ 3.(149ms)
   * |__ 4.carbon optimizer taken: 50 ms
   *       end time: 2018-03-22 17:12:22.477
   */
  private def buildForQuery(): String = {
    val builder = new JavaStringBuilder(1000)
    builder.append(s"\n[statement id]: ${ statementId }")
    builder.append(s"\n[sql text]:\n")
    CarbonUtil.logTable(builder, sqlText, "")
    builder.append(s"\n[start time]: ${ ProfilerLogger.format(startTime) }\n")
    builder.append(s"[driver side total taken]: ${ parserToOptimizer }ms\n")
    builder.append(s"  |__ 1.parser taken: $parserTaken ms\n")
    builder.append(s"  |__ 2.analyzer taken: $analyzerTaken ms\n")
    builder.append(s"  |__ 3.(${ optimizerStart - analyzerEnd }ms)\n")
    builder.append(s"  |__ 4.carbon optimizer taken: $optimizerTaken ms\n")
    builder.append(s"        end time: ${ ProfilerLogger.format(optimizerEnd) }")
    builder.toString
  }
}

/**
 * summarize the execution information
 */
private[profiler] class ExecutionSummary(
    executionId: Long,
    messages: ArrayBuffer[ProfilerMessage]
) {

  private var sqlPlan: String = ""

  private var startTime: Long = -1

  private var endTime: Long = -1

  private val partitions = new util.ArrayList[GetPartition]()

  private val tasks = new util.ArrayList[TaskStatistics]()

  // summarize the messages
  messages.foreach {
    case start: ExecutionStart =>
      sqlPlan = start.plan
      startTime = start.startTime
    case end: ExecutionEnd =>
      endTime = end.endTime
    case partition: GetPartition =>
      partitions.add(partition)
    case task: QueryTaskEnd =>
      tasks.add(new TaskStatistics(task.queryId, task.values, task.size, task.files))
  }

  private def totalTaken: Long = endTime - startTime

  /**
   * for example
   * (prepare inputFormat 55ms)~(getSplits 90ms)~(distributeSplits 4ms)~(3ms)
   */
  private def detail(p: GetPartition, builder: JavaStringBuilder): Unit = {
    builder.append("(prepare inputFormat ").append(p.getSplitsStart - p.startTime).append("ms)~")
    builder.append("(getSplits ").append(p.getSplitsEnd - p.getSplitsStart).append("ms)~")
    val gap1 = p.distributeStart - p.getSplitsEnd
    if (gap1 > 0) {
      builder.append("(").append(gap1).append("ms)~")
    }
    builder.append("(distributeSplits ").append(p.distributeEnd - p.distributeStart).append("ms)")
    val gap2 = p.endTime - p.distributeEnd
    if (gap2 > 0) {
      builder.append("~(").append(gap2).append("ms)")
    }
  }

  private def printGetPartitionTable(builder: JavaStringBuilder, indent: String): Unit = {
    util.Collections.sort(partitions)
    for (rowIndex <- 0 until partitions.size()) {
      val partition = partitions.get(rowIndex)
      val content = new JavaStringBuilder()
      content.append("query_id: ").append(partition.queryId).append("\n")
        .append("table_name: ").append(partition.tableName).append("\n")
        .append("table_path: ").append(partition.tablePath).append("\n")
        .append("start_time: ").append(ProfilerLogger.format(partition.startTime)).append("\n")
      // total time
      content.append("total_time: ").append(partition.endTime - partition.startTime).append("ms")
      content.append(" [")
      detail(partition, content)
      content.append("]\n")
      content.append("valid_segment_num: ").append(partition.numSegments).append("\n")
        .append("stream_segment_num: ").append(partition.numStreamSegments).append("\n")
        .append("hit_data_block: ").append(partition.numBlocks).append("\n")
        .append("spark_partition_num: ").append(partition.numOfPartitions).append("\n")
        .append("pushed_filter: ").append(partition.filter).append("\n")
        .append("pushed_projection: ").append(partition.projection)
      if (rowIndex > 0) {
        builder.append("\n")
      }
      CarbonUtil.logTable(builder, content.toString, indent)
    }
  }

  private def printStatisticTable(builder: JavaStringBuilder, indent: String): Unit = {
    util.Collections.sort(tasks, comparator)
    TaskStatistics.printStatisticTable(tasks, builder, indent)
  }

  private def printInputFiles(builder: JavaStringBuilder, indent: String): Unit = {
    for (taskIndex <- 0 until tasks.size()) {
      val task = tasks.get(taskIndex)
      val content = new JavaStringBuilder()
      content.append("query_id: ").append(task.getQueryId).append("\n")
        .append("task_id: ").append(task.getValues()(1)).append("\n")
        .append("total_size: ").append(task.getFileSize).append("Byte\n")
        .append("file_list: ")
      task.getFiles.foreach { file =>
        content.append("\n  Segment_").append(file)
      }
      if (taskIndex > 0) {
        builder.append("\n")
      }
      CarbonUtil.logTable(builder, content.toString, indent)
    }
  }

  // use to sort tasks
  private lazy val comparator = new Comparator[TaskStatistics]() {
    override def compare(o1: TaskStatistics,
        o2: TaskStatistics) = {
      val result = o1.getQueryId.compareTo(o2.getQueryId())
      if (result != 0) {
        result
      } else {
        val task = o1.getValues()(1) - o2.getValues()(1)
        if (task > 0) {
          1
        } else if (task < 0) {
          -1
        } else {
          0
        }
      }
    }
  }

  // scalastyle:off
  /**
   * for example
   * [execution id]: 0
   * [start time]: 2018-03-22 17:12:22.608
   * [executor side total taken]: 845 ms
   *   |_1.getPartition
   *     +------------------------------------------------------------------------------------------------------------------+
   *     |query_id: 23737310772188                                                                                          |
   *     |table_name: default.carbon_table                                                                                  |
   *     |table_path: /carbondata/examples/spark2/target/store/default/carbon_table                                         |
   *     |start_time: 2018-03-22 17:12:23.141                                                                               |
   *     |total_time: 152ms [(prepare inputFormat 55ms)~(getSplits 90ms)~(distributeSplits 4ms)~(3ms)]                      |
   *     |valid_segment_num: 1                                                                                              |
   *     |stream_segment_num: 1                                                                                             |
   *     |hit_data_block: 1                                                                                                 |
   *     |spark_partition_num: 1                                                                                            |
   *     |pushed_filter: (((stringfield <> null and decimalfield <> null) and stringfield = spark) and decimalfield > 40.00)|
   *     |pushed_projection: charfield,stringfield,intfield                                                                 |
   *     +------------------------------------------------------------------------------------------------------------------+
   *   |_2.task statistics
   *     +--------------+-------+-----------------------+----------+----------------+--------------------+----------------+--------------+---------------+---------------+---------------+-----------+-------------+-----------+-----------+
   *     |query_id      |task_id|start_time             |total_time|load_blocks_time|load_dictionary_time|carbon_scan_time|carbon_IO_time|scan_blocks_num|total_blocklets|valid_blocklets|total_pages|scanned_pages|valid_pages|result_size|
   *     +--------------+-------+-----------------------+----------+----------------+--------------------+----------------+--------------+---------------+---------------+---------------+-----------+-------------+-----------+-----------+
   *     |23737310772188|      0|2018-03-22 17:12:23.334|     106ms|             3ms|                 0ms|            -1ms|          -1ms|              1|              1|              1|          0|            1|          1|          3|
   *     +--------------+-------+-----------------------+----------+----------------+--------------------+----------------+--------------+---------------+---------------+---------------+-----------+-------------+-----------+-----------+
   *   |_3.input files for each task
   *     +--------------------------------------------------------+
   *     |query_id: 23737310772188                                |
   *     |task_id: 0                                              |
   *     |total_size: 2717Byte                                    |
   *     |file_list:                                              |
   *     |  Segment_0/part-0-0_batchno0-0-1521709939969.carbondata|
   *     +--------------------------------------------------------+
   * [sql plan]:
   * +----------+
   * | ...      |
   * +----------+
   */
  // scalastyle:on
  override def toString: String = {
    val builder = new JavaStringBuilder(1000)
    builder.append(s"\n[execution id]: ${ executionId }\n")
    builder.append(s"[start time]: ${ ProfilerLogger.format(startTime) }\n")
    builder.append(s"[executor side total taken]: $totalTaken ms")
    builder.append(s"\n  |_1.getPartition\n")
    printGetPartitionTable(builder, "    ")
    builder.append(s"\n  |_2.task statistics\n")
    printStatisticTable(builder, "    ")
    builder.append(s"\n  |_3.input files for each task\n")
    printInputFiles(builder, "    ")
    builder.append(s"\n[sql plan]:\n")
    CarbonUtil.logTable(builder, sqlPlan, "")
    builder.toString
  }
}

1	/*
2	* Licensed to the Apache Software Foundation (ASF) under one or more
3	* contributor license agreements. See the NOTICE file distributed with
4	* this work for additional information regarding copyright ownership.
5	* The ASF licenses this file to You under the Apache License, Version 2.0
6	* (the "License"); you may not use this file except in compliance with
7	* the License. You may obtain a copy of the License at
8	*
9	* http://www.apache.org/licenses/LICENSE-2.0
10	*
11	* Unless required by applicable law or agreed to in writing, software
12	* distributed under the License is distributed on an "AS IS" BASIS,
13	* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14	* See the License for the specific language governing permissions and
15	* limitations under the License.
16	*/
17
18	package org.apache.spark.sql.profiler
19
20	import java.lang.{StringBuilder => JavaStringBuilder}
21	import java.sql.Timestamp
22	import java.text.SimpleDateFormat
23	import java.util
24	import java.util.Comparator
25
26	import scala.collection.mutable.ArrayBuffer
27
28	import org.apache.carbondata.common.logging.LogServiceFactory
29	import org.apache.carbondata.core.stats.TaskStatistics
30	import org.apache.carbondata.core.util.CarbonUtil
31
32	/**
33	* the util of profiler logger
34	*/
35	private[profiler] object ProfilerLogger {
36
37	val LOGGER = LogServiceFactory.getLogService(this.getClass.getCanonicalName)	1✔
38
39	lazy val simpleDateFormat = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS")	1✔
40
41	// format timestamp value
42	def format(time: Long): String = this.synchronized {
43	if (time < 0) {	1✔
44	""	×
45	} else {
46	val timestamp = new Timestamp(time)	1✔
47	simpleDateFormat.format(timestamp)	1✔
48	}
49	}
50
51	def logStatementSummary(statementId: Long, messages: ArrayBuffer[ProfilerMessage]): Unit = {
52	LOGGER.info(new StatementSummary(statementId, messages).toString)	1✔
53	}
54
55	def logExecutionSummary(executionId: Long, messages: ArrayBuffer[ProfilerMessage]): Unit = {
56	LOGGER.info(new ExecutionSummary(executionId, messages).toString)	1✔
57	}
58	}
59
60	/**
61	* summarize the statement information
62	*/
63	private[profiler] class StatementSummary(	1✔
64	statementId: Long,	1✔
65	messages: ArrayBuffer[ProfilerMessage]
66	) {
67
68	private var sqlText: String = ""	1✔
69
70	private var isCommand = false	1✔
71
72	private var startTime: Long = -1	1✔
73
74	private var parserEnd: Long = -1	1✔
75
76	private var analyzerEnd: Long = -1	1✔
77
78	private var optimizerStart: Long = -1	1✔
79
80	private var optimizerEnd: Long = -1	1✔
81
82	private var optimizerTaken: Long = -1	1✔
83
84	private var endTime: Long = -1	1✔
85
86	// summarize the messages
87	messages.foreach {	1✔
88	case sqlStart: SQLStart =>	1✔
89	sqlText = sqlStart.sqlText.trim	1✔
90	isCommand = sqlStart.isCommand	1✔
91	startTime = sqlStart.startTime	1✔
92	parserEnd = sqlStart.parseEnd	1✔
93	analyzerEnd = sqlStart.analyzerEnd	1✔
94	endTime = sqlStart.endTime	1✔
95	case optimizer: Optimizer =>	1✔
96	optimizerTaken = optimizer.timeTaken	1✔
97	optimizerStart = optimizer.startTime	1✔
98	optimizerEnd = optimizerStart + optimizerTaken	1✔
99	}
100
101	private def totalTaken: Long = endTime - startTime	1✔
102
103	private def parserTaken: Long = parserEnd - startTime	1✔
104
105	private def analyzerTaken: Long = analyzerEnd - parserEnd	1✔
106
107	private def parserToOptimizer: Long = optimizerEnd - startTime	1✔
108
109	private def commandTaken: Long = endTime - analyzerEnd	1✔
110
111	override def toString: String = {
112	if (isCommand) {	1✔
113	buildForComand()	1✔
114	} else {
115	buildForQuery()	1✔
116	}
117	}
118
119	/**
120	* for example
121	* [statement id]: 1
122	* [sql text]:
123	* +-----------------------------------------------------------+
124	* \|CREATE TABLE carbon_table( \|
125	* \| shortField SHORT, \|
126	* \| intField INT, \|
127	* \| bigintField LONG, \|
128	* \| doubleField DOUBLE, \|
129	* \| stringField STRING, \|
130	* \| timestampField TIMESTAMP, \|
131	* \| decimalField DECIMAL(18,2), \|
132	* \| dateField DATE, \|
133	* \| charField CHAR(5), \|
134	* \| floatField FLOAT \|
135	* \| ) \|
136	* \| STORED BY 'carbondata' \|
137	* \| TBLPROPERTIES('DICTIONARY_INCLUDE'='dateField, charField')\|
138	* +-----------------------------------------------------------+
139	* [start time]: 2018-03-22 17:12:18.310
140	* [driver side total taken]: 1255 ms
141	* \|__ 1.parser taken: 203 ms
142	* \|__ 2.analyzer taken: 1 ms
143	* \|__ 3.execution taken: 1051 ms
144	* \|__ ...
145	*/
146	private def buildForComand(): String = {
147	val builder = new JavaStringBuilder(1000)	1✔
148	builder.append(s"\n[statement id]: ${ statementId }")	1✔
149	builder.append(s"\n[sql text]:\n")	1✔
150	CarbonUtil.logTable(builder, sqlText, "")	1✔
151	builder.append(s"\n[start time]: ${ ProfilerLogger.format(startTime) }\n")	1✔
152	builder.append(s"[driver side total taken]: $totalTaken ms\n")	1✔
153	builder.append(s" \|__ 1.parser taken: $parserTaken ms\n")	1✔
154	builder.append(s" \|__ 2.analyzer taken: $analyzerTaken ms\n")	1✔
155	builder.append(s" \|__ 3.execution taken: $commandTaken ms")	1✔
156	builder.toString	1✔
157	}
158
159	/**
160	* for example
161	* [statement id]: 4
162	* [sql text]:
163	* +--------------------------------------------------+
164	* \|SELECT charField, stringField, intField \|
165	* \| FROM carbon_table \|
166	* \| WHERE stringfield = 'spark' AND decimalField > 40\|
167	* +--------------------------------------------------+
168	* [start time]: 2018-03-22 17:12:22.001
169	* [driver side total taken]: 476ms
170	* \|__ 1.parser taken: 82 ms
171	* \|__ 2.analyzer taken: 195 ms
172	* \|__ 3.(149ms)
173	* \|__ 4.carbon optimizer taken: 50 ms
174	* end time: 2018-03-22 17:12:22.477
175	*/
176	private def buildForQuery(): String = {
177	val builder = new JavaStringBuilder(1000)	1✔
178	builder.append(s"\n[statement id]: ${ statementId }")	1✔
179	builder.append(s"\n[sql text]:\n")	1✔
180	CarbonUtil.logTable(builder, sqlText, "")	1✔
181	builder.append(s"\n[start time]: ${ ProfilerLogger.format(startTime) }\n")	1✔
182	builder.append(s"[driver side total taken]: ${ parserToOptimizer }ms\n")	1✔
183	builder.append(s" \|__ 1.parser taken: $parserTaken ms\n")	1✔
184	builder.append(s" \|__ 2.analyzer taken: $analyzerTaken ms\n")	1✔
185	builder.append(s" \|__ 3.(${ optimizerStart - analyzerEnd }ms)\n")	1✔
186	builder.append(s" \|__ 4.carbon optimizer taken: $optimizerTaken ms\n")	1✔
187	builder.append(s" end time: ${ ProfilerLogger.format(optimizerEnd) }")	1✔
188	builder.toString	1✔
189	}
190	}
191
192	/**
193	* summarize the execution information
194	*/
195	private[profiler] class ExecutionSummary(	1✔
196	executionId: Long,	1✔
197	messages: ArrayBuffer[ProfilerMessage]
198	) {
199
200	private var sqlPlan: String = ""	1✔
201
202	private var startTime: Long = -1	1✔
203
204	private var endTime: Long = -1	1✔
205
206	private val partitions = new util.ArrayList[GetPartition]()	1✔
207
208	private val tasks = new util.ArrayList[TaskStatistics]()	1✔
209
210	// summarize the messages
211	messages.foreach {	1✔
212	case start: ExecutionStart =>	1✔
213	sqlPlan = start.plan	1✔
214	startTime = start.startTime	1✔
215	case end: ExecutionEnd =>	1✔
216	endTime = end.endTime	1✔
217	case partition: GetPartition =>	1✔
218	partitions.add(partition)	1✔
219	case task: QueryTaskEnd =>	1✔
220	tasks.add(new TaskStatistics(task.queryId, task.values, task.size, task.files))	1✔
221	}
222
223	private def totalTaken: Long = endTime - startTime	1✔
224
225	/**
226	* for example
227	* (prepare inputFormat 55ms)~(getSplits 90ms)~(distributeSplits 4ms)~(3ms)
228	*/
229	private def detail(p: GetPartition, builder: JavaStringBuilder): Unit = {	1✔
230	builder.append("(prepare inputFormat ").append(p.getSplitsStart - p.startTime).append("ms)~")	1✔
231	builder.append("(getSplits ").append(p.getSplitsEnd - p.getSplitsStart).append("ms)~")	1✔
232	val gap1 = p.distributeStart - p.getSplitsEnd	1✔
233	if (gap1 > 0) {	1✔
234	builder.append("(").append(gap1).append("ms)~")	×
235	}
236	builder.append("(distributeSplits ").append(p.distributeEnd - p.distributeStart).append("ms)")	1✔
237	val gap2 = p.endTime - p.distributeEnd	1✔
238	if (gap2 > 0) {	1✔
239	builder.append("~(").append(gap2).append("ms)")	×
240	}
241	}
242
243	private def printGetPartitionTable(builder: JavaStringBuilder, indent: String): Unit = {
244	util.Collections.sort(partitions)	1✔
245	for (rowIndex <- 0 until partitions.size()) {	1✔
246	val partition = partitions.get(rowIndex)	1✔
247	val content = new JavaStringBuilder()	1✔
248	content.append("query_id: ").append(partition.queryId).append("\n")	1✔
249	.append("table_name: ").append(partition.tableName).append("\n")	1✔
250	.append("table_path: ").append(partition.tablePath).append("\n")	1✔
251	.append("start_time: ").append(ProfilerLogger.format(partition.startTime)).append("\n")	1✔
252	// total time
253	content.append("total_time: ").append(partition.endTime - partition.startTime).append("ms")	1✔
254	content.append(" [")	1✔
255	detail(partition, content)	1✔
256	content.append("]\n")	1✔
257	content.append("valid_segment_num: ").append(partition.numSegments).append("\n")	1✔
258	.append("stream_segment_num: ").append(partition.numStreamSegments).append("\n")	1✔
259	.append("hit_data_block: ").append(partition.numBlocks).append("\n")	1✔
260	.append("spark_partition_num: ").append(partition.numOfPartitions).append("\n")	1✔
261	.append("pushed_filter: ").append(partition.filter).append("\n")	1✔
262	.append("pushed_projection: ").append(partition.projection)	1✔
263	if (rowIndex > 0) {	1✔
264	builder.append("\n")	1✔
265	}
266	CarbonUtil.logTable(builder, content.toString, indent)	1✔
267	}
268	}
269
270	private def printStatisticTable(builder: JavaStringBuilder, indent: String): Unit = {
271	util.Collections.sort(tasks, comparator)	1✔
272	TaskStatistics.printStatisticTable(tasks, builder, indent)	1✔
273	}
274
275	private def printInputFiles(builder: JavaStringBuilder, indent: String): Unit = {
276	for (taskIndex <- 0 until tasks.size()) {	1✔
277	val task = tasks.get(taskIndex)	1✔
278	val content = new JavaStringBuilder()	1✔
279	content.append("query_id: ").append(task.getQueryId).append("\n")	1✔
280	.append("task_id: ").append(task.getValues()(1)).append("\n")	1✔
281	.append("total_size: ").append(task.getFileSize).append("Byte\n")	1✔
282	.append("file_list: ")	1✔
283	task.getFiles.foreach { file =>	1✔
284	content.append("\n Segment_").append(file)	1✔
285	}
286	if (taskIndex > 0) {	1✔
287	builder.append("\n")	1✔
288	}
289	CarbonUtil.logTable(builder, content.toString, indent)	1✔
290	}
291	}
292
293	// use to sort tasks
294	private lazy val comparator = new Comparator[TaskStatistics]() {	1✔
295	override def compare(o1: TaskStatistics,
296	o2: TaskStatistics) = {	1✔
297	val result = o1.getQueryId.compareTo(o2.getQueryId())	1✔
298	if (result != 0) {	1✔
299	result	1✔
300	} else {
301	val task = o1.getValues()(1) - o2.getValues()(1)	×
302	if (task > 0) {	×
303	1	×
304	} else if (task < 0) {	×
305	-1	×
306	} else {
307	0	×
308	}
309	}
310	}
311	}
312
313	// scalastyle:off
314	/**
315	* for example
316	* [execution id]: 0
317	* [start time]: 2018-03-22 17:12:22.608
318	* [executor side total taken]: 845 ms
319	* \|_1.getPartition
320	* +------------------------------------------------------------------------------------------------------------------+
321	* \|query_id: 23737310772188 \|
322	* \|table_name: default.carbon_table \|
323	* \|table_path: /carbondata/examples/spark2/target/store/default/carbon_table \|
324	* \|start_time: 2018-03-22 17:12:23.141 \|
325	* \|total_time: 152ms [(prepare inputFormat 55ms)~(getSplits 90ms)~(distributeSplits 4ms)~(3ms)] \|
326	* \|valid_segment_num: 1 \|
327	* \|stream_segment_num: 1 \|
328	* \|hit_data_block: 1 \|
329	* \|spark_partition_num: 1 \|
330	* \|pushed_filter: (((stringfield <> null and decimalfield <> null) and stringfield = spark) and decimalfield > 40.00)\|
331	* \|pushed_projection: charfield,stringfield,intfield \|
332	* +------------------------------------------------------------------------------------------------------------------+
333	* \|_2.task statistics
334	* +--------------+-------+-----------------------+----------+----------------+--------------------+----------------+--------------+---------------+---------------+---------------+-----------+-------------+-----------+-----------+
335	* \|query_id \|task_id\|start_time \|total_time\|load_blocks_time\|load_dictionary_time\|carbon_scan_time\|carbon_IO_time\|scan_blocks_num\|total_blocklets\|valid_blocklets\|total_pages\|scanned_pages\|valid_pages\|result_size\|
336	* +--------------+-------+-----------------------+----------+----------------+--------------------+----------------+--------------+---------------+---------------+---------------+-----------+-------------+-----------+-----------+
337	* \|23737310772188\| 0\|2018-03-22 17:12:23.334\| 106ms\| 3ms\| 0ms\| -1ms\| -1ms\| 1\| 1\| 1\| 0\| 1\| 1\| 3\|
338	* +--------------+-------+-----------------------+----------+----------------+--------------------+----------------+--------------+---------------+---------------+---------------+-----------+-------------+-----------+-----------+
339	* \|_3.input files for each task
340	* +--------------------------------------------------------+
341	* \|query_id: 23737310772188 \|
342	* \|task_id: 0 \|
343	* \|total_size: 2717Byte \|
344	* \|file_list: \|
345	* \| Segment_0/part-0-0_batchno0-0-1521709939969.carbondata\|
346	* +--------------------------------------------------------+
347	* [sql plan]:
348	* +----------+
349	* \| ... \|
350	* +----------+
351	*/
352	// scalastyle:on
353	override def toString: String = {
354	val builder = new JavaStringBuilder(1000)	1✔
355	builder.append(s"\n[execution id]: ${ executionId }\n")	1✔
356	builder.append(s"[start time]: ${ ProfilerLogger.format(startTime) }\n")	1✔
357	builder.append(s"[executor side total taken]: $totalTaken ms")	1✔
358	builder.append(s"\n \|_1.getPartition\n")	1✔
359	printGetPartitionTable(builder, " ")	1✔
360	builder.append(s"\n \|_2.task statistics\n")	1✔
361	printStatisticTable(builder, " ")	1✔
362	builder.append(s"\n \|_3.input files for each task\n")	1✔
363	printInputFiles(builder, " ")	1✔
364	builder.append(s"\n[sql plan]:\n")	1✔
365	CarbonUtil.logTable(builder, sqlPlan, "")	1✔
366	builder.toString	1✔
367	}
368	}	1✔

apache / carbondata / 9134

Source File Press 'n' to go to next uncovered line, 'b' for previous

Source File
Press 'n' to go to next uncovered line, 'b' for previous