From user-return-12407-archive-asf-public=cust-asf.ponee.io@zookeeper.apache.org Thu Dec 12 03:49:47 2019 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 [207.244.88.153]) by mx-eu-01.ponee.io (Postfix) with SMTP id 160D4180638 for ; Thu, 12 Dec 2019 04:49:46 +0100 (CET) Received: (qmail 1460 invoked by uid 500); 12 Dec 2019 03:49:45 -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 1448 invoked by uid 99); 12 Dec 2019 03:49:45 -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; Thu, 12 Dec 2019 03:49:45 +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 862F2C02C9 for ; Thu, 12 Dec 2019 03:49:44 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd1-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: 0 X-Spam-Level: X-Spam-Status: No, score=0 tagged_above=-999 required=6.31 tests=[DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, DKIM_VALID_EF=-0.1, HTML_MESSAGE=0.2, SPF_HELO_NONE=0.001, SPF_PASS=-0.001] autolearn=disabled Authentication-Results: spamd1-us-west.apache.org (amavisd-new); dkim=pass (2048-bit key) header.d=gmail.com Received: from mx1-he-de.apache.org ([10.40.0.8]) by localhost (spamd1-us-west.apache.org [10.40.0.7]) (amavisd-new, port 10024) with ESMTP id AN2zns7MIC0p for ; Thu, 12 Dec 2019 03:49:39 +0000 (UTC) Received-SPF: Pass (mailfrom) identity=mailfrom; client-ip=2607:f8b0:4864:20::f30; helo=mail-qv1-xf30.google.com; envelope-from=rammohanganap@gmail.com; receiver= Received: from mail-qv1-xf30.google.com (mail-qv1-xf30.google.com [IPv6:2607:f8b0:4864:20::f30]) by mx1-he-de.apache.org (ASF Mail Server at mx1-he-de.apache.org) with ESMTPS id E82AC7DDAC for ; Thu, 12 Dec 2019 03:49:38 +0000 (UTC) Received: by mail-qv1-xf30.google.com with SMTP id n8so389163qvg.11 for ; Wed, 11 Dec 2019 19:49:38 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:references:in-reply-to:from:date:message-id:subject:to; bh=C1E+N/I85CTz7M2vvaw7aQQ6mv1Cv8sKm4EUBGClb2A=; b=vQHp/97ihoNy4IE469Y4hdWcWrVre2AJInvoP8/S41PvLo1e2VhvpyegyWNl41NbqQ 2twykFUPI3L7SfyrRf5JXGADrDsFgI+3rxdsLQ7p8eu0dnfM7x13PYkn+mOFkN3+lYyR S/fw45Vr2ob8ygn2sPj6fz7aybtDKzw1RdxwJ3psaI5h+F4HBtYmu8LC3st39ITV4ZeD WTZoBPRC3kNW1uH7AiNn1jOzqr3WzMj/a8uAQqzr7nCvoD/cjURQWhGoQMXRx2BzrVRX 5BB8096rg7YuLLiDUKuklrGfn6qQFvOMEHH456DWaEKORDmOK0t1Q30NhzemowB6+iDl Yt/g== 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=C1E+N/I85CTz7M2vvaw7aQQ6mv1Cv8sKm4EUBGClb2A=; b=LjonPwI8ppi0/oqA4YaYLbzTsMOGaSyn+JK6cPFh3iL7SeTXedsubEPOXwX2yiLaFy K/B6x891A0Tn/a7xtzQYR4bcZ6X8AI+IPJUIwCb+uLnzlQiNJzxnE2zDchNBT4LMWnhc 4w5sGVKMDbsrRZgaEPoKxooGcSun78jXc4ViRQvW5hglJsIgJApkTKYFFpMWJbFB6NQG HnVcV3DGp4jasXeOK2iFQoFMycebsiFoJmwEo/qa952OeE0Oh0A7rzmm9adBwRrHaHsT TriMB/MsMk4CgARxKSEgYDkbGBjGN51kyAxGgoHVZ/8/OXhojKZgO/2XbjwWvojPJ1Nm QD1g== X-Gm-Message-State: APjAAAVD407p1R/SnaYME7Of60bZg7n4uonTp0O/SOrKi/t0Rs2FaYe1 iwf06mrlYDkYgTX/X79+v48KTOSf9McLwjCxNppf8Ipf+GQ= X-Google-Smtp-Source: APXvYqy69a1D8pTjfuib/LnO9ed3Km43lXIxqui6jmi++/2kGaThZhgK/iXy+Tz5sOuwozIBvrl5BRLt2fOmhayMCP8= X-Received: by 2002:ad4:4b21:: with SMTP id s1mr6357780qvw.34.1576122571586; Wed, 11 Dec 2019 19:49:31 -0800 (PST) MIME-Version: 1.0 References: In-Reply-To: From: rammohan ganapavarapu Date: Wed, 11 Dec 2019 19:48:55 -0800 Message-ID: Subject: Re: Notification messages in log To: user@zookeeper.apache.org Content-Type: multipart/alternative; boundary="00000000000000831c059979a264" --00000000000000831c059979a264 Content-Type: text/plain; charset="UTF-8" Hi Enrico, Since i have log rotation, i am not worried about size but i see ~14 such messages for a second which seems unusual for me. grep "Notification: 0 (message format version)" zookeeper.log|awk '{print $1" "$2}'|awk -F "," '{print $1}'|sort |uniq -c 9 2019-12-12 03:11:14 14 2019-12-12 03:11:15 13 2019-12-12 03:11:16 14 2019-12-12 03:11:17 14 2019-12-12 03:11:18 14 2019-12-12 03:11:19 14 2019-12-12 03:11:20 13 2019-12-12 03:11:21 14 2019-12-12 03:11:22 14 2019-12-12 03:11:23 14 2019-12-12 03:11:24 14 2019-12-12 03:11:25 13 2019-12-12 03:11:26 14 2019-12-12 03:11:27 14 2019-12-12 03:11:28 14 2019-12-12 03:11:29 14 2019-12-12 03:11:30 13 2019-12-12 03:11:31 14 2019-12-12 03:11:32 14 2019-12-12 03:11:33 14 2019-12-12 03:11:34 14 2019-12-12 03:11:35 FYI: I am in upgrade processes where leader is still on 3.4.5 version and this observer is 3.4.14 version does it cause such behavior? Thanks, Ram On Wed, Dec 11, 2019 at 3:22 PM Enrico Olivelli wrote: > Ram, > How many GB of logs do you have? > Those messages are not scary but they shouldn't be so many. > > Enrico > > > Il mer 11 dic 2019, 23:16 rammohan ganapavarapu > ha scritto: > > > After 3.4.14 version upgrade i am seeing continuous messages as bellow in > > logs, is it normal? > > > > > > 2019-12-11 22:12:44,036 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:44,108 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:44,180 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:44,252 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:44,323 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:44,395 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:44,467 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:44,538 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:44,610 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:44,682 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:44,754 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:44,825 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:44,897 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:44,969 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:45,041 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:45,112 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:45,184 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > 2019-12-11 22:12:45,256 [myid:104] - INFO > > [WorkerReceiver[myid=104]:FastLeaderElection@595] - Notification: 0 > > (message format version), 100 (n.leader), 0x0 (n.zxid), 0x1 (n.round), > > LOOKING (n.state), 100 (n.sid), 0x0 (n.peerEpoch) OBSERVING (my state) > > > > > > But status looks ok though. > > > > echo mntr |nc localhost 2181 > > zk_version 3.4.14-4c25d480e66aadd371de8bd2fd8da255ac140bcf, built on > > 03/06/2019 16:18 GMT > > zk_avg_latency 75 > > zk_max_latency 76 > > zk_min_latency 75 > > zk_packets_received 907 > > zk_packets_sent 906 > > zk_num_alive_connections 1 > > zk_outstanding_requests 0 > > zk_server_state observer > > zk_znode_count 12168170 > > zk_watch_count 0 > > zk_ephemerals_count 0 > > zk_approximate_data_size 1592831251 > > zk_open_file_descriptor_count 40 > > zk_max_file_descriptor_count 100000 > > zk_fsync_threshold_exceed_count 0 > > > > Thanks, > > Ram > > > --00000000000000831c059979a264--