You are viewing a plain text version of this content. The canonical link for it is here.
Posted to mapreduce-issues@hadoop.apache.org by "Haibo Chen (JIRA)" <ji...@apache.org> on 2016/12/02 00:31:58 UTC
[jira] [Commented] (MAPREDUCE-6815) Fix flaky
TestKill.testKillTask()
[ https://issues.apache.org/jira/browse/MAPREDUCE-6815?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15713539#comment-15713539 ]
Haibo Chen commented on MAPREDUCE-6815:
---------------------------------------
STD out
{code}
2016-11-23 10:08:07,209 INFO [main] app.MRAppMaster (MRAppMaster.java:<init>(269)) - Created MRAppMaster for application appattempt_0_0000_000001
2016-11-23 10:08:07,209 INFO [main] app.MRApp (MRApp.java:<init>(239)) - PathUsed: /data/jenkins/workspace/cdh6.x-Hadoop-MR/hadoop-mapreduce-project/hadoop-mapreduce-client/hadoop-mapreduce-client-app/target/testKill
2016-11-23 10:08:07,254 INFO [main] app.MRAppMaster (MRAppMaster.java:call(539)) - OutputCommitter set in config null
2016-11-23 10:08:07,254 INFO [main] app.MRAppMaster (MRAppMaster.java:call(562)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2016-11-23 10:08:07,256 INFO [main] event.AsyncDispatcher (AsyncDispatcher.java:register(212)) - Registering class org.apache.hadoop.mapreduce.jobhistory.EventType for class org.apache.hadoop.mapreduce.v2.app.MRApp$4
2016-11-23 10:08:07,256 INFO [main] event.AsyncDispatcher (AsyncDispatcher.java:register(212)) - Registering class org.apache.hadoop.mapreduce.v2.app.job.event.JobEventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$JobEventDispatcher
2016-11-23 10:08:07,256 INFO [main] event.AsyncDispatcher (AsyncDispatcher.java:register(212)) - Registering class org.apache.hadoop.mapreduce.v2.app.job.event.TaskEventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$TaskEventDispatcher
2016-11-23 10:08:07,256 INFO [main] event.AsyncDispatcher (AsyncDispatcher.java:register(212)) - Registering class org.apache.hadoop.mapreduce.v2.app.job.event.TaskAttemptEventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$TaskAttemptEventDispatcher
2016-11-23 10:08:07,256 INFO [main] event.AsyncDispatcher (AsyncDispatcher.java:register(212)) - Registering class org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventType for class org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler
2016-11-23 10:08:07,256 INFO [main] event.AsyncDispatcher (AsyncDispatcher.java:register(212)) - Registering class org.apache.hadoop.mapreduce.v2.app.speculate.Speculator$EventType for class org.apache.hadoop.mapreduce.v2.app.MRAppMaster$SpeculatorEventDispatcher
2016-11-23 10:08:07,257 INFO [main] event.AsyncDispatcher (AsyncDispatcher.java:register(212)) - Registering class org.apache.hadoop.mapreduce.v2.app.rm.ContainerAllocator$EventType for class org.apache.hadoop.mapreduce.v2.app.MRApp$MRAppContainerAllocator
2016-11-23 10:08:07,257 INFO [main] event.AsyncDispatcher (AsyncDispatcher.java:register(212)) - Registering class org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncher$EventType for class org.apache.hadoop.mapreduce.v2.app.MRApp$MockContainerLauncher
2016-11-23 10:08:07,259 INFO [main] event.AsyncDispatcher (AsyncDispatcher.java:register(212)) - Registering class org.apache.hadoop.mapreduce.v2.app.job.event.JobFinishEvent$Type for class org.apache.hadoop.mapreduce.v2.app.MRApp$1
2016-11-23 10:08:07,260 WARN [main] impl.MetricsConfig (MetricsConfig.java:loadFirst(127)) - Cannot locate configuration: tried hadoop-metrics2-mrappmaster.properties,hadoop-metrics2.properties
2016-11-23 10:08:07,261 INFO [main] impl.MetricsSystemImpl (MetricsSystemImpl.java:startTimer(375)) - Scheduled snapshot period at 10 second(s).
2016-11-23 10:08:07,261 INFO [main] impl.MetricsSystemImpl (MetricsSystemImpl.java:start(192)) - MRAppMaster metrics system started
2016-11-23 10:08:07,262 INFO [main] impl.JobImpl (JobImpl.java:setup(1531)) - Adding job token for job_0_0000 to jobTokenSecretManager
2016-11-23 10:08:07,263 WARN [main] impl.JobImpl (JobImpl.java:setup(1537)) - Shuffle secret key missing from job credentials. Using job token secret as shuffle secret.
2016-11-23 10:08:07,264 INFO [main] impl.JobImpl (JobImpl.java:makeUberDecision(1302)) - Not uberizing job_0_0000 because: not enabled;
2016-11-23 10:08:07,264 INFO [main] impl.JobImpl (JobImpl.java:createMapTasks(1559)) - Input size for job job_0_0000 = 0. Number of splits = 2
2016-11-23 10:08:07,264 INFO [main] impl.JobImpl (JobImpl.java:createReduceTasks(1576)) - Number of reduces for job job_0_0000 = 0
2016-11-23 10:08:07,265 INFO [main] impl.JobImpl (JobImpl.java:handle(1012)) - job_0_0000Job Transitioned from NEW to INITED
2016-11-23 10:08:07,265 INFO [main] app.MRAppMaster (MRAppMaster.java:serviceStart(1256)) - MRAppMaster launching normal, non-uberized, multi-container job job_0_0000.
2016-11-23 10:08:07,265 INFO [main] ipc.CallQueueManager (CallQueueManager.java:<init>(75)) - Using callQueue: class java.util.concurrent.LinkedBlockingQueue queueCapacity: 100 scheduler: class org.apache.hadoop.ipc.DefaultRpcScheduler
2016-11-23 10:08:07,266 INFO [Socket Reader #1 for port 37121] ipc.Server (Server.java:run(818)) - Starting Socket Reader #1 for port 37121
2016-11-23 10:08:07,269 INFO [main] pb.RpcServerFactoryPBImpl (RpcServerFactoryPBImpl.java:createServer(174)) - Adding protocol org.apache.hadoop.mapreduce.v2.api.MRClientProtocolPB to the server
2016-11-23 10:08:07,270 INFO [IPC Server Responder] ipc.Server (Server.java:run(1052)) - IPC Server Responder: starting
2016-11-23 10:08:07,270 INFO [IPC Server listener on 37121] ipc.Server (Server.java:run(888)) - IPC Server listener on 37121: starting
2016-11-23 10:08:07,277 INFO [main] client.MRClientService (MRClientService.java:serviceStart(137)) - Instantiated MRClientService at localhost/127.0.0.1:37121
2016-11-23 10:08:07,279 INFO [main] server.AuthenticationFilter (AuthenticationFilter.java:constructSecretProvider(240)) - Unable to initialize FileSignerSecretProvider, falling back to use random secrets.
2016-11-23 10:08:07,279 INFO [main] http.HttpRequestLog (HttpRequestLog.java:getRequestLog(80)) - Http request log for http.requests.mapreduce is not defined
2016-11-23 10:08:07,280 INFO [main] http.HttpServer2 (HttpServer2.java:addGlobalFilter(754)) - Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer2$QuotingInputFilter)
2016-11-23 10:08:07,281 INFO [main] http.HttpServer2 (HttpServer2.java:addFilter(729)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context mapreduce
2016-11-23 10:08:07,282 INFO [main] http.HttpServer2 (HttpServer2.java:addFilter(737)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2016-11-23 10:08:07,282 INFO [main] http.HttpServer2 (HttpServer2.java:addFilter(737)) - Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2016-11-23 10:08:07,282 INFO [main] http.HttpServer2 (HttpServer2.java:initializeWebServer(458)) - adding path spec: /mapreduce/*
2016-11-23 10:08:07,283 INFO [main] http.HttpServer2 (HttpServer2.java:initializeWebServer(458)) - adding path spec: /ws/*
2016-11-23 10:08:07,300 INFO [main] webapp.WebApps (WebApps.java:build(339)) - Registered webapp guice modules
2016-11-23 10:08:07,301 INFO [main] http.HttpServer2 (HttpServer2.java:openListeners(959)) - Jetty bound to port 44196
2016-11-23 10:08:07,301 INFO [main] mortbay.log (Slf4jLog.java:info(67)) - jetty-6.1.26
2016-11-23 10:08:07,304 INFO [main] mortbay.log (Slf4jLog.java:info(67)) - Extract jar:file:/var/lib/jenkins/.m2/repository/org/apache/hadoop/hadoop-yarn-common/3.0.0-alpha1-cdh6.x-SNAPSHOT/hadoop-yarn-common-3.0.0-alpha1-cdh6.x-SNAPSHOT.jar!/webapps/mapreduce to /tmp/Jetty_0_0_0_0_44196_mapreduce____imw8h7/webapp
2016-11-23 10:08:07,701 INFO [main] mortbay.log (Slf4jLog.java:info(67)) - Started SelectChannelConnector@0.0.0.0:44196
2016-11-23 10:08:07,702 INFO [main] webapp.WebApps (WebApps.java:start(376)) - Web app mapreduce started at 44196
2016-11-23 10:08:07,705 INFO [main] impl.MetricsSystemImpl (MetricsSystemImpl.java:stop(211)) - Stopping MRAppMaster metrics system...
2016-11-23 10:08:07,706 INFO [main] impl.MetricsSystemImpl (MetricsSystemImpl.java:stop(217)) - MRAppMaster metrics system stopped.
2016-11-23 10:08:07,706 INFO [main] impl.MetricsSystemImpl (MetricsSystemImpl.java:shutdown(607)) - MRAppMaster metrics system shutdown complete.
2016-11-23 10:08:07,707 INFO [main] app.MRApp (MRApp.java:submit(311)) - Writing job conf to /data/jenkins/workspace/cdh6.x-Hadoop-MR/hadoop-mapreduce-project/hadoop-mapreduce-client/hadoop-mapreduce-client-app/target/testKill/jenkins/.staging/job_0_0000/job.xml
2016-11-23 10:08:07,716 INFO [AsyncDispatcher event handler] impl.JobImpl (JobImpl.java:handle(1012)) - job_0_0000Job Transitioned from INITED to SETUP
2016-11-23 10:08:07,716 INFO [CommitterEvent Processor #0] commit.CommitterEventHandler (CommitterEventHandler.java:run(232)) - Processing the event EventType: JOB_SETUP
Job State is : RUNNING
2016-11-23 10:08:07,724 INFO [CommitterEvent Processor #0] output.FileOutputCommitter (FileOutputCommitter.java:<init>(123)) - File Output Committer Algorithm version is 2
2016-11-23 10:08:07,724 INFO [CommitterEvent Processor #0] output.FileOutputCommitter (FileOutputCommitter.java:<init>(138)) - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
2016-11-23 10:08:07,725 WARN [CommitterEvent Processor #0] output.FileOutputCommitter (FileOutputCommitter.java:setupJob(347)) - Output Path is null in setupJob()
2016-11-23 10:08:07,725 INFO [AsyncDispatcher event handler] impl.TaskImpl (TaskImpl.java:handle(661)) - task_0_0000_m_000000 Task Transitioned from NEW to KILLED
Job State is : RUNNING Waiting for state : SUCCEEDED map progress : 0.0 reduce progress : 0.0
2016-11-23 10:08:07,725 ERROR [AsyncDispatcher event handler] impl.JobImpl (JobImpl.java:handle(1004)) - Can't handle this event at current state
org.apache.hadoop.yarn.state.InvalidStateTransitionException: Invalid event: JOB_TASK_COMPLETED at SETUP
at org.apache.hadoop.yarn.state.StateMachineFactory.doTransition(StateMachineFactory.java:305)
at org.apache.hadoop.yarn.state.StateMachineFactory.access$300(StateMachineFactory.java:46)
at org.apache.hadoop.yarn.state.StateMachineFactory$InternalStateMachine.doTransition(StateMachineFactory.java:448)
at org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl.handle(JobImpl.java:1002)
at org.apache.hadoop.mapreduce.v2.app.job.impl.JobImpl.handle(JobImpl.java:140)
at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$JobEventDispatcher.handle(MRAppMaster.java:1465)
at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$JobEventDispatcher.handle(MRAppMaster.java:1461)
at org.apache.hadoop.yarn.event.AsyncDispatcher.dispatch(AsyncDispatcher.java:187)
at org.apache.hadoop.yarn.event.AsyncDispatcher$1.run(AsyncDispatcher.java:113)
at java.lang.Thread.run(Thread.java:745)
2016-11-23 10:08:07,726 INFO [AsyncDispatcher event handler] impl.JobImpl (JobImpl.java:handle(1012)) - job_0_0000Job Transitioned from SETUP to RUNNING
2016-11-23 10:08:07,726 INFO [AsyncDispatcher event handler] impl.JobImpl (JobImpl.java:handle(1012)) - job_0_0000Job Transitioned from RUNNING to ERROR
2016-11-23 10:08:07,726 ERROR [AsyncDispatcher event handler] impl.TaskImpl (TaskImpl.java:handle(656)) - Can't handle this event at current state for task_0_0000_m_000000
org.apache.hadoop.yarn.state.InvalidStateTransitionException: Invalid event: T_SCHEDULE at KILLED
at org.apache.hadoop.yarn.state.StateMachineFactory.doTransition(StateMachineFactory.java:305)
at org.apache.hadoop.yarn.state.StateMachineFactory.access$300(StateMachineFactory.java:46)
at org.apache.hadoop.yarn.state.StateMachineFactory$InternalStateMachine.doTransition(StateMachineFactory.java:448)
at org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl.handle(TaskImpl.java:654)
at org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl.handle(TaskImpl.java:101)
at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$TaskEventDispatcher.handle(MRAppMaster.java:1475)
at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$TaskEventDispatcher.handle(MRAppMaster.java:1469)
at org.apache.hadoop.yarn.event.AsyncDispatcher.dispatch(AsyncDispatcher.java:187)
at org.apache.hadoop.yarn.event.AsyncDispatcher$1.run(AsyncDispatcher.java:113)
at java.lang.Thread.run(Thread.java:745)
2016-11-23 10:08:07,726 ERROR [AsyncDispatcher event handler] impl.TaskImpl (TaskImpl.java:internalError(671)) - Invalid event T_SCHEDULE on Task task_0_0000_m_000000
2016-11-23 10:08:07,729 INFO [AsyncDispatcher event handler] impl.TaskImpl (TaskImpl.java:handle(661)) - task_0_0000_m_000001 Task Transitioned from NEW to SCHEDULED
2016-11-23 10:08:07,733 INFO [AsyncDispatcher event handler] app.MRAppMaster (MRAppMaster.java:serviceStop(1053)) - Skipping cleaning up the staging dir. assuming AM will be retried.
2016-11-23 10:08:07,734 INFO [Ping Checker] util.AbstractLivelinessMonitor (AbstractLivelinessMonitor.java:run(139)) - TaskAttemptFinishingMonitor thread interrupted
2016-11-23 10:08:07,735 WARN [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:serviceStop(166)) - Interrupted Exception while stopping
java.lang.InterruptedException
at java.lang.Object.wait(Native Method)
at java.lang.Thread.join(Thread.java:1245)
at java.lang.Thread.join(Thread.java:1319)
at org.apache.hadoop.yarn.event.AsyncDispatcher.serviceStop(AsyncDispatcher.java:164)
at org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221)
at org.apache.hadoop.service.ServiceOperations.stop(ServiceOperations.java:52)
at org.apache.hadoop.service.ServiceOperations.stopQuietly(ServiceOperations.java:80)
at org.apache.hadoop.service.CompositeService.stop(CompositeService.java:157)
at org.apache.hadoop.service.CompositeService.serviceStop(CompositeService.java:131)
at org.apache.hadoop.mapreduce.v2.app.MRAppMaster.serviceStop(MRAppMaster.java:1794)
at org.apache.hadoop.service.AbstractService.stop(AbstractService.java:221)
at org.apache.hadoop.mapreduce.v2.app.MRAppMaster.stop(MRAppMaster.java:1286)
at org.apache.hadoop.mapreduce.v2.app.MRApp$1.handle(MRApp.java:482)
at org.apache.hadoop.mapreduce.v2.app.MRApp$1.handle(MRApp.java:479)
at org.apache.hadoop.yarn.event.AsyncDispatcher.dispatch(AsyncDispatcher.java:187)
at org.apache.hadoop.yarn.event.AsyncDispatcher$1.run(AsyncDispatcher.java:113)
at java.lang.Thread.run(Thread.java:745)
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR Waiting for state : SUCCEEDED map progress : 0.5 reduce progress : 0.0
Job State is : ERROR
{code}
> Fix flaky TestKill.testKillTask()
> ---------------------------------
>
> Key: MAPREDUCE-6815
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-6815
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: mrv2
> Affects Versions: 3.0.0-alpha1
> Reporter: Haibo Chen
> Assignee: Haibo Chen
>
> Error Message
> Job state is not correct (timedout) expected:<SUCCEEDED> but was:<ERROR>
> Stacktrace
> java.lang.AssertionError: Job state is not correct (timedout) expected:<SUCCEEDED> but was:<ERROR>
> at org.junit.Assert.fail(Assert.java:88)
> at org.junit.Assert.failNotEquals(Assert.java:743)
> at org.junit.Assert.assertEquals(Assert.java:118)
> at org.apache.hadoop.mapreduce.v2.app.MRApp.waitForState(MRApp.java:416)
> at org.apache.hadoop.mapreduce.v2.app.TestKill.testKillTask(TestKill.java:124)
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: mapreduce-issues-unsubscribe@hadoop.apache.org
For additional commands, e-mail: mapreduce-issues-help@hadoop.apache.org