Chukwa
  1. Chukwa
  2. CHUKWA-314

START_TIME="0" for failed task throws SQL Exception

    Details

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

      Description

      2009-06-18 16:38:32,301 ERROR pool-1-thread-3 MetricDataLoader - java.sql.BatchUpdateException: Data truncation:
      Incorrect datetime value: '1970-01-01 00:00:00' for column 'start_time' at row 1
      java.sql.BatchUpdateException: Data truncation: Incorrect datetime value: '1970-01-01 00:00:00' for column 'start_time'
      at row 1
      at com.mysql.jdbc.StatementImpl.executeBatch(StatementImpl.java:1007)
      at org.apache.hadoop.chukwa.dataloader.MetricDataLoader.run(MetricDataLoader.java:484)
      at org.apache.hadoop.chukwa.dataloader.MetricDataLoader.call(MetricDataLoader.java:561)
      at org.apache.hadoop.chukwa.dataloader.MetricDataLoader.call(MetricDataLoader.java:50)
      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
      at java.util.concurrent.FutureTask.run(FutureTask.java:138)
      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
      at java.util.concurrent.FutureTask.run(FutureTask.java:138)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
      at java.lang.Thread.run(Thread.java:619)
      2009-06-18 16:38:32,301 ERROR pool-1-thread-3 MetricDataLoader - SQLException: Data truncation: Incorrect datetime
      value: '1970-01-01 00:00:00' for column 'start_time' at row 1

      The data in the sequence file contains:

      Key: 1245355200000/job_200906170135_0110/1245355568122
      ===== Value =====
      Timestamp : 1245355568122
      [ERROR] :Error initializing
      attempt_200906170135_0110_m_000004_0:org\.apache\.hadoop\.util\.DiskChecker$DiskErrorException: Could not find any
      valid local directory for taskTracker/jobcache/job_200906170135_0110/job\.xmlat
      org\.apache\.hadoop\.fs\.LocalDirAllocator$AllocatorPerContext\.getLocalPathForWrite(LocalDirAllocator\.java:335)at
      org\.apache\.hadoop\.fs\.LocalDirAllocator\.getLocalPathForWrite(LocalDirAllocator\.java:124)at
      org\.apache\.hadoop\.mapred\.TaskTracker\.localizeJob(TaskTracker\.java:799)at
      org\.apache\.hadoop\.mapred\.TaskTracker\.startNewTask(TaskTracker\.java:1743)at
      org\.apache\.hadoop\.mapred\.TaskTracker\.access$1200(TaskTracker\.java:97)at
      org\.apache\.hadoop\.mapred\.TaskTracker$TaskLauncher\.run(TaskTracker\.java:1708)
      [FINISH_TIME] :1245268355013
      [HOSTNAME] :hostname
      [JOBID] :job_200906170135_0110
      [TASKID] :task_200906170135_0110_m_000004
      [TASK_ATTEMPT_ID] :attempt_200906170135_0110_m_000004_0
      [TASK_ATTEMPT_TIMES] :1
      [TASK_STATUS] :FAILED
      [TASK_TYPE] :MAP
      [capp]
      :/var/log/history/hostname_1245202542124_job_200906170135_0110_user_Chukwa-Demux_20090617_19_51
      [csource] :hostname
      [ctags] : cluster="chukwadev"

      Key: 1245355200000/job_200906170135_0110/1245355568122
      ===== Value =====
      Timestamp : 1245355568122
      [HTTP_PORT] :50060
      [JOBID] :job_200906170135_0110
      [START_TIME] :0
      [TASKID] :task_200906170135_0110_m_000004
      [TASK_ATTEMPT_ID] :attempt_200906170135_0110_m_000004_0
      [TASK_ATTEMPT_TIMES] :1
      [TASK_TYPE] :MAP
      [TRACKER_NAME] :tracker_hostname:localhost/127\.0\.0\.1:57852
      [capp]
      :/var/log/history/hostname_1245202542124_job_200906170135_0110_user_Chukwa-Demux_20090617_19_51
      [csource] :hostname
      [ctags] : cluster="chukwadev"

      START_TIME is 0 which is out of SQL time range.
      mysql> INSERT INTO mr_task_2059_week SET type='map', task_id='attempt_200906170135_0110_m_000004_0',
      job_id='job_200906170135_0110', attempts=1, start_time="1970-01-01 00:00:00" ON DUPLICATE KEY UPDATE
      type='map', task_id='attempt_200906170135_0110_m_000004_0', job_id='job_200906170135_0110', attempts=1,
      start_time="1970-01-01 00:00:00";
      Query OK, 0 rows affected, 2 warnings (0.00 sec)

      mysql> show warnings;
      ----------------------------------------------------------------

      Level Code Message

      ----------------------------------------------------------------

      Warning 1264 Out of range value for column 'start_time' at row 1
      Warning 1264 Out of range value for column 'start_time' at row 1

      ----------------------------------------------------------------
      2 rows in set (0.01 sec)

      The error reported by MDL is correct from SQL prespective. The map reduce job never had a chance to start due to
      error. start_time=0 is correct from the log file, however, this should be filtered in demux as part of invalid
      values.

        Activity

          People

          • Assignee:
            Eric Yang
            Reporter:
            Eric Yang
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development