Контейнер заданий MapReduce убит Google Cloud Platform [код ошибки: 143]

Я попытался запустить задание mapreduce в кластере в Google Cloud Platform, используя пакет Python mrjob следующим образом:

python mr_script.py -r dataproc --cluster-id [CLUSTER-ID] [gs://DATAFILE_FOLDER]

Я могу успешно запустить тот же сценарий для тех же данных с правильными результатами в Hadoop локально (с опцией -r hadoop). Однако это же задание не удалось выполнить в Google Cloud Platform примерно через 1 час со следующим сообщением об ошибке:

Waiting for job completion - sleeping 10.0 second(s)
link_stats-vagrant-20170430-021027-125936---step-00001-of-00001 => RUNNING
Waiting for job completion - sleeping 10.0 second(s)
link_stats-vagrant-20170430-021027-125936---step-00001-of-00001 => RUNNING
Waiting for job completion - sleeping 10.0 second(s)
link_stats-vagrant-20170430-021027-125936---step-00001-of-00001 => ERROR
Step 1 of 1 failed

После проверки файла журнала в рабочем узле Google Cloud Platform я обнаружил в /var/log/hadoop-yarn/yarn-yarn-nodemanager-mrjob-w-13.log следующие сообщения об ошибках:

2017-04-30 02:58:48,213 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl: Memory usage of ProcessTree 3497 for container-id container_1493517964776_0001_01_004115: 447.5 MB of 10 GB physical memory used; 9.9 GB of 21 GB virtual memory used
2017-04-30 02:58:48,217 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl: Memory usage of ProcessTree 3097 for container-id container_1493517964776_0001_01_001385: 351.7 MB of 10 GB physical memory used; 9.9 GB of 21 GB virtual memory used
2017-04-30 02:58:51,222 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl: Memory usage of ProcessTree 3773 for container-id container_1493517964776_0001_01_006384: 349.3 MB of 10 GB physical memory used; 9.9 GB of 21 GB virtual memory used
2017-04-30 02:58:51,226 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl: Memory usage of ProcessTree 3660 for container-id container_1493517964776_0001_01_005935: 344.8 MB of 10 GB physical memory used; 9.9 GB of 21 GB virtual memory used
2017-04-30 02:58:51,230 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl: Memory usage of ProcessTree 3497 for container-id container_1493517964776_0001_01_004115: 447.5 MB of 10 GB physical memory used; 9.9 GB of 21 GB virtual memory used
2017-04-30 02:58:51,234 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl: Memory usage of ProcessTree 3097 for container-id container_1493517964776_0001_01_001385: 351.7 MB of 10 GB physical memory used; 9.9 GB of 21 GB virtual memory used
2017-04-30 02:58:52,803 INFO SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for appattempt_1493517964776_0001_000001 (auth:SIMPLE)
2017-04-30 02:58:52,809 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.ContainerManagerImpl: Stopping container with container Id: container_1493517964776_0001_01_001385
2017-04-30 02:58:52,809 INFO org.apache.hadoop.yarn.server.nodemanager.NMAuditLogger: USER=root IP=10.142.0.20  OPERATION=Stop Container Request        TARGET=ContainerManageImpl      RESULT=SUCCESS  APPID=application_1493517964776_0001    CONTAINERID=container_1493517964776_0001_01_001385
2017-04-30 02:58:52,809 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.container.ContainerImpl: Container container_1493517964776_0001_01_001385 transitioned from RUNNING to KILLING
2017-04-30 02:58:52,809 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.launcher.ContainerLaunch: Cleaning up container container_1493517964776_0001_01_001385
2017-04-30 02:58:52,810 INFO SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for appattempt_1493517964776_0001_000001 (auth:SIMPLE)
2017-04-30 02:58:52,812 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.ContainerManagerImpl: Stopping container with container Id: container_1493517964776_0001_01_004115
2017-04-30 02:58:52,812 INFO org.apache.hadoop.yarn.server.nodemanager.NMAuditLogger: USER=root IP=10.142.0.20  OPERATION=Stop Container Request        TARGET=ContainerManageImpl      RESULT=SUCCESS  APPID=application_1493517964776_0001    CONTAINERID=container_1493517964776_0001_01_004115
2017-04-30 02:58:52,815 WARN org.apache.hadoop.yarn.server.nodemanager.DefaultContainerExecutor: Exit code from container container_1493517964776_0001_01_001385 is : 143
2017-04-30 02:58:52,821 INFO SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for appattempt_1493517964776_0001_000001 (auth:SIMPLE)
2017-04-30 02:58:52,823 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.ContainerManagerImpl: Stopping container with container Id: container_1493517964776_0001_01_006384
2017-04-30 02:58:52,823 INFO org.apache.hadoop.yarn.server.nodemanager.NMAuditLogger: USER=root IP=10.142.0.20  OPERATION=Stop Container Request        TARGET=ContainerManageImpl      RESULT=SUCCESS  APPID=application_1493517964776_0001    CONTAINERID=container_1493517964776_0001_01_006384
2017-04-30 02:58:52,826 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.container.ContainerImpl: Container container_1493517964776_0001_01_004115 transitioned from RUNNING to KILLING
2017-04-30 02:58:52,826 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.container.ContainerImpl: Container container_1493517964776_0001_01_001385 transitioned from KILLING to CONTAINER_CLEANEDUP_AFTER_KILL
2017-04-30 02:58:52,826 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.container.ContainerImpl: Container container_1493517964776_0001_01_006384 transitioned from RUNNING to KILLING
2017-04-30 02:58:52,826 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.launcher.ContainerLaunch: Cleaning up container container_1493517964776_0001_01_004115

Похоже, что моя работа была прервана диспетчером контейнеров, однако не похоже, что моя работа была прервана из-за превышения физической / логической памяти (поправьте меня, если я ошибаюсь). Я вижу, что это код ошибки 143.

Не могли бы вы посоветовать, почему моя работа не удалась, и как я могу ее исправить или изменить какие-либо настройки в mrjob, чтобы работа прошла успешно (если это действительно проблема с памятью)? Или где еще я могу найти дополнительные подсказки для отладки этой проблемы? Спасибо!

РЕДАКТИРОВАТЬ: Вот отчет о невыполненных заданиях (в Cloud Dataproc -> Jobs, Status: Failed, Elapsed time: 48min 41sec):

Конфигурация:

Cluster     mrjob
Job type    Hadoop
Jar files   Main class or jar   
file:///usr/lib/hadoop-mapreduce/hadoop-streaming.jar
Arguments:  
-files
gs://mrjob-us-east1-bb4f10dbae4d77dc/tmp/link_stats.vagrant.20170504.185601.135018/files/link_stats.py#link_stats.py
-mapper
python link_stats.py --step-num=0 --mapper
-reducer
python link_stats.py --step-num=0 --reducer
-input
gs://vc1/data/wikipedia/english
-output
gs://mrjob-us-east1-bb4f10dbae4d77dc/tmp/link_stats.vagrant.20170504.185601.135018/output/

Вывод:

17/05/04 19:40:52 INFO mapreduce.Job:  map 74% reduce 6%
17/05/04 19:41:42 INFO mapreduce.Job:  map 75% reduce 6%
17/05/04 19:41:42 INFO mapreduce.Job: Task Id : attempt_1493924193762_0001_m_000481_0, Status : FAILED
AttemptID:attempt_1493924193762_0001_m_000481_0 Timed out after 600 secs
17/05/04 19:41:42 INFO mapreduce.Job: Task Id : attempt_1493924193762_0001_m_000337_2, Status : FAILED
AttemptID:attempt_1493924193762_0001_m_000337_2 Timed out after 600 secs
17/05/04 19:41:43 INFO mapreduce.Job:  map 74% reduce 6%
17/05/04 19:41:45 INFO mapreduce.Job:  map 75% reduce 6%
17/05/04 19:42:12 INFO mapreduce.Job: Task Id : attempt_1493924193762_0001_m_000173_2, Status : FAILED
AttemptID:attempt_1493924193762_0001_m_000173_2 Timed out after 600 secs
17/05/04 19:42:40 INFO mapreduce.Job:  map 76% reduce 6%
17/05/04 19:43:26 INFO mapreduce.Job:  map 77% reduce 6%
17/05/04 19:44:16 INFO mapreduce.Job:  map 78% reduce 6%
17/05/04 19:44:42 INFO mapreduce.Job:  map 100% reduce 100%
17/05/04 19:44:47 INFO mapreduce.Job: Job job_1493924193762_0001 failed with state FAILED due to: Task failed task_1493924193762_0001_m_000161
Job failed as tasks failed. failedMaps:1 failedReduces:0

17/05/04 19:44:47 INFO mapreduce.Job: Counters: 45
    File System Counters
        FILE: Number of bytes read=0
        FILE: Number of bytes written=110101249
        FILE: Number of read operations=0
        FILE: Number of large read operations=0
        FILE: Number of write operations=0
        GS: Number of bytes read=8815472899
        GS: Number of bytes written=0
        GS: Number of read operations=0
        GS: Number of large read operations=0
        GS: Number of write operations=0
        HDFS: Number of bytes read=57120
        HDFS: Number of bytes written=0
        HDFS: Number of read operations=560
        HDFS: Number of large read operations=0
        HDFS: Number of write operations=0
    Job Counters 
        Failed map tasks=39
        Killed map tasks=192
        Killed reduce tasks=196
        Launched map tasks=685
        Launched reduce tasks=48
        Other local map tasks=38
        Rack-local map tasks=647
        Total time spent by all maps in occupied slots (ms)=1015831401
        Total time spent by all reduces in occupied slots (ms)=559653642
        Total time spent by all map tasks (ms)=338610467
        Total time spent by all reduce tasks (ms)=93275607
        Total vcore-milliseconds taken by all map tasks=338610467
        Total vcore-milliseconds taken by all reduce tasks=186551214
        Total megabyte-milliseconds taken by all map tasks=1040211354624
        Total megabyte-milliseconds taken by all reduce tasks=573085329408
    Map-Reduce Framework
        Map input records=594556238
        Map output records=560
        Map output bytes=35862346
        Map output materialized bytes=36523515
        Input split bytes=57120
        Combine input records=0
        Spilled Records=560
        Failed Shuffles=0
        Merged Map outputs=0
        GC time elapsed (ms)=115614
        CPU time spent (ms)=272576210
        Physical memory (bytes) snapshot=268956098560
        Virtual memory (bytes) snapshot=2461942099968
        Total committed heap usage (bytes)=244810514432
    File Input Format Counters 
        Bytes Read=8815472899
17/05/04 19:44:47 ERROR streaming.StreamJob: Job not successful!
Streaming Command Failed!
Job output is complete

google-cloud-platform google-cloud-dataproc hadoop mapreduce mrjob
person vkc    schedule 30.04.2017    source источник
comment
Пожалуйста, опубликуйте журнал неудачных задач или главный журнал приложения (находится в диспетчере ресурсов II).   -  person Paul Back    schedule 02.05.2017
comment
@PaulBack Я только что добавил журнал неудачных заданий (см. Редактирование), надеюсь, что это поможет? Если вы имели в виду не это, не могли бы вы уточнить, где я могу найти этот главный журнал? Я также проверил Stackdriver- ›Logging-› Logs в журналах уровня VM, но, к сожалению, ошибок не регистрируется.   -  person vkc    schedule 04.05.2017
comment
Посмотрите, как есть строка «Задание не выполнено, так как задания не выполнены». failedMaps: 1 failedReduces: 0 '? В вашем диспетчере ресурсов и / или сервере истории заданий есть журнал задач для этого сбойного сопоставителя, который будет содержать трассировку стека, которая поможет диагностировать основную причину ошибки. Вставьте указанную трассировку стека.   -  person Paul Back    schedule 04.05.2017
comment
@PaulBack Извините, я новичок в Google Cloud Platform, не могли бы вы мне точно показать, как я могу перейти из верхнего меню к трассировке стека, о которой вы говорите?   -  person vkc    schedule 04.05.2017

Ответы (2)


arrow_upward
0
arrow_downward

Я отвечаю только потому, что у меня недостаточно очков для комментариев, но вам следует попробовать отслеживать состояние каждой задачи карты, когда она выполняется с помощью графического интерфейса ResourceManager.

Может случиться так, что один картограф выходит из строя (например, поврежденная строка вызывает необработанные исключения) и mapreduce.map.failures.maxpercent = 0, что приводит к завершению задания.

person Bill    schedule 02.05.2017
comment
Я только что добавил журнал неудачных заданий (см. Редактирование), надеюсь, это поможет? Если вы имели в виду не это, не могли бы вы уточнить, где я могу найти этот главный журнал? Я также проверил Stackdriver- ›Logging-› Logs в журналах уровня VM, но, к сожалению, ошибок не регистрируется. - person vkc; 04.05.2017
comment
Извините, я не знаком с DataProc, так как всю свою работу я выполняю на AWS. Но вот некоторая документация о том, как получить доступ к интерфейсу ResourceManager. cloud.google.com/dataproc/docs/concepts/cluster-web- интерфейсы. Через этот интерфейс вы сможете просматривать состояние каждой задачи по мере ее выполнения и получить доступ к журналам для каждой задачи, которые дадут вам представление о том, почему она терпит неудачу. Именно так я выполняю большую часть отладки заданий MapReduce. - person Bill; 08.05.2017
comment
Кроме того, ошибка «тайм-аут» может быть результатом нехватки памяти на главном узле, поэтому убедитесь, что вы используете достаточно большой экземпляр. Но я рекомендую покопаться в журналах, чтобы найти точную причину. - person Bill; 08.05.2017

arrow_upward
0
arrow_downward

Код ошибки 143 обычно указывает на OOME. Вы должны использовать эти параметры, чтобы установить размеры вашей памяти для преобразователей и редукторов, чтобы выяснить, сколько памяти фактически использует ваше приложение.

-Dmapreduce.map.memory.mb = 1024 -Dmapreduce.reduce.memory.mb = 1024

Еще одно соображение - это то, как ваши данные разделяются. Иногда ваши данные искажены, и один сопоставитель имеет в 3 раза больше записей, чем остальные сопоставители. Вы можете определить это, просмотрев папку с данными и убедившись, что все файлы примерно равны.

person tk421    schedule 09.05.2017