Uploaded image for project: 'Ambari'
  1. Ambari
  2. AMBARI-18194

Hsi-Hs2: Mondrian tests intermittently fail with "java.io.IOException: Connection reset by peer"

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 2.4.0
    • Component/s: None
    • Labels:
      None

      Description

      I'd reported this issue previously in
      not see this due to its intermitent nature.
      In yesterdays nightly, around 8 tests had failed with this issue and on rerun
      48 failed. Hs2 logs are below:

      2016-08-17T07:28:55,479 INFO [HiveServer2-Background-Pool: Thread-6508]: SessionState (SessionState.java:printInfo(1075)) - Status: Running (Executing on YARN cluster with App id application_1471417242320_0006)

      Map 1: 1/1 Reducer 2: 0(+1)/1 Reducer 3: 0/1
      2016-08-17T07:28:55,480 INFO [HiveServer2-Background-Pool: Thread-6508]: SessionState (SessionState.java:printInfo(1075)) - Map 1: 1/1 Reducer 2: 0(+1)/1 Reducer 3: 0/1
      Map 1: 1/1 Reducer 2: 1/1 Reducer 3: 0(+1)/1
      2016-08-17T07:28:55,681 INFO [HiveServer2-Background-Pool: Thread-6508]: SessionState (SessionState.java:printInfo(1075)) - Map 1: 1/1 Reducer 2: 1/1 Reducer 3: 0(+1)/1
      Map 1: 1/1 Reducer 2: 1/1 Reducer 3: 0(+1,-2)/1
      2016-08-17T07:28:58,422 INFO [HiveServer2-Background-Pool: Thread-6503]: SessionState (SessionState.java:printInfo(1075)) - Map 1: 1/1 Reducer 2: 1/1 Reducer 3: 0(+1,-2)/1
      Map 1: 1/1 Reducer 2: 1/1 Reducer 3: 0(+1,-1)/1
      2016-08-17T07:28:58,422 INFO [HiveServer2-Background-Pool: Thread-6507]: SessionState (SessionState.java:printInfo(1075)) - Map 1: 1/1 Reducer 2: 1/1 Reducer 3: 0(+1,-1)/1
      Map 1: 1/1 Reducer 2: 1/1 Reducer 3: 0(+1)/1
      2016-08-17T07:28:58,955 INFO [HiveServer2-Background-Pool: Thread-6508]: SessionState (SessionState.java:printInfo(1075)) - Map 1: 1/1 Reducer 2: 1/1 Reducer 3: 0(+1)/1
      Map 1: 1/1 Reducer 2: 1/1 Reducer 3: 0(+1,-1)/1
      2016-08-17T07:29:00,566 INFO [HiveServer2-Background-Pool: Thread-6508]: SessionState (SessionState.java:printInfo(1075)) - Map 1: 1/1 Reducer 2: 1/1 Reducer 3: 0(+1,-1)/1
      Map 1: 1/1 Reducer 2: 1/1 Reducer 3: 0(+1,-3)/1
      2016-08-17T07:29:00,633 INFO [HiveServer2-Background-Pool: Thread-6503]: SessionState (SessionState.java:printInfo(1075)) - Map 1: 1/1 Reducer 2: 1/1 Reducer 3: 0(+1,-3)/1
      Map 1: 1/1 Reducer 2: 1/1 Reducer 3: 0(+1,-2)/1
      2016-08-17T07:29:00,635 INFO [HiveServer2-Background-Pool: Thread-6507]: SessionState (SessionState.java:printInfo(1075)) - Map 1: 1/1 Reducer 2: 1/1 Reducer 3: 0(+1,-2)/1
      Status: Failed
      2016-08-17T07:29:00,708 ERROR [HiveServer2-Background-Pool: Thread-6503]: SessionState (SessionState.java:printError(1084)) - Status: Failed
      Vertex failed, vertexName=Reducer 3, vertexId=vertex_1471417242320_0005_293_02, diagnostics=[Task failed, taskId=task_1471417242320_0005_293_02_000000, diagnostics=[TaskAttempt 0 failed, info=[Error: Error while running task ( failure ) : attempt_1471417242320_0005_293_02_000000_0:java.lang.RuntimeException: java.lang.RuntimeException: Hive Runtime Error while closing operators: java.io.IOException: Connection reset by peer
      at org.apache.hadoop.hive.ql.exec.tez.TezProcessor.initializeAndRunProcessor(TezProcessor.java:211)
      at org.apache.hadoop.hive.ql.exec.tez.TezProcessor.run(TezProcessor.java:168)
      at org.apache.tez.runtime.LogicalIOProcessorRuntimeTask.run(LogicalIOProcessorRuntimeTask.java:370)
      at org.apache.tez.runtime.task.TaskRunner2Callable$1.run(TaskRunner2Callable.java:73)
      at org.apache.tez.runtime.task.TaskRunner2Callable$1.run(TaskRunner2Callable.java:61)
      at java.security.AccessController.doPrivileged(Native Method)
      at javax.security.auth.Subject.doAs(Subject.java:422)
      at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1724)
      at org.apache.tez.runtime.task.TaskRunner2Callable.callInternal(TaskRunner2Callable.java:61)
      at org.apache.tez.runtime.task.TaskRunner2Callable.callInternal(TaskRunner2Callable.java:37)
      at org.apache.tez.common.CallableWithNdc.call(CallableWithNdc.java:36)
      at org.apache.hadoop.hive.llap.daemon.impl.StatsRecordingThreadPool$WrappedCallable.call(StatsRecordingThreadPool.java:110)
      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      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)
      Caused by: java.lang.RuntimeException: Hive Runtime Error while closing operators: java.io.IOException: Connection reset by peer
      at org.apache.hadoop.hive.ql.exec.tez.ReduceRecordProcessor.close(ReduceRecordProcessor.java:360)
      at org.apache.hadoop.hive.ql.exec.tez.TezProcessor.initializeAndRunProcessor(TezProcessor.java:199)
      ... 15 more
      Caused by: org.apache.hadoop.hive.ql.metadata.HiveException: java.io.IOException: Connection reset by peer
      at org.apache.hadoop.hive.ql.exec.FileSinkOperator$FSPaths.closeWriters(FileSinkOperator.java:194)
      at org.apache.hadoop.hive.ql.exec.FileSinkOperator.closeOp(FileSinkOperator.java:1039)
      at org.apache.hadoop.hive.ql.exec.Operator.close(Operator.java:683)
      at org.apache.hadoop.hive.ql.exec.Operator.close(Operator.java:697)
      at org.apache.hadoop.hive.ql.exec.tez.ReduceRecordProcessor.close(ReduceRecordProcessor.java:337)
      ... 16 more

      Attached the logs for the failed application_1471417242320_0006.

      Test console logs:

      2016-08-17 07:28:54,010|beaver.machine|INFO|18245|140470708778752|MainThread|[4382] Running query #6: select employee.employee_id as c0, employee.full_name as c1 from employee as employee where employee.supervisor_id = 30 group by employee.employee_id, employee.full_name order by employee.employee_id ASC

      2016-08-17 07:29:00,745|beaver.machine|INFO|18245|140470708778752|MainThread|[4382] Error while processing statement: FAILED: Execution Error, return code 2 from org.apache.hadoop.hive.ql.exec.tez.TezTask. Vertex failed, vertexName=Reducer 3, vertexId=vertex_1471417242320_0005_293_02, diagnostics=[Task failed, taskId=task_1471417242320_0005_293_02_000000, diagnostics=[TaskAttempt 0 failed, info=[Error: Error while running task ( failure ) : attempt_1471417242320_0005_293_02_000000_0:java.lang.RuntimeException: java.lang.RuntimeException: Hive Runtime Error while closing operators: java.io.IOException: Connection reset by peer
      2016-08-17 07:29:00,746|beaver.machine|INFO|18245|140470708778752|MainThread|at org.apache.hadoop.hive.ql.exec.tez.TezProcessor.initializeAndRunProcessor(TezProcessor.java:211)
      2016-08-17 07:29:00,746|beaver.machine|INFO|18245|140470708778752|MainThread|at org.apache.hadoop.hive.ql.exec.tez.TezProcessor.run(TezProcessor.java:168)
      2016-08-17 07:29:00,746|beaver.machine|INFO|18245|140470708778752|MainThread|at org.apache.tez.runtime.LogicalIOProcessorRuntimeTask.run(LogicalIOProcessorRuntimeTask.java:370)
      2016-08-17 07:29:00,746|beaver.machine|INFO|18245|140470708778752|MainThread|at org.apache.tez.runtime.task.TaskRunner2Callable$1.run(TaskRunner2Callable.java:73)
      2016-08-17 07:29:00,746|beaver.machine|INFO|18245|140470708778752|MainThread|at org.apache.tez.runtime.task.TaskRunner2Callable$1.run(TaskRunner2Callable.java:61)
      2016-08-17 07:29:00,747|beaver.machine|INFO|18245|140470708778752|MainThread|at java.security.AccessController.doPrivileged(Native Method)
      2016-08-17 07:29:00,747|beaver.machine|INFO|18245|140470708778752|MainThread|at javax.security.auth.Subject.doAs(Subject.java:422)
      2016-08-17 07:29:00,747|beaver.machine|INFO|18245|140470708778752|MainThread|at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1724)
      2016-08-17 07:29:00,747|beaver.machine|INFO|18245|140470708778752|MainThread|at org.apache.tez.runtime.task.TaskRunner2Callable.callInternal(TaskRunner2Callable.java:61)
      2016-08-17 07:29:00,747|beaver.machine|INFO|18245|140470708778752|MainThread|at org.apache.tez.runtime.task.TaskRunner2Callable.callInternal(TaskRunner2Callable.java:37)
      2016-08-17 07:29:00,747|beaver.machine|INFO|18245|140470708778752|MainThread|at org.apache.tez.common.CallableWithNdc.call(CallableWithNdc.java:36)
      2016-08-17 07:29:00,747|beaver.machine|INFO|18245|140470708778752|MainThread|at org.apache.hadoop.hive.llap.daemon.impl.StatsRecordingThreadPool$WrappedCallable.call(StatsRecordingThreadPool.java:110)
      2016-08-17 07:29:00,748|beaver.machine|INFO|18245|140470708778752|MainThread|at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      2016-08-17 07:29:00,748|beaver.machine|INFO|18245|140470708778752|MainThread|at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
      2016-08-17 07:29:00,748|beaver.machine|INFO|18245|140470708778752|MainThread|at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      2016-08-17 07:29:00,748|beaver.machine|INFO|18245|140470708778752|MainThread|at java.lang.Thread.run(Thread.java:745)
      2016-08-17 07:29:00,748|beaver.machine|INFO|18245|140470708778752|MainThread|Caused by: java.lang.RuntimeException: Hive Runtime Error while closing operators: java.io.IOException: Connection reset by peer

      Unfortunately we are not able to extend the lifetime beyond 24 hours on
      nightly clusters.

        Attachments

        1. AMBARI-18194.patch
          2 kB
          Andrew Onischuk
        2. AMBARI-18194.patch
          2 kB
          Andrew Onischuk

          Issue Links

            Activity

              People

              • Assignee:
                aonishuk Andrew Onischuk
                Reporter:
                aonishuk Andrew Onischuk
              • Votes:
                0 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: