You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@zookeeper.apache.org by Andor Molnar <an...@apache.org> on 2020/01/06 13:53:19 UTC
Re: Notification messages in log
Hi Ram,
I haven’t seen such behaviour, but it’s hard to say what has been changed in leader election between these 2 version. Have you finished your upgrading? Are messages still emitted by the leader?
Andor
> On 2019. Dec 12., at 18:12, rammohan ganapavarapu <ra...@gmail.com> wrote:
>
> Any thoughts?
>
> On Wed, Dec 11, 2019 at 7:48 PM rammohan ganapavarapu <
> rammohanganap@gmail.com> wrote:
>
>> 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 <eo...@gmail.com>
>> 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 <ra...@gmail.com>
>>> 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
>>>>
>>>
>>