[jira] [Commented] (HIVE-20989) JDBC - The GetOperationStatus + log can block query progress via sleep()
[
https://issues.apache.org/jira/browse/HIVE-20989?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16726550#comment-16726550
]
anishek commented on HIVE-20989:
+1
> JDBC - The GetOperationStatus + log can block query progress via sleep()
>
>
> Key: HIVE-20989
> URL: https://issues.apache.org/jira/browse/HIVE-20989
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 4.0.0
>Reporter: Gopal V
>Assignee: Sankar Hariappan
>Priority: Major
> Attachments: HIVE-20989.01.patch
>
>
> There is an exponential sleep operation inside the CLIService which can end
> up adding tens of seconds to a query which has already completed.
> {code}
> "HiveServer2-Handler-Pool: Thread-9373" #9373 prio=5 os_prio=0
> tid=0x7f4d5e72d800 nid=0xb634a waiting on condition [0x7f28d06a5000]
> java.lang.Thread.State: TIMED_WAITING (sleeping)
> at java.lang.Thread.sleep(Native Method)
> at
> org.apache.hive.service.cli.CLIService.progressUpdateLog(CLIService.java:506)
> at
> org.apache.hive.service.cli.CLIService.getOperationStatus(CLIService.java:480)
> at
> org.apache.hive.service.cli.thrift.ThriftCLIService.GetOperationStatus(ThriftCLIService.java:695)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1757)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1742)
> at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
> at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39)
> at
> org.apache.hive.service.auth.TSetIpAddressProcessor.process(TSetIpAddressProcessor.java:56)
> at
> org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> {code}
> The sleep loop is on the server side.
> {code}
> private static final long PROGRESS_MAX_WAIT_NS = 30 * 10l;
> private JobProgressUpdate progressUpdateLog(boolean isProgressLogRequested,
> Operation operation, HiveConf conf) {
> ...
> long startTime = System.nanoTime();
> int timeOutMs = 8;
> try {
> while (sessionState.getProgressMonitor() == null &&
> !operation.isDone()) {
> long remainingMs = (PROGRESS_MAX_WAIT_NS - (System.nanoTime() -
> startTime)) / 100l;
> if (remainingMs <= 0) {
> LOG.debug("timed out and hence returning progress log as NULL");
> return new JobProgressUpdate(ProgressMonitor.NULL);
> }
> Thread.sleep(Math.min(remainingMs, timeOutMs));
> timeOutMs <<= 1;
> }
> {code}
> After about 16 seconds of execution of the query, the timeOutMs is 16384 ms,
> which means the next sleep cycle is for min(30 - 17, 16) = 13.
> If the query finishes on the 17th second, the JDBC server will only respond
> after the 30th second when it will check for operation.isDone() and return.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
[jira] [Commented] (HIVE-20989) JDBC - The GetOperationStatus + log can block query progress via sleep()
[
https://issues.apache.org/jira/browse/HIVE-20989?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16725994#comment-16725994
]
Sankar Hariappan commented on HIVE-20989:
-
[~gopalv]
I fixed it with CountDownLatch. Can you please review?
> JDBC - The GetOperationStatus + log can block query progress via sleep()
>
>
> Key: HIVE-20989
> URL: https://issues.apache.org/jira/browse/HIVE-20989
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 4.0.0
>Reporter: Gopal V
>Assignee: Sankar Hariappan
>Priority: Major
> Attachments: HIVE-20989.01.patch
>
>
> There is an exponential sleep operation inside the CLIService which can end
> up adding tens of seconds to a query which has already completed.
> {code}
> "HiveServer2-Handler-Pool: Thread-9373" #9373 prio=5 os_prio=0
> tid=0x7f4d5e72d800 nid=0xb634a waiting on condition [0x7f28d06a5000]
> java.lang.Thread.State: TIMED_WAITING (sleeping)
> at java.lang.Thread.sleep(Native Method)
> at
> org.apache.hive.service.cli.CLIService.progressUpdateLog(CLIService.java:506)
> at
> org.apache.hive.service.cli.CLIService.getOperationStatus(CLIService.java:480)
> at
> org.apache.hive.service.cli.thrift.ThriftCLIService.GetOperationStatus(ThriftCLIService.java:695)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1757)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1742)
> at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
> at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39)
> at
> org.apache.hive.service.auth.TSetIpAddressProcessor.process(TSetIpAddressProcessor.java:56)
> at
> org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> {code}
> The sleep loop is on the server side.
> {code}
> private static final long PROGRESS_MAX_WAIT_NS = 30 * 10l;
> private JobProgressUpdate progressUpdateLog(boolean isProgressLogRequested,
> Operation operation, HiveConf conf) {
> ...
> long startTime = System.nanoTime();
> int timeOutMs = 8;
> try {
> while (sessionState.getProgressMonitor() == null &&
> !operation.isDone()) {
> long remainingMs = (PROGRESS_MAX_WAIT_NS - (System.nanoTime() -
> startTime)) / 100l;
> if (remainingMs <= 0) {
> LOG.debug("timed out and hence returning progress log as NULL");
> return new JobProgressUpdate(ProgressMonitor.NULL);
> }
> Thread.sleep(Math.min(remainingMs, timeOutMs));
> timeOutMs <<= 1;
> }
> {code}
> After about 16 seconds of execution of the query, the timeOutMs is 16384 ms,
> which means the next sleep cycle is for min(30 - 17, 16) = 13.
> If the query finishes on the 17th second, the JDBC server will only respond
> after the 30th second when it will check for operation.isDone() and return.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
[jira] [Commented] (HIVE-20989) JDBC - The GetOperationStatus + log can block query progress via sleep()
[
https://issues.apache.org/jira/browse/HIVE-20989?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16725801#comment-16725801
]
Hive QA commented on HIVE-20989:
Here are the results of testing the latest attachment:
https://issues.apache.org/jira/secure/attachment/12952487/HIVE-20989.01.patch
{color:red}ERROR:{color} -1 due to no test(s) being added or modified.
{color:green}SUCCESS:{color} +1 due to 15737 tests passed
Test results:
https://builds.apache.org/job/PreCommit-HIVE-Build/15400/testReport
Console output: https://builds.apache.org/job/PreCommit-HIVE-Build/15400/console
Test logs: http://104.198.109.242/logs/PreCommit-HIVE-Build-15400/
Messages:
{noformat}
Executing org.apache.hive.ptest.execution.TestCheckPhase
Executing org.apache.hive.ptest.execution.PrepPhase
Executing org.apache.hive.ptest.execution.YetusPhase
Executing org.apache.hive.ptest.execution.ExecutionPhase
Executing org.apache.hive.ptest.execution.ReportingPhase
{noformat}
This message is automatically generated.
ATTACHMENT ID: 12952487 - PreCommit-HIVE-Build
> JDBC - The GetOperationStatus + log can block query progress via sleep()
>
>
> Key: HIVE-20989
> URL: https://issues.apache.org/jira/browse/HIVE-20989
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 4.0.0
>Reporter: Gopal V
>Assignee: Sankar Hariappan
>Priority: Major
> Attachments: HIVE-20989.01.patch
>
>
> There is an exponential sleep operation inside the CLIService which can end
> up adding tens of seconds to a query which has already completed.
> {code}
> "HiveServer2-Handler-Pool: Thread-9373" #9373 prio=5 os_prio=0
> tid=0x7f4d5e72d800 nid=0xb634a waiting on condition [0x7f28d06a5000]
> java.lang.Thread.State: TIMED_WAITING (sleeping)
> at java.lang.Thread.sleep(Native Method)
> at
> org.apache.hive.service.cli.CLIService.progressUpdateLog(CLIService.java:506)
> at
> org.apache.hive.service.cli.CLIService.getOperationStatus(CLIService.java:480)
> at
> org.apache.hive.service.cli.thrift.ThriftCLIService.GetOperationStatus(ThriftCLIService.java:695)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1757)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1742)
> at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
> at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39)
> at
> org.apache.hive.service.auth.TSetIpAddressProcessor.process(TSetIpAddressProcessor.java:56)
> at
> org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> {code}
> The sleep loop is on the server side.
> {code}
> private static final long PROGRESS_MAX_WAIT_NS = 30 * 10l;
> private JobProgressUpdate progressUpdateLog(boolean isProgressLogRequested,
> Operation operation, HiveConf conf) {
> ...
> long startTime = System.nanoTime();
> int timeOutMs = 8;
> try {
> while (sessionState.getProgressMonitor() == null &&
> !operation.isDone()) {
> long remainingMs = (PROGRESS_MAX_WAIT_NS - (System.nanoTime() -
> startTime)) / 100l;
> if (remainingMs <= 0) {
> LOG.debug("timed out and hence returning progress log as NULL");
> return new JobProgressUpdate(ProgressMonitor.NULL);
> }
> Thread.sleep(Math.min(remainingMs, timeOutMs));
> timeOutMs <<= 1;
> }
> {code}
> After about 16 seconds of execution of the query, the timeOutMs is 16384 ms,
> which means the next sleep cycle is for min(30 - 17, 16) = 13.
> If the query finishes on the 17th second, the JDBC server will only respond
> after the 30th second when it will check for operation.isDone() and return.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
[jira] [Commented] (HIVE-20989) JDBC - The GetOperationStatus + log can block query progress via sleep()
[
https://issues.apache.org/jira/browse/HIVE-20989?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16725778#comment-16725778
]
Hive QA commented on HIVE-20989:
| (/) *{color:green}+1 overall{color}* |
\\
\\
|| Vote || Subsystem || Runtime || Comment ||
|| || || || {color:brown} Prechecks {color} ||
| {color:green}+1{color} | {color:green} @author {color} | {color:green} 0m
0s{color} | {color:green} The patch does not contain any @author tags. {color} |
|| || || || {color:brown} master Compile Tests {color} ||
| {color:green}+1{color} | {color:green} mvninstall {color} | {color:green} 7m
41s{color} | {color:green} master passed {color} |
| {color:green}+1{color} | {color:green} compile {color} | {color:green} 0m
21s{color} | {color:green} master passed {color} |
| {color:green}+1{color} | {color:green} checkstyle {color} | {color:green} 0m
11s{color} | {color:green} master passed {color} |
| {color:blue}0{color} | {color:blue} findbugs {color} | {color:blue} 0m
35s{color} | {color:blue} service in master has 48 extant Findbugs warnings.
{color} |
| {color:green}+1{color} | {color:green} javadoc {color} | {color:green} 0m
16s{color} | {color:green} master passed {color} |
|| || || || {color:brown} Patch Compile Tests {color} ||
| {color:green}+1{color} | {color:green} mvninstall {color} | {color:green} 0m
22s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} compile {color} | {color:green} 0m
22s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} javac {color} | {color:green} 0m
22s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} checkstyle {color} | {color:green} 0m
11s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} whitespace {color} | {color:green} 0m
0s{color} | {color:green} The patch has no whitespace issues. {color} |
| {color:green}+1{color} | {color:green} findbugs {color} | {color:green} 0m
41s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} javadoc {color} | {color:green} 0m
15s{color} | {color:green} the patch passed {color} |
|| || || || {color:brown} Other Tests {color} ||
| {color:green}+1{color} | {color:green} asflicense {color} | {color:green} 0m
12s{color} | {color:green} The patch does not generate ASF License warnings.
{color} |
| {color:black}{color} | {color:black} {color} | {color:black} 11m 29s{color} |
{color:black} {color} |
\\
\\
|| Subsystem || Report/Notes ||
| Optional Tests | asflicense javac javadoc findbugs checkstyle compile |
| uname | Linux hiveptest-server-upstream 3.16.0-4-amd64 #1 SMP Debian
3.16.36-1+deb8u1 (2016-09-03) x86_64 GNU/Linux |
| Build tool | maven |
| Personality |
/data/hiveptest/working/yetus_PreCommit-HIVE-Build-15400/dev-support/hive-personality.sh
|
| git revision | master / 1020be0 |
| Default Java | 1.8.0_111 |
| findbugs | v3.0.0 |
| modules | C: service U: service |
| Console output |
http://104.198.109.242/logs//PreCommit-HIVE-Build-15400/yetus.txt |
| Powered by | Apache Yetushttp://yetus.apache.org |
This message was automatically generated.
> JDBC - The GetOperationStatus + log can block query progress via sleep()
>
>
> Key: HIVE-20989
> URL: https://issues.apache.org/jira/browse/HIVE-20989
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 4.0.0
>Reporter: Gopal V
>Assignee: Sankar Hariappan
>Priority: Major
> Attachments: HIVE-20989.01.patch
>
>
> There is an exponential sleep operation inside the CLIService which can end
> up adding tens of seconds to a query which has already completed.
> {code}
> "HiveServer2-Handler-Pool: Thread-9373" #9373 prio=5 os_prio=0
> tid=0x7f4d5e72d800 nid=0xb634a waiting on condition [0x7f28d06a5000]
> java.lang.Thread.State: TIMED_WAITING (sleeping)
> at java.lang.Thread.sleep(Native Method)
> at
> org.apache.hive.service.cli.CLIService.progressUpdateLog(CLIService.java:506)
> at
> org.apache.hive.service.cli.CLIService.getOperationStatus(CLIService.java:480)
> at
> org.apache.hive.service.cli.thrift.ThriftCLIService.GetOperationStatus(ThriftCLIService.java:695)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1757)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1742)
> at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
> at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39)
> at
> org.apache.hive.service.auth.TSetIpAddressProcessor.process(TSetIpAddressProcessor.java:56)
> at
> org.apache.th
[jira] [Commented] (HIVE-20989) JDBC - The GetOperationStatus + log can block query progress via sleep()
[
https://issues.apache.org/jira/browse/HIVE-20989?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16725654#comment-16725654
]
Hive QA commented on HIVE-20989:
Here are the results of testing the latest attachment:
https://issues.apache.org/jira/secure/attachment/12952457/HIVE-20989.01.patch
{color:red}ERROR:{color} -1 due to no test(s) being added or modified.
{color:red}ERROR:{color} -1 due to 1 failed/errored test(s), 15722 tests
executed
*Failed tests:*
{noformat}
TestMiniLlapCliDriver - did not produce a TEST-*.xml file (likely timed out)
(batchId=153)
[mapreduce2.q,bucket6.q,insert_into1.q,empty_dir_in_table.q,alter_table_location3.q,parquet_struct_type_vectorization.q,orc_merge1.q,parquet_types_vectorization.q,orc_merge_diff_fs.q,llap_stats.q,llapdecider.q,llap_nullscan.q,orc_ppd_basic.q,rcfile_merge4.q,orc_merge3.q]
{noformat}
Test results:
https://builds.apache.org/job/PreCommit-HIVE-Build/15397/testReport
Console output: https://builds.apache.org/job/PreCommit-HIVE-Build/15397/console
Test logs: http://104.198.109.242/logs/PreCommit-HIVE-Build-15397/
Messages:
{noformat}
Executing org.apache.hive.ptest.execution.TestCheckPhase
Executing org.apache.hive.ptest.execution.PrepPhase
Executing org.apache.hive.ptest.execution.YetusPhase
Executing org.apache.hive.ptest.execution.ExecutionPhase
Executing org.apache.hive.ptest.execution.ReportingPhase
Tests exited with: TestsFailedException: 1 tests failed
{noformat}
This message is automatically generated.
ATTACHMENT ID: 12952457 - PreCommit-HIVE-Build
> JDBC - The GetOperationStatus + log can block query progress via sleep()
>
>
> Key: HIVE-20989
> URL: https://issues.apache.org/jira/browse/HIVE-20989
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 4.0.0
>Reporter: Gopal V
>Assignee: Sankar Hariappan
>Priority: Major
> Attachments: HIVE-20989.01.patch
>
>
> There is an exponential sleep operation inside the CLIService which can end
> up adding tens of seconds to a query which has already completed.
> {code}
> "HiveServer2-Handler-Pool: Thread-9373" #9373 prio=5 os_prio=0
> tid=0x7f4d5e72d800 nid=0xb634a waiting on condition [0x7f28d06a5000]
> java.lang.Thread.State: TIMED_WAITING (sleeping)
> at java.lang.Thread.sleep(Native Method)
> at
> org.apache.hive.service.cli.CLIService.progressUpdateLog(CLIService.java:506)
> at
> org.apache.hive.service.cli.CLIService.getOperationStatus(CLIService.java:480)
> at
> org.apache.hive.service.cli.thrift.ThriftCLIService.GetOperationStatus(ThriftCLIService.java:695)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1757)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1742)
> at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
> at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39)
> at
> org.apache.hive.service.auth.TSetIpAddressProcessor.process(TSetIpAddressProcessor.java:56)
> at
> org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> {code}
> The sleep loop is on the server side.
> {code}
> private static final long PROGRESS_MAX_WAIT_NS = 30 * 10l;
> private JobProgressUpdate progressUpdateLog(boolean isProgressLogRequested,
> Operation operation, HiveConf conf) {
> ...
> long startTime = System.nanoTime();
> int timeOutMs = 8;
> try {
> while (sessionState.getProgressMonitor() == null &&
> !operation.isDone()) {
> long remainingMs = (PROGRESS_MAX_WAIT_NS - (System.nanoTime() -
> startTime)) / 100l;
> if (remainingMs <= 0) {
> LOG.debug("timed out and hence returning progress log as NULL");
> return new JobProgressUpdate(ProgressMonitor.NULL);
> }
> Thread.sleep(Math.min(remainingMs, timeOutMs));
> timeOutMs <<= 1;
> }
> {code}
> After about 16 seconds of execution of the query, the timeOutMs is 16384 ms,
> which means the next sleep cycle is for min(30 - 17, 16) = 13.
> If the query finishes on the 17th second, the JDBC server will only respond
> after the 30th second when it will check for operation.isDone() and return.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
[jira] [Commented] (HIVE-20989) JDBC - The GetOperationStatus + log can block query progress via sleep()
[
https://issues.apache.org/jira/browse/HIVE-20989?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16725629#comment-16725629
]
Hive QA commented on HIVE-20989:
| (/) *{color:green}+1 overall{color}* |
\\
\\
|| Vote || Subsystem || Runtime || Comment ||
|| || || || {color:brown} Prechecks {color} ||
| {color:green}+1{color} | {color:green} @author {color} | {color:green} 0m
0s{color} | {color:green} The patch does not contain any @author tags. {color} |
|| || || || {color:brown} master Compile Tests {color} ||
| {color:green}+1{color} | {color:green} mvninstall {color} | {color:green} 7m
34s{color} | {color:green} master passed {color} |
| {color:green}+1{color} | {color:green} compile {color} | {color:green} 0m
20s{color} | {color:green} master passed {color} |
| {color:green}+1{color} | {color:green} checkstyle {color} | {color:green} 0m
12s{color} | {color:green} master passed {color} |
| {color:blue}0{color} | {color:blue} findbugs {color} | {color:blue} 0m
33s{color} | {color:blue} service in master has 48 extant Findbugs warnings.
{color} |
| {color:green}+1{color} | {color:green} javadoc {color} | {color:green} 0m
15s{color} | {color:green} master passed {color} |
|| || || || {color:brown} Patch Compile Tests {color} ||
| {color:green}+1{color} | {color:green} mvninstall {color} | {color:green} 0m
23s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} compile {color} | {color:green} 0m
22s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} javac {color} | {color:green} 0m
22s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} checkstyle {color} | {color:green} 0m
11s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} whitespace {color} | {color:green} 0m
0s{color} | {color:green} The patch has no whitespace issues. {color} |
| {color:green}+1{color} | {color:green} findbugs {color} | {color:green} 0m
43s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} javadoc {color} | {color:green} 0m
16s{color} | {color:green} the patch passed {color} |
|| || || || {color:brown} Other Tests {color} ||
| {color:green}+1{color} | {color:green} asflicense {color} | {color:green} 0m
12s{color} | {color:green} The patch does not generate ASF License warnings.
{color} |
| {color:black}{color} | {color:black} {color} | {color:black} 11m 23s{color} |
{color:black} {color} |
\\
\\
|| Subsystem || Report/Notes ||
| Optional Tests | asflicense javac javadoc findbugs checkstyle compile |
| uname | Linux hiveptest-server-upstream 3.16.0-4-amd64 #1 SMP Debian
3.16.36-1+deb8u1 (2016-09-03) x86_64 GNU/Linux |
| Build tool | maven |
| Personality |
/data/hiveptest/working/yetus_PreCommit-HIVE-Build-15397/dev-support/hive-personality.sh
|
| git revision | master / 1020be0 |
| Default Java | 1.8.0_111 |
| findbugs | v3.0.0 |
| modules | C: service U: service |
| Console output |
http://104.198.109.242/logs//PreCommit-HIVE-Build-15397/yetus.txt |
| Powered by | Apache Yetushttp://yetus.apache.org |
This message was automatically generated.
> JDBC - The GetOperationStatus + log can block query progress via sleep()
>
>
> Key: HIVE-20989
> URL: https://issues.apache.org/jira/browse/HIVE-20989
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 4.0.0
>Reporter: Gopal V
>Assignee: Sankar Hariappan
>Priority: Major
> Attachments: HIVE-20989.01.patch
>
>
> There is an exponential sleep operation inside the CLIService which can end
> up adding tens of seconds to a query which has already completed.
> {code}
> "HiveServer2-Handler-Pool: Thread-9373" #9373 prio=5 os_prio=0
> tid=0x7f4d5e72d800 nid=0xb634a waiting on condition [0x7f28d06a5000]
> java.lang.Thread.State: TIMED_WAITING (sleeping)
> at java.lang.Thread.sleep(Native Method)
> at
> org.apache.hive.service.cli.CLIService.progressUpdateLog(CLIService.java:506)
> at
> org.apache.hive.service.cli.CLIService.getOperationStatus(CLIService.java:480)
> at
> org.apache.hive.service.cli.thrift.ThriftCLIService.GetOperationStatus(ThriftCLIService.java:695)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1757)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1742)
> at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
> at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39)
> at
> org.apache.hive.service.auth.TSetIpAddressProcessor.process(TSetIpAddressProcessor.java:56)
> at
> org.apache.th
[jira] [Commented] (HIVE-20989) JDBC - The GetOperationStatus + log can block query progress via sleep()
[
https://issues.apache.org/jira/browse/HIVE-20989?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16725320#comment-16725320
]
Hive QA commented on HIVE-20989:
Here are the results of testing the latest attachment:
https://issues.apache.org/jira/secure/attachment/12952392/HIVE-20989.01.patch
{color:red}ERROR:{color} -1 due to no test(s) being added or modified.
{color:red}ERROR:{color} -1 due to 2 failed/errored test(s), 15735 tests
executed
*Failed tests:*
{noformat}
TestLocationQueries - did not produce a TEST-*.xml file (likely timed out)
(batchId=251)
TestSemanticAnalyzerHookLoading - did not produce a TEST-*.xml file (likely
timed out) (batchId=251)
{noformat}
Test results:
https://builds.apache.org/job/PreCommit-HIVE-Build/15387/testReport
Console output: https://builds.apache.org/job/PreCommit-HIVE-Build/15387/console
Test logs: http://104.198.109.242/logs/PreCommit-HIVE-Build-15387/
Messages:
{noformat}
Executing org.apache.hive.ptest.execution.TestCheckPhase
Executing org.apache.hive.ptest.execution.PrepPhase
Executing org.apache.hive.ptest.execution.YetusPhase
Executing org.apache.hive.ptest.execution.ExecutionPhase
Executing org.apache.hive.ptest.execution.ReportingPhase
Tests exited with: TestsFailedException: 2 tests failed
{noformat}
This message is automatically generated.
ATTACHMENT ID: 12952392 - PreCommit-HIVE-Build
> JDBC - The GetOperationStatus + log can block query progress via sleep()
>
>
> Key: HIVE-20989
> URL: https://issues.apache.org/jira/browse/HIVE-20989
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 4.0.0
>Reporter: Gopal V
>Assignee: Sankar Hariappan
>Priority: Major
> Attachments: HIVE-20989.01.patch
>
>
> There is an exponential sleep operation inside the CLIService which can end
> up adding tens of seconds to a query which has already completed.
> {code}
> "HiveServer2-Handler-Pool: Thread-9373" #9373 prio=5 os_prio=0
> tid=0x7f4d5e72d800 nid=0xb634a waiting on condition [0x7f28d06a5000]
> java.lang.Thread.State: TIMED_WAITING (sleeping)
> at java.lang.Thread.sleep(Native Method)
> at
> org.apache.hive.service.cli.CLIService.progressUpdateLog(CLIService.java:506)
> at
> org.apache.hive.service.cli.CLIService.getOperationStatus(CLIService.java:480)
> at
> org.apache.hive.service.cli.thrift.ThriftCLIService.GetOperationStatus(ThriftCLIService.java:695)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1757)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1742)
> at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
> at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39)
> at
> org.apache.hive.service.auth.TSetIpAddressProcessor.process(TSetIpAddressProcessor.java:56)
> at
> org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> {code}
> The sleep loop is on the server side.
> {code}
> private static final long PROGRESS_MAX_WAIT_NS = 30 * 10l;
> private JobProgressUpdate progressUpdateLog(boolean isProgressLogRequested,
> Operation operation, HiveConf conf) {
> ...
> long startTime = System.nanoTime();
> int timeOutMs = 8;
> try {
> while (sessionState.getProgressMonitor() == null &&
> !operation.isDone()) {
> long remainingMs = (PROGRESS_MAX_WAIT_NS - (System.nanoTime() -
> startTime)) / 100l;
> if (remainingMs <= 0) {
> LOG.debug("timed out and hence returning progress log as NULL");
> return new JobProgressUpdate(ProgressMonitor.NULL);
> }
> Thread.sleep(Math.min(remainingMs, timeOutMs));
> timeOutMs <<= 1;
> }
> {code}
> After about 16 seconds of execution of the query, the timeOutMs is 16384 ms,
> which means the next sleep cycle is for min(30 - 17, 16) = 13.
> If the query finishes on the 17th second, the JDBC server will only respond
> after the 30th second when it will check for operation.isDone() and return.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
[jira] [Commented] (HIVE-20989) JDBC - The GetOperationStatus + log can block query progress via sleep()
[
https://issues.apache.org/jira/browse/HIVE-20989?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16725284#comment-16725284
]
Hive QA commented on HIVE-20989:
| (/) *{color:green}+1 overall{color}* |
\\
\\
|| Vote || Subsystem || Runtime || Comment ||
|| || || || {color:brown} Prechecks {color} ||
| {color:green}+1{color} | {color:green} @author {color} | {color:green} 0m
0s{color} | {color:green} The patch does not contain any @author tags. {color} |
|| || || || {color:brown} master Compile Tests {color} ||
| {color:green}+1{color} | {color:green} mvninstall {color} | {color:green} 7m
44s{color} | {color:green} master passed {color} |
| {color:green}+1{color} | {color:green} compile {color} | {color:green} 0m
20s{color} | {color:green} master passed {color} |
| {color:green}+1{color} | {color:green} checkstyle {color} | {color:green} 0m
12s{color} | {color:green} master passed {color} |
| {color:blue}0{color} | {color:blue} findbugs {color} | {color:blue} 0m
35s{color} | {color:blue} service in master has 48 extant Findbugs warnings.
{color} |
| {color:green}+1{color} | {color:green} javadoc {color} | {color:green} 0m
16s{color} | {color:green} master passed {color} |
|| || || || {color:brown} Patch Compile Tests {color} ||
| {color:green}+1{color} | {color:green} mvninstall {color} | {color:green} 0m
23s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} compile {color} | {color:green} 0m
22s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} javac {color} | {color:green} 0m
22s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} checkstyle {color} | {color:green} 0m
12s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} whitespace {color} | {color:green} 0m
0s{color} | {color:green} The patch has no whitespace issues. {color} |
| {color:green}+1{color} | {color:green} findbugs {color} | {color:green} 0m
42s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} javadoc {color} | {color:green} 0m
16s{color} | {color:green} the patch passed {color} |
|| || || || {color:brown} Other Tests {color} ||
| {color:green}+1{color} | {color:green} asflicense {color} | {color:green} 0m
12s{color} | {color:green} The patch does not generate ASF License warnings.
{color} |
| {color:black}{color} | {color:black} {color} | {color:black} 11m 40s{color} |
{color:black} {color} |
\\
\\
|| Subsystem || Report/Notes ||
| Optional Tests | asflicense javac javadoc findbugs checkstyle compile |
| uname | Linux hiveptest-server-upstream 3.16.0-4-amd64 #1 SMP Debian
3.16.36-1+deb8u1 (2016-09-03) x86_64 GNU/Linux |
| Build tool | maven |
| Personality |
/data/hiveptest/working/yetus_PreCommit-HIVE-Build-15387/dev-support/hive-personality.sh
|
| git revision | master / 1020be0 |
| Default Java | 1.8.0_111 |
| findbugs | v3.0.0 |
| modules | C: service U: service |
| Console output |
http://104.198.109.242/logs//PreCommit-HIVE-Build-15387/yetus.txt |
| Powered by | Apache Yetushttp://yetus.apache.org |
This message was automatically generated.
> JDBC - The GetOperationStatus + log can block query progress via sleep()
>
>
> Key: HIVE-20989
> URL: https://issues.apache.org/jira/browse/HIVE-20989
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 4.0.0
>Reporter: Gopal V
>Assignee: Sankar Hariappan
>Priority: Major
> Attachments: HIVE-20989.01.patch
>
>
> There is an exponential sleep operation inside the CLIService which can end
> up adding tens of seconds to a query which has already completed.
> {code}
> "HiveServer2-Handler-Pool: Thread-9373" #9373 prio=5 os_prio=0
> tid=0x7f4d5e72d800 nid=0xb634a waiting on condition [0x7f28d06a5000]
> java.lang.Thread.State: TIMED_WAITING (sleeping)
> at java.lang.Thread.sleep(Native Method)
> at
> org.apache.hive.service.cli.CLIService.progressUpdateLog(CLIService.java:506)
> at
> org.apache.hive.service.cli.CLIService.getOperationStatus(CLIService.java:480)
> at
> org.apache.hive.service.cli.thrift.ThriftCLIService.GetOperationStatus(ThriftCLIService.java:695)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1757)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1742)
> at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
> at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39)
> at
> org.apache.hive.service.auth.TSetIpAddressProcessor.process(TSetIpAddressProcessor.java:56)
> at
> org.apache.th
[jira] [Commented] (HIVE-20989) JDBC: The GetOperationStatus + log can block query progress via sleep()
[
https://issues.apache.org/jira/browse/HIVE-20989?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16704366#comment-16704366
]
Gopal V commented on HIVE-20989:
A CountDownLatch(1) inside Operation.onNewState(OperationState, OperationState)
might be a good enough way to use .await() instead of sleep() here.
> JDBC: The GetOperationStatus + log can block query progress via sleep()
> ---
>
> Key: HIVE-20989
> URL: https://issues.apache.org/jira/browse/HIVE-20989
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Reporter: Gopal V
>Priority: Major
>
> There is an exponential sleep operation inside the CLIService which can end
> up adding tens of seconds to a query which has already completed.
> {code}
> "HiveServer2-Handler-Pool: Thread-9373" #9373 prio=5 os_prio=0
> tid=0x7f4d5e72d800 nid=0xb634a waiting on condition [0x7f28d06a5000]
> java.lang.Thread.State: TIMED_WAITING (sleeping)
> at java.lang.Thread.sleep(Native Method)
> at
> org.apache.hive.service.cli.CLIService.progressUpdateLog(CLIService.java:506)
> at
> org.apache.hive.service.cli.CLIService.getOperationStatus(CLIService.java:480)
> at
> org.apache.hive.service.cli.thrift.ThriftCLIService.GetOperationStatus(ThriftCLIService.java:695)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1757)
> at
> org.apache.hive.service.rpc.thrift.TCLIService$Processor$GetOperationStatus.getResult(TCLIService.java:1742)
> at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
> at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39)
> at
> org.apache.hive.service.auth.TSetIpAddressProcessor.process(TSetIpAddressProcessor.java:56)
> at
> org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> {code}
> The sleep loop is on the server side.
> {code}
> private static final long PROGRESS_MAX_WAIT_NS = 30 * 10l;
> private JobProgressUpdate progressUpdateLog(boolean isProgressLogRequested,
> Operation operation, HiveConf conf) {
> ...
> long startTime = System.nanoTime();
> int timeOutMs = 8;
> try {
> while (sessionState.getProgressMonitor() == null &&
> !operation.isDone()) {
> long remainingMs = (PROGRESS_MAX_WAIT_NS - (System.nanoTime() -
> startTime)) / 100l;
> if (remainingMs <= 0) {
> LOG.debug("timed out and hence returning progress log as NULL");
> return new JobProgressUpdate(ProgressMonitor.NULL);
> }
> Thread.sleep(Math.min(remainingMs, timeOutMs));
> timeOutMs <<= 1;
> }
> {code}
> After about 16 seconds of execution of the query, the timeOutMs is 16384 ms,
> which means the next sleep cycle is for min(30 - 17, 16) = 13.
> If the query finishes on the 17th second, the JDBC server will only respond
> after the 30th second when it will check for operation.isDone() and return.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
