The connect exception is fine, it usually takes more than one connect attempt to zk. The reason your job failed is due to not having enough simultaneous map tasks on your Hadoop instance.

See http://svn.apache.org/repos/asf/giraph/trunk/README for details on running in pseudo-distributed mode.

Avery

On 10/17/12 11:09 AM, rodrigo zerbini wrote:
Hello, everybody.

I'm trying to run the shortest paths example with the command below:

hadoop jar giraph-0.2-SNAPSHOT-for-hadoop-0.20.203.0-jar-with-dependencies.jar org.apache.giraph.GiraphRunner org.apache.giraph.examples.SimpleShortestPathsVertex -if org.apache.giraph.io.JsonLongDoubleFloatDoubleVertexInputFormat -ip shortestPathsInputGraph -of org.apache.giraph.io.JsonLongDoubleFloatDoubleVertexOutputFormat -op shortestPathsOutputGraph -w 3

However, it didn't work. In jobtracker I found that some jobs failed. I had 4 killed tasks. Below you can see the log of the first task. I got a ConnectException. Does anyone have some ideia why this connection was refused? Thanks in advance.


2012-10-16 17:40:40,788 WARN org.apache.hadoop.util.NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java classes where applicable 2012-10-16 17:40:42,331 WARN org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Source name ugi already exists! 2012-10-16 17:40:44,019 INFO org.apache.hadoop.mapred.Task: Using ResourceCalculatorPlugin : null 2012-10-16 17:40:44,729 INFO org.apache.giraph.graph.GraphMapper: setup: Set log level to info 2012-10-16 17:40:44,729 INFO org.apache.giraph.graph.GraphMapper: Distributed cache is empty. Assuming fatjar. 2012-10-16 17:40:44,729 INFO org.apache.giraph.graph.GraphMapper: setup: classpath @ /tmp/hadoop-ro/mapred/local/taskTracker/ro/jobcache/job_201210161739_0001/jars/job.jar 2012-10-16 17:40:45,514 INFO org.apache.giraph.zk.ZooKeeperManager: createCandidateStamp: Made the directory _bsp/_defaultZkManagerDir/job_201210161739_0001 2012-10-16 17:40:45,531 INFO org.apache.giraph.zk.ZooKeeperManager: createCandidateStamp: Creating my filestamp _bsp/_defaultZkManagerDir/job_201210161739_0001/_task/practivate.adobe.com <http://practivate.adobe.com> 0 2012-10-16 17:40:47,160 INFO org.apache.giraph.zk.ZooKeeperManager: getZooKeeperServerList: Got [practivate.adobe.com <http://practivate.adobe.com>] 1 hosts from 1 candidates when 1 required (polling period is 3000) on attempt 0 2012-10-16 17:40:47,233 INFO org.apache.giraph.zk.ZooKeeperManager: createZooKeeperServerList: Creating the final ZooKeeper file '_bsp/_defaultZkManagerDir/job_201210161739_0001/zkServerList_practivate.adobe.com <http://zkServerList_practivate.adobe.com> 0 ' 2012-10-16 17:40:48,029 INFO org.apache.giraph.zk.ZooKeeperManager: getZooKeeperServerList: For task 0, got file 'zkServerList_practivate.adobe.com <http://zkServerList_practivate.adobe.com> 0 ' (polling period is 3000) 2012-10-16 17:40:48,030 INFO org.apache.giraph.zk.ZooKeeperManager: getZooKeeperServerList: Found [practivate.adobe.com <http://practivate.adobe.com>, 0] 2 hosts in filename 'zkServerList_practivate.adobe.com <http://zkServerList_practivate.adobe.com> 0 ' 2012-10-16 17:40:48,142 INFO org.apache.giraph.zk.ZooKeeperManager: onlineZooKeeperServers: Trying to delete old directory /tmp/hadoop-ro/mapred/local/taskTracker/ro/jobcache/job_201210161739_0001/work/_bspZooKeeper 2012-10-16 17:40:48,300 INFO org.apache.giraph.zk.ZooKeeperManager: generateZooKeeperConfigFile: Creating file /tmp/hadoop-ro/mapred/local/taskTracker/ro/jobcache/job_201210161739_0001/work/_bspZooKeeper/zoo.cfg in /tmp/hadoop-ro/mapred/local/taskTracker/ro/jobcache/job_201210161739_0001/work/_bspZooKeeper with base port 22181 2012-10-16 17:40:48,300 INFO org.apache.giraph.zk.ZooKeeperManager: generateZooKeeperConfigFile: Make directory of _bspZooKeeper = true 2012-10-16 17:40:48,300 INFO org.apache.giraph.zk.ZooKeeperManager: generateZooKeeperConfigFile: Delete of zoo.cfg = false 2012-10-16 17:40:48,643 INFO org.apache.giraph.zk.ZooKeeperManager: onlineZooKeeperServers: Attempting to start ZooKeeper server with command [/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home/bin/java, -Xmx512m, -XX:ParallelGCThreads=4, -XX:+UseConcMarkSweepGC, -XX:CMSInitiatingOccupancyFraction=70, -XX:MaxGCPauseMillis=100, -cp, /tmp/hadoop-ro/mapred/local/taskTracker/ro/jobcache/job_201210161739_0001/jars/job.jar, org.apache.zookeeper.server.quorum.QuorumPeerMain, /tmp/hadoop-ro/mapred/local/taskTracker/ro/jobcache/job_201210161739_0001/work/_bspZooKeeper/zoo.cfg] in directory /tmp/hadoop-ro/mapred/local/taskTracker/ro/jobcache/job_201210161739_0001/work/_bspZooKeeper 2012-10-16 17:40:48,803 INFO org.apache.giraph.zk.ZooKeeperManager: onlineZooKeeperServers: Connect attempt 0 of 10 max trying to connect to practivate.adobe.com:22181 <http://practivate.adobe.com:22181> with poll msecs = 3000 2012-10-16 17:40:48,946 WARN org.apache.giraph.zk.ZooKeeperManager: onlineZooKeeperServers: Got ConnectException
java.net.ConnectException: Connection refused
    at java.net.PlainSocketImpl.socketConnect(Native Method)
    at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
    at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
    at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
    at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
    at java.net.Socket.connect(Socket.java:529)
at org.apache.giraph.zk.ZooKeeperManager.onlineZooKeeperServers(ZooKeeperManager.java:661)
    at org.apache.giraph.graph.GraphMapper.setup(GraphMapper.java:329)
    at org.apache.giraph.graph.GraphMapper.run(GraphMapper.java:578)
    at org.apache.hadoop.mapred.MapTask.runNewMapper(MapTask.java:764)
    at org.apache.hadoop.mapred.MapTask.run(MapTask.java:370)
    at org.apache.hadoop.mapred.Child$4.run(Child.java:255)
    at java.security.AccessController.doPrivileged(Native Method)
    at javax.security.auth.Subject.doAs(Subject.java:396)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1121)
    at org.apache.hadoop.mapred.Child.main(Child.java:249)
2012-10-16 17:40:51,948 INFO org.apache.giraph.zk.ZooKeeperManager: onlineZooKeeperServers: Connect attempt 1 of 10 max trying to connect to practivate.adobe.com:22181 <http://practivate.adobe.com:22181> with poll msecs = 3000 2012-10-16 17:40:51,950 INFO org.apache.giraph.zk.ZooKeeperManager: onlineZooKeeperServers: Connected to practivate.adobe.com/127.0.0.1:22181 <http://practivate.adobe.com/127.0.0.1:22181>! 2012-10-16 17:40:51,950 INFO org.apache.giraph.zk.ZooKeeperManager: onlineZooKeeperServers: Creating my filestamp _bsp/_defaultZkManagerDir/job_201210161739_0001/_zkServer/practivate.adobe.com <http://practivate.adobe.com> 0 2012-10-16 17:40:52,031 INFO org.apache.giraph.graph.GraphMapper: setup: Starting up BspServiceMaster (master thread)... 2012-10-16 17:40:52,956 INFO org.apache.giraph.graph.BspService: BspService: Connecting to ZooKeeper with job job_201210161739_0001, 0 on practivate.adobe.com:22181 <http://practivate.adobe.com:22181> 2012-10-16 17:40:53,139 INFO org.apache.zookeeper.ZooKeeper: Client environment:zookeeper.version=3.3.3-1073969, built on 02/23/2011 22:27 GMT 2012-10-16 17:40:53,139 INFO org.apache.zookeeper.ZooKeeper: Client environment:host.name <http://host.name>=practivate.adobe.com <http://practivate.adobe.com> 2012-10-16 17:40:53,139 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.version=1.6.0_26 2012-10-16 17:40:53,140 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.vendor=Apple Inc. 2012-10-16 17:40:53,140 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.home=/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home 2012-10-16 17:40:53,140 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.class.path=/tmp/hadoop-ro/mapred/local/taskTracker/ro/jobcache/job_201210161739_0001/jars/classes:/tmp/hadoop-ro/mapred/local/taskTracker/ro/jobcache/job_201210161739_0001/jars:/tmp/hadoop-ro/mapred/local/taskTracker/ro/jobcache/job_201210161739_0001/attempt_201210161739_0001_m_000000_0/work:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../conf:/System/Library/Frameworks/JavaVM.framework//Versions/1.6.0/Home//lib/tools.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/..:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../hadoop-core-1.0.3.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/asm-3.2.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/aspectjrt-1.6.5.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/aspectjtools-1.6.5.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/commons-beanutils-1.7.0.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/commons-beanutils-core-1.8.0.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/commons-cli-1.2.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/commons-codec-1.4.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/commons-collections-3.2.1.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/commons-configuration-1.6.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/commons-daemon-1.0.1.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/commons-digester-1.8.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/commons-el-1.0.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/commons-httpclient-3.0.1.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/commons-io-2.1.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/commons-lang-2.4.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/commons-logging-1.1.1.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/commons-logging-api-1.0.4.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/commons-math-2.1.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/commons-net-1.4.1.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/core-3.1.1.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/hadoop-capacity-scheduler-1.0.3.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/hadoop-fairscheduler-1.0.3.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/hadoop-thriftfs-1.0.3.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/hsqldb-1.8.0.10.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/jackson-core-asl-1.8.8.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/jackson-mapper-asl-1.8.8.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/jasper-compiler-5.5.12.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/jasper-runtime-5.5.12.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/jdeb-0.8.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/jersey-core-1.8.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/jersey-json-1.8.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/jersey-server-1.8.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/jets3t-0.6.1.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/jetty-6.1.26.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/jetty-util-6.1.26.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/jsch-0.1.42.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/junit-4.5.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/kfs-0.2.2.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/log4j-1.2.15.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/mockito-all-1.8.5.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/oro-2.0.8.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/servlet-api-2.5-20081211.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/slf4j-api-1.4.3.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/slf4j-log4j12-1.4.3.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/xmlenc-0.52.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/jsp-2.1/jsp-2.1.jar:/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/jsp-2.1/jsp-api-2.1.jar 2012-10-16 17:40:53,142 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.library.path=/Users/ro/Desktop/usp/iniciacao/hadoop-1.0.3/libexec/../lib/native/Mac_OS_X-x86_64-64:/tmp/hadoop-ro/mapred/local/taskTracker/ro/jobcache/job_201210161739_0001/attempt_201210161739_0001_m_000000_0/work 2012-10-16 17:40:53,142 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.io.tmpdir=/tmp/hadoop-ro/mapred/local/taskTracker/ro/jobcache/job_201210161739_0001/attempt_201210161739_0001_m_000000_0/work/tmp 2012-10-16 17:40:53,142 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.compiler=<NA> 2012-10-16 17:40:53,142 INFO org.apache.zookeeper.ZooKeeper: Client environment:os.name <http://os.name>=Mac OS X 2012-10-16 17:40:53,142 INFO org.apache.zookeeper.ZooKeeper: Client environment:os.arch=x86_64 2012-10-16 17:40:53,142 INFO org.apache.zookeeper.ZooKeeper: Client environment:os.version=10.5.8 2012-10-16 17:40:53,143 INFO org.apache.zookeeper.ZooKeeper: Client environment:user.name <http://user.name>=ro 2012-10-16 17:40:53,143 INFO org.apache.zookeeper.ZooKeeper: Client environment:user.home=/homes/ 2012-10-16 17:40:53,143 INFO org.apache.zookeeper.ZooKeeper: Client environment:user.dir=/private/tmp/hadoop-ro/mapred/local/taskTracker/ro/jobcache/job_201210161739_0001/attempt_201210161739_0001_m_000000_0/work 2012-10-16 17:40:53,146 INFO org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=practivate.adobe.com:22181 <http://practivate.adobe.com:22181> sessionTimeout=60000 watcher=org.apache.giraph.graph.BspServiceMaster@1f0dc656 2012-10-16 17:40:53,208 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server practivate.adobe.com/127.0.0.1:22181 <http://practivate.adobe.com/127.0.0.1:22181> 2012-10-16 17:40:53,212 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to practivate.adobe.com/127.0.0.1:22181 <http://practivate.adobe.com/127.0.0.1:22181>, initiating session 2012-10-16 17:40:53,558 INFO org.apache.zookeeper.ClientCnxn: Session establishment complete on server practivate.adobe.com/127.0.0.1:22181 <http://practivate.adobe.com/127.0.0.1:22181>, sessionid = 0x13a6b4eae550000, negotiated timeout = 300000 2012-10-16 17:40:53,562 INFO org.apache.giraph.graph.BspService: process: Asynchronous connection complete. 2012-10-16 17:40:53,597 INFO org.apache.giraph.graph.GraphMapper: map: No need to do anything when not a worker 2012-10-16 17:40:53,597 INFO org.apache.giraph.graph.GraphMapper: cleanup: Starting for MASTER_ZOOKEEPER_ONLY 2012-10-16 17:40:53,751 INFO org.apache.giraph.graph.BspServiceMaster: becomeMaster: First child is '/_hadoopBsp/job_201210161739_0001/_masterElectionDir/rodrigozerbini-2.local_00000000000' and my bid is '/_hadoopBsp/job_201210161739_0001/_masterElectionDir/rodrigozerbini-2.local_00000000000' 2012-10-16 17:40:53,778 INFO org.apache.giraph.graph.BspServiceMaster: becomeMaster: I am now the master! 2012-10-16 17:40:53,810 INFO org.apache.giraph.graph.BspService: process: applicationAttemptChanged signaled 2012-10-16 17:40:53,828 WARN org.apache.giraph.graph.BspService: process: Unknown and unprocessed event (path=/_hadoopBsp/job_201210161739_0001/_applicationAttemptsDir/0/_superstepDir, type=NodeChildrenChanged, state=SyncConnected) 2012-10-16 17:41:25,178 INFO org.apache.giraph.graph.BspServiceMaster: checkWorkers: Only found 1 responses of 3 needed to start superstep -1. Sleeping for 30000 msecs and used 0 of 10 attempts. 2012-10-16 17:41:55,188 INFO org.apache.giraph.graph.BspServiceMaster: checkWorkers: Only found 1 responses of 3 needed to start superstep -1. Sleeping for 30000 msecs and used 1 of 10 attempts. 2012-10-16 17:42:25,202 INFO org.apache.giraph.graph.BspServiceMaster: checkWorkers: Only found 1 responses of 3 needed to start superstep -1. Sleeping for 30000 msecs and used 2 of 10 attempts. 2012-10-16 17:42:55,215 INFO org.apache.giraph.graph.BspServiceMaster: checkWorkers: Only found 1 responses of 3 needed to start superstep -1. Sleeping for 30000 msecs and used 3 of 10 attempts. 2012-10-16 17:43:25,260 INFO org.apache.giraph.graph.BspServiceMaster: checkWorkers: Only found 1 responses of 3 needed to start superstep -1. Sleeping for 30000 msecs and used 4 of 10 attempts. 2012-10-16 17:43:55,367 INFO org.apache.giraph.graph.BspServiceMaster: checkWorkers: Only found 1 responses of 3 needed to start superstep -1. Sleeping for 30000 msecs and used 5 of 10 attempts. 2012-10-16 17:44:25,381 INFO org.apache.giraph.graph.BspServiceMaster: checkWorkers: Only found 1 responses of 3 needed to start superstep -1. Sleeping for 30000 msecs and used 6 of 10 attempts. 2012-10-16 17:44:55,395 INFO org.apache.giraph.graph.BspServiceMaster: checkWorkers: Only found 1 responses of 3 needed to start superstep -1. Sleeping for 30000 msecs and used 7 of 10 attempts. 2012-10-16 17:45:25,409 INFO org.apache.giraph.graph.BspServiceMaster: checkWorkers: Only found 1 responses of 3 needed to start superstep -1. Sleeping for 30000 msecs and used 8 of 10 attempts. 2012-10-16 17:45:55,447 INFO org.apache.giraph.graph.BspServiceMaster: checkWorkers: Only found 1 responses of 3 needed to start superstep -1. Sleeping for 30000 msecs and used 9 of 10 attempts. 2012-10-16 17:45:55,469 ERROR org.apache.giraph.graph.BspServiceMaster: checkWorkers: Did not receive enough processes in time (only 1 of 3 required). This occurs if you do not have enough map tasks available simultaneously on your Hadoop instance to fulfill the number of requested workers. 2012-10-16 17:45:55,500 INFO org.apache.giraph.graph.BspServiceMaster: setJobState: {"_stateKey":"FAILED","_applicationAttemptKey":-1,"_superstepKey":-1} on superstep -1 2012-10-16 17:45:59,077 FATAL org.apache.giraph.graph.BspServiceMaster: failJob: Killing job job_201210161739_0001 2012-10-16 17:45:59,275 INFO org.apache.giraph.graph.BspServiceMaster: cleanup: Notifying master its okay to cleanup with /_hadoopBsp/job_201210161739_0001/_cleanedUpDir/0_master 2012-10-16 17:45:59,276 INFO org.apache.giraph.graph.BspServiceMaster: cleanUpZooKeeper: Node /_hadoopBsp/job_201210161739_0001/_cleanedUpDir already exists, no need to create. 2012-10-16 17:45:59,278 INFO org.apache.giraph.graph.BspServiceMaster: cleanUpZooKeeper: Got 1 of 4 desired children from /_hadoopBsp/job_201210161739_0001/_cleanedUpDir 2012-10-16 17:45:59,278 INFO org.apache.giraph.graph.BspServiceMaster: cleanedUpZooKeeper: Waiting for the children of /_hadoopBsp/job_201210161739_0001/_cleanedUpDir to change since only got 1 nodes. 2012-10-16 17:46:00,292 WARN org.apache.giraph.zk.ZooKeeperManager: onlineZooKeeperServers: Forced a shutdown hook kill of the ZooKeeper process.

Reply via email to