You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hive.apache.org by "anishek (JIRA)" <ji...@apache.org> on 2017/02/27 07:18:45 UTC
[jira] [Comment Edited] (HIVE-16045) Print progress bar along with
operation log
[ https://issues.apache.org/jira/browse/HIVE-16045?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15885246#comment-15885246 ]
anishek edited comment on HIVE-16045 at 2/27/17 7:17 AM:
---------------------------------------------------------
sample output from the beeline after patch
{code}
0: jdbc:hive2://localhost:10007/default> select max(age) from t;
INFO : Compiling command(queryId=root_20170227071717_0810070a-71bc-450b-b88d-fbd505e38d4b): select max(age) from t
INFO : Semantic Analysis Completed
INFO : Returning Hive schema: Schema(fieldSchemas:[FieldSchema(name:_c0, type:bigint, comment:null)], properties:null)
INFO : Completed compiling command(queryId=root_20170227071717_0810070a-71bc-450b-b88d-fbd505e38d4b); Time taken: 3.994 seconds
INFO : Concurrency mode is disabled, not creating a lock manager
INFO : Executing command(queryId=root_20170227071717_0810070a-71bc-450b-b88d-fbd505e38d4b): select max(age) from t
INFO : Query ID = root_20170227071717_0810070a-71bc-450b-b88d-fbd505e38d4b
INFO : Total jobs = 1
INFO : Launching Job 1 out of 1
INFO : Starting task [Stage-1:MAPRED] in serial mode
INFO : Session is already open
INFO : Dag name: select max(age) from t(Stage-1)
INFO : Status: Running (Executing on YARN cluster with App id application_1486985293385_0278)
INFO : Map 1: 0/1 Reducer 2: 0/1
----------------------------------------------------------------------------------------------
VERTICES MODE STATUS TOTAL COMPLETED RUNNING PENDING FAILED KILLED
----------------------------------------------------------------------------------------------
Map 1 .......... container SUCCEEDED 1 1 0 0 0 0
Reducer 2 ...... container SUCCEEDED 1 1 0 0 0 0
----------------------------------------------------------------------------------------------
VERTICES: 02/02 [==========================>>] 100% ELAPSED TIME: 4.48 s
----------------------------------------------------------------------------------------------
INFO : Map 1: 0(+1)/1 Reducer 2: 0/1
INFO : Map 1: 1/1 Reducer 2: 0(+1)/1
INFO : Map 1: 1/1 Reducer 2: 1/1
INFO : Status: DAG finished successfully in 4.35 seconds
INFO :
INFO : Query Execution Summary
INFO : ----------------------------------------------------------------------------------------------
INFO : OPERATION DURATION
INFO : ----------------------------------------------------------------------------------------------
INFO : Compile Query 3.99s
INFO : Prepare Plan 0.64s
INFO : Submit Plan 0.43s
INFO : Start DAG 0.61s
INFO : Run DAG 4.35s
INFO : ----------------------------------------------------------------------------------------------
INFO :
INFO : Task Execution Summary
INFO : ----------------------------------------------------------------------------------------------
INFO : VERTICES DURATION(ms) CPU_TIME(ms) GC_TIME(ms) INPUT_RECORDS OUTPUT_RECORDS
INFO : ----------------------------------------------------------------------------------------------
INFO : Map 1 2061.00 3,920 26 5 1
INFO : Reducer 2 429.00 1,690 0 1 0
INFO : ----------------------------------------------------------------------------------------------
INFO :
INFO : LLAP IO Summary
INFO : ----------------------------------------------------------------------------------------------
INFO : VERTICES ROWGROUPS META_HIT META_MISS DATA_HIT DATA_MISS ALLOCATION USED TOTAL_IO
INFO : ----------------------------------------------------------------------------------------------
INFO : Map 1 0 0 0 0B 0B 0B 0B 0.00s
INFO : ----------------------------------------------------------------------------------------------
INFO :
INFO : FileSystem Counters Summary
INFO :
INFO : Scheme: FILE
INFO : ----------------------------------------------------------------------------------------------
INFO : VERTICES BYTES_READ READ_OPS LARGE_READ_OPS BYTES_WRITTEN WRITE_OPS
INFO : ----------------------------------------------------------------------------------------------
INFO : Map 1 0B 0 0 59B 0
INFO : Reducer 2 0B 0 0 0B 0
INFO : ----------------------------------------------------------------------------------------------
INFO :
INFO : Scheme: HDFS
INFO : ----------------------------------------------------------------------------------------------
INFO : VERTICES BYTES_READ READ_OPS LARGE_READ_OPS BYTES_WRITTEN WRITE_OPS
INFO : ----------------------------------------------------------------------------------------------
INFO : Map 1 14B 1 0 0B 0
INFO : Reducer 2 0B 2 0 103B 2
INFO : ----------------------------------------------------------------------------------------------
INFO :
INFO : org.apache.tez.common.counters.DAGCounter:
INFO : NUM_SUCCEEDED_TASKS: 2
INFO : TOTAL_LAUNCHED_TASKS: 2
INFO : DATA_LOCAL_TASKS: 1
INFO : AM_CPU_MILLISECONDS: 3210
INFO : AM_GC_TIME_MILLIS: 33
INFO : File System Counters:
INFO : FILE_BYTES_READ: 0
INFO : FILE_BYTES_WRITTEN: 59
INFO : FILE_READ_OPS: 0
INFO : FILE_LARGE_READ_OPS: 0
INFO : FILE_WRITE_OPS: 0
INFO : HDFS_BYTES_READ: 14
INFO : HDFS_BYTES_WRITTEN: 103
INFO : HDFS_READ_OPS: 3
INFO : HDFS_LARGE_READ_OPS: 0
INFO : HDFS_WRITE_OPS: 2
INFO : org.apache.tez.common.counters.TaskCounter:
INFO : SPILLED_RECORDS: 0
INFO : NUM_SHUFFLED_INPUTS: 1
INFO : NUM_FAILED_SHUFFLE_INPUTS: 0
INFO : GC_TIME_MILLIS: 26
INFO : CPU_MILLISECONDS: 5610
INFO : PHYSICAL_MEMORY_BYTES: 4294967296
INFO : VIRTUAL_MEMORY_BYTES: 25336373248
INFO : COMMITTED_HEAP_BYTES: 4294967296
INFO : INPUT_RECORDS_PROCESSED: 6
INFO : INPUT_SPLIT_LENGTH_BYTES: 14
INFO : OUTPUT_RECORDS: 1
INFO : OUTPUT_LARGE_RECORDS: 0
INFO : OUTPUT_BYTES: 5
INFO : OUTPUT_BYTES_WITH_OVERHEAD: 13
INFO : OUTPUT_BYTES_PHYSICAL: 51
INFO : ADDITIONAL_SPILLS_BYTES_WRITTEN: 0
INFO : ADDITIONAL_SPILLS_BYTES_READ: 0
INFO : ADDITIONAL_SPILL_COUNT: 0
INFO : SHUFFLE_BYTES: 27
INFO : SHUFFLE_BYTES_DECOMPRESSED: 13
INFO : SHUFFLE_BYTES_TO_MEM: 27
INFO : SHUFFLE_BYTES_TO_DISK: 0
INFO : SHUFFLE_BYTES_DISK_DIRECT: 0
INFO : SHUFFLE_PHASE_TIME: 110
INFO : FIRST_EVENT_RECEIVED: 79
INFO : LAST_EVENT_RECEIVED: 79
INFO : HIVE:
INFO : CREATED_FILES: 1
INFO : DESERIALIZE_ERRORS: 0
INFO : RECORDS_IN_Map_1: 5
INFO : RECORDS_OUT_0: 1
INFO : RECORDS_OUT_INTERMEDIATE_Map_1: 1
INFO : TaskCounter_Map_1_INPUT_t:
INFO : INPUT_RECORDS_PROCESSED: 5
INFO : INPUT_SPLIT_LENGTH_BYTES: 14
INFO : TaskCounter_Map_1_OUTPUT_Reducer_2:
INFO : ADDITIONAL_SPILLS_BYTES_READ: 0
INFO : ADDITIONAL_SPILLS_BYTES_WRITTEN: 0
INFO : ADDITIONAL_SPILL_COUNT: 0
INFO : OUTPUT_BYTES: 5
INFO : OUTPUT_BYTES_PHYSICAL: 51
INFO : OUTPUT_BYTES_WITH_OVERHEAD: 13
INFO : OUTPUT_LARGE_RECORDS: 0
INFO : OUTPUT_RECORDS: 1
INFO : SPILLED_RECORDS: 0
INFO : TaskCounter_Reducer_2_INPUT_Map_1:
INFO : FIRST_EVENT_RECEIVED: 79
INFO : INPUT_RECORDS_PROCESSED: 1
INFO : LAST_EVENT_RECEIVED: 79
INFO : NUM_FAILED_SHUFFLE_INPUTS: 0
INFO : NUM_SHUFFLED_INPUTS: 1
INFO : SHUFFLE_BYTES: 27
INFO : SHUFFLE_BYTES_DECOMPRESSED: 13
INFO : SHUFFLE_BYTES_DISK_DIRECT: 0
INFO : SHUFFLE_BYTES_TO_DISK: 0
INFO : SHUFFLE_BYTES_TO_MEM: 27
INFO : SHUFFLE_PHASE_TIME: 110
INFO : TaskCounter_Reducer_2_OUTPUT_out_Reducer_2:
INFO : OUTPUT_RECORDS: 0
INFO : Completed executing command(queryId=root_20170227071717_0810070a-71bc-450b-b88d-fbd505e38d4b); Time taken: 6.1 seconds
INFO : OK
+------+
| _c0 |
+------+
| 854 |
+------+
1 row selected (10.541 seconds)
{code}
was (Author: anishek):
sample output from the beeline after patch
{code}
0: jdbc:hive2://localhost:10007/default> select max(age) from t;
INFO : Compiling command(queryId=root_20170227064051_dab7f2ad-0009-44c2-b59b-e55179bc6eae): select max(age) from t
INFO : We are setting the hadoop caller context from HIVE_SSN_ID:5d59ff69-3f21-48af-a688-9855b4052901 to root_20170227064051_dab7f2ad-0009-44c2-b59b-e55179bc6eae
INFO : Semantic Analysis Completed
INFO : Returning Hive schema: Schema(fieldSchemas:[FieldSchema(name:_c0, type:bigint, comment:null)], properties:null)
INFO : Completed compiling command(queryId=root_20170227064051_dab7f2ad-0009-44c2-b59b-e55179bc6eae); Time taken: 3.78 seconds
INFO : We are resetting the hadoop caller context to HIVE_SSN_ID:5d59ff69-3f21-48af-a688-9855b4052901
INFO : Concurrency mode is disabled, not creating a lock manager
INFO : Setting caller context to query id root_20170227064051_dab7f2ad-0009-44c2-b59b-e55179bc6eae
INFO : Executing command(queryId=root_20170227064051_dab7f2ad-0009-44c2-b59b-e55179bc6eae): select max(age) from t
INFO : Query ID = root_20170227064051_dab7f2ad-0009-44c2-b59b-e55179bc6eae
INFO : Total jobs = 1
INFO : Launching Job 1 out of 1
INFO : Starting task [Stage-1:MAPRED] in serial mode
INFO : Session is already open
INFO : Dag name: select max(age) from t(Stage-1)
INFO : Status: Running (Executing on YARN cluster with App id application_1486985293385_0274)
INFO : Map 1: 0/1 Reducer 2: 0/1
----------------------------------------------------------------------------------------------
VERTICES MODE STATUS TOTAL COMPLETED RUNNING PENDING FAILED KILLED
----------------------------------------------------------------------------------------------
Map 1 .......... container SUCCEEDED 1 1 0 0 0 0
Reducer 2 ...... container SUCCEEDED 1 1 0 0 0 0
VERTICES: 02/02 [==========================>>] 100% ELAPSED TIME: 3.93 s
----------------------------------------------------------------------------------------------
INFO : Map 1: 0(+1)/1 Reducer 2: 0/1
INFO : Map 1: 1/1 Reducer 2: 0/1
INFO : Map 1: 1/1 Reducer 2: 0(+1)/1
INFO : Map 1: 1/1 Reducer 2: 1/1
INFO : Status: DAG finished successfully in 3.83 seconds
INFO :
INFO : Query Execution Summary
INFO : ----------------------------------------------------------------------------------------------
INFO : OPERATION DURATION
INFO : ----------------------------------------------------------------------------------------------
INFO : Compile Query 3.78s
INFO : Prepare Plan 0.70s
INFO : Submit Plan 0.40s
INFO : Start DAG 0.59s
INFO : Run DAG 3.83s
INFO : ----------------------------------------------------------------------------------------------
INFO :
INFO : Task Execution Summary
INFO : --------------------------------------------------------------------------------------------------------------------------------
INFO : VERTICES TOTAL_TASKS FAILED_ATTEMPTS KILLED_TASKS DURATION(ms) CPU_TIME(ms) GC_TIME(ms) INPUT_RECORDS OUTPUT_RECORDS
INFO : --------------------------------------------------------------------------------------------------------------------------------
INFO : Map 1 1 0 0 1983.00 3,670 26 5 1
INFO : Reducer 2 1 0 0 347.00 1,780 0 1 0
INFO : --------------------------------------------------------------------------------------------------------------------------------
INFO :
INFO : LLAP IO Summary
INFO : ----------------------------------------------------------------------------------------------
INFO : VERTICES ROWGROUPS META_HIT META_MISS DATA_HIT DATA_MISS ALLOCATION USED TOTAL_IO
INFO : ----------------------------------------------------------------------------------------------
INFO : Map 1 0 0 0 0B 0B 0B 0B 0.00s
INFO : ----------------------------------------------------------------------------------------------
INFO :
INFO : FileSystem Counters Summary
INFO :
INFO : Scheme: FILE
INFO : ----------------------------------------------------------------------------------------------
INFO : VERTICES BYTES_READ READ_OPS LARGE_READ_OPS BYTES_WRITTEN WRITE_OPS
INFO : ----------------------------------------------------------------------------------------------
INFO : Map 1 0B 0 0 59B 0
INFO : Reducer 2 27B 0 0 27B 0
INFO : ----------------------------------------------------------------------------------------------
INFO :
INFO : Scheme: HDFS
INFO : ----------------------------------------------------------------------------------------------
INFO : VERTICES BYTES_READ READ_OPS LARGE_READ_OPS BYTES_WRITTEN WRITE_OPS
INFO : ----------------------------------------------------------------------------------------------
INFO : Map 1 14B 1 0 0B 0
INFO : Reducer 2 0B 2 0 103B 2
INFO : ----------------------------------------------------------------------------------------------
INFO :
INFO : org.apache.tez.common.counters.DAGCounter:
INFO : NUM_SUCCEEDED_TASKS: 2
INFO : TOTAL_LAUNCHED_TASKS: 2
INFO : DATA_LOCAL_TASKS: 1
INFO : AM_CPU_MILLISECONDS: 2860
INFO : AM_GC_TIME_MILLIS: 26
INFO : File System Counters:
INFO : FILE_BYTES_READ: 27
INFO : FILE_BYTES_WRITTEN: 86
INFO : FILE_READ_OPS: 0
INFO : FILE_LARGE_READ_OPS: 0
INFO : FILE_WRITE_OPS: 0
INFO : HDFS_BYTES_READ: 14
INFO : HDFS_BYTES_WRITTEN: 103
INFO : HDFS_READ_OPS: 3
INFO : HDFS_LARGE_READ_OPS: 0
INFO : HDFS_WRITE_OPS: 2
INFO : org.apache.tez.common.counters.TaskCounter:
INFO : REDUCE_INPUT_GROUPS: 1
INFO : REDUCE_INPUT_RECORDS: 1
INFO : COMBINE_INPUT_RECORDS: 0
INFO : SPILLED_RECORDS: 2
INFO : NUM_SHUFFLED_INPUTS: 1
INFO : NUM_SKIPPED_INPUTS: 0
INFO : NUM_FAILED_SHUFFLE_INPUTS: 0
INFO : MERGED_MAP_OUTPUTS: 1
INFO : GC_TIME_MILLIS: 26
INFO : CPU_MILLISECONDS: 5450
INFO : PHYSICAL_MEMORY_BYTES: 4294967296
INFO : VIRTUAL_MEMORY_BYTES: 25287217152
INFO : COMMITTED_HEAP_BYTES: 4294967296
INFO : INPUT_RECORDS_PROCESSED: 5
INFO : INPUT_SPLIT_LENGTH_BYTES: 14
INFO : OUTPUT_RECORDS: 1
INFO : OUTPUT_BYTES: 5
INFO : OUTPUT_BYTES_WITH_OVERHEAD: 13
INFO : OUTPUT_BYTES_PHYSICAL: 27
INFO : ADDITIONAL_SPILLS_BYTES_WRITTEN: 27
INFO : ADDITIONAL_SPILLS_BYTES_READ: 27
INFO : ADDITIONAL_SPILL_COUNT: 0
INFO : SHUFFLE_CHUNK_COUNT: 1
INFO : SHUFFLE_BYTES: 27
INFO : SHUFFLE_BYTES_DECOMPRESSED: 13
INFO : SHUFFLE_BYTES_TO_MEM: 27
INFO : SHUFFLE_BYTES_TO_DISK: 0
INFO : SHUFFLE_BYTES_DISK_DIRECT: 0
INFO : NUM_MEM_TO_DISK_MERGES: 0
INFO : NUM_DISK_TO_DISK_MERGES: 0
INFO : SHUFFLE_PHASE_TIME: 154
INFO : MERGE_PHASE_TIME: 170
INFO : FIRST_EVENT_RECEIVED: 114
INFO : LAST_EVENT_RECEIVED: 114
INFO : HIVE:
INFO : CREATED_FILES: 1
INFO : DESERIALIZE_ERRORS: 0
INFO : RECORDS_IN_Map_1: 5
INFO : RECORDS_OUT_0: 1
INFO : RECORDS_OUT_INTERMEDIATE_Map_1: 1
INFO : Shuffle Errors:
INFO : BAD_ID: 0
INFO : CONNECTION: 0
INFO : IO_ERROR: 0
INFO : WRONG_LENGTH: 0
INFO : WRONG_MAP: 0
INFO : WRONG_REDUCE: 0
INFO : Shuffle Errors_Reducer_2_INPUT_Map_1:
INFO : BAD_ID: 0
INFO : CONNECTION: 0
INFO : IO_ERROR: 0
INFO : WRONG_LENGTH: 0
INFO : WRONG_MAP: 0
INFO : WRONG_REDUCE: 0
INFO : TaskCounter_Map_1_INPUT_t:
INFO : INPUT_RECORDS_PROCESSED: 5
INFO : INPUT_SPLIT_LENGTH_BYTES: 14
INFO : TaskCounter_Map_1_OUTPUT_Reducer_2:
INFO : ADDITIONAL_SPILLS_BYTES_READ: 0
INFO : ADDITIONAL_SPILLS_BYTES_WRITTEN: 0
INFO : ADDITIONAL_SPILL_COUNT: 0
INFO : OUTPUT_BYTES: 5
INFO : OUTPUT_BYTES_PHYSICAL: 27
INFO : OUTPUT_BYTES_WITH_OVERHEAD: 13
INFO : OUTPUT_RECORDS: 1
INFO : SHUFFLE_CHUNK_COUNT: 1
INFO : SPILLED_RECORDS: 1
INFO : TaskCounter_Reducer_2_INPUT_Map_1:
INFO : ADDITIONAL_SPILLS_BYTES_READ: 27
INFO : ADDITIONAL_SPILLS_BYTES_WRITTEN: 27
INFO : COMBINE_INPUT_RECORDS: 0
INFO : FIRST_EVENT_RECEIVED: 114
INFO : LAST_EVENT_RECEIVED: 114
INFO : MERGED_MAP_OUTPUTS: 1
INFO : MERGE_PHASE_TIME: 170
INFO : NUM_DISK_TO_DISK_MERGES: 0
INFO : NUM_FAILED_SHUFFLE_INPUTS: 0
INFO : NUM_MEM_TO_DISK_MERGES: 0
INFO : NUM_SHUFFLED_INPUTS: 1
INFO : NUM_SKIPPED_INPUTS: 0
INFO : REDUCE_INPUT_GROUPS: 1
INFO : REDUCE_INPUT_RECORDS: 1
INFO : SHUFFLE_BYTES: 27
INFO : SHUFFLE_BYTES_DECOMPRESSED: 13
INFO : SHUFFLE_BYTES_DISK_DIRECT: 0
INFO : SHUFFLE_BYTES_TO_DISK: 0
INFO : SHUFFLE_BYTES_TO_MEM: 27
INFO : SHUFFLE_PHASE_TIME: 154
INFO : SPILLED_RECORDS: 1
INFO : TaskCounter_Reducer_2_OUTPUT_out_Reducer_2:
INFO : OUTPUT_RECORDS: 0
INFO : Resetting the caller context to HIVE_SSN_ID:5d59ff69-3f21-48af-a688-9855b4052901
INFO : Completed executing command(queryId=root_20170227064051_dab7f2ad-0009-44c2-b59b-e55179bc6eae); Time taken: 5.568 seconds
INFO : OK
+------+--+
| _c0 |
+------+--+
| 854 |
+------+--+
1 row selected (9.953 seconds)
{code}
> Print progress bar along with operation log
> -------------------------------------------
>
> Key: HIVE-16045
> URL: https://issues.apache.org/jira/browse/HIVE-16045
> Project: Hive
> Issue Type: Improvement
> Components: HiveServer2
> Affects Versions: 2.2.0
> Reporter: anishek
> Assignee: anishek
> Fix For: 2.2.0
>
> Attachments: HIVE-16045.1.patch
>
>
> allow printing of the operation logs and progress bar such that,
> allow operations logs to output data once -> block it -> start progress bar -> finish progress bar -> unblock the operations log -> finish operations log -> print query results.
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)