You are viewing a plain text version of this content. The canonical link for it is here.
Posted to common-issues@hadoop.apache.org by "Steve Loughran (Jira)" <ji...@apache.org> on 2020/04/17 15:06:00 UTC
[jira] [Commented] (HADOOP-16798) job commit failure in S3A MR
test, executor rejected submission
[ https://issues.apache.org/jira/browse/HADOOP-16798?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17085851#comment-17085851 ]
Steve Loughran commented on HADOOP-16798:
-----------------------------------------
seen again, got more trace. Hypothesis: the AM is killing one task attempt, and that is triggering the thread pool shutdown. If time-to-commit > 60s, we get a timeout and the thread pool is interrupted
```
2020-04-17 15:16:27,330 [AsyncDispatcher event handler] INFO impl.JobImpl (JobImpl.java:transition(1979)) - Num completed Tasks: 9
2020-04-17 15:16:27,380 [RMCommunicator Allocator] INFO rm.RMContainerAllocator (RMContainerAllocator.java:log(1626)) - Before Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:5 AssignedReds:0 CompletedMaps:9 CompletedReds:0 ContAlloc:13 ContRel:2 HostLocal:11 RackLocal:0
2020-04-17 15:16:27,382 [RMCommunicator Allocator] INFO rm.RMContainerAllocator (RMContainerAllocator.java:processFinishedContainer(897)) - Received completed container container_1587132747259_0003_01_000009
2020-04-17 15:16:27,383 [RMCommunicator Allocator] INFO rm.RMContainerAllocator (RMContainerAllocator.java:processFinishedContainer(897)) - Received completed container container_1587132747259_0003_01_000010
2020-04-17 15:16:27,383 [AsyncDispatcher event handler] INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:transition(2524)) - Diagnostics report from attempt_1587132747259_0003_m_000007_0:
2020-04-17 15:16:27,383 [RMCommunicator Allocator] INFO rm.RMContainerAllocator (RMContainerAllocator.java:log(1626)) - After Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:3 AssignedReds:0 CompletedMaps:9 CompletedReds:0 ContAlloc:13 ContRel:2 HostLocal:11 RackLocal:0
2020-04-17 15:16:27,383 [AsyncDispatcher event handler] INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:handle(1391)) - attempt_1587132747259_0003_m_000007_0 TaskAttempt Transitioned from SUCCESS_FINISHING_CONTAINER to SUCCEEDED
2020-04-17 15:16:27,383 [AsyncDispatcher event handler] INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:transition(2524)) - Diagnostics report from attempt_1587132747259_0003_m_000008_0:
2020-04-17 15:16:27,384 [AsyncDispatcher event handler] INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:handle(1391)) - attempt_1587132747259_0003_m_000008_0 TaskAttempt Transitioned from SUCCESS_FINISHING_CONTAINER to SUCCEEDED
2020-04-17 15:16:27,384 [ContainerLauncher #7] INFO launcher.ContainerLauncherImpl (ContainerLauncherImpl.java:run(382)) - Processing the event EventType: CONTAINER_COMPLETED for container container_1587132747259_0003_01_000009 taskAttempt attempt_1587132747259_0003_m_000007_0
2020-04-17 15:16:27,384 [ContainerLauncher #8] INFO launcher.ContainerLauncherImpl (ContainerLauncherImpl.java:run(382)) - Processing the event EventType: CONTAINER_COMPLETED for container container_1587132747259_0003_01_000010 taskAttempt attempt_1587132747259_0003_m_000008_0
2020-04-17 15:16:27,437 [IPC Server handler 13 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:resetLog(685)) - Progress of TaskAttempt attempt_1587132747259_0003_m_000006_0 is : 1.0
2020-04-17 15:16:27,441 [IPC Server handler 12 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:done(283)) - Done acknowledgment from attempt_1587132747259_0003_m_000006_0
2020-04-17 15:16:27,441 [AsyncDispatcher event handler] INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:handle(1391)) - attempt_1587132747259_0003_m_000006_0 TaskAttempt Transitioned from COMMIT_PENDING to SUCCESS_FINISHING_CONTAINER
2020-04-17 15:16:27,442 [AsyncDispatcher event handler] INFO impl.TaskImpl (TaskImpl.java:sendTaskSucceededEvents(759)) - Task succeeded with attempt attempt_1587132747259_0003_m_000006_0
2020-04-17 15:16:27,443 [AsyncDispatcher event handler] INFO impl.TaskImpl (TaskImpl.java:transition(963)) - Issuing kill to other attempt attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:27,444 [AsyncDispatcher event handler] INFO impl.TaskImpl (TaskImpl.java:handle(665)) - task_1587132747259_0003_m_000006 Task Transitioned from RUNNING to SUCCEEDED
2020-04-17 15:16:27,444 [AsyncDispatcher event handler] INFO impl.JobImpl (JobImpl.java:transition(1979)) - Num completed Tasks: 10
2020-04-17 15:16:27,445 [AsyncDispatcher event handler] INFO impl.JobImpl (JobImpl.java:handle(1020)) - job_1587132747259_0003Job Transitioned from RUNNING to COMMITTING
2020-04-17 15:16:27,446 [AsyncDispatcher event handler] INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:handle(1391)) - attempt_1587132747259_0003_m_000006_1 TaskAttempt Transitioned from RUNNING to KILL_CONTAINER_CLEANUP
2020-04-17 15:16:27,446 [ContainerLauncher #4] INFO launcher.ContainerLauncherImpl (ContainerLauncherImpl.java:run(382)) - Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1587132747259_0003_01_000014 taskAttempt attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:27,446 [ContainerLauncher #4] INFO launcher.ContainerLauncherImpl (ContainerLauncherImpl.java:kill(208)) - KILLING attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:27,446 [CommitterEvent Processor #1] INFO commit.CommitterEventHandler (CommitterEventHandler.java:run(232)) - Processing the event EventType: JOB_COMMIT
2020-04-17 15:16:27,480 [AsyncDispatcher event handler] INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:handle(1391)) - attempt_1587132747259_0003_m_000006_1 TaskAttempt Transitioned from KILL_CONTAINER_CLEANUP to KILL_TASK_CLEANUP
2020-04-17 15:16:27,481 [CommitterEvent Processor #2] INFO commit.CommitterEventHandler (CommitterEventHandler.java:run(232)) - Processing the event EventType: TASK_ABORT
2020-04-17 15:16:27,481 [CommitterEvent Processor #2] INFO magic.MagicS3GuardCommitter (DurationInfo.java:<init>(77)) - Starting: Abort task attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:27,490 [CommitterEvent Processor #1] INFO commit.AbstractS3ACommitter (DurationInfo.java:<init>(77)) - Starting: Task committer attempt_1587132747259_0003_m_000000_0: commitJob(job_1587132747259_0003)
2020-04-17 15:16:27,623 [CommitterEvent Processor #2] INFO magic.MagicS3GuardCommitter (DurationInfo.java:close(98)) - Abort task attempt_1587132747259_0003_m_000006_1: duration 0:00.142s
2020-04-17 15:16:27,640 [CommitterEvent Processor #2] INFO s3a.S3AFileSystem (S3Guard.java:logS3GuardDisabled(1072)) - S3Guard is disabled on this bucket: stevel-london
2020-04-17 15:16:27,672 [CommitterEvent Processor #1] INFO commit.AbstractS3ACommitter (DurationInfo.java:<init>(77)) - Starting: committing the output of 10 task(s)
2020-04-17 15:16:28,388 [RMCommunicator Allocator] INFO rm.RMContainerAllocator (RMContainerAllocator.java:log(1626)) - Before Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:3 AssignedReds:0 CompletedMaps:10 CompletedReds:0 ContAlloc:13 ContRel:2 HostLocal:11 RackLocal:0
2020-04-17 15:16:28,390 [RMCommunicator Allocator] INFO rm.RMContainerAllocator (RMContainerAllocator.java:processFinishedContainer(897)) - Received completed container container_1587132747259_0003_01_000014
2020-04-17 15:16:28,390 [RMCommunicator Allocator] INFO rm.RMContainerAllocator (RMContainerAllocator.java:processFinishedContainer(897)) - Received completed container container_1587132747259_0003_01_000008
2020-04-17 15:16:28,390 [AsyncDispatcher event handler] INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:transition(2524)) - Diagnostics report from attempt_1587132747259_0003_m_000006_1: [2020-04-17 15:16:27.470]Container killed by the ApplicationMaster.
[2020-04-17 15:16:27.530]Container killed on request. Exit code is 143
[2020-04-17 15:16:27.533]Container exited with a non-zero exit code 143.
2020-04-17 15:16:28,390 [RMCommunicator Allocator] INFO rm.RMContainerAllocator (RMContainerAllocator.java:processFinishedContainer(897)) - Received completed container container_1587132747259_0003_01_000011
2020-04-17 15:16:28,391 [AsyncDispatcher event handler] INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:transition(2524)) - Diagnostics report from attempt_1587132747259_0003_m_000006_0:
2020-04-17 15:16:28,391 [RMCommunicator Allocator] INFO rm.RMContainerAllocator (RMContainerAllocator.java:log(1626)) - After Scheduling: PendingReds:0 ScheduledMaps:0 ScheduledReds:0 AssignedMaps:0 AssignedReds:0 CompletedMaps:10 CompletedReds:0 ContAlloc:13 ContRel:2 HostLocal:11 RackLocal:0
2020-04-17 15:16:28,391 [AsyncDispatcher event handler] INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:handle(1391)) - attempt_1587132747259_0003_m_000006_0 TaskAttempt Transitioned from SUCCESS_FINISHING_CONTAINER to SUCCEEDED
2020-04-17 15:16:28,391 [AsyncDispatcher event handler] INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:transition(2524)) - Diagnostics report from attempt_1587132747259_0003_m_000009_0:
2020-04-17 15:16:28,391 [AsyncDispatcher event handler] INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:handle(1391)) - attempt_1587132747259_0003_m_000009_0 TaskAttempt Transitioned from SUCCESS_FINISHING_CONTAINER to SUCCEEDED
2020-04-17 15:16:28,391 [ContainerLauncher #9] INFO launcher.ContainerLauncherImpl (ContainerLauncherImpl.java:run(382)) - Processing the event EventType: CONTAINER_COMPLETED for container container_1587132747259_0003_01_000008 taskAttempt attempt_1587132747259_0003_m_000006_0
2020-04-17 15:16:28,391 [ContainerLauncher #1] INFO launcher.ContainerLauncherImpl (ContainerLauncherImpl.java:run(382)) - Processing the event EventType: CONTAINER_COMPLETED for container container_1587132747259_0003_01_000011 taskAttempt attempt_1587132747259_0003_m_000009_0
2020-04-17 15:16:30,978 [IPC Server handler 21 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:commitPending(251)) - Commit-pending state update from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:30,980 [IPC Server handler 6 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:30,980 [IPC Server handler 6 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:31,985 [IPC Server handler 10 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:31,986 [IPC Server handler 10 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:32,990 [IPC Server handler 19 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:32,990 [IPC Server handler 19 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:33,994 [IPC Server handler 11 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:33,994 [IPC Server handler 11 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:34,997 [IPC Server handler 14 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:34,997 [IPC Server handler 14 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:36,000 [IPC Server handler 22 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:36,001 [IPC Server handler 22 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:37,006 [IPC Server handler 20 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:37,006 [IPC Server handler 20 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:38,011 [IPC Server handler 8 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:38,011 [IPC Server handler 8 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:39,013 [IPC Server handler 9 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:39,014 [IPC Server handler 9 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:40,016 [IPC Server handler 12 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:40,016 [IPC Server handler 12 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:41,022 [IPC Server handler 13 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:41,023 [IPC Server handler 13 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:42,028 [IPC Server handler 24 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:42,029 [IPC Server handler 24 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:43,032 [IPC Server handler 17 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:43,033 [IPC Server handler 17 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:44,039 [IPC Server handler 28 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:44,039 [IPC Server handler 28 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:45,043 [IPC Server handler 27 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:45,044 [IPC Server handler 27 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:46,049 [IPC Server handler 15 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:46,050 [IPC Server handler 15 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:47,052 [IPC Server handler 23 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:47,053 [IPC Server handler 23 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:48,058 [IPC Server handler 26 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:48,058 [IPC Server handler 26 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:49,062 [IPC Server handler 16 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:49,062 [IPC Server handler 16 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:50,067 [IPC Server handler 29 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:50,067 [IPC Server handler 29 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:51,072 [IPC Server handler 25 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:51,072 [IPC Server handler 25 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:52,075 [IPC Server handler 7 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:52,075 [IPC Server handler 7 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:53,080 [IPC Server handler 18 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:53,080 [IPC Server handler 18 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:54,084 [IPC Server handler 4 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:54,084 [IPC Server handler 4 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:55,090 [IPC Server handler 3 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:55,090 [IPC Server handler 3 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:56,097 [IPC Server handler 0 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:56,098 [IPC Server handler 0 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:57,102 [IPC Server handler 5 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:57,103 [IPC Server handler 5 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:58,109 [IPC Server handler 2 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:58,110 [IPC Server handler 2 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:16:59,120 [IPC Server handler 1 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:16:59,120 [IPC Server handler 1 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:00,127 [IPC Server handler 10 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:00,127 [IPC Server handler 10 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:01,129 [IPC Server handler 21 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:01,130 [IPC Server handler 21 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:02,133 [IPC Server handler 6 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:02,133 [IPC Server handler 6 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:03,140 [IPC Server handler 19 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:03,141 [IPC Server handler 19 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:04,169 [IPC Server handler 19 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:04,170 [IPC Server handler 19 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:05,187 [IPC Server handler 11 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:05,188 [IPC Server handler 11 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:06,192 [IPC Server handler 20 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:06,192 [IPC Server handler 20 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:07,194 [IPC Server handler 9 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:07,194 [IPC Server handler 9 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:08,196 [IPC Server handler 14 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:08,197 [IPC Server handler 14 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:09,202 [IPC Server handler 22 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:09,202 [IPC Server handler 22 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:10,204 [IPC Server handler 8 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:10,205 [IPC Server handler 8 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:11,209 [IPC Server handler 12 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:11,209 [IPC Server handler 12 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:12,212 [IPC Server handler 24 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:12,213 [IPC Server handler 24 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:13,215 [IPC Server handler 15 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:13,236 [IPC Server handler 15 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:14,239 [IPC Server handler 28 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:14,239 [IPC Server handler 28 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:15,245 [IPC Server handler 23 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:15,245 [IPC Server handler 23 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:16,249 [IPC Server handler 27 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:16,249 [IPC Server handler 27 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:17,251 [IPC Server handler 26 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:17,253 [IPC Server handler 26 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:18,260 [IPC Server handler 13 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:18,260 [IPC Server handler 13 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:19,262 [IPC Server handler 17 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:19,263 [IPC Server handler 17 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:20,267 [IPC Server handler 7 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:20,268 [IPC Server handler 7 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:21,276 [IPC Server handler 4 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:21,276 [IPC Server handler 4 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:22,284 [IPC Server handler 16 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:22,284 [IPC Server handler 16 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:23,291 [IPC Server handler 29 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:23,291 [IPC Server handler 29 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:24,298 [IPC Server handler 18 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:24,299 [IPC Server handler 18 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:25,303 [IPC Server handler 25 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:25,303 [IPC Server handler 25 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:26,305 [IPC Server handler 3 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:26,306 [IPC Server handler 3 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:27,308 [IPC Server handler 5 on default port 49732] INFO mapred.TaskAttemptListenerImpl (TaskAttemptListenerImpl.java:canCommit(216)) - Commit go/no-go request from attempt_1587132747259_0003_m_000006_1
2020-04-17 15:17:27,308 [IPC Server handler 5 on default port 49732] INFO impl.TaskImpl (TaskImpl.java:canCommit(575)) - Result of canCommit for attempt_1587132747259_0003_m_000006_1:false
2020-04-17 15:17:27,981 [CommitterEvent Processor #2] ERROR commit.AbstractS3ACommitter (HadoopExecutors.java:shutdown(131)) - Unable to shutdown executor service after timeout 60 SECONDS
2020-04-17 15:17:27,993 [s3a-committer-pool-job_1587132747259_0003-7] WARN commit.CommitOperations (CommitOperations.java:commit(170)) - Failed to commit upload against fork-0001/test/ITestS3ACommitterMRJob-execute-magic/part-m-00009: java.io.InterruptedIOException: Completing multipart commit on fork-0001/test/ITestS3ACommitterMRJob-execute-magic/part-m-00009: com.amazonaws.AbortedException:
java.io.InterruptedIOException: Completing multipart commit on fork-0001/test/ITestS3ACommitterMRJob-execute-magic/part-m-00009: com.amazonaws.AbortedException:
at org.apache.hadoop.fs.s3a.S3AUtils.translateInterruptedException(S3AUtils.java:387)
at org.apache.hadoop.fs.s3a.S3AUtils.translateException(S3AUtils.java:194)
at org.apache.hadoop.fs.s3a.Invoker.once(Invoker.java:112)
at org.apache.hadoop.fs.s3a.Invoker.lambda$retry$4(Invoker.java:315)
at org.apache.hadoop.fs.s3a.Invoker.retryUntranslated(Invoker.java:407)
at org.apache.hadoop.fs.s3a.Invoker.retry(Invoker.java:311)
at org.apache.hadoop.fs.s3a.WriteOperationHelper.finalizeMultipartUpload(WriteOperationHelper.java:257)
at org.apache.hadoop.fs.s3a.WriteOperationHelper.commitUpload(WriteOperationHelper.java:526)
at org.apache.hadoop.fs.s3a.commit.CommitOperations.innerCommit(CommitOperations.java:194)
at org.apache.hadoop.fs.s3a.commit.CommitOperations.commit(CommitOperations.java:163)
at org.apache.hadoop.fs.s3a.commit.CommitOperations.commitOrFail(CommitOperations.java:142)
at org.apache.hadoop.fs.s3a.commit.CommitOperations.access$100(CommitOperations.java:72)
at org.apache.hadoop.fs.s3a.commit.CommitOperations$CommitContext.commitOrFail(CommitOperations.java:595)
at org.apache.hadoop.fs.s3a.commit.AbstractS3ACommitter.lambda$loadAndCommit$5(AbstractS3ACommitter.java:534)
at org.apache.hadoop.fs.s3a.commit.Tasks$Builder.runSingleThreaded(Tasks.java:165)
at org.apache.hadoop.fs.s3a.commit.Tasks$Builder.run(Tasks.java:150)
at org.apache.hadoop.fs.s3a.commit.AbstractS3ACommitter.loadAndCommit(AbstractS3ACommitter.java:533)
at org.apache.hadoop.fs.s3a.commit.AbstractS3ACommitter.lambda$commitPendingUploads$2(AbstractS3ACommitter.java:481)
at org.apache.hadoop.fs.s3a.commit.Tasks$Builder$1.run(Tasks.java:254)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: com.amazonaws.AbortedException:
at com.amazonaws.internal.SdkFilterInputStream.abortIfNeeded(SdkFilterInputStream.java:61)
at com.amazonaws.internal.SdkFilterInputStream.markSupported(SdkFilterInputStream.java:125)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeHelper(AmazonHttpClient.java:1063)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.doExecute(AmazonHttpClient.java:770)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeWithTimer(AmazonHttpClient.java:744)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.execute(AmazonHttpClient.java:726)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.access$500(AmazonHttpClient.java:686)
at com.amazonaws.http.AmazonHttpClient$RequestExecutionBuilderImpl.execute(AmazonHttpClient.java:668)
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:532)
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:512)
at com.amazonaws.services.s3.AmazonS3Client.invoke(AmazonS3Client.java:4920)
at com.amazonaws.services.s3.AmazonS3Client.invoke(AmazonS3Client.java:4866)
at com.amazonaws.services.s3.AmazonS3Client.completeMultipartUpload(AmazonS3Client.java:3464)
at org.apache.hadoop.fs.s3a.WriteOperationHelper.lambda$finalizeMultipartUpload$1(WriteOperationHelper.java:263)
at org.apache.hadoop.fs.s3a.Invoker.once(Invoker.java:110)
... 21 more
```
> job commit failure in S3A MR test, executor rejected submission
> ---------------------------------------------------------------
>
> Key: HADOOP-16798
> URL: https://issues.apache.org/jira/browse/HADOOP-16798
> Project: Hadoop Common
> Issue Type: Sub-task
> Components: fs/s3
> Affects Versions: 3.3.0
> Reporter: Steve Loughran
> Assignee: Steve Loughran
> Priority: Major
> Attachments: stdout
>
>
> failure in
> {code}
> ITestS3ACommitterMRJob.test_200_execute:304->Assert.fail:88 Job job_1578669113137_0003 failed in state FAILED with cause Job commit failed: java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@6e894de2 rejected from org.apache.hadoop.util.concurrent.HadoopThreadPoolExecutor@225eed53[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
> {code}
> Stack implies thread pool rejected it, but toString says "Terminated". Race condition?
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: common-issues-unsubscribe@hadoop.apache.org
For additional commands, e-mail: common-issues-help@hadoop.apache.org