From user-return-11748-archive-asf-public=cust-asf.ponee.io@zookeeper.apache.org Tue Oct 23 14:32:17 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 A5BAD18066B for ; Tue, 23 Oct 2018 14:32:16 +0200 (CEST) Received: (qmail 93277 invoked by uid 500); 23 Oct 2018 12:32:15 -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 93264 invoked by uid 99); 23 Oct 2018 12:32:14 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd1-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 23 Oct 2018 12:32:14 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd1-us-west.apache.org (ASF Mail Server at spamd1-us-west.apache.org) with ESMTP id 4F763C9FA3 for ; Tue, 23 Oct 2018 12:32:14 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd1-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: 3.904 X-Spam-Level: *** X-Spam-Status: No, score=3.904 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_H3=0.001, RCVD_IN_MSPIKE_WL=0.001, SPF_PASS=-0.001, WEIRD_PORT=0.001] autolearn=disabled Authentication-Results: spamd1-us-west.apache.org (amavisd-new); dkim=pass (2048-bit key) header.d=cloudera.com Received: from mx1-lw-eu.apache.org ([10.40.0.8]) by localhost (spamd1-us-west.apache.org [10.40.0.7]) (amavisd-new, port 10024) with ESMTP id wAz5TnoeHEFP for ; Tue, 23 Oct 2018 12:32:11 +0000 (UTC) Received: from mail-pf1-f177.google.com (mail-pf1-f177.google.com [209.85.210.177]) by mx1-lw-eu.apache.org (ASF Mail Server at mx1-lw-eu.apache.org) with ESMTPS id D357A5F16F for ; Tue, 23 Oct 2018 12:32:10 +0000 (UTC) Received: by mail-pf1-f177.google.com with SMTP id v11-v6so597246pfn.5 for ; Tue, 23 Oct 2018 05:32:10 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:references:in-reply-to:from:date :message-id:subject:to; bh=wPYw6IDrz3p87N7nYx7UOOAeRyhYpW2YrmLcLB9jaR4=; b=aIjU1nHRlzfFLjKOh7j5rFlPeaPufmXJypPxp3i9E9AABjHdgPUQkZmF2/NJPIzNsE CFNoaLBpgwK5ojEdRWi7zpsUxb6xX22PFxpDNmzgpPLFrbXcignNyMWslmkSvCY2uc1J tcXeZofuz2VgoCKQk2+LBUQmnzo1uXnfbrZoUGbn5HWV717xDNH/NfW5r1z40qpHgRFJ nc9/bB3qT3XwpDlEXEbYhRPmy7jdGoC9mT7bmc6+as9VEZNs2r1nkdibY+Sl9PQP6ytt /yjGuN4kxpBOawdrCsUjke8BQLkAdytEmkEKYR+0xXlurTMrxBCaUerDXUvv9HoYqxZM Dyng== X-Gm-Message-State: ABuFfohEZc1SnPSKah5j1xVOgkr+sUxUb2HgBfrt2PtSi+JJ1cSs1Tuv 4fhVTgmnwosz/m7irRY5Upf6jbH/cW+npFWR0synW7SC X-Google-Smtp-Source: ACcGV63uIOXQfjMwReD7jHpTKuXndJ0DKekooEhf8PrZrFl32tfVh8yN8k4iow1Lftr7bUSF2aoEb5rU/E0p4t71wjE= X-Received: by 2002:a65:56cc:: with SMTP id w12-v6mr23355400pgs.224.1540297928972; Tue, 23 Oct 2018 05:32:08 -0700 (PDT) MIME-Version: 1.0 References: In-Reply-To: From: Norbert Kalmar Date: Tue, 23 Oct 2018 14:31:57 +0200 Message-ID: Subject: Re: ZooKeeperServer not running To: user@zookeeper.apache.org Content-Type: multipart/alternative; boundary="000000000000e7c1880578e48e55" --000000000000e7c1880578e48e55 Content-Type: text/plain; charset="UTF-8" Hi, Looks like to me ZooKeeper quorum simply didn't complete leader election yet. You can see server state as "LOOKING", and after the errors client timeouting, you get the server created and FOLLOWING log message. After that, I assume there is no more error message. So probably ZooKeeper should be started earlier a bit if you don't want these error messages. Regards, Norbert On Tue, Oct 23, 2018 at 3:35 AM Susheel Kumar wrote: > Hello, > > I am seeing "ZookeeperServer not running" WARM messages in zookeeper logs > which is causing the Solr client connections to timeout... > > What could be the problem? > > ZK: 3.4.10 > > Zookeeper.out > == > 2018-10-22 06:04:51,071 [myid:2] - INFO > [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message > format version), 5 (n.leader), 0xf00000461 (n.zxid), 0x10 (n.round), > FOLLOWING (n.state), 4 (n.sid), 0xf (n.peerEpoch) LOOKING (my state) > 2018-10-22 06:04:51,093 [myid:2] - INFO [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxnFactory@192] - Accepted socket > connection > from /192.72.25.177:39514 > 2018-10-22 06:04:51,094 [myid:2] - WARN [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxn@373] - Exception causing close of > session 0x0 due to java.io.IOException: ZooKeeperServer not running > 2018-10-22 06:04:51,094 [myid:2] - INFO [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxn@1044] - Closed socket connection for > client /192.72.25.177:39514 (no session established for client) > 2018-10-22 06:04:51,138 [myid:2] - INFO [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxnFactory@192] - Accepted socket > connection > from /192.3.101.219:56298 > 2018-10-22 06:04:51,138 [myid:2] - WARN [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxn@373] - Exception causing close of > session 0x0 due to java.io.IOException: ZooKeeperServer not running > 2018-10-22 06:04:51,139 [myid:2] - INFO [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxn@1044] - Closed socket connection for > client /192.3.101.219:56298 (no session established for client) > 2018-10-22 06:04:51,250 [myid:2] - INFO [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxnFactory@192] - Accepted socket > connection > from /192.72.27.181:46414 > 2018-10-22 06:04:51,250 [myid:2] - WARN [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxn@373] - Exception causing close of > session 0x0 due to java.io.IOException: ZooKeeperServer not running > 2018-10-22 06:04:51,250 [myid:2] - INFO [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxn@1044] - Closed socket connection for > client /192.72.27.181:46414 (no session established for client) > 2018-10-22 06:04:51,275 [myid:2] - INFO > [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message > format version), 4 (n.leader), 0xf00000461 (n.zxid), 0x192 (n.round), > LOOKING (n.state), 4 (n.sid), 0xf (n.peerEpoch) LOOKING (my state) > 2018-10-22 06:04:51,275 [myid:2] - INFO > [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message > format version), 4 (n.leader), 0xf00000461 (n.zxid), 0x192 (n.round), > LOOKING (n.state), 2 (n.sid), 0xf (n.peerEpoch) LOOKING (my state) > 2018-10-22 06:04:51,275 [myid:2] - INFO > [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message > format version), 4 (n.leader), 0xf00000461 (n.zxid), 0x192 (n.round), > LOOKING (n.state), 1 (n.sid), 0xf (n.peerEpoch) LOOKING (my state) > 2018-10-22 06:04:51,309 [myid:2] - INFO [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxnFactory@192] - Accepted socket > connection > from /192.72.5.212:38944 > 2018-10-22 06:04:51,309 [myid:2] - WARN [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxn@373] - Exception causing close of > session 0x0 due to java.io.IOException: ZooKeeperServer not running > 2018-10-22 06:04:51,309 [myid:2] - INFO [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxn@1044] - Closed socket connection for > client /192.72.5.212:38944 (no session established for client) > 2018-10-22 06:04:51,356 [myid:2] - INFO [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxnFactory@192] - Accepted socket > connection > from /192.72.7.201:59310 > 2018-10-22 06:04:51,356 [myid:2] - WARN [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxn@373] - Exception causing close of > session 0x0 due to java.io.IOException: ZooKeeperServer not running > 2018-10-22 06:04:51,356 [myid:2] - INFO [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxn@1044] - Closed socket connection for > client /192.72.7.201:59310 (no session established for client) > 2018-10-22 06:04:51,402 [myid:2] - INFO [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxnFactory@192] - Accepted socket > connection > from /192.3.101.219:56302 > 2018-10-22 06:04:51,402 [myid:2] - WARN [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxn@373] - Exception causing close of > session 0x0 due to java.io.IOException: ZooKeeperServer not running > 2018-10-22 06:04:51,402 [myid:2] - INFO [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxn@1044] - Closed socket connection for > client /192.3.101.219:56302 (no session established for client) > 2018-10-22 06:04:51,467 [myid:2] - INFO [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxnFactory@192] - Accepted socket > connection > from /192.72.7.205:46694 > 2018-10-22 06:04:51,468 [myid:2] - WARN [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxn@373] - Exception causing close of > session 0x0 due to java.io.IOException: ZooKeeperServer not running > 2018-10-22 06:04:51,468 [myid:2] - INFO [NIOServerCxn.Factory: > 0.0.0.0/0.0.0.0:2182:NIOServerCnxn@1044] - Closed socket connection for > client /192.72.7.205:46694 (no session established for client) > 2018-10-22 06:04:51,476 [myid:2] - INFO > [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:2182:QuorumPeer@935] - FOLLOWING > 2018-10-22 06:04:51,476 [myid:2] - INFO > [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:2182:ZooKeeperServer@173] - Created > server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 > datadir /app/zookeeper-3.4.10/log/version-2 snapdir > /app/zookeeper-3.4.10/data/version-2 > 2018-10-22 06:04:51,476 [myid:2] - INFO > [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:2182:Follower@64] - FOLLOWING - LEADER > ELECTION TOOK - 1008 > 2018-10-22 06:04:51,477 [myid:2] - INFO > [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:2182:QuorumPeer$QuorumServer@167] - > Resolved hostname: srch0120.whc.dc02.us.adp to address: srch0120/ > 192.3.35.243 > > > solr.log > 2018-10-22 10:02:21.466 WARN (main-SendThread(srch0118:2182)) [ ] > o.a.z.ClientCnxn Client session timed out, have not heard from server in > 26675ms for sessionid 0x5665c67cb0d000b > 2018-10-22 10:02:48.891 WARN (main-SendThread(srch0119:2182)) [ ] > o.a.z.ClientCnxn Client session timed out, have not heard from server in > 26667ms for sessionid 0x5665c67cb0d000b > 2018-10-22 10:02:57.720 WARN (main-SendThread(srch0117:2182)) [ ] > o.a.z.ClientCnxn Client session timed out, have not heard from server in > 8007ms for sessionid 0x5665c67cb0d000b > 2018-10-22 10:03:06.776 WARN (main-SendThread(srch0120:2182)) [ ] > o.a.z.ClientCnxn Client session timed out, have not heard from server in > 8006ms for sessionid 0x5665c67cb0d000b > 2018-10-22 10:03:15.734 WARN (main-SendThread(srch0121:2182)) [ ] > o.a.z.ClientCnxn Client session timed out, have not heard from server in > 8004ms for sessionid 0x5665c67cb0d000b > 2018-10-22 10:03:24.568 WARN (main-SendThread(srch0118:2182)) [ ] > o.a.z.ClientCnxn Client session timed out, have not heard from server in > 8003ms for sessionid 0x5665c67cb0d000b > 2018-10-22 10:03:33.844 WARN (main-SendThread(srch0119:2182)) [ ] > o.a.z.ClientCnxn Client session timed out, have not heard from server in > 8001ms for sessionid 0x5665c67cb0d000b > 2018-10-22 10:03:42.377 WARN (main-SendThread(srch0117:2182)) [ ] > o.a.z.ClientCnxn Client session timed out, have not heard from server in > 8008ms for sessionid 0x5665c67cb0d000b > 2018-10-22 10:03:51.138 WARN (main-SendThread(srch0120:2182)) [ ] > o.a.z.ClientCnxn Client session timed out, have not heard from server in > 8004ms for sessionid 0x5665c67cb0d000b > 2018-10-22 10:04:10.229 WARN (main-SendThread(srch0119:2182)) [ ] > o.a.z.ClientCnxn Client session timed out, have not heard from server in > 8008ms for sessionid 0x5665c67cb0d000b > 2018-10-22 10:04:20.669 WARN (main-SendThread(srch0119:2182)) [ ] > o.a.z.ClientCnxn Client session timed out, have not heard from server in > 9272ms for sessionid 0x5665c67cb0d000b > 2018-10-22 10:04:34.076 WARN (main-SendThread(srch0119:2182)) [ ] > o.a.z.ClientCnxn Client session timed out, have not heard from server in > 9873ms for sessionid 0x5665c67cb0d000b > --000000000000e7c1880578e48e55--