hdfs-deprecated
hdfs-deprecated copied to clipboard
Published
20 hours ago •
mesosphere-backup
mesosphere-backup
Scheduler stuck in RECONCILING_TASKS and not launching tasks
I am running mesos 0.24, ZooKeeper 3.4.6, Marathon 0.10.1 and docker 1.8.1 on CoreOS 801.0.0.
All of the above are running natively and not within docker containers.
I have built the latest head and deployed it using marathon:
{
"id": "hdfs",
"cpus": 0.5,
"mem": 512,
"disk": 100,
"instances": 1,
"env": {
"LD_LIBRARY_PATH": "/opt/test/packages/mesos/lib/",
"JAVA_HOME": "/opt/test/packages/java"
},
"cmd": "cd hdfs-mesos-0.1.4 && ./bin/hdfs-mesos",
"uris": [
"https://somesite.com/hdfs-mesos.tgz"
]
}
This is my mesos-site.xml
<?xml version="1.0" encoding="UTF-8"?>
<?xml-stylesheet type="text/xsl" href="configuration.xsl"?>
<!--
Licensed under the Apache License, Version 2.0 (the "License");
you may not use this file except in compliance with the License.
You may obtain a copy of the License at
http://www.apache.org/licenses/LICENSE-2.0
Unless required by applicable law or agreed to in writing, software
distributed under the License is distributed on an "AS IS" BASIS,
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
See the License for the specific language governing permissions and
limitations under the License. See accompanying LICENSE file.
-->
<!-- Put site-specific property overrides in this file. -->
<configuration>
<property>
<name>mesos.hdfs.data.dir</name>
<description>The primary data directory in HDFS</description>
<value>/var/lib/hdfs/data</value>
</property>
<property>
<name>mesos.hdfs.secondary.data.dir</name>
<description>The secondary data directory in HDFS</description>
<value>/var/run/hadoop-hdfs</value>
</property>
<property>
<name>mesos.hdfs.native-hadoop-binaries</name>
<description>Mark true if you have hadoop pre-installed on your host machines (otherwise it will be distributed by the scheduler)</description>
<value>false</value>
</property>
<property>
<name>mesos.hdfs.framework.mnt.path</name>
<description>Mount location (if mesos.hdfs.native-hadoop-binaries is marked false)</description>
<value>/opt/mesosphere</value>
</property>
<property>
<name>mesos.hdfs.state.zk</name>
<description>Comma-separated hostname-port pairs of zookeeper node locations for HDFS framework state information</description>
<value>master.mesos:2181</value>
</property>
<property>
<name>mesos.master.uri</name>
<description>Zookeeper entry for mesos master location</description>
<value>zk://master.mesos:2181/mesos</value>
</property>
<property>
<name>mesos.hdfs.zkfc.ha.zookeeper.quorum</name>
<description>Comma-separated list of zookeeper hostname-port pairs for HDFS HA features</description>
<value>master.mesos:2181</value>
</property>
<property>
<name>mesos.hdfs.framework.name</name>
<description>Your Mesos framework name and cluster name when accessing files (hdfs://YOUR_NAME)</description>
<value>hdfs</value>
</property>
<property>
<name>mesos.hdfs.mesosdns</name>
<description>Whether to use Mesos DNS for service discovery within HDFS</description>
<value>true</value>
</property>
<property>
<name>mesos.hdfs.mesosdns.domain</name>
<description>Root domain name of Mesos DNS (usually 'mesos')</description>
<value>mesos</value>
</property>
<property>
<name>mesos.native.library</name>
<description>Location of libmesos.so</description>
<value>/opt/airglow/packages/mesos/lib/libmesos.so</value>
</property>
<property>
<name>mesos.hdfs.journalnode.count</name>
<description>Number of journal nodes (must be odd)</description>
<value>1</value>
</property>
<!-- Additional settings for fine-tuning -->
<property>
<name>mesos.hdfs.jvm.overhead</name>
<description>Multiplier on resources reserved in order to account for JVM allocation</description>
<value>1</value>
</property>
<property>
<name>mesos.hdfs.hadoop.heap.size</name>
<value>512</value>
</property>
<property>
<name>mesos.hdfs.namenode.heap.size</name>
<value>512</value>
</property>
<property>
<name>mesos.hdfs.datanode.heap.size</name>
<value>512</value>
</property>
<property>
<name>mesos.hdfs.executor.heap.size</name>
<value>256</value>
</property>
<property>
<name>mesos.hdfs.executor.cpus</name>
<value>0.5</value>
</property>
<property>
<name>mesos.hdfs.namenode.cpus</name>
<value>0.5</value>
</property>
<property>
<name>mesos.hdfs.journalnode.cpus</name>
<value>0.5</value>
</property>
<property>
<name>mesos.hdfs.datanode.cpus</name>
<value>0.5</value>
</property>
<property>
<name>mesos.hdfs.user</name>
<value>root</value>
</property>
<property>
<name>mesos.hdfs.role</name>
<value>*</value>
</property>
</configuration>
This is the output of stderr:
I0916 04:03:52.071491 1100 logging.cpp:172] INFO level logging started!
I0916 04:03:52.072974 1100 fetcher.cpp:414] Fetcher Info: {"cache_directory":"\/tmp\/mesos\/fetch\/slaves\/20150916-033940-169978048-5050-585-S3\/root","items":[{"action":"BYPASS_CACHE","uri":{"extract":true,"value":"https:\/\/somesite.com\/hdfs-mesos.tgz"}}],"sandbox_directory":"\/tmp\/mesos\/slaves\/20150916-033940-169978048-5050-585-S3\/frameworks\/20150916-001025-169978048-5050-1205-0000\/executors\/hdfs.f0ea612c-5c27-11e5-83c3-0800273462a2\/runs\/8877566d-5ad9-4cf4-8ae5-c91e0c843e88","user":"root"}
I0916 04:03:52.078835 1100 fetcher.cpp:369] Fetching URI 'https://somesite.com/hdfs-mesos.tgz'
I0916 04:03:52.078902 1100 fetcher.cpp:243] Fetching directly into the sandbox directory
I0916 04:03:52.078956 1100 fetcher.cpp:180] Fetching URI 'https://somesite.com/hdfs-mesos.tgz'
I0916 04:03:52.079008 1100 fetcher.cpp:127] Downloading resource from 'https://somesite.com/hdfs-mesos.tgz' to '/tmp/mesos/slaves/20150916-033940-169978048-5050-585-S3/frameworks/20150916-001025-169978048-5050-1205-0000/executors/hdfs.f0ea612c-5c27-11e5-83c3-0800273462a2/runs/8877566d-5ad9-4cf4-8ae5-c91e0c843e88/hdfs-mesos.tgz'
I0916 04:08:39.556895 1100 fetcher.cpp:76] Extracting with command: tar -C '/tmp/mesos/slaves/20150916-033940-169978048-5050-585-S3/frameworks/20150916-001025-169978048-5050-1205-0000/executors/hdfs.f0ea612c-5c27-11e5-83c3-0800273462a2/runs/8877566d-5ad9-4cf4-8ae5-c91e0c843e88' -xf '/tmp/mesos/slaves/20150916-033940-169978048-5050-585-S3/frameworks/20150916-001025-169978048-5050-1205-0000/executors/hdfs.f0ea612c-5c27-11e5-83c3-0800273462a2/runs/8877566d-5ad9-4cf4-8ae5-c91e0c843e88/hdfs-mesos.tgz'
I0916 04:08:41.093192 1100 fetcher.cpp:84] Extracted '/tmp/mesos/slaves/20150916-033940-169978048-5050-585-S3/frameworks/20150916-001025-169978048-5050-1205-0000/executors/hdfs.f0ea612c-5c27-11e5-83c3-0800273462a2/runs/8877566d-5ad9-4cf4-8ae5-c91e0c843e88/hdfs-mesos.tgz' into '/tmp/mesos/slaves/20150916-033940-169978048-5050-585-S3/frameworks/20150916-001025-169978048-5050-1205-0000/executors/hdfs.f0ea612c-5c27-11e5-83c3-0800273462a2/runs/8877566d-5ad9-4cf4-8ae5-c91e0c843e88'
W0916 04:08:41.093310 1100 fetcher.cpp:265] Copying instead of extracting resource from URI with 'extract' flag, because it does not seem to be an archive: https://somesite.com/hdfs-mesos.tgz
I0916 04:08:41.093575 1100 fetcher.cpp:446] Fetched 'https://somesite.com/hdfs-mesos.tgz' to '/tmp/mesos/slaves/20150916-033940-169978048-5050-585-S3/frameworks/20150916-001025-169978048-5050-1205-0000/executors/hdfs.f0ea612c-5c27-11e5-83c3-0800273462a2/runs/8877566d-5ad9-4cf4-8ae5-c91e0c843e88/hdfs-mesos.tgz'
I0916 04:08:41.285573 1097 exec.cpp:133] Version: 0.24.0
I0916 04:08:41.298492 1164 exec.cpp:207] Executor registered on slave 20150916-033940-169978048-5050-585-S3
2015-09-16 04:08:47,382:1169(0x7f16b8f1c700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
2015-09-16 04:08:47,382:1169(0x7f16b8f1c700):ZOO_INFO@log_env@716: Client environment:host.name=core-04
2015-09-16 04:08:47,382:1169(0x7f16b8f1c700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
2015-09-16 04:08:47,382:1169(0x7f16b8f1c700):ZOO_INFO@log_env@724: Client environment:os.arch=4.1.6-coreos-r2
2015-09-16 04:08:47,382:1169(0x7f16b8f1c700):ZOO_INFO@log_env@725: Client environment:os.version=#2 SMP Thu Sep 10 06:08:51 UTC 2015
2015-09-16 04:08:47,383:1169(0x7f16b8f1c700):ZOO_INFO@log_env@733: Client environment:user.name=(null)
2015-09-16 04:08:47,383:1169(0x7f16b8f1c700):ZOO_INFO@log_env@741: Client environment:user.home=/root
2015-09-16 04:08:47,383:1169(0x7f16b8f1c700):ZOO_INFO@log_env@753: Client environment:user.dir=/tmp/mesos/slaves/20150916-033940-169978048-5050-585-S3/frameworks/20150916-001025-169978048-5050-1205-0000/executors/hdfs.f0ea612c-5c27-11e5-83c3-0800273462a2/runs/8877566d-5ad9-4cf4-8ae5-c91e0c843e88/hdfs-mesos-0.1.4
2015-09-16 04:08:47,383:1169(0x7f16b8f1c700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=master.mesos:2181 sessionTimeout=20000 watcher=0x7f1682367838 sessionId=0 sessionPasswd=<null> context=0x7f1668001960 flags=0
2015-09-16 04:08:47,456:1169(0x7f16897fa700):ZOO_INFO@check_events@1703: initiated connection to server [192.168.33.10:2181]
2015-09-16 04:08:47,461:1169(0x7f16897fa700):ZOO_INFO@check_events@1750: session establishment complete on server [192.168.33.10:2181], sessionId=0x14fd43d14560011, negotiated timeout=20000
2015-09-16 04:08:48,279:1169(0x7f168a7fc700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
2015-09-16 04:08:48,279:1169(0x7f168a7fc700):ZOO_INFO@log_env@716: Client environment:host.name=core-04
2015-09-16 04:08:48,279:1169(0x7f168a7fc700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
2015-09-16 04:08:48,279:1169(0x7f168a7fc700):ZOO_INFO@log_env@724: Client environment:os.arch=4.1.6-coreos-r2
2015-09-16 04:08:48,279:1169(0x7f168a7fc700):ZOO_INFO@log_env@725: Client environment:os.version=#2 SMP Thu Sep 10 06:08:51 UTC 2015
I0916 04:08:48.280235 1206 sched.cpp:164] Version: 0.24.0
2015-09-16 04:08:48,281:1169(0x7f168a7fc700):ZOO_INFO@log_env@733: Client environment:user.name=(null)
2015-09-16 04:08:48,281:1169(0x7f168a7fc700):ZOO_INFO@log_env@741: Client environment:user.home=/root
2015-09-16 04:08:48,281:1169(0x7f168a7fc700):ZOO_INFO@log_env@753: Client environment:user.dir=/tmp/mesos/slaves/20150916-033940-169978048-5050-585-S3/frameworks/20150916-001025-169978048-5050-1205-0000/executors/hdfs.f0ea612c-5c27-11e5-83c3-0800273462a2/runs/8877566d-5ad9-4cf4-8ae5-c91e0c843e88/hdfs-mesos-0.1.4
2015-09-16 04:08:48,281:1169(0x7f168a7fc700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=master.mesos:2181 sessionTimeout=10000 watcher=0x7f1682367838 sessionId=0 sessionPasswd=<null> context=0x7f1654000c20 flags=0
2015-09-16 04:08:48,286:1169(0x7f167ee00700):ZOO_INFO@check_events@1703: initiated connection to server [192.168.33.10:2181]
2015-09-16 04:08:48,290:1169(0x7f167ee00700):ZOO_INFO@check_events@1750: session establishment complete on server [192.168.33.10:2181], sessionId=0x14fd43d14560012, negotiated timeout=10000
I0916 04:08:48.292358 1200 group.cpp:331] Group process (group(1)@192.168.33.13:34019) connected to ZooKeeper
I0916 04:08:48.292434 1200 group.cpp:805] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0)
I0916 04:08:48.292479 1200 group.cpp:403] Trying to create path '/mesos' in ZooKeeper
I0916 04:08:48.301005 1195 detector.cpp:156] Detected a new leader: (id='5')
I0916 04:08:48.301506 1195 group.cpp:674] Trying to get '/mesos/json.info_0000000005' in ZooKeeper
I0916 04:08:48.336174 1198 detector.cpp:481] A new leading master ([email protected]:5050) is detected
I0916 04:08:48.336534 1195 sched.cpp:262] New master detected at [email protected]:5050
I0916 04:08:48.337579 1195 sched.cpp:272] No credentials provided. Attempting to register without authentication
I0916 04:08:48.350497 1199 sched.cpp:640] Framework registered with 20150916-004521-169978048-5050-604-0000
2015-09-16 04:09:05,009:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 19ms
2015-09-16 04:09:18,368:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 13ms
2015-09-16 04:09:28,505:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 11ms
2015-09-16 04:09:31,730:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 14ms
2015-09-16 04:09:55,212:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 26ms
2015-09-16 04:10:35,291:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 49ms
2015-09-16 04:11:08,688:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 36ms
2015-09-16 04:11:18,547:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 12ms
2015-09-16 04:11:28,570:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 11ms
2015-09-16 04:11:31,965:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 61ms
2015-09-16 04:11:55,412:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 14ms
2015-09-16 04:12:02,059:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 47ms
2015-09-16 04:12:05,491:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 98ms
2015-09-16 04:12:18,859:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 14ms
2015-09-16 04:12:22,112:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 13ms
2015-09-16 04:12:22,218:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 24ms
2015-09-16 04:12:42,162:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 35ms
2015-09-16 04:12:55,516:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 13ms
2015-09-16 04:13:08,889:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 33ms
2015-09-16 04:13:28,911:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 11ms
2015-09-16 04:13:42,454:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 202ms
2015-09-16 04:13:42,454:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 138ms
2015-09-16 04:13:52,591:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 127ms
2015-09-16 04:13:55,822:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 25ms
2015-09-16 04:14:02,500:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 11ms
2015-09-16 04:14:15,853:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 12ms
2015-09-16 04:14:15,975:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 16ms
2015-09-16 04:14:19,400:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 91ms
2015-09-16 04:14:22,540:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 20ms
2015-09-16 04:14:55,913:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 17ms
2015-09-16 04:15:16,183:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 41ms
2015-09-16 04:15:19,619:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 101ms
2015-09-16 04:15:22,970:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 18ms
2015-09-16 04:15:29,413:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 134ms
2015-09-16 04:15:33,121:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 144ms
2015-09-16 04:15:36,487:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 32ms
2015-09-16 04:15:42,771:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 17ms
2015-09-16 04:15:53,192:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 22ms
2015-09-16 04:17:22,886:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 14ms
2015-09-16 04:17:29,628:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 75ms
2015-09-16 04:17:36,409:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 114ms
2015-09-16 04:17:37,132:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 482ms
2015-09-16 04:17:50,492:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 12ms
2015-09-16 04:18:40,588:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 28ms
2015-09-16 04:18:57,289:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 16ms
2015-09-16 04:19:10,652:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 13ms
2015-09-16 04:19:16,541:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 28ms
2015-09-16 04:19:34,056:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 43ms
2015-09-16 04:19:37,460:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 70ms
2015-09-16 04:19:40,881:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 87ms
2015-09-16 04:20:09,939:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 12ms
2015-09-16 04:20:40,977:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 15ms
2015-09-16 04:21:10,062:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 68ms
2015-09-16 04:21:24,372:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 13ms
2015-09-16 04:21:54,548:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 136ms
2015-09-16 04:22:11,260:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 26ms
2015-09-16 04:22:14,684:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 90ms
2015-09-16 04:22:30,159:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 18ms
2015-09-16 04:22:41,594:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 211ms
2015-09-16 04:22:51,628:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 19ms
2015-09-16 04:22:54,986:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 23ms
2015-09-16 04:22:56,862:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 11ms
2015-09-16 04:23:03,550:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 20ms
2015-09-16 04:23:05,022:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 29ms
2015-09-16 04:23:10,228:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 11ms
2015-09-16 04:23:18,425:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 55ms
2015-09-16 04:23:23,584:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 15ms
2015-09-16 04:23:36,938:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 11ms
2015-09-16 04:24:17,094:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 122ms
2015-09-16 04:24:18,563:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 49ms
2015-09-16 04:24:21,911:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 14ms
2015-09-16 04:24:24,139:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 379ms
2015-09-16 04:24:25,288:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 42ms
2015-09-16 04:24:28,635:1169(0x7f167ee00700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 13ms
2015-09-16 04:24:44,166:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 12ms
2015-09-16 04:25:04,233:1169(0x7f16897fa700):ZOO_WARN@zookeeper_interest@1557: Exceeded deadline by 53ms
This is what I see in stdout:
=========================================
04:25:17.097 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Explicitly Reconciling Tasks
04:25:17.097 [Thread-3] WARN o.a.m.hdfs.scheduler.HdfsScheduler - NULL TaskID encountered during Explicit Reconciliation.
04:25:17.097 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Implicitly Reconciling Tasks
04:25:17.097 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Sleeping for 30000ms before retrying reconciliation.
04:25:20.859 [Thread-559] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:25:20.859 [Thread-559] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2800"
04:25:20.859 [Thread-559] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2800"
04:25:21.872 [Thread-560] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 3 offers
04:25:21.880 [Thread-560] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2801"
04:25:21.880 [Thread-560] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2802"
04:25:21.880 [Thread-560] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2803"
04:25:21.880 [Thread-560] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2801"
04:25:21.880 [Thread-560] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2802"
04:25:21.880 [Thread-560] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2803"
04:25:25.896 [Thread-561] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:25:25.897 [Thread-561] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2807"
04:25:25.897 [Thread-561] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2807"
04:25:26.902 [Thread-562] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:25:26.902 [Thread-562] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2809"
04:25:26.902 [Thread-562] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2809"
04:25:27.910 [Thread-563] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:25:27.910 [Thread-563] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2810"
04:25:27.910 [Thread-563] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2811"
04:25:27.910 [Thread-563] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2810"
04:25:27.911 [Thread-563] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2811"
04:25:30.968 [Thread-564] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:25:30.968 [Thread-564] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2816"
04:25:30.968 [Thread-564] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2816"
04:25:31.979 [Thread-565] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:25:31.979 [Thread-565] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2817"
04:25:31.979 [Thread-565] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2817"
04:25:32.984 [Thread-566] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:25:32.984 [Thread-566] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2818"
04:25:32.985 [Thread-566] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2819"
04:25:32.985 [Thread-566] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2818"
04:25:32.985 [Thread-566] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2819"
04:25:36.019 [Thread-567] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:25:36.019 [Thread-567] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2823"
04:25:36.019 [Thread-567] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2823"
04:25:37.029 [Thread-568] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:25:37.029 [Thread-568] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2825"
04:25:37.029 [Thread-568] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2825"
04:25:38.034 [Thread-569] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:25:38.034 [Thread-569] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2826"
04:25:38.034 [Thread-569] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2827"
04:25:38.034 [Thread-569] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2826"
04:25:38.034 [Thread-569] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2827"
04:25:41.059 [Thread-570] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:25:41.059 [Thread-570] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2831"
04:25:41.059 [Thread-570] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2831"
04:25:42.069 [Thread-571] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:25:42.069 [Thread-571] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2833"
04:25:42.069 [Thread-571] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2833"
04:25:43.078 [Thread-572] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:25:43.079 [Thread-572] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2834"
04:25:43.079 [Thread-572] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2835"
04:25:43.079 [Thread-572] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2834"
04:25:43.079 [Thread-572] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2835"
04:25:46.094 [Thread-573] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:25:46.094 [Thread-573] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2840"
04:25:46.094 [Thread-573] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2840"
04:25:47.098 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - =========================================
04:25:47.098 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - pendingTasks size: 1
04:25:47.098 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - null
04:25:47.098 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - =========================================
04:25:47.098 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Explicitly Reconciling Tasks
04:25:47.098 [Thread-3] WARN o.a.m.hdfs.scheduler.HdfsScheduler - NULL TaskID encountered during Explicit Reconciliation.
04:25:47.098 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Implicitly Reconciling Tasks
04:25:47.098 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Sleeping for 30000ms before retrying reconciliation.
04:25:47.100 [Thread-574] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:25:47.100 [Thread-574] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2841"
04:25:47.100 [Thread-574] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2841"
04:25:48.102 [Thread-575] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:25:48.102 [Thread-575] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2842"
04:25:48.102 [Thread-575] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2843"
04:25:48.102 [Thread-575] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2842"
04:25:48.103 [Thread-575] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2843"
04:25:51.124 [Thread-576] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:25:51.125 [Thread-576] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2847"
04:25:51.125 [Thread-576] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2847"
04:25:52.130 [Thread-577] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:25:52.130 [Thread-577] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2849"
04:25:52.130 [Thread-577] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2849"
04:25:53.142 [Thread-578] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:25:53.142 [Thread-578] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2850"
04:25:53.142 [Thread-578] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2851"
04:25:53.142 [Thread-578] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2850"
04:25:53.143 [Thread-578] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2851"
04:25:56.163 [Thread-579] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:25:56.164 [Thread-579] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2855"
04:25:56.164 [Thread-579] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2855"
04:25:57.168 [Thread-580] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:25:57.168 [Thread-580] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2857"
04:25:57.168 [Thread-580] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2857"
04:25:58.181 [Thread-581] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:25:58.182 [Thread-581] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2858"
04:25:58.182 [Thread-581] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2859"
04:25:58.182 [Thread-581] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2858"
04:25:58.182 [Thread-581] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2859"
04:26:01.201 [Thread-582] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:26:01.201 [Thread-582] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2864"
04:26:01.201 [Thread-582] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2864"
04:26:02.241 [Thread-583] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:26:02.241 [Thread-583] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2865"
04:26:02.241 [Thread-583] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2865"
04:26:03.211 [Thread-584] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:03.212 [Thread-584] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2866"
04:26:03.212 [Thread-584] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2867"
04:26:03.212 [Thread-584] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2866"
04:26:03.212 [Thread-584] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2867"
04:26:06.251 [Thread-585] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:26:06.251 [Thread-585] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2871"
04:26:06.251 [Thread-585] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2871"
04:26:07.255 [Thread-586] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:26:07.255 [Thread-586] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2873"
04:26:07.255 [Thread-586] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2873"
04:26:08.261 [Thread-587] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:08.261 [Thread-587] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2874"
04:26:08.261 [Thread-587] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2875"
04:26:08.261 [Thread-587] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2874"
04:26:08.262 [Thread-587] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2875"
04:26:11.288 [Thread-588] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:26:11.289 [Thread-588] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2879"
04:26:11.289 [Thread-588] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2879"
04:26:12.303 [Thread-589] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:26:12.303 [Thread-589] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2881"
04:26:12.303 [Thread-589] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2881"
04:26:13.312 [Thread-590] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:13.312 [Thread-590] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2882"
04:26:13.312 [Thread-590] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2883"
04:26:13.312 [Thread-590] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2882"
04:26:13.312 [Thread-590] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2883"
04:26:17.099 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - =========================================
04:26:17.099 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - pendingTasks size: 1
04:26:17.099 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - null
04:26:17.099 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - =========================================
04:26:17.099 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Explicitly Reconciling Tasks
04:26:17.099 [Thread-3] WARN o.a.m.hdfs.scheduler.HdfsScheduler - NULL TaskID encountered during Explicit Reconciliation.
04:26:17.099 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Implicitly Reconciling Tasks
04:26:17.099 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Sleeping for 30000ms before retrying reconciliation.
04:26:17.327 [Thread-591] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:17.327 [Thread-591] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2888"
04:26:17.327 [Thread-591] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2889"
04:26:17.327 [Thread-591] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2888"
04:26:17.327 [Thread-591] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2889"
04:26:19.341 [Thread-592] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:19.341 [Thread-592] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2890"
04:26:19.341 [Thread-592] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2891"
04:26:19.341 [Thread-592] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2890"
04:26:19.341 [Thread-592] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2891"
04:26:22.432 [Thread-593] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:22.432 [Thread-593] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2896"
04:26:22.432 [Thread-593] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2897"
04:26:22.432 [Thread-593] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2896"
04:26:22.432 [Thread-593] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2897"
04:26:24.451 [Thread-594] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:24.451 [Thread-594] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2899"
04:26:24.451 [Thread-594] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2900"
04:26:24.451 [Thread-594] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2899"
04:26:24.451 [Thread-594] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2900"
04:26:27.478 [Thread-595] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:27.479 [Thread-595] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2904"
04:26:27.479 [Thread-595] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2905"
04:26:27.479 [Thread-595] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2904"
04:26:27.480 [Thread-595] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2905"
04:26:29.492 [Thread-596] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:29.492 [Thread-596] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2907"
04:26:29.492 [Thread-596] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2908"
04:26:29.492 [Thread-596] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2907"
04:26:29.492 [Thread-596] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2908"
04:26:32.537 [Thread-597] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:32.537 [Thread-597] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2912"
04:26:32.537 [Thread-597] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2913"
04:26:32.537 [Thread-597] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2912"
04:26:32.538 [Thread-597] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2913"
04:26:34.558 [Thread-598] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:34.558 [Thread-598] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2915"
04:26:34.558 [Thread-598] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2916"
04:26:34.558 [Thread-598] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2915"
04:26:34.558 [Thread-598] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2916"
04:26:37.583 [Thread-599] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:37.583 [Thread-599] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2920"
04:26:37.583 [Thread-599] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2921"
04:26:37.583 [Thread-599] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2920"
04:26:37.584 [Thread-599] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2921"
04:26:39.600 [Thread-600] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:39.600 [Thread-600] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2922"
04:26:39.600 [Thread-600] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2923"
04:26:39.600 [Thread-600] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2922"
04:26:39.601 [Thread-600] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2923"
04:26:42.794 [Thread-601] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:42.794 [Thread-601] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2928"
04:26:42.794 [Thread-601] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2929"
04:26:42.794 [Thread-601] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2928"
04:26:42.794 [Thread-601] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2929"
04:26:44.634 [Thread-602] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:44.634 [Thread-602] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2931"
04:26:44.634 [Thread-602] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2932"
04:26:44.634 [Thread-602] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2931"
04:26:44.635 [Thread-602] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2932"
04:26:47.100 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - =========================================
04:26:47.100 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - pendingTasks size: 1
04:26:47.100 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - null
04:26:47.100 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - =========================================
04:26:47.100 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Explicitly Reconciling Tasks
04:26:47.100 [Thread-3] WARN o.a.m.hdfs.scheduler.HdfsScheduler - NULL TaskID encountered during Explicit Reconciliation.
04:26:47.100 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Implicitly Reconciling Tasks
04:26:47.100 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Sleeping for 30000ms before retrying reconciliation.
04:26:48.659 [Thread-603] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:48.659 [Thread-603] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2936"
04:26:48.659 [Thread-603] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2937"
04:26:48.659 [Thread-603] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2936"
04:26:48.659 [Thread-603] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2937"
04:26:49.664 [Thread-604] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:49.664 [Thread-604] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2939"
04:26:49.664 [Thread-604] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2940"
04:26:49.664 [Thread-604] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2939"
04:26:49.665 [Thread-604] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2940"
04:26:53.685 [Thread-605] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:53.686 [Thread-605] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2944"
04:26:53.686 [Thread-605] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2945"
04:26:53.686 [Thread-605] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2944"
04:26:53.686 [Thread-605] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2945"
04:26:54.715 [Thread-606] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:54.715 [Thread-606] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2947"
04:26:54.715 [Thread-606] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2948"
04:26:54.715 [Thread-606] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2947"
04:26:54.716 [Thread-606] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2948"
04:26:58.757 [Thread-607] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:26:58.758 [Thread-607] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2952"
04:26:58.758 [Thread-607] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2953"
04:26:58.758 [Thread-607] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2952"
04:26:58.758 [Thread-607] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2953"
04:27:00.758 [Thread-608] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:27:00.758 [Thread-608] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2956"
04:27:00.758 [Thread-608] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2957"
04:27:00.758 [Thread-608] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2956"
04:27:00.758 [Thread-608] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2957"
04:27:04.818 [Thread-609] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:27:04.818 [Thread-609] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2960"
04:27:04.818 [Thread-609] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2961"
04:27:04.818 [Thread-609] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2960"
04:27:04.819 [Thread-609] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2961"
04:27:05.829 [Thread-610] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:27:05.829 [Thread-610] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2962"
04:27:05.829 [Thread-610] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2963"
04:27:05.829 [Thread-610] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2962"
04:27:05.829 [Thread-610] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2963"
04:27:10.864 [Thread-611] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:10.864 [Thread-611] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2969"
04:27:10.864 [Thread-611] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2969"
04:27:11.880 [Thread-612] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:27:11.880 [Thread-612] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2972"
04:27:11.880 [Thread-612] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2973"
04:27:11.880 [Thread-612] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2972"
04:27:11.881 [Thread-612] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2973"
04:27:12.887 [Thread-613] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:12.887 [Thread-613] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2974"
04:27:12.888 [Thread-613] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2974"
04:27:15.910 [Thread-614] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:15.910 [Thread-614] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2977"
04:27:15.910 [Thread-614] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2977"
04:27:16.921 [Thread-615] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:27:16.921 [Thread-615] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2980"
04:27:16.921 [Thread-615] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2981"
04:27:16.922 [Thread-615] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2980"
04:27:16.923 [Thread-615] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2981"
04:27:17.114 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - =========================================
04:27:17.114 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - pendingTasks size: 1
04:27:17.114 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - null
04:27:17.114 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - =========================================
04:27:17.114 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Explicitly Reconciling Tasks
04:27:17.114 [Thread-3] WARN o.a.m.hdfs.scheduler.HdfsScheduler - NULL TaskID encountered during Explicit Reconciliation.
04:27:17.114 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Implicitly Reconciling Tasks
04:27:17.114 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Sleeping for 30000ms before retrying reconciliation.
04:27:17.928 [Thread-616] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:17.928 [Thread-616] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2982"
04:27:17.928 [Thread-616] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2982"
04:27:21.982 [Thread-617] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:27:21.982 [Thread-617] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2986"
04:27:21.982 [Thread-617] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2987"
04:27:21.982 [Thread-617] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2986"
04:27:21.982 [Thread-617] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2987"
04:27:22.987 [Thread-618] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:22.988 [Thread-618] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2990"
04:27:22.988 [Thread-618] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2990"
04:27:23.991 [Thread-619] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:23.991 [Thread-619] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2991"
04:27:23.991 [Thread-619] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2991"
04:27:27.013 [Thread-620] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:27:27.013 [Thread-620] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2993"
04:27:27.013 [Thread-620] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2994"
04:27:27.013 [Thread-620] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2993"
04:27:27.014 [Thread-620] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2994"
04:27:28.023 [Thread-621] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:28.023 [Thread-621] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2998"
04:27:28.023 [Thread-621] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2998"
04:27:30.037 [Thread-622] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:30.038 [Thread-622] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O2999"
04:27:30.038 [Thread-622] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O2999"
04:27:32.058 [Thread-623] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:27:32.058 [Thread-623] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3002"
04:27:32.058 [Thread-623] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3003"
04:27:32.058 [Thread-623] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3002"
04:27:32.059 [Thread-623] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3003"
04:27:33.063 [Thread-624] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:33.063 [Thread-624] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3004"
04:27:33.063 [Thread-624] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3004"
04:27:35.081 [Thread-625] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:35.081 [Thread-625] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3007"
04:27:35.081 [Thread-625] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3007"
04:27:37.096 [Thread-626] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:27:37.096 [Thread-626] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3009"
04:27:37.096 [Thread-626] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3010"
04:27:37.096 [Thread-626] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3009"
04:27:37.096 [Thread-626] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3010"
04:27:38.108 [Thread-627] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:38.108 [Thread-627] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3014"
04:27:38.108 [Thread-627] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3014"
04:27:41.131 [Thread-628] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:41.132 [Thread-628] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3015"
04:27:41.132 [Thread-628] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3015"
04:27:42.137 [Thread-629] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:27:42.137 [Thread-629] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3018"
04:27:42.138 [Thread-629] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3019"
04:27:42.138 [Thread-629] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3018"
04:27:42.138 [Thread-629] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3019"
04:27:43.148 [Thread-630] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:43.148 [Thread-630] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3020"
04:27:43.148 [Thread-630] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3020"
04:27:46.171 [Thread-631] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:46.171 [Thread-631] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3024"
04:27:46.171 [Thread-631] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3024"
04:27:47.115 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - =========================================
04:27:47.115 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - pendingTasks size: 1
04:27:47.115 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - null
04:27:47.115 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - =========================================
04:27:47.115 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Explicitly Reconciling Tasks
04:27:47.115 [Thread-3] WARN o.a.m.hdfs.scheduler.HdfsScheduler - NULL TaskID encountered during Explicit Reconciliation.
04:27:47.115 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Implicitly Reconciling Tasks
04:27:47.116 [Thread-3] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Sleeping for 30000ms before retrying reconciliation.
04:27:47.185 [Thread-632] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:47.185 [Thread-632] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3025"
04:27:47.185 [Thread-632] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3025"
04:27:48.192 [Thread-633] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:48.193 [Thread-633] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3027"
04:27:48.193 [Thread-633] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3027"
04:27:49.197 [Thread-634] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:49.197 [Thread-634] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3029"
04:27:49.197 [Thread-634] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3029"
04:27:51.215 [Thread-635] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:51.215 [Thread-635] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3031"
04:27:51.215 [Thread-635] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3031"
04:27:53.228 [Thread-636] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:53.228 [Thread-636] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3034"
04:27:53.228 [Thread-636] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3034"
04:27:54.234 [Thread-637] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:54.234 [Thread-637] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3036"
04:27:54.234 [Thread-637] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3036"
04:27:55.238 [Thread-638] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:55.238 [Thread-638] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3038"
04:27:55.238 [Thread-638] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3038"
04:27:56.244 [Thread-639] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:27:56.244 [Thread-639] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3040"
04:27:56.244 [Thread-639] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3040"
04:27:59.266 [Thread-640] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:27:59.267 [Thread-640] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3043"
04:27:59.267 [Thread-640] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3044"
04:27:59.267 [Thread-640] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3043"
04:27:59.267 [Thread-640] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3044"
04:28:00.277 [Thread-641] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:28:00.277 [Thread-641] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3046"
04:28:00.277 [Thread-641] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3046"
04:28:01.677 [Thread-642] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:28:01.678 [Thread-642] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3047"
04:28:01.678 [Thread-642] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3047"
04:28:04.595 [Thread-643] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 2 offers
04:28:04.595 [Thread-643] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3051"
04:28:04.595 [Thread-643] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3052"
04:28:04.595 [Thread-643] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3051"
04:28:04.595 [Thread-643] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3052"
04:28:05.599 [Thread-644] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:28:05.599 [Thread-644] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3053"
04:28:05.599 [Thread-644] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3053"
04:28:07.721 [Thread-645] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Received 1 offers
04:28:07.721 [Thread-645] INFO o.a.m.hdfs.scheduler.HdfsScheduler - value: "20150916-033940-169978048-5050-585-O3056"
04:28:07.721 [Thread-645] INFO o.a.m.hdfs.scheduler.HdfsScheduler - Scheduler in phase: RECONCILING_TASKS, declining offer: value: "20150916-033940-169978048-5050-585-O3056"
The scheduler appears to be running properly, but it never launches any of the executors.
May be related to #194
Thanks @F21. It looks like you had some old state in Zookeeper. Regardless the reconciliation should recover without this message. "NULL TaskID encountered during Explicit Reconciliation." I will leave this open for investigation.
