Uploaded image for project: 'Apache Tez'
  1. Apache Tez
  2. TEZ-1118

Tez with container reuse reports negative CPU usage

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 0.4.0, 0.5.0
    • Fix Version/s: 0.5.0
    • Component/s: None

      Description

      2014-05-13 12:47:37,243 INFO [AsyncDispatcher event handler] org.apache.tez.dag.history.HistoryEventHandler: [HISTORY][DAG:dag_1399351577718_0764_8][Event:TASK_ATTEMPT_FINISHED]: vertexName=Map 2, taskAttemptId=attempt_1399351577718_0764_8_01_000321_0, startTime=1400010446382, finishTime=1400010457242, timeTaken=10860, status=SUCCEEDED, diagnostics=, counters=Counters: 30, org.apache.tez.common.counters.DAGCounter, RACK_LOCAL_TASKS=1, File System Counters, FILE: BYTES_READ=32, FILE: BYTES_WRITTEN=103495, FILE: READ_OPS=0, FILE: LARGE_READ_OPS=0, FILE: WRITE_OPS=0, HDFS: BYTES_READ=158991064, HDFS: BYTES_WRITTEN=0, HDFS: READ_OPS=2, HDFS: LARGE_READ_OPS=0, HDFS: WRITE_OPS=0, org.apache.tez.common.counters.TaskCounter, GC_TIME_MILLIS=72, CPU_MILLISECONDS=-455600

      This seems to get worse as new tasks are scheduled on the container, CPU is obvious column in this csv (attempts are in execution order):

      Map 2,attempt_1399351577718_0764_1_01_000063_0,22678,269235481,27830,17536,11967
      Map 2,attempt_1399351577718_0764_1_01_000167_0,16472,265337919,-19970,17044,11854
      Map 2,attempt_1399351577718_0764_1_01_000301_0,10197,173878898,-46140,11427,6899
      Map 2,attempt_1399351577718_0764_2_01_000059_0,18545,269736723,-51050,17590,12271
      Map 2,attempt_1399351577718_0764_2_01_000107_0,14677,269520373,-84270,17673,11095
      Map 2,attempt_1399351577718_0764_2_01_000228_0,14910,261276556,-104380,16937,11470
      Map 2,attempt_1399351577718_0764_3_01_000008_0,16164,269641107,-124260,17013,11306
      Map 2,attempt_1399351577718_0764_3_01_000136_0,15105,267827690,-140730,17834,10370
      Map 2,attempt_1399351577718_0764_3_01_000240_0,17380,235117784,-165260,15303,10948
      Map 2,attempt_1399351577718_0764_4_01_000056_0,19848,269790867,-167870,17487,11510
      Map 2,attempt_1399351577718_0764_4_01_000146_0,15303,267603313,-204130,17029,11672
      Map 2,attempt_1399351577718_0764_4_01_000264_0,9518,188372846,-231590,12273,8495
      Map 2,attempt_1399351577718_0764_5_01_000024_0,15836,270431273,-229970,17688,11045
      Map 2,attempt_1399351577718_0764_5_01_000150_0,15368,266500919,-258690,17012,11385
      Map 2,attempt_1399351577718_0764_5_01_000266_0,11882,183276660,-286700,11893,8350
      Map 2,attempt_1399351577718_0764_6_01_000017_0,17037,270252275,-293420,17517,12030
      Map 2,attempt_1399351577718_0764_6_01_000156_0,12759,266500919,-313380,17012,11385
      Map 2,attempt_1399351577718_0764_6_01_000266_0,10078,188372846,-338580,12273,8495
      Map 2,attempt_1399351577718_0764_7_01_000021_0,15984,270757527,-343980,17972,11519
      Map 2,attempt_1399351577718_0764_7_01_000102_0,14149,269589224,-355560,17698,10871
      Map 2,attempt_1399351577718_0764_7_01_000243_0,11578,235644691,-395730,15244,10508
      Map 2,attempt_1399351577718_0764_8_01_000026_0,16377,270431273,-402260,17688,11045
      Map 2,attempt_1399351577718_0764_8_01_000127_0,15517,268903941,-422380,17591,11681
      Map 2,attempt_1399351577718_0764_8_01_000321_0,10860,158991064,-455600,10658,6764
      

        Attachments

        1. TEZ-1118-1.patch
          0.9 kB
          Robert Grandl

          Activity

            People

            • Assignee:
              gopalv Gopal Vijayaraghavan
              Reporter:
              sershe Sergey Shelukhin
            • Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: