{"action":"created","issue":{"url":"https://api.github.com/repos/akka/akka/issues/25639","repository_url":"https://api.github.com/repos/akka/akka","labels_url":"https://api.github.com/repos/akka/akka/issues/25639/labels{/name}","comments_url":"https://api.github.com/repos/akka/akka/issues/25639/comments","events_url":"https://api.github.com/repos/akka/akka/issues/25639/events","html_url":"https://github.com/akka/akka/issues/25639","id":361300724,"node_id":"MDU6SXNzdWUzNjEzMDA3MjQ=","number":25639,"title":"ClusterSingletonManager does not handle event TakeOver in state Younger","user":{"login":"412b","id":12436202,"node_id":"MDQ6VXNlcjEyNDM2MjAy","avatar_url":"https://avatars3.githubusercontent.com/u/12436202?v=4","gravatar_id":"","url":"https://api.github.com/users/412b","html_url":"https://github.com/412b","followers_url":"https://api.github.com/users/412b/followers","following_url":"https://api.github.com/users/412b/following{/other_user}","gists_url":"https://api.github.com/users/412b/gists{/gist_id}","starred_url":"https://api.github.com/users/412b/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/412b/subscriptions","organizations_url":"https://api.github.com/users/412b/orgs","repos_url":"https://api.github.com/users/412b/repos","events_url":"https://api.github.com/users/412b/events{/privacy}","received_events_url":"https://api.github.com/users/412b/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":0,"created_at":"2018-09-18T13:19:12Z","updated_at":"2018-09-24T07:28:56Z","closed_at":null,"author_association":"CONTRIBUTOR","body":"**What happens**\r\nespecially when using `CoordinatedShutdown` I've observed a lot of `Ignoring TakeOver request in [Younger] from`, when oldest is shutting down, which means that handover takes way more time than it should. the reason is that new singleton holder gets aware of the oldest shutting down later than oldest has started the handover.\r\n\r\n**What happens (detailed)** \r\nstarting up:\r\n> [INFO] [09/18/2018 15:38:56.744] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-19] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553/user/echo] Singleton manager starting singleton actor [akka://ClusterSingletonRestartSpec/user/echo/singleton]\r\n> [INFO] [09/18/2018 15:38:56.745] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-19] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553/user/echo] ClusterSingletonManager state change [Start -> Oldest]\r\n> [INFO] [09/18/2018 15:38:57.584] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-15] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45471/user/echo] ClusterSingletonManager state change [Start -> Younger]\r\n> [INFO] [09/18/2018 15:38:57.618] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-15] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45471/user/proxy2] Singleton identified at [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553/user/echo/singleton]\r\n\r\nshutting down:\r\n> [INFO] [09/18/2018 15:38:58.532] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-18] [akka.cluster.Cluster(akka://ClusterSingletonRestartSpec)] Cluster Node [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553] - Cluster Node [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553] dc [default] is no longer the leader\r\n> [INFO] [09/18/2018 15:38:58.566] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-15] [akka.cluster.Cluster(akka://ClusterSingletonRestartSpec)] Cluster Node [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45471] - Cluster Node [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45471] dc [default] is the new leader\r\n> [INFO] [09/18/2018 15:38:58.637] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-19] [akka.cluster.Cluster(akka://ClusterSingletonRestartSpec)] Cluster Node [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553] - Marked address [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553] as [Leaving]\r\n> [INFO] [09/18/2018 15:38:58.644] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-15] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553/user/echo] Exited [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553]\r\n\r\nstart of the handover:\r\n> [INFO] [09/18/2018 15:38:58.647] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-17] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553/user/echo] Oldest observed OldestChanged: [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553 -> Some(akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45471)]\r\n> [INFO] [09/18/2018 15:38:58.649] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-17] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553/user/echo] ClusterSingletonManager state change [Oldest -> WasOldest]\r\n\r\nnew singleton holder haven't yet seen change of the oldest:\r\n> [INFO] [09/18/2018 15:38:58.651] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-16] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45471/user/echo] Ignoring TakeOver request in [Younger] from [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553].\r\n> [INFO] [09/18/2018 15:38:59.567] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-16] [akka.cluster.Cluster(akka://ClusterSingletonRestartSpec)] Cluster Node [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45471] - Leader is moving node [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553] to [Exiting]\r\n\r\nand now new holder is aware:\r\n> [INFO] [09/18/2018 15:38:59.573] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-3] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45471/user/echo] Younger observed OldestChanged: [Some(akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553) -> myself]\r\n> [INFO] [09/18/2018 15:38:59.575] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-3] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45471/user/echo] ClusterSingletonManager state change [Younger -> BecomingOldest]\r\n> [INFO] [09/18/2018 15:38:59.577] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-15] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553/user/echo] ClusterSingletonManager state change [WasOldest -> HandingOver]\r\n> [INFO] [09/18/2018 15:38:59.578] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-15] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553/user/echo] Singleton terminated, hand-over done [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553 -> Some(akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45471)]\r\n> [INFO] [09/18/2018 15:38:59.579] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-15] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553/user/echo] ClusterSingletonManager state change [HandingOver -> End]\r\n> [INFO] [09/18/2018 15:38:59.579] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-18] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45471/user/echo] Hand-over in progress at [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553]\r\n> [INFO] [09/18/2018 15:38:59.581] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-18] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45471/user/echo] Singleton manager starting singleton actor [akka://ClusterSingletonRestartSpec/user/echo/singleton]\r\n> [INFO] [09/18/2018 15:38:59.581] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-18] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45471/user/echo] ClusterSingletonManager state change [BecomingOldest -> Oldest]\r\n> [INFO] [09/18/2018 15:39:00.541] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-19] [akka.cluster.Cluster(akka://ClusterSingletonRestartSpec)] Cluster Node [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553] - Exiting, starting coordinated shutdown\r\n> [INFO] [09/18/2018 15:39:00.542] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-18] [akka.cluster.Cluster(akka://ClusterSingletonRestartSpec)] Cluster Node [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553] - Exiting completed\r\n> [INFO] [09/18/2018 15:39:00.546] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-18] [akka.cluster.Cluster(akka://ClusterSingletonRestartSpec)] Cluster Node [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553] - Shutting down...\r\n> [INFO] [09/18/2018 15:39:00.550] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-18] [akka.cluster.Cluster(akka://ClusterSingletonRestartSpec)] Cluster Node [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553] - Successfully shut down\r\n> [INFO] [09/18/2018 15:39:00.551] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-18] [akka.cluster.Cluster(akka://ClusterSingletonRestartSpec)] Cluster Node [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45471] - Exiting confirmed [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553]\r\n> [INFO] [09/18/2018 15:39:00.558] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-16] [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553/user/echo] Self removed, stopping ClusterSingletonManager\r\n> [INFO] [09/18/2018 15:39:00.566] [ClusterSingletonRestartSpec-akka.actor.default-dispatcher-19] [akka.cluster.Cluster(akka://ClusterSingletonRestartSpec)] Cluster Node [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45471] - Leader is removing confirmed Exiting node [akka.tcp://ClusterSingletonRestartSpec@127.0.0.1:45553]\r\n\r\nthe problem here is that in bigger real-life cluster (like we have) handover happens many `TakeOverFromMe` later, it can even give up trying.\r\n\r\nthe fix can be pretty trivial, I can submit PR right away, the main question is if going from `Younger` to `BecomingOldest` without seeing `OldestChanged` is acceptable. WDYT?"},"comment":{"url":"https://api.github.com/repos/akka/akka/issues/comments/423894296","html_url":"https://github.com/akka/akka/issues/25639#issuecomment-423894296","issue_url":"https://api.github.com/repos/akka/akka/issues/25639","id":423894296,"node_id":"MDEyOklzc3VlQ29tbWVudDQyMzg5NDI5Ng==","user":{"login":"patriknw","id":336161,"node_id":"MDQ6VXNlcjMzNjE2MQ==","avatar_url":"https://avatars3.githubusercontent.com/u/336161?v=4","gravatar_id":"","url":"https://api.github.com/users/patriknw","html_url":"https://github.com/patriknw","followers_url":"https://api.github.com/users/patriknw/followers","following_url":"https://api.github.com/users/patriknw/following{/other_user}","gists_url":"https://api.github.com/users/patriknw/gists{/gist_id}","starred_url":"https://api.github.com/users/patriknw/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/patriknw/subscriptions","organizations_url":"https://api.github.com/users/patriknw/orgs","repos_url":"https://api.github.com/users/patriknw/repos","events_url":"https://api.github.com/users/patriknw/events{/privacy}","received_events_url":"https://api.github.com/users/patriknw/received_events","type":"User","site_admin":false},"created_at":"2018-09-24T07:28:56Z","updated_at":"2018-09-24T07:28:56Z","author_association":"MEMBER","body":"Currently we trigger the `OldestChanged` by the `MemberExited` event. The problem I can see with triggering the transition earlier is that there might be a risk that the leaving process is not completed in time (e.g. unreachable nodes halting it) and then new singleton is started up too early, via `ClusterSingletonManagerIsStuck`.\r\n\r\nI think changing this logic is far from a trivial change. I agree that we have a successful hand-over exchange we should be able to use that as evidence for that the old singleton was stopped and ok to start new. The problems are around all failure cases.\r\n\r\nJust curious, how many seconds delay are we talking about? What cluster size? Have you tried to reduce the gossip interval?"}}
{"actor":{"display_login":"patriknw"}}