From user-return-11472-archive-asf-public=cust-asf.ponee.io@zookeeper.apache.org Tue May 29 17:49:20 2018 Return-Path: X-Original-To: archive-asf-public@cust-asf.ponee.io Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by mx-eu-01.ponee.io (Postfix) with SMTP id E27AC180648 for ; Tue, 29 May 2018 17:49:19 +0200 (CEST) Received: (qmail 65090 invoked by uid 500); 29 May 2018 15:49:18 -0000 Mailing-List: contact user-help@zookeeper.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: user@zookeeper.apache.org Delivered-To: mailing list user@zookeeper.apache.org Received: (qmail 65076 invoked by uid 99); 29 May 2018 15:49:18 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd3-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 29 May 2018 15:49:18 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd3-us-west.apache.org (ASF Mail Server at spamd3-us-west.apache.org) with ESMTP id A89001807B2 for ; Tue, 29 May 2018 15:49:17 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd3-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: 3.901 X-Spam-Level: *** X-Spam-Status: No, score=3.901 tagged_above=-999 required=6.31 tests=[DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, HTML_MESSAGE=2, KAM_BADIPHTTP=2, KAM_SHORT=0.001, NORMAL_HTTP_TO_IP=0.001, RCVD_IN_DNSWL_NONE=-0.0001, RCVD_IN_MSPIKE_H2=-0.001, SPF_PASS=-0.001, WEIRD_PORT=0.001] autolearn=disabled Authentication-Results: spamd3-us-west.apache.org (amavisd-new); dkim=pass (1024-bit key) header.d=mesosphere.io Received: from mx1-lw-us.apache.org ([10.40.0.8]) by localhost (spamd3-us-west.apache.org [10.40.0.10]) (amavisd-new, port 10024) with ESMTP id bk9wZHpBVTJ5 for ; Tue, 29 May 2018 15:49:14 +0000 (UTC) Received: from mail-io0-f200.google.com (mail-io0-f200.google.com [209.85.223.200]) by mx1-lw-us.apache.org (ASF Mail Server at mx1-lw-us.apache.org) with ESMTPS id 854FC5F49F for ; Tue, 29 May 2018 15:49:14 +0000 (UTC) Received: by mail-io0-f200.google.com with SMTP id o24-v6so11770075ioa.20 for ; Tue, 29 May 2018 08:49:14 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=mesosphere.io; s=google; h=mime-version:in-reply-to:references:from:date:message-id:subject:to; bh=SZLoWiLgoRecao0DFrOACgbJZ/KZOr6v4la3GWA+YCY=; b=qO6qnAmdzLsb9UrSI8pxKCv8sJj7b8qkUfYnTpiMpFbPM3PpS2gLKFiauEs7mEdzQ9 VgZ9Avd+g0tNFwp7Sh2jQbCcBOtrB3caLvFX1SM46mrqmCCheUn+YEh/T7PxjfuEJNdY 1iEXZLjHgzhjyWVIJ3mmkds32tgnSr6lcxSK8= X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:in-reply-to:references:from:date :message-id:subject:to; bh=SZLoWiLgoRecao0DFrOACgbJZ/KZOr6v4la3GWA+YCY=; b=LyaeA/ugOxc7x0UGIqIrZbET7uYlUZfxU8Yfypag7AegmEtdJwPbl+mA815dLORsNu n4EziANkA1PaUVuchtLsKVN9uh7jMcnTLyGAsZD+P5O8VJ7fC1Hh7B7OTVRH1wgaLD3C ZHkvOzmAR+d8iwzcoapIGVaCHPgtBektbptW2H5qaAtI/GE3FErKL0+oTGDcCUOA7rRh i4O3k1qkAUhg4cH/ZKw2FTn3gBgITGkwUt4oFdX0YDZAM2beA0TU+hCNdw8SHwa+8hYT eu5OID+s5Caa4iA7WXDQmhf9C3InuTnDG9YpsrTfIHSXqeJM9aygYiizrI1ny6teXMHM zbHg== X-Gm-Message-State: ALKqPwd6Y6QkNo/p7dEfkEwvjYD9cal3HCLqCWQkk2nnQTenhhq5WzMN yQYTIhnOZUeu6qftdBxQ/WJf5Rkn+pYQEJfnWWC7 X-Google-Smtp-Source: ADUXVKL18nEUR+nixUooMBeCariG92iRECYL8cgqWLH2Zk0NHhP5LnZmi8p6VwhqOALiX/va31rXDnTpF8eTTKvtaE0= X-Received: by 2002:a6b:c80f:: with SMTP id y15-v6mr12048800iof.187.1527608947491; Tue, 29 May 2018 08:49:07 -0700 (PDT) MIME-Version: 1.0 Received: by 2002:a6b:d90d:0:0:0:0:0 with HTTP; Tue, 29 May 2018 08:49:07 -0700 (PDT) In-Reply-To: References: From: Ben Wood Date: Tue, 29 May 2018 08:49:07 -0700 Message-ID: Subject: Re: ZooKeeper gets a bind exception: Leader Election Fails To: user@zookeeper.apache.org Content-Type: multipart/alternative; boundary="000000000000abd8f7056d5a2c5f" --000000000000abd8f7056d5a2c5f Content-Type: text/plain; charset="UTF-8" Just to double check, you confirmed via netstat (or similar) that nothing is using the port, correct? On Tue, May 29, 2018 at 7:39 AM, Raghav wrote: > Hi > > We have a 3 node zk ensemble. On all three nodes, we see following logs > that indicate that ZK can't bind to port 3888, and after three tries it > gives up. See the logs and highlighted in bold. Subsequently, ZK prints log > "*As I'm leaving the listener thread, I won't be able to participate in > leader election any longer: /1.1.1.143:3888 *". > > ZK was gracefully shutdown atleast 15 minutes before restarting again. We > can rule out that anything was using that port already. > > Any help is greatly appreciated. > > ************************************************************ > ************************************** > 2018-05-28_07:38:56.15336 2018-05-28 07:38:56,148 [myid:] - INFO > [main:QuorumPeerConfig@136] - Reading configuration from: > conf/zoo.cfg > 2018-05-28_07:38:56.18385 2018-05-28 07:38:56,183 [myid:] - INFO > [main:QuorumPeer$QuorumServer@184] - Resolved hostname: 1.1.1.144 to > address: /1.1.1.144 2018-05-28_07:38:56.18643 > 2018-05-28 07:38:56,184 [myid:] - INFO [main:QuorumPeer$QuorumServer@184] > - Resolved hostname: 1.1.1.143 to address: /1.1.1.143 > 2018-05-28_07:38:56.18666 2018-05-28 07:38:56,186 [myid:] - INFO > [main:QuorumPeer$QuorumServer@184] - Resolved hostname: 1.1.1.142 to > address: /1.1.1.142 2018-05-28_07:38:56.18700 > 2018-05-28 07:38:56,186 [myid:] - INFO [main:QuorumPeerConfig@398] - > Defaulting to majority > quorums > 2018-05-28_07:38:56.19613 2018-05-28 07:38:56,195 [myid:2] - INFO > [main:DatadirCleanupManager@78] - autopurge.snapRetainCount set to > 200 2018-05-28_07:38:56.19634 > 2018-05-28 07:38:56,196 [myid:2] - INFO [main:DatadirCleanupManager@79] - > autopurge.purgeInterval set to > 24 2018-05-28_07:38:56.19835 > 2018-05-28 07:38:56,198 [myid:2] - INFO > [PurgeTask:DatadirCleanupManager$PurgeTask@138] - Purge task > started. 2018-05-28_07:38:56.21229 > 2018-05-28 07:38:56,212 [myid:2] - INFO > [PurgeTask:DatadirCleanupManager$PurgeTask@144] - Purge task completed. > 2018-05-28_07:38:56.34200 2018-05-28 07:38:56,341 [myid:2] - INFO > [main:QuorumPeerMain@130] - Starting quorum > peer > 2018-05-28_07:38:56.34870 2018-05-28 07:38:56,348 [myid:2] - INFO > [main:ServerCnxnFactory@117] - Using > org.apache.zookeeper.server.NIOServerCnxnFactory as server connection > factory > 2018-05-28_07:38:56.35725 2018-05-28 07:38:56,357 [myid:2] - INFO > [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:2181 > 2018-05-28_07:38:56.36150 2018-05-28 07:38:56,361 [myid:2] - INFO > [main:QuorumPeer@1158] - tickTime set to > 2000 > 2018-05-28_07:38:56.36181 2018-05-28 07:38:56,361 [myid:2] - INFO > [main:QuorumPeer@1204] - initLimit set to > 10 > 2018-05-28_07:38:56.36211 2018-05-28 07:38:56,361 [myid:2] - INFO > [main:QuorumPeer@1178] - minSessionTimeout set to > -1 > 2018-05-28_07:38:56.36411 2018-05-28 07:38:56,362 [myid:2] - INFO > [main:QuorumPeer@1189] - maxSessionTimeout set to > -1 > 2018-05-28_07:38:56.37134 2018-05-28 07:38:56,371 [myid:2] - INFO > [main:QuorumPeer@1467] - QuorumPeer communication is not > secured! > 2018-05-28_07:38:56.37161 2018-05-28 07:38:56,371 [myid:2] - INFO > [main:QuorumPeer@1496] - quorum.cnxn.threads.size set to 20 > 2018-05-28_07:38:57.09036 2018-05-28 07:38:57,090 [myid:2] - INFO > [ListenerThread:QuorumCnxManager$Listener@736] - My election bind port: / > 1.1.1.143:3888 > 2018-05-28_07:38:57.09877 2018-05-28 07:38:57,091 [myid:2] - ERROR > [/1.1.1.143:3888:QuorumCnxManager$Listener@760] - > *Exception while listening2018-05-28_07:38:57.09878 > java.net.BindException: > Cannot assign requested address* > 2018-05-28_07:38:57.09878 at > java.net.PlainSocketImpl.socketBind(Native Method) > 2018-05-28_07:38:57.09878 at > java.net.AbstractPlainSocketImpl.bind(AbstractPlainSocketImpl.java:382) > 2018-05-28_07:38:57.09878 at > java.net.ServerSocket.bind(ServerSocket.java:375) > 2018-05-28_07:38:57.09878 at > java.net.ServerSocket.bind(ServerSocket.java:329) > 2018-05-28_07:38:57.09879 at > org.apache.zookeeper.server.quorum.QuorumCnxManager$ > Listener.run(QuorumCnxManager.java:739) > 2018-05-28_07:38:57.10491 2018-05-28 07:38:57,104 [myid:2] - INFO > [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:2181:QuorumPeer@909] - LOOKING > 2018-05-28_07:38:57.10613 2018-05-28 07:38:57,106 [myid:2] - INFO > [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:2181:FastLeaderElection@813] - New > election. My id = 2, proposed zxid=0x9000023ff > > > > . > . > . > . > > > > 2018-05-28_07:38:59.10092 2018-05-28 07:38:59,100 [myid:2] - ERROR > [/1.1.1.143:3888:QuorumCnxManager$Listener@760] - Exception while > listening 2018-05-28_07:38:59.10093 > *java.net.BindException: > Cannot assign requested address* > 2018-05-28_07:38:59.10093 at > java.net.PlainSocketImpl.socketBind(Native > Method) > 2018-05-28_07:38:59.10093 at > java.net.AbstractPlainSocketImpl.bind(AbstractPlainSocketImpl.java:382) > 2018-05-28_07:38:59.10093 at > java.net.ServerSocket.bind(ServerSocket.java:375) > 2018-05-28_07:38:59.10094 at > java.net.ServerSocket.bind(ServerSocket.java:329) > 2018-05-28_07:38:59.10094 at > org.apache.zookeeper.server.quorum.QuorumCnxManager$ > Listener.run(QuorumCnxManager.java:739) > 2018-05-28_07:39:00.10155 2018-05-28 07:39:00,101 [myid:2] - INFO > [/1.1.1.143:3888:QuorumCnxManager$Listener@773] - Leaving > listener > 2018-05-28_07:39:00.10186 2018-05-28 07:39:00,101 [myid:2] - ERROR > [/1.1.1.143:3888:QuorumCnxManager$Listener@775] - *As I'm leaving the > listener thread, I won't be able to participate in leader election any > longer: /1.1.1.143:3888 * > > > > R > -- Ben Wood Software Engineer - Data Agility Mesosphere --000000000000abd8f7056d5a2c5f--