search

owncloud / ocis

:atom_symbol: ownCloud Infinite Scale Stack
https://doc.owncloud.com/ocis/next/
Apache License 2.0
1.36k stars 179 forks source link

JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > xxxxx' #7948

Closed wkloucek closed 8 months ago

wkloucek commented 9 months ago

Describe the bug

NATS is logging a lot. Probably triggered by oCIS.

Steps to reproduce

  1. use natsjs service registry

Expected behavior

everything is working fine

Actual behavior

everything is working fine from a functional perspective

Only NATS is reporting a lot of messages like:

nats-2 nats [6] 2023/12/12 16:48:23.409379 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > nt3kiPkN'
nats-2 nats [6] 2023/12/12 16:48:23.420655 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > 6KsWh9tO'
nats-2 nats [6] 2023/12/12 16:48:23.971032 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > YoegYx6u'
nats-2 nats [6] 2023/12/12 16:48:23.986501 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > Wpcrkxiv'
nats-2 nats [6] 2023/12/12 16:48:27.458323 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > R2Ggf5ff'
nats-2 nats [6] 2023/12/12 16:48:27.471388 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > nM11H0hJ'
nats-2 nats [6] 2023/12/12 16:48:28.660625 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > E3voOSnX'
nats-2 nats [6] 2023/12/12 16:48:28.677238 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > 1GtjBV3z'
nats-2 nats [6] 2023/12/12 16:48:30.288861 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > sHsO9CxQ'
nats-2 nats [6] 2023/12/12 16:48:30.301413 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > AStJ1viU'
nats-2 nats [6] 2023/12/12 16:48:30.316610 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > qCYzBzkX'
nats-2 nats [6] 2023/12/12 16:48:30.328864 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > TeOqdfrN'
nats-2 nats [6] 2023/12/12 16:48:30.334796 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > uyoKeq5w'
nats-2 nats [6] 2023/12/12 16:48:30.363024 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > WVemVHXN'
nats-2 nats [6] 2023/12/12 16:48:30.371802 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > yxsYDNwZ'
nats-2 nats [6] 2023/12/12 16:48:30.381370 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > NR9fMAGY'
nats-2 nats [6] 2023/12/12 16:48:30.390908 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > 3naWF43q'
nats-2 nats [6] 2023/12/12 16:48:30.987854 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > Gx4Xx4Fr'
nats-2 nats [6] 2023/12/12 16:48:31.016388 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > Xh5u986M'
nats-2 nats [6] 2023/12/12 16:48:31.025810 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > 77LP4ARr'
nats-2 nats [6] 2023/12/12 16:48:31.565382 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > O0K9n3zO'
nats-2 nats [6] 2023/12/12 16:48:31.659048 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > jRU3kkNH'
nats-2 nats [6] 2023/12/12 16:48:31.663654 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > MyR8tHQF'
nats-2 nats [6] 2023/12/12 16:48:31.680130 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > XQWaqQvo'
nats-2 nats [6] 2023/12/12 16:48:31.713719 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > lOWfidN9'
nats-2 nats [6] 2023/12/12 16:48:31.726103 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > tOCQrv5i'
nats-2 nats [6] 2023/12/12 16:48:31.804391 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > l9D0uHEu'
nats-2 nats [6] 2023/12/12 16:48:35.626334 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > RF2RLCse'
nats-2 nats [6] 2023/12/12 16:48:36.178514 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > r3dcKfee'
nats-2 nats [6] 2023/12/12 16:48:36.186875 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > 3TBUmgTb'
nats-2 nats [6] 2023/12/12 16:48:36.199363 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > SjpU3jsT'
nats-2 nats [6] 2023/12/12 16:48:36.328820 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > 78GegLu3'
nats-2 nats [6] 2023/12/12 16:48:36.336208 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > jO1oDEBu'
nats-2 nats [6] 2023/12/12 16:48:36.782571 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > 15OPtijX'
nats-2 nats [6] 2023/12/12 16:48:36.892983 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > hc5qEw05'
nats-2 nats [6] 2023/12/12 16:48:36.999554 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > ZsQoV2Ai'
nats-2 nats [6] 2023/12/12 16:48:37.019511 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > 92zPIaUA'
nats-2 nats [6] 2023/12/12 16:48:37.032484 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > sNz3cTTJ'
nats-2 nats [6] 2023/12/12 16:48:39.091803 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > dzHu289o'
nats-2 nats [6] 2023/12/12 16:48:39.098321 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > Gm1sgvTi'
nats-2 nats [6] 2023/12/12 16:48:39.105867 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > 4Op2iMe8'
nats-2 nats [6] 2023/12/12 16:48:39.112784 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > ewfehcaV'
nats-2 nats [6] 2023/12/12 16:48:39.241498 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > HxZOIK9C'
nats-2 nats [6] 2023/12/12 16:48:39.870124 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > Wylr43lz'
nats-2 nats [6] 2023/12/12 16:48:39.870709 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > i6L3FzIV'
nats-2 nats [6] 2023/12/12 16:48:39.876394 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > qeSbY9AN'
nats-2 nats [6] 2023/12/12 16:48:39.882859 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > GKK7XGxC'
nats-2 nats [6] 2023/12/12 16:48:46.149081 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > dwQqqmXK'
nats-2 nats [6] 2023/12/12 16:48:46.368415 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > 70IzfMlP'
nats-2 nats [6] 2023/12/12 16:48:46.388592 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > uTQoD3Ij'
nats-2 nats [6] 2023/12/12 16:48:46.396704 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > P9o7AiWZ'
nats-2 nats [6] 2023/12/12 16:48:46.404429 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > cNk4JJd9'
nats-2 nats [6] 2023/12/12 16:48:46.409541 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > u7ebRQUC'
nats-2 nats [6] 2023/12/12 16:48:46.722878 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > c3D1A3yY'
nats-2 nats [6] 2023/12/12 16:48:47.813355 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > 8ALEfYVx'
nats-2 nats [6] 2023/12/12 16:48:47.981461 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > 32xccKbi'
nats-2 nats [6] 2023/12/12 16:48:47.991227 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > Zlro7feJ'
nats-2 nats [6] 2023/12/12 16:48:52.506623 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > NxPVfXaG'
nats-2 nats [6] 2023/12/12 16:48:53.084278 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > uZutSbUE'
nats-2 nats [6] 2023/12/12 16:48:53.093284 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > t10VQyqZ'
nats-2 nats [6] 2023/12/12 16:48:53.140436 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > 1olQpt4O'
nats-2 nats [6] 2023/12/12 16:48:53.791561 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > wHGw0D66'
nats-2 nats [6] 2023/12/12 16:48:54.490311 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > QVoOvxk3'
nats-2 nats [6] 2023/12/12 16:48:54.659990 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > bNUEIC4G'
nats-2 nats [6] 2023/12/12 16:49:00.353368 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > QkughTzU'
nats-2 nats [6] 2023/12/12 16:49:00.359665 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > koCN5rys'
nats-2 nats [6] 2023/12/12 16:49:00.365465 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > XqZBQ0Z5'
nats-2 nats [6] 2023/12/12 16:49:00.373784 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > LGm3mj6E'
nats-2 nats [6] 2023/12/12 16:49:00.461570 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > D9rarceE'
nats-2 nats [6] 2023/12/12 16:49:06.123037 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > DEEGPUQZ'
nats-2 nats [6] 2023/12/12 16:49:06.207783 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > 0oBsbf4X'
nats-2 nats [6] 2023/12/12 16:49:07.111674 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > NOmIrxWO'
nats-2 nats [6] 2023/12/12 16:49:07.121624 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > C8Kz7CfO'
nats-2 nats [6] 2023/12/12 16:49:07.130088 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > cERNArNT'
nats-2 nats [6] 2023/12/12 16:49:07.138235 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > IiF7vyBN'
nats-2 nats [6] 2023/12/12 16:49:07.158902 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > zQOQwVmf'
nats-2 nats [6] 2023/12/12 16:49:07.170829 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > PZY5nr7p'
nats-2 nats [6] 2023/12/12 16:49:07.455605 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > bJCKgk60'
nats-2 nats [6] 2023/12/12 16:49:07.461559 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > bvnT9OEO'
nats-2 nats [6] 2023/12/12 16:49:08.185260 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > hsTsCgON'
nats-2 nats [6] 2023/12/12 16:49:08.199453 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > b4Y1w5Hf'
nats-2 nats [6] 2023/12/12 16:49:08.702581 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > lQKAqZp3'
nats-2 nats [6] 2023/12/12 16:49:08.709326 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > N3Ujhy3v'
nats-2 nats [6] 2023/12/12 16:49:08.718193 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > FrP8tVKK'
nats-2 nats [6] 2023/12/12 16:49:09.101236 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > 1A06RCtZ'
nats-2 nats [6] 2023/12/12 16:49:09.128356 [INF] JetStream cluster new consumer leader for '$OCIS > OBJ_service-registry > 3HOtCoSk'

Setup

Eg. use this example https://github.com/owncloud/ocis-charts/tree/next/deployments/ocis-nats from the next branch with oCIS 5.0.0-alpha.6

micbar commented 9 months ago

@kobergj @2403905 We need to take a look.

micbar commented 9 months ago

raising to p2 because of critical path for usable nats.

dragonchaser commented 8 months ago

After investigation, it seems like the cluster is switching the leader on a regular basis. It seems like the output can not be suppressed (unless redirecting it away from stderr to a file (which is contra productive in our scenario)). I am currently trying to figure out if it is possible to give each node a priority to prevent switching the leader.

wkloucek commented 8 months ago

cluster is switching the leader on a regular basis.

new consumer leader who decides who the consumer leader is?

Please note that it's on a sub-second basis. That doesn't sound healthy for a leader switch

From what I understand this is not about the nats jetstream node stream leader change. It can be easily ruled out by having a stream with replica set to 1 (because there is only one node that can be leader, ever)

dragonchaser commented 8 months ago

Probably :D might have to do with the quorum, https://docs.nats.io/running-a-nats-service/configuration/clustering/jetstream_clustering#the-quorum I am currently experimenting with the scaling to see if the issue persists with a higher number of nodes.

dragonchaser commented 8 months ago

Ok that does not seem to be the issue.

wkloucek commented 8 months ago

Did you look at the NATS source code to see where this log originates?

wkloucek commented 8 months ago

I found only that one: https://github.com/nats-io/nats-server/blob/67d41da49bb24b56705dc84bf06e1fac887d1c77/server/jetstream_cluster.go#L4995C31-L4995C31

dragonchaser commented 8 months ago

haven't digged into the code yet, what I found is that: https://github.com/nats-io/nats-server/issues/4480

dragonchaser commented 8 months ago

@wkloucek fixed with move to nats key-value store in 5.0.0-rc2

dragonchaser commented 8 months ago

@wkloucek can we close this?

wkloucek commented 8 months ago

@wkloucek can we close this?

Didn't have any time yet to look at it / deploy rc.2

dragonchaser commented 8 months ago

@wkloucek can we close this?

Didn't have any time yet to look at it / deploy rc.2

Ok, when it works, just close it. If there are still issues, let me know.

wkloucek commented 8 months ago

Please close it when you feel comfortable. I can always reopen or create another one