Cluster join failing using kubernetes-api discovery

jackpines · October 24, 2019, 10:46pm

I’ve done some due diligence, even digging into Akka code, but can’t figure out why my nodes are being discovered via kubernetes-api, one node self-joins, promotes to leader, but the other fails to join the cluster due to the leader being unable to resolve the requester’s address. I’ll post the application config and logs separately.

This is a 2-node (for now) Akka Cluster using Akka Management and Akka Discovery using kubernetes-api to discovery the nodes in 2 pods. I’m using a custom label selector of “application=vcsvc,environment=multibox,akka-cluster=vcsvc”.

Can anyone help identify where I’ve misconfigured things?

jackpines · October 24, 2019, 10:48pm

Snippet from application.conf:

akka: {
  management: {
    cluster: {
      bootstrap: {
        # optionally prohibits creating a new cluster, forcing a member to wait until cluster is formed
        new-cluster-enabled: on

        contact-point-discovery: {
          # pick the discovery method you'd like to use:
          discovery-method: "kubernetes-api"

          # the exact number of nodes for the initial startup of the cluster
          required-contact-point-nr: 2
        }
      }

      health-check: {
        # Ready health check returns 200 when cluster membership is in the following states.
        # Intended to be used to indicate this node is ready for user traffic so Up/WeaklyUp
        # Valid values: "Joining", "WeaklyUp", "Up", "Leaving", "Exiting", "Down", "Removed"
        ready-states: ["Up", "WeaklyUp"]

        readiness-path: "health/ready"
        liveness-path: "health/alive"
      }
    }
  }

  discovery: {
    # Set the following in your application.conf if you want to use this discovery mechanism:
    method: kubernetes-api

    kubernetes-api: {
      class = akka.discovery.kubernetes.KubernetesApiServiceDiscovery

      # API server, cert and token information. Currently these are present on K8s versions: 1.6, 1.7, 1.8, and perhaps more
      api-ca-path = "/var/run/secrets/kubernetes.io/serviceaccount/ca.crt"
      api-token-path = "/var/run/secrets/kubernetes.io/serviceaccount/token"
      api-service-host-env-name = "KUBERNETES_SERVICE_HOST"
      api-service-port-env-name = "KUBERNETES_SERVICE_PORT"

      # Namespace to query for pods.
      #
      # Set this value to a specific string to override discovering the namespace using pod-namespace-path.
      pod-namespace = ${com.apptio.vcsvc.namespace}

      # Selector value to query pod API with.
      # `%s` will be replaced with the configured effective name, which defaults to the actor system name
      pod-label-selector: "application="${com.apptio.vcsvc.namespace}",environment="${com.apptio.vcsvc.environment}",akka-cluster="${com.apptio.vcsvc.cluster.name}
    }
  }
}

I’ll add more upon request. I’m questioning the method line and the api- lines as the behavior didn’t change when I added those.

jackpines · October 24, 2019, 11:25pm

Worker (192.168.186.11) seems to have won the race to leader so here are it’s logs starting shortly before it got there and stopping when Orchestrator (192.168.42.176) fails to join the cluster:

[DEBUG] [10/24/2019 23:03:58.328] [vcsvc-akka.actor.default-dispatcher-8] [TimerScheduler(akka://vcsvc)] Start timer [probing-key] with generation [5]
[INFO] [10/24/2019 23:03:58.328] [vcsvc-akka.actor.default-dispatcher-3] [akka://vcsvc@192.168.186.11:2551/system/bootstrapCoordinator] Contact point [akka://vcsvc@192.168.186.11:2551] returned [0] seed-nodes []
[INFO] [10/24/2019 23:03:58.577] [vcsvc-akka.actor.default-dispatcher-21] [HttpClusterBootstrapRoutes(akka://vcsvc)] Bootstrap request from 192.168.42.176:59750: Contact Point returning 0 seed-nodes ([TreeSet()])
[INFO] [10/24/2019 23:03:59.115] [vcsvc-akka.actor.default-dispatcher-23] [akka://vcsvc@192.168.186.11:2551/system/bootstrapCoordinator] Initiating new cluster, self-joining [akka://vcsvc@192.168.186.11:2551]. Other nodes are expected to locate this cluster via continued contact-point probing.
[INFO] [10/24/2019 23:03:59.116] [vcsvc-akka.actor.default-dispatcher-2] [akka://vcsvc/deadLetters] Message [akka.management.cluster.bootstrap.internal.BootstrapCoordinator$Protocol$BootstrappingCompleted$] from Actor[akka://vcsvc/system/bootstrapCoordinator#-121996272] to Actor[akka://vcsvc/deadLetters] was not delivered. [1] dead letters encountered. If this is not an expected behavior, then [Actor[akka://vcsvc/deadLetters]] may have terminated unexpectedly, This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
[DEBUG] [10/24/2019 23:03:59.119] [vcsvc-akka.actor.default-dispatcher-4] [TimerScheduler(akka://vcsvc)] Cancel all timers
[DEBUG] [10/24/2019 23:03:59.119] [vcsvc-akka.actor.default-dispatcher-9] [TimerScheduler(akka://vcsvc)] Cancel all timers
[DEBUG] [10/24/2019 23:03:59.121] [vcsvc-akka.actor.default-dispatcher-13] [TimerScheduler(akka://vcsvc)] Cancel all timers
[INFO] [10/24/2019 23:03:59.121] [vcsvc-akka.actor.default-dispatcher-12] [akka://vcsvc/system/bootstrapCoordinator] Message [akka.actor.TimerSchedulerImpl$InfluenceReceiveTimeoutTimerMsg] without sender to Actor[akka://vcsvc/system/bootstrapCoordinator#-121996272] was not delivered. [2] dead letters encountered. If this is not an expected behavior, then [Actor[akka://vcsvc/system/bootstrapCoordinator#-121996272]] may have terminated unexpectedly, This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
[INFO] [10/24/2019 23:03:59.128] [vcsvc-akka.actor.default-dispatcher-22] [akka.cluster.Cluster(akka://vcsvc)] Cluster Node [akka://vcsvc@192.168.186.11:2551] - Node [akka://vcsvc@192.168.186.11:2551] is JOINING itself (with roles [Worker, dc-default]) and forming new cluster
[INFO] [10/24/2019 23:03:59.131] [vcsvc-akka.actor.default-dispatcher-22] [akka.cluster.Cluster(akka://vcsvc)] Cluster Node [akka://vcsvc@192.168.186.11:2551] - is the new leader among reachable nodes (more leaders may exist)
[INFO] [10/24/2019 23:03:59.137] [vcsvc-akka.actor.default-dispatcher-22] [akka.cluster.Cluster(akka://vcsvc)] Cluster Node [akka://vcsvc@192.168.186.11:2551] - Leader is moving node [akka://vcsvc@192.168.186.11:2551] to [Up]
[ INFO] 24-10-19 23:03:59:142 [vcsvc-pinned-dispatcher-11] Worker:219 MemberUp: MemberUp(Member(address = akka://vcsvc@192.168.186.11:2551, status = Up))
[INFO] [10/24/2019 23:03:59.648] [vcsvc-akka.actor.default-dispatcher-2] [HttpClusterBootstrapRoutes(akka://vcsvc)] Bootstrap request from 192.168.42.176:59750: Contact Point returning 1 seed-nodes ([TreeSet(ClusterMember(akka://vcsvc@192.168.186.11:2551,4841541468880616991,Up,Set(Worker, dc-default)))])
[DEBUG] [10/24/2019 23:03:59.769] [vcsvc-akka.actor.default-dispatcher-13] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/0] New connection accepted
[DEBUG] [10/24/2019 23:03:59.780] [vcsvc-akka.actor.default-dispatcher-2] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/0] New connection accepted
[DEBUG] [10/24/2019 23:03:59.786] [vcsvc-akka.remote.default-remote-dispatcher-6] [Decoder(akka://vcsvc)] Decoded message but unable to record hits for compression as no remoteAddress known. No association yet?
[DEBUG] [10/24/2019 23:03:59.786] [vcsvc-akka.remote.default-remote-dispatcher-5] [Decoder(akka://vcsvc)] Decoded message but unable to record hits for compression as no remoteAddress known. No association yet?
[DEBUG] [10/24/2019 23:03:59.788] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.serialization.Serialization(akka://vcsvc)] Using serializer [akka.remote.serialization.ArteryMessageSerializer] for message [akka.remote.artery.OutboundHandshake$HandshakeReq]
[DEBUG] [10/24/2019 23:03:59.801] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.remote.artery.Association(akka://vcsvc)] Starting outbound control stream to [akka://vcsvc@192.168.42.176:2551]
[DEBUG] [10/24/2019 23:03:59.819] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.remote.artery.Association(akka://vcsvc)] Starting outbound message stream to [akka://vcsvc@192.168.42.176:2551]
[DEBUG] [10/24/2019 23:03:59.826] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.serialization.Serialization(akka://vcsvc)] Using serializer [akka.remote.serialization.ArteryMessageSerializer] for message [akka.remote.artery.OutboundHandshake$HandshakeRsp]
[DEBUG] [10/24/2019 23:03:59.842] [vcsvc-akka.actor.default-dispatcher-13] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/10] Resolving 192.168.42.176 before connecting
[DEBUG] [10/24/2019 23:03:59.842] [vcsvc-akka.actor.default-dispatcher-22] [akka://vcsvc@192.168.186.11:2551/system/IO-DNS] Resolution request for 192.168.42.176 from Actor[akka://vcsvc/system/IO-TCP/selectors/$a/10#-150982164]
[DEBUG] [10/24/2019 23:03:59.842] [vcsvc-akka.actor.default-dispatcher-13] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/11] Resolving 192.168.42.176 before connecting
[DEBUG] [10/24/2019 23:03:59.842] [vcsvc-akka.actor.default-dispatcher-22] [akka://vcsvc@192.168.186.11:2551/system/IO-DNS] Resolution request for 192.168.42.176 from Actor[akka://vcsvc/system/IO-TCP/selectors/$a/11#-651344730]
[DEBUG] [10/24/2019 23:03:59.842] [vcsvc-akka.actor.default-dispatcher-22] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/10] Attempting connection to [/192.168.42.176:2551]
[DEBUG] [10/24/2019 23:03:59.843] [vcsvc-akka.actor.default-dispatcher-2] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/11] Attempting connection to [/192.168.42.176:2551]
[DEBUG] [10/24/2019 23:03:59.843] [vcsvc-akka.actor.default-dispatcher-2] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/10] Connection established to [192.168.42.176:2551]
[DEBUG] [10/24/2019 23:03:59.844] [vcsvc-akka.actor.default-dispatcher-2] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/11] Connection established to [192.168.42.176:2551]
[DEBUG] [10/24/2019 23:03:59.878] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.], using deadLetters.
[DEBUG] [10/24/2019 23:03:59.878] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/system/cluste], using deadLetters.
[DEBUG] [10/24/2019 23:03:59.882] [vcsvc-akka.remote.default-remote-dispatcher-5] [InboundActorRefCompression(akka://vcsvc)] Initializing InboundActorRefCompression for originUid [-669718903822771492]
[DEBUG] [10/24/2019 23:03:59.883] [vcsvc-akka.remote.default-remote-dispatcher-5] [InboundManifestCompression(akka://vcsvc)] Initializing InboundManifestCompression for originUid [-669718903822771492]
[INFO] [10/24/2019 23:03:59.889] [vcsvc-akka.actor.default-dispatcher-13] [akka://vcsvc/deadLetters] Message [akka.cluster.InternalClusterAction$InitJoin] without sender to Actor[akka://vcsvc/deadLetters] was not delivered. [3] dead letters encountered. If this is not an expected behavior, then [Actor[akka://vcsvc/deadLetters]] may have terminated unexpectedly, This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
[DEBUG] [10/24/2019 23:04:02.331] [vcsvc-akka.actor.default-dispatcher-23] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[DEBUG] [10/24/2019 23:04:04.763] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.], using deadLetters.
[DEBUG] [10/24/2019 23:04:04.763] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/system/cluste], using deadLetters.
[INFO] [10/24/2019 23:04:04.765] [vcsvc-akka.actor.default-dispatcher-9] [akka://vcsvc/deadLetters] Message [akka.cluster.InternalClusterAction$InitJoin] without sender to Actor[akka://vcsvc/deadLetters] was not delivered. [4] dead letters encountered. If this is not an expected behavior, then [Actor[akka://vcsvc/deadLetters]] may have terminated unexpectedly, This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
[DEBUG] [10/24/2019 23:04:04.913] [vcsvc-akka.actor.default-dispatcher-13] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[DEBUG] [10/24/2019 23:04:09.792] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.], using deadLetters.
[DEBUG] [10/24/2019 23:04:09.792] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/system/cluste], using deadLetters.
[INFO] [10/24/2019 23:04:09.793] [vcsvc-akka.actor.default-dispatcher-23] [akka://vcsvc/deadLetters] Message [akka.cluster.InternalClusterAction$InitJoin] without sender to Actor[akka://vcsvc/deadLetters] was not delivered. [5] dead letters encountered. If this is not an expected behavior, then [Actor[akka://vcsvc/deadLetters]] may have terminated unexpectedly, This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
[DEBUG] [10/24/2019 23:04:12.331] [vcsvc-akka.actor.default-dispatcher-3] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[DEBUG] [10/24/2019 23:04:14.816] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.], using deadLetters.
[DEBUG] [10/24/2019 23:04:14.817] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/system/cluste], using deadLetters.
[INFO] [10/24/2019 23:04:14.818] [vcsvc-akka.actor.default-dispatcher-9] [akka://vcsvc/deadLetters] Message [akka.cluster.InternalClusterAction$InitJoin] without sender to Actor[akka://vcsvc/deadLetters] was not delivered. [6] dead letters encountered. If this is not an expected behavior, then [Actor[akka://vcsvc/deadLetters]] may have terminated unexpectedly, This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
[DEBUG] [10/24/2019 23:04:14.913] [vcsvc-akka.actor.default-dispatcher-13] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[DEBUG] [10/24/2019 23:04:19.847] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.], using deadLetters.
[DEBUG] [10/24/2019 23:04:19.847] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/system/cluste], using deadLetters.
[INFO] [10/24/2019 23:04:19.848] [vcsvc-akka.actor.default-dispatcher-3] [akka://vcsvc/deadLetters] Message [akka.cluster.InternalClusterAction$InitJoin] without sender to Actor[akka://vcsvc/deadLetters] was not delivered. [7] dead letters encountered. If this is not an expected behavior, then [Actor[akka://vcsvc/deadLetters]] may have terminated unexpectedly, This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
[DEBUG] [10/24/2019 23:04:22.331] [vcsvc-akka.actor.default-dispatcher-9] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[DEBUG] [10/24/2019 23:04:24.875] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.], using deadLetters.
[DEBUG] [10/24/2019 23:04:24.875] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/system/cluste], using deadLetters.
[INFO] [10/24/2019 23:04:24.877] [vcsvc-akka.actor.default-dispatcher-21] [akka://vcsvc/deadLetters] Message [akka.cluster.InternalClusterAction$InitJoin] without sender to Actor[akka://vcsvc/deadLetters] was not delivered. [8] dead letters encountered. If this is not an expected behavior, then [Actor[akka://vcsvc/deadLetters]] may have terminated unexpectedly, This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
[DEBUG] [10/24/2019 23:04:24.913] [vcsvc-akka.actor.default-dispatcher-22] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[DEBUG] [10/24/2019 23:04:28.042] [vcsvc-akka.actor.default-dispatcher-8] [vcsvc/Pool(shared->https://10.96.0.1:443)] Shutting down host connection pool immediately
[DEBUG] [10/24/2019 23:04:28.043] [vcsvc-akka.actor.default-dispatcher-9] [vcsvc/Pool(shared->https://10.96.0.1:443)] Pool upstream was completed
[DEBUG] [10/24/2019 23:04:28.043] [vcsvc-akka.actor.default-dispatcher-9] [vcsvc/Pool(shared->https://10.96.0.1:443)] Pool stopped
[DEBUG] [10/24/2019 23:04:28.330] [vcsvc-akka.actor.default-dispatcher-22] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] Shutting down host connection pool immediately
[DEBUG] [10/24/2019 23:04:28.330] [vcsvc-akka.actor.default-dispatcher-8] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] Pool upstream was completed
[DEBUG] [10/24/2019 23:04:28.330] [vcsvc-akka.actor.default-dispatcher-8] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] Pool stopped
[DEBUG] [10/24/2019 23:04:28.340] [vcsvc-akka.actor.default-dispatcher-21] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] Shutting down host connection pool immediately
[DEBUG] [10/24/2019 23:04:28.340] [vcsvc-akka.actor.default-dispatcher-22] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] Pool upstream was completed
[DEBUG] [10/24/2019 23:04:28.340] [vcsvc-akka.actor.default-dispatcher-22] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] Pool stopped
[DEBUG] [10/24/2019 23:04:29.897] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.], using deadLetters.
[DEBUG] [10/24/2019 23:04:29.898] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/system/cluste], using deadLetters.
[INFO] [10/24/2019 23:04:29.899] [vcsvc-akka.actor.default-dispatcher-21] [akka://vcsvc/deadLetters] Message [akka.cluster.InternalClusterAction$InitJoin] without sender to Actor[akka://vcsvc/deadLetters] was not delivered. [9] dead letters encountered. If this is not an expected behavior, then [Actor[akka://vcsvc/deadLetters]] may have terminated unexpectedly, This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
[DEBUG] [10/24/2019 23:04:30.290] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/sys], using deadLetters.
[DEBUG] [10/24/2019 23:04:30.290] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/sys], using deadLetters.
[INFO] [10/24/2019 23:04:30.292] [vcsvc-akka.actor.default-dispatcher-8] [akka://vcsvc/deadLetters] Message [akka.remote.artery.ActorSystemTerminatingAck] without sender to Actor[akka://vcsvc/deadLetters] was not delivered. [10] dead letters encountered, no more dead letters will be logged. If this is not an expected behavior, then [Actor[akka://vcsvc/deadLetters]] may have terminated unexpectedly, This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
[INFO] [10/24/2019 23:04:31.310] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.remote.artery.Association(akka://vcsvc)] Association to [akka://vcsvc@192.168.42.176:2551] having UID [-669718903822771492] has been stopped. All messages to this UID will be delivered to dead letters. Reason: ActorSystem terminated
[DEBUG] [10/24/2019 23:04:31.310] [vcsvc-akka.actor.default-dispatcher-2] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/9] Closing connection due to IO error java.io.IOException: Connection reset by peer
[DEBUG] [10/24/2019 23:04:31.312] [vcsvc-akka.actor.default-dispatcher-22] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/8] Closing connection due to IO error java.io.IOException: Connection reset by peer
[DEBUG] [10/24/2019 23:04:31.314] [vcsvc-akka.remote.default-remote-dispatcher-5] [SystemMessageDelivery(akka://vcsvc)] Clear system message delivery of [akka://vcsvc@192.168.42.176:2551#-669718903822771492]
[DEBUG] [10/24/2019 23:04:31.319] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.stream.Log(akka://vcsvc/system/StreamSupervisor-0)] [outbound connection to [akka://vcsvc@192.168.42.176:2551], message stream] Upstream finished.
[DEBUG] [10/24/2019 23:04:31.319] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.stream.Log(akka://vcsvc/system/StreamSupervisor-0)] [outbound connection to [akka://vcsvc@192.168.42.176:2551], control stream] Upstream finished.
[DEBUG] [10/24/2019 23:04:31.319] [vcsvc-akka.remote.default-remote-dispatcher-6] [RestartWithBackoffFlow(akka://vcsvc)] Last restart attempt was more than 1000 milliseconds ago, resetting restart count
[DEBUG] [10/24/2019 23:04:31.319] [vcsvc-akka.remote.default-remote-dispatcher-5] [RestartWithBackoffFlow(akka://vcsvc)] Last restart attempt was more than 1000 milliseconds ago, resetting restart count
[DEBUG] [10/24/2019 23:04:31.320] [vcsvc-akka.remote.default-remote-dispatcher-6] [RestartWithBackoffFlow(akka://vcsvc)] Restarting graph in 1050796029 nanoseconds
[DEBUG] [10/24/2019 23:04:31.320] [vcsvc-akka.remote.default-remote-dispatcher-5] [RestartWithBackoffFlow(akka://vcsvc)] Restarting graph in 1046074149 nanoseconds
[DEBUG] [10/24/2019 23:04:32.331] [vcsvc-akka.actor.default-dispatcher-22] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[WARN] [10/24/2019 23:04:34.337] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.stream.Log(akka://vcsvc/system/StreamSupervisor-0)] [outbound connection to [akka://vcsvc@192.168.42.176:2551], message stream] Upstream failed, cause: Association$OutboundStreamStopQuarantinedSignal$: 
[WARN] [10/24/2019 23:04:34.337] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.stream.Log(akka://vcsvc/system/StreamSupervisor-0)] [outbound connection to [akka://vcsvc@192.168.42.176:2551], control stream] Upstream failed, cause: Association$OutboundStreamStopQuarantinedSignal$: 
[DEBUG] [10/24/2019 23:04:34.338] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.remote.artery.Association(akka://vcsvc)] Outbound message stream to [akka://vcsvc@192.168.42.176:2551] was quarantined and stopped. It will be restarted if used again.
[DEBUG] [10/24/2019 23:04:34.338] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.remote.artery.Association(akka://vcsvc)] Outbound control stream to [akka://vcsvc@192.168.42.176:2551] was quarantined and stopped. It will be restarted if used again.
[DEBUG] [10/24/2019 23:04:34.913] [vcsvc-akka.actor.default-dispatcher-4] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[DEBUG] [10/24/2019 23:04:35.902] [vcsvc-akka.actor.default-dispatcher-22] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[INFO] [10/24/2019 23:04:35.909] [vcsvc-akka.actor.default-dispatcher-9] [HttpClusterBootstrapRoutes(akka://vcsvc)] Bootstrap request from 192.168.42.176:60486: Contact Point returning 1 seed-nodes ([TreeSet(ClusterMember(akka://vcsvc@192.168.186.11:2551,4841541468880616991,Up,Set(Worker, dc-default)))])
[DEBUG] [10/24/2019 23:04:36.080] [vcsvc-akka.actor.default-dispatcher-22] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/0] New connection accepted
[DEBUG] [10/24/2019 23:04:36.083] [vcsvc-akka.actor.default-dispatcher-9] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/0] New connection accepted
[DEBUG] [10/24/2019 23:04:36.084] [vcsvc-akka.remote.default-remote-dispatcher-5] [Decoder(akka://vcsvc)] Decoded message but unable to record hits for compression as no remoteAddress known. No association yet?
[DEBUG] [10/24/2019 23:04:36.085] [vcsvc-akka.actor.default-dispatcher-4] [akka.remote.artery.Association(akka://vcsvc)] Incarnation 2 of association to [akka://vcsvc@192.168.42.176:2551] with new UID [-1733688541202605010] (old UID [-669718903822771492])
[DEBUG] [10/24/2019 23:04:36.085] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.remote.artery.Association(akka://vcsvc)] Starting outbound control stream to [akka://vcsvc@192.168.42.176:2551]
[DEBUG] [10/24/2019 23:04:36.093] [vcsvc-akka.actor.default-dispatcher-2] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/23] Resolving 192.168.42.176 before connecting
[DEBUG] [10/24/2019 23:04:36.093] [vcsvc-akka.actor.default-dispatcher-4] [akka://vcsvc@192.168.186.11:2551/system/IO-DNS] Resolution request for 192.168.42.176 from Actor[akka://vcsvc/system/IO-TCP/selectors/$a/23#-543521644]
[DEBUG] [10/24/2019 23:04:36.094] [vcsvc-akka.actor.default-dispatcher-4] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/23] Attempting connection to [/192.168.42.176:2551]
[DEBUG] [10/24/2019 23:04:36.095] [vcsvc-akka.actor.default-dispatcher-22] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/23] Connection established to [192.168.42.176:2551]
[DEBUG] [10/24/2019 23:04:36.123] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.], using deadLetters.
[DEBUG] [10/24/2019 23:04:36.123] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/system/cluste], using deadLetters.
[DEBUG] [10/24/2019 23:04:36.124] [vcsvc-akka.remote.default-remote-dispatcher-6] [InboundActorRefCompression(akka://vcsvc)] Initializing InboundActorRefCompression for originUid [-1733688541202605010]
[DEBUG] [10/24/2019 23:04:36.124] [vcsvc-akka.remote.default-remote-dispatcher-6] [InboundManifestCompression(akka://vcsvc)] Initializing InboundManifestCompression for originUid [-1733688541202605010]
[DEBUG] [10/24/2019 23:04:41.080] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.], using deadLetters.
[DEBUG] [10/24/2019 23:04:41.080] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/system/cluste], using deadLetters.
[DEBUG] [10/24/2019 23:04:42.331] [vcsvc-akka.actor.default-dispatcher-4] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[DEBUG] [10/24/2019 23:04:44.913] [vcsvc-akka.actor.default-dispatcher-22] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[DEBUG] [10/24/2019 23:04:46.117] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.], using deadLetters.
[DEBUG] [10/24/2019 23:04:46.117] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/system/cluste], using deadLetters.
[DEBUG] [10/24/2019 23:04:51.139] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.], using deadLetters.
[DEBUG] [10/24/2019 23:04:51.139] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/system/cluste], using deadLetters.
[DEBUG] [10/24/2019 23:04:52.331] [vcsvc-akka.actor.default-dispatcher-2] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[DEBUG] [10/24/2019 23:04:54.914] [vcsvc-akka.actor.default-dispatcher-4] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[DEBUG] [10/24/2019 23:04:54.926] [vcsvc-akka.actor.default-dispatcher-22] [akka://vcsvc/system/IO-TCP/selectors/$a/27] unhandled message from Actor[akka://vcsvc/deadLetters]: ChannelReadable
[DEBUG] [10/24/2019 23:04:56.171] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.], using deadLetters.
[DEBUG] [10/24/2019 23:04:56.171] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/system/cluste], using deadLetters.
[DEBUG] [10/24/2019 23:05:01.199] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.], using deadLetters.
[DEBUG] [10/24/2019 23:05:01.199] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/system/cluste], using deadLetters.
[DEBUG] [10/24/2019 23:05:02.331] [vcsvc-akka.actor.default-dispatcher-23] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[DEBUG] [10/24/2019 23:05:04.913] [vcsvc-akka.actor.default-dispatcher-23] [akka://vcsvc@192.168.186.11:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[DEBUG] [10/24/2019 23:05:06.230] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.], using deadLetters.
[DEBUG] [10/24/2019 23:05:06.230] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/system/cluste], using deadLetters.
[DEBUG] [10/24/2019 23:05:06.767] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/syst], using deadLetters.
[DEBUG] [10/24/2019 23:05:06.768] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.cluster.ClusterActorRefProvider] Resolve (deserialization) of unknown (invalid) path [akka://vcsvc@192.168.42.176:2551/syst], using deadLetters.

Possibly unrelated, but it seems strange to me that the resolver goes so wrong at the end after Orchestrator has already shutdown. At least, the log looks like it chops off part of the URL to resolve in the log brackets.

jackpines · October 24, 2019, 11:47pm

And here are Orchestrator’s logs for the same period. I did remove some stuff for brevity.

.
.
.
[TimerScheduler(akka://vcsvc)] Start timer [probing-key] with generation [6]
[INFO] [10/24/2019 23:03:58.683] [vcsvc-akka.actor.default-dispatcher-9] [akka://vcsvc@192.168.42.176:2551/system/bootstrapCoordinator] Looking up [Lookup(vcsvc,None,Some(tcp))]
[INFO] [10/24/2019 23:03:58.683] [vcsvc-akka.actor.default-dispatcher-9] [KubernetesApiServiceDiscovery(akka://vcsvc)] Querying for pods with label selector: [application=vcsvc,environment=multibox,akka-cluster=vcsvc]. Namespace: [vcsvc]. Port: [None]
[DEBUG] [10/24/2019 23:03:58.684] [vcsvc-akka.actor.default-dispatcher-4] [vcsvc/Pool(shared->https://10.96.0.1:443)] [0 (Idle)] Dispatching request [GET /api/v1/namespaces/vcsvc/pods Empty]
[DEBUG] [10/24/2019 23:03:58.684] [vcsvc-akka.actor.default-dispatcher-4] [vcsvc/Pool(shared->https://10.96.0.1:443)] [0 (Idle)] Before event [onNewRequest] In state [Idle] for [1210 ms]
[DEBUG] [10/24/2019 23:03:58.684] [vcsvc-akka.actor.default-dispatcher-4] [vcsvc/Pool(shared->https://10.96.0.1:443)] [0 (PushingRequestToConnection)] After event [onNewRequest] State change [Idle] -> [PushingRequestToConnection]
[DEBUG] [10/24/2019 23:03:58.684] [vcsvc-akka.actor.default-dispatcher-4] [vcsvc/Pool(shared->https://10.96.0.1:443)] [0 (PushingRequestToConnection)] Before event [onRequestDispatched] In state [PushingRequestToConnection] for [0 ms]
[DEBUG] [10/24/2019 23:03:58.684] [vcsvc-akka.actor.default-dispatcher-4] [vcsvc/Pool(shared->https://10.96.0.1:443)] [0 (WaitingForResponse)] After event [onRequestDispatched] State change [PushingRequestToConnection] -> [WaitingForResponse]
[DEBUG] [10/24/2019 23:03:58.697] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->https://10.96.0.1:443)] [0 (WaitingForResponse)] Received response
[DEBUG] [10/24/2019 23:03:58.697] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->https://10.96.0.1:443)] [0 (WaitingForResponse)] Before event [onResponseReceived] In state [WaitingForResponse] for [12 ms]
[DEBUG] [10/24/2019 23:03:58.697] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->https://10.96.0.1:443)] [0 (WaitingForResponse)] onResponseReceived in WaitingForResponse with false
[DEBUG] [10/24/2019 23:03:58.697] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->https://10.96.0.1:443)] [0 (WaitingForResponseDispatch)] After event [onResponseReceived] State change [WaitingForResponse] -> [WaitingForResponseDispatch]
[DEBUG] [10/24/2019 23:03:58.697] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->https://10.96.0.1:443)] [0 (WaitingForResponseDispatch)] Before event [onResponseDispatchable] In state [WaitingForResponseDispatch] for [0 ms]
[DEBUG] [10/24/2019 23:03:58.697] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->https://10.96.0.1:443)] [0 (WaitingForResponseEntitySubscription)] After event [onResponseDispatchable] State change [WaitingForResponseDispatch] -> [WaitingForResponseEntitySubscription]
[DEBUG] [10/24/2019 23:03:58.698] [vcsvc-akka.actor.default-dispatcher-4] [vcsvc/Pool(shared->https://10.96.0.1:443)] [0 (WaitingForResponseEntitySubscription)] Before event [onResponseEntitySubscribed] In state [WaitingForResponseEntitySubscription] for [1 ms]
[DEBUG] [10/24/2019 23:03:58.698] [vcsvc-akka.actor.default-dispatcher-4] [vcsvc/Pool(shared->https://10.96.0.1:443)] [0 (WaitingForEndOfResponseEntity)] After event [onResponseEntitySubscribed] State change [WaitingForResponseEntitySubscription] -> [WaitingForEndOfResponseEntity]
[DEBUG] [10/24/2019 23:03:58.699] [vcsvc-akka.actor.default-dispatcher-3] [vcsvc/Pool(shared->https://10.96.0.1:443)] [0 (WaitingForEndOfResponseEntity)] Before event [onResponseEntityCompleted] In state [WaitingForEndOfResponseEntity] for [0 ms]
[DEBUG] [10/24/2019 23:03:58.699] [vcsvc-akka.actor.default-dispatcher-3] [vcsvc/Pool(shared->https://10.96.0.1:443)] [0 (Idle)] After event [onResponseEntityCompleted] State change [WaitingForEndOfResponseEntity] -> [Idle]
[DEBUG] [10/24/2019 23:03:58.699] [vcsvc-akka.actor.default-dispatcher-3] [vcsvc/Pool(shared->https://10.96.0.1:443)] [0 (Idle)] Slot became idle... Trying to pull
[DEBUG] [10/24/2019 23:03:58.699] [vcsvc-akka.actor.default-dispatcher-9] [KubernetesApiServiceDiscovery(akka://vcsvc)] Kubernetes API entity: []
[INFO] [10/24/2019 23:03:58.702] [vcsvc-akka.actor.default-dispatcher-9] [akka://vcsvc@192.168.42.176:2551/system/bootstrapCoordinator] Located service members based on: [Lookup(vcsvc,None,Some(tcp))]: [ResolvedTarget(192-168-42-176.vcsvc.pod.cluster.local,None,Some(/192.168.42.176)), ResolvedTarget(192-168-186-11.vcsvc.pod.cluster.local,None,Some(/192.168.186.11))], filtered to [ResolvedTarget(192-168-42-176.vcsvc.pod.cluster.local,None,Some(/192.168.42.176)), ResolvedTarget(192-168-186-11.vcsvc.pod.cluster.local,None,Some(/192.168.186.11))]
[DEBUG] [10/24/2019 23:03:58.702] [vcsvc-akka.actor.default-dispatcher-9] [akka://vcsvc@192.168.42.176:2551/system/bootstrapCoordinator] Ensuring probing actor: contactPointProbe-192-168-42-176.vcsvc.pod.cluster.local-8558
[DEBUG] [10/24/2019 23:03:58.703] [vcsvc-akka.actor.default-dispatcher-9] [akka://vcsvc@192.168.42.176:2551/system/bootstrapCoordinator] Ensuring probing actor: contactPointProbe-192-168-186-11.vcsvc.pod.cluster.local-8558
[DEBUG] [10/24/2019 23:03:58.703] [vcsvc-akka.actor.default-dispatcher-9] [TimerScheduler(akka://vcsvc)] Start timer [resolve-key] with generation [21]
[INFO] [10/24/2019 23:03:58.933] [vcsvc-akka.actor.default-dispatcher-17] [LowestAddressJoinDecider(akka://vcsvc)] Exceeded stable margins without locating seed-nodes, however this node 192.168.42.176:8558 is NOT the lowest address out of the discovered endpoints in this deployment, thus NOT joining self. Expecting node [ResolvedTarget(192-168-186-11.vcsvc.pod.cluster.local,None,Some(/192.168.186.11))] (out of [ResolvedTarget(192-168-42-176.vcsvc.pod.cluster.local,None,Some(/192.168.42.176)), ResolvedTarget(192-168-186-11.vcsvc.pod.cluster.local,None,Some(/192.168.186.11))]) to perform the self-join and initiate the cluster.
[DEBUG] [10/24/2019 23:03:59.293] [vcsvc-akka.actor.default-dispatcher-17] [akka://vcsvc@192.168.42.176:2551/system/bootstrapCoordinator/contactPointProbe-192-168-42-176.vcsvc.pod.cluster.local-8558] Probing [http://192-168-42-176.vcsvc.pod.cluster.local:8558/bootstrap/seed-nodes] for seed nodes...
[DEBUG] [10/24/2019 23:03:59.293] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] [0 (Idle)] Dispatching request [GET /bootstrap/seed-nodes Empty]
[DEBUG] [10/24/2019 23:03:59.293] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] [0 (Idle)] Before event [onNewRequest] In state [Idle] for [1065 ms]
[DEBUG] [10/24/2019 23:03:59.294] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] [0 (PushingRequestToConnection)] After event [onNewRequest] State change [Idle] -> [PushingRequestToConnection]
[DEBUG] [10/24/2019 23:03:59.294] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] [0 (PushingRequestToConnection)] Before event [onRequestDispatched] In state [PushingRequestToConnection] for [0 ms]
[DEBUG] [10/24/2019 23:03:59.294] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] [0 (WaitingForResponse)] After event [onRequestDispatched] State change [PushingRequestToConnection] -> [WaitingForResponse]
[INFO] [10/24/2019 23:03:59.297] [vcsvc-akka.actor.default-dispatcher-17] [HttpClusterBootstrapRoutes(akka://vcsvc)] Bootstrap request from 192.168.42.176:55192: Contact Point returning 0 seed-nodes ([TreeSet()])
[DEBUG] [10/24/2019 23:03:59.298] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] [0 (WaitingForResponse)] Received response
[DEBUG] [10/24/2019 23:03:59.299] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] [0 (WaitingForResponse)] Before event [onResponseReceived] In state [WaitingForResponse] for [4 ms]
[DEBUG] [10/24/2019 23:03:59.299] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] [0 (WaitingForResponse)] onResponseReceived in WaitingForResponse with false
[DEBUG] [10/24/2019 23:03:59.299] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] [0 (WaitingForResponseDispatch)] After event [onResponseReceived] State change [WaitingForResponse] -> [WaitingForResponseDispatch]
[DEBUG] [10/24/2019 23:03:59.299] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] [0 (WaitingForResponseDispatch)] Before event [onResponseDispatchable] In state [WaitingForResponseDispatch] for [0 ms]
[DEBUG] [10/24/2019 23:03:59.299] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] [0 (WaitingForResponseEntitySubscription)] After event [onResponseDispatchable] State change [WaitingForResponseDispatch] -> [WaitingForResponseEntitySubscription]
[DEBUG] [10/24/2019 23:03:59.299] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] [0 (WaitingForResponseEntitySubscription)] Before event [onResponseEntitySubscribed] In state [WaitingForResponseEntitySubscription] for [0 ms]
[DEBUG] [10/24/2019 23:03:59.299] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] [0 (WaitingForEndOfResponseEntity)] After event [onResponseEntitySubscribed] State change [WaitingForResponseEntitySubscription] -> [WaitingForEndOfResponseEntity]
[DEBUG] [10/24/2019 23:03:59.299] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] [0 (WaitingForEndOfResponseEntity)] Before event [onResponseEntityCompleted] In state [WaitingForEndOfResponseEntity] for [0 ms]
[DEBUG] [10/24/2019 23:03:59.299] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] [0 (Idle)] After event [onResponseEntityCompleted] State change [WaitingForEndOfResponseEntity] -> [Idle]
[DEBUG] [10/24/2019 23:03:59.299] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] [0 (Idle)] Slot became idle... Trying to pull
[INFO] [10/24/2019 23:03:59.299] [vcsvc-akka.actor.default-dispatcher-2] [akka://vcsvc@192.168.42.176:2551/system/bootstrapCoordinator] Contact point [akka://vcsvc@192.168.42.176:2551] returned [0] seed-nodes []
[DEBUG] [10/24/2019 23:03:59.299] [vcsvc-akka.actor.default-dispatcher-17] [TimerScheduler(akka://vcsvc)] Start timer [probing-key] with generation [20]
[DEBUG] [10/24/2019 23:03:59.643] [vcsvc-akka.actor.default-dispatcher-3] [akka://vcsvc@192.168.42.176:2551/system/bootstrapCoordinator/contactPointProbe-192-168-186-11.vcsvc.pod.cluster.local-8558] Probing [http://192-168-186-11.vcsvc.pod.cluster.local:8558/bootstrap/seed-nodes] for seed nodes...
[DEBUG] [10/24/2019 23:03:59.644] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] [0 (Idle)] Dispatching request [GET /bootstrap/seed-nodes Empty]
[DEBUG] [10/24/2019 23:03:59.644] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] [0 (Idle)] Before event [onNewRequest] In state [Idle] for [1063 ms]
[DEBUG] [10/24/2019 23:03:59.644] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] [0 (PushingRequestToConnection)] After event [onNewRequest] State change [Idle] -> [PushingRequestToConnection]
[DEBUG] [10/24/2019 23:03:59.644] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] [0 (PushingRequestToConnection)] Before event [onRequestDispatched] In state [PushingRequestToConnection] for [0 ms]
[DEBUG] [10/24/2019 23:03:59.644] [vcsvc-akka.actor.default-dispatcher-17] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] [0 (WaitingForResponse)] After event [onRequestDispatched] State change [PushingRequestToConnection] -> [WaitingForResponse]
[DEBUG] [10/24/2019 23:03:59.651] [vcsvc-akka.actor.default-dispatcher-2] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] [0 (WaitingForResponse)] Received response
[DEBUG] [10/24/2019 23:03:59.651] [vcsvc-akka.actor.default-dispatcher-2] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] [0 (WaitingForResponse)] Before event [onResponseReceived] In state [WaitingForResponse] for [6 ms]
[DEBUG] [10/24/2019 23:03:59.651] [vcsvc-akka.actor.default-dispatcher-2] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] [0 (WaitingForResponse)] onResponseReceived in WaitingForResponse with false
[DEBUG] [10/24/2019 23:03:59.651] [vcsvc-akka.actor.default-dispatcher-2] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] [0 (WaitingForResponseDispatch)] After event [onResponseReceived] State change [WaitingForResponse] -> [WaitingForResponseDispatch]
[DEBUG] [10/24/2019 23:03:59.651] [vcsvc-akka.actor.default-dispatcher-2] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] [0 (WaitingForResponseDispatch)] Before event [onResponseDispatchable] In state [WaitingForResponseDispatch] for [0 ms]
[DEBUG] [10/24/2019 23:03:59.651] [vcsvc-akka.actor.default-dispatcher-2] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] [0 (WaitingForResponseEntitySubscription)] After event [onResponseDispatchable] State change [WaitingForResponseDispatch] -> [WaitingForResponseEntitySubscription]
[DEBUG] [10/24/2019 23:03:59.651] [vcsvc-akka.actor.default-dispatcher-2] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] [0 (WaitingForResponseEntitySubscription)] Before event [onResponseEntitySubscribed] In state [WaitingForResponseEntitySubscription] for [0 ms]
[DEBUG] [10/24/2019 23:03:59.651] [vcsvc-akka.actor.default-dispatcher-2] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] [0 (WaitingForEndOfResponseEntity)] After event [onResponseEntitySubscribed] State change [WaitingForResponseEntitySubscription] -> [WaitingForEndOfResponseEntity]
[DEBUG] [10/24/2019 23:03:59.651] [vcsvc-akka.actor.default-dispatcher-2] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] [0 (WaitingForEndOfResponseEntity)] Before event [onResponseEntityCompleted] In state [WaitingForEndOfResponseEntity] for [0 ms]
[DEBUG] [10/24/2019 23:03:59.651] [vcsvc-akka.actor.default-dispatcher-2] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] [0 (Idle)] After event [onResponseEntityCompleted] State change [WaitingForEndOfResponseEntity] -> [Idle]
[DEBUG] [10/24/2019 23:03:59.651] [vcsvc-akka.actor.default-dispatcher-2] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] [0 (Idle)] Slot became idle... Trying to pull
[DEBUG] [10/24/2019 23:03:59.652] [vcsvc-akka.actor.default-dispatcher-17] [TimerScheduler(akka://vcsvc)] Start timer [probing-key] with generation [7]
[INFO] [10/24/2019 23:03:59.652] [vcsvc-akka.actor.default-dispatcher-2] [akka://vcsvc@192.168.42.176:2551/system/bootstrapCoordinator] Contact point [akka://vcsvc@192.168.186.11:2551] returned [1] seed-nodes [akka://vcsvc@192.168.186.11:2551]
[INFO] [10/24/2019 23:03:59.654] [vcsvc-akka.actor.default-dispatcher-17] [akka://vcsvc@192.168.42.176:2551/system/bootstrapCoordinator] Joining [akka://vcsvc@192.168.42.176:2551] to existing cluster [akka://vcsvc@192.168.186.11:2551]
[INFO] [10/24/2019 23:03:59.655] [vcsvc-akka.actor.default-dispatcher-8] [akka://vcsvc/deadLetters] Message [akka.management.cluster.bootstrap.internal.BootstrapCoordinator$Protocol$BootstrappingCompleted$] from Actor[akka://vcsvc/system/bootstrapCoordinator#1575387557] to Actor[akka://vcsvc/deadLetters] was not delivered. [2] dead letters encountered. If this is not an expected behavior, then [Actor[akka://vcsvc/deadLetters]] may have terminated unexpectedly, This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
[DEBUG] [10/24/2019 23:03:59.657] [vcsvc-akka.actor.default-dispatcher-8] [TimerScheduler(akka://vcsvc)] Cancel all timers
[DEBUG] [10/24/2019 23:03:59.657] [vcsvc-akka.actor.default-dispatcher-3] [TimerScheduler(akka://vcsvc)] Cancel all timers
[DEBUG] [10/24/2019 23:03:59.658] [vcsvc-akka.actor.default-dispatcher-17] [TimerScheduler(akka://vcsvc)] Cancel all timers
[DEBUG] [10/24/2019 23:03:59.707] [vcsvc-akka.actor.default-dispatcher-2] [akka.remote.artery.Association(akka://vcsvc)] Starting outbound control stream to [akka://vcsvc@192.168.186.11:2551]
[DEBUG] [10/24/2019 23:03:59.724] [vcsvc-akka.actor.default-dispatcher-2] [akka.remote.artery.Association(akka://vcsvc)] Starting outbound message stream to [akka://vcsvc@192.168.186.11:2551]
[DEBUG] [10/24/2019 23:03:59.739] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.serialization.Serialization(akka://vcsvc)] Using serializer [akka.remote.serialization.ArteryMessageSerializer] for message [akka.remote.artery.OutboundHandshake$HandshakeReq]
[DEBUG] [10/24/2019 23:03:59.766] [vcsvc-akka.actor.default-dispatcher-2] [akka://vcsvc@192.168.42.176:2551/system/IO-TCP/selectors/$a/17] Resolving 192.168.186.11 before connecting
[DEBUG] [10/24/2019 23:03:59.766] [vcsvc-akka.actor.default-dispatcher-3] [akka://vcsvc@192.168.42.176:2551/system/IO-DNS] Resolution request for 192.168.186.11 from Actor[akka://vcsvc/system/IO-TCP/selectors/$a/17#2060590484]
[DEBUG] [10/24/2019 23:03:59.767] [vcsvc-akka.actor.default-dispatcher-2] [akka://vcsvc@192.168.42.176:2551/system/IO-TCP/selectors/$a/18] Resolving 192.168.186.11 before connecting
[DEBUG] [10/24/2019 23:03:59.767] [vcsvc-akka.actor.default-dispatcher-17] [akka://vcsvc@192.168.42.176:2551/system/IO-DNS] Resolution request for 192.168.186.11 from Actor[akka://vcsvc/system/IO-TCP/selectors/$a/18#-285784206]
[DEBUG] [10/24/2019 23:03:59.767] [vcsvc-akka.actor.default-dispatcher-3] [akka://vcsvc@192.168.42.176:2551/system/IO-TCP/selectors/$a/17] Attempting connection to [/192.168.186.11:2551]
[DEBUG] [10/24/2019 23:03:59.768] [vcsvc-akka.actor.default-dispatcher-3] [akka://vcsvc@192.168.42.176:2551/system/IO-TCP/selectors/$a/18] Attempting connection to [/192.168.186.11:2551]
[DEBUG] [10/24/2019 23:03:59.768] [vcsvc-akka.actor.default-dispatcher-3] [akka://vcsvc@192.168.42.176:2551/system/IO-TCP/selectors/$a/17] Connection established to [192.168.186.11:2551]
[DEBUG] [10/24/2019 23:03:59.769] [vcsvc-akka.actor.default-dispatcher-17] [akka://vcsvc@192.168.42.176:2551/system/IO-TCP/selectors/$a/18] Connection established to [192.168.186.11:2551]
[DEBUG] [10/24/2019 23:03:59.844] [vcsvc-akka.actor.default-dispatcher-17] [akka://vcsvc@192.168.42.176:2551/system/IO-TCP/selectors/$a/0] New connection accepted
[DEBUG] [10/24/2019 23:03:59.852] [vcsvc-akka.actor.default-dispatcher-3] [akka://vcsvc@192.168.42.176:2551/system/IO-TCP/selectors/$a/0] New connection accepted
[DEBUG] [10/24/2019 23:03:59.857] [vcsvc-akka.remote.default-remote-dispatcher-5] [Decoder(akka://vcsvc)] Decoded message but unable to record hits for compression as no remoteAddress known. No association yet?
[DEBUG] [10/24/2019 23:03:59.857] [vcsvc-akka.remote.default-remote-dispatcher-6] [Decoder(akka://vcsvc)] Decoded message but unable to record hits for compression as no remoteAddress known. No association yet?
[DEBUG] [10/24/2019 23:03:59.867] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.serialization.Serialization(akka://vcsvc)] Using serializer [akka.remote.serialization.ArteryMessageSerializer] for message [akka.remote.artery.OutboundHandshake$HandshakeRsp]
[DEBUG] [10/24/2019 23:03:59.870] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.serialization.Serialization(akka://vcsvc)] Using serializer [akka.cluster.protobuf.ClusterMessageSerializer] for message [akka.cluster.InternalClusterAction$InitJoin]
[DEBUG] [10/24/2019 23:04:07.140] [vcsvc-akka.actor.default-dispatcher-8] [akka://vcsvc@192.168.42.176:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[DEBUG] [10/24/2019 23:04:08.347] [vcsvc-akka.actor.default-dispatcher-10] [akka://vcsvc@192.168.42.176:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[WARN] [10/24/2019 23:04:09.773] [vcsvc-akka.actor.default-dispatcher-8] [akka.cluster.Cluster(akka://vcsvc)] Cluster Node [akka://vcsvc@192.168.42.176:2551] - Couldn't join seed nodes after [2] attempts, will try again. seed-nodes=[akka://vcsvc@192.168.186.11:2551]
[WARN] [10/24/2019 23:04:14.802] [vcsvc-akka.actor.default-dispatcher-2] [akka.cluster.Cluster(akka://vcsvc)] Cluster Node [akka://vcsvc@192.168.42.176:2551] - Couldn't join seed nodes after [3] attempts, will try again. seed-nodes=[akka://vcsvc@192.168.186.11:2551]
[WARN] [10/24/2019 23:04:56.156] [vcsvc-akka.actor.default-dispatcher-11] [akka.cluster.Cluster(akka://vcsvc)] Cluster Node [akka://vcsvc@192.168.42.176:2551] - Couldn't join seed nodes after [4] attempts, will try again. seed-nodes=[akka://vcsvc@192.168.186.11:2551]
[DEBUG] [10/24/2019 23:04:57.140] [vcsvc-akka.actor.default-dispatcher-21] [akka://vcsvc@192.168.42.176:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[DEBUG] [10/24/2019 23:04:58.347] [vcsvc-akka.actor.default-dispatcher-11] [akka://vcsvc@192.168.42.176:2551/system/IO-TCP/selectors/$a/1] New connection accepted
.
.
.
[WARN] [10/24/2019 23:05:01.186] [vcsvc-akka.actor.default-dispatcher-21] [akka.cluster.Cluster(akka://vcsvc)] Cluster Node [akka://vcsvc@192.168.42.176:2551] - Couldn't join seed nodes after [5] attempts, will try again. seed-nodes=[akka://vcsvc@192.168.186.11:2551]
[DEBUG] [10/24/2019 23:05:05.788] [vcsvc-akka.actor.default-dispatcher-18] [vcsvc/Pool(shared->https://10.96.0.1:443)] Shutting down host connection pool immediately
[DEBUG] [10/24/2019 23:05:05.789] [vcsvc-akka.actor.default-dispatcher-10] [vcsvc/Pool(shared->https://10.96.0.1:443)] Pool upstream was completed
[DEBUG] [10/24/2019 23:05:05.789] [vcsvc-akka.actor.default-dispatcher-10] [vcsvc/Pool(shared->https://10.96.0.1:443)] Pool stopped
[DEBUG] [10/24/2019 23:05:05.926] [vcsvc-akka.actor.default-dispatcher-10] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] Shutting down host connection pool immediately
[DEBUG] [10/24/2019 23:05:05.926] [vcsvc-akka.actor.default-dispatcher-18] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] Pool upstream was completed
[DEBUG] [10/24/2019 23:05:05.926] [vcsvc-akka.actor.default-dispatcher-18] [vcsvc/Pool(shared->http://192-168-186-11.vcsvc.pod.cluster.local:8558)] Pool stopped
[DEBUG] [10/24/2019 23:05:06.066] [vcsvc-akka.actor.default-dispatcher-11] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] Shutting down host connection pool immediately
[DEBUG] [10/24/2019 23:05:06.066] [vcsvc-akka.actor.default-dispatcher-18] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] Pool upstream was completed
[DEBUG] [10/24/2019 23:05:06.066] [vcsvc-akka.actor.default-dispatcher-18] [vcsvc/Pool(shared->http://192-168-42-176.vcsvc.pod.cluster.local:8558)] Pool stopped
[WARN] [10/24/2019 23:05:06.216] [vcsvc-akka.actor.default-dispatcher-18] [akka.cluster.Cluster(akka://vcsvc)] Cluster Node [akka://vcsvc@192.168.42.176:2551] - Couldn't join seed nodes after [6] attempts, will try again. seed-nodes=[akka://vcsvc@192.168.186.11:2551]
[WARN] [10/24/2019 23:05:06.736] [vcsvc-akka.actor.default-dispatcher-21] [akka.cluster.Cluster(akka://vcsvc)] Cluster Node [akka://vcsvc@192.168.42.176:2551] - Joining of seed-nodes [akka://vcsvc@192.168.186.11:2551] was unsuccessful after configured shutdown-after-unsuccessful-join-seed-nodes [30000 milliseconds]. Running CoordinatedShutdown.
[DEBUG] [10/24/2019 23:05:06.737] [vcsvc-akka.actor.default-dispatcher-21] [CoordinatedShutdown(akka://vcsvc)] Performing phase [before-service-unbind] with [0] tasks
[DEBUG] [10/24/2019 23:05:06.738] [vcsvc-akka.actor.default-dispatcher-10] [CoordinatedShutdown(akka://vcsvc)] Performing phase [service-unbind] with [0] tasks
[DEBUG] [10/24/2019 23:05:06.738] [vcsvc-akka.actor.default-dispatcher-10] [CoordinatedShutdown(akka://vcsvc)] Performing phase [service-requests-done] with [0] tasks
[DEBUG] [10/24/2019 23:05:06.738] [vcsvc-akka.actor.default-dispatcher-10] [CoordinatedShutdown(akka://vcsvc)] Performing phase [service-stop] with [0] tasks
[DEBUG] [10/24/2019 23:05:06.738] [vcsvc-akka.actor.default-dispatcher-10] [CoordinatedShutdown(akka://vcsvc)] Performing phase [before-cluster-shutdown] with [0] tasks
[DEBUG] [10/24/2019 23:05:06.738] [vcsvc-akka.actor.default-dispatcher-10] [CoordinatedShutdown(akka://vcsvc)] Performing phase [cluster-sharding-shutdown-region] with [0] tasks
[DEBUG] [10/24/2019 23:05:06.738] [vcsvc-akka.actor.default-dispatcher-10] [CoordinatedShutdown(akka://vcsvc)] Performing phase [cluster-leave] with [1] tasks: [leave]
[DEBUG] [10/24/2019 23:05:06.743] [vcsvc-akka.actor.default-dispatcher-10] [akka://vcsvc/system/cluster/core/daemon] unhandled message from Actor[akka://vcsvc/deadLetters]: Leave(akka://vcsvc@192.168.42.176:2551)
[DEBUG] [10/24/2019 23:05:06.743] [vcsvc-akka.actor.default-dispatcher-19] [CoordinatedShutdown(akka://vcsvc)] Performing phase [cluster-exiting] with [1] tasks: [wait-exiting]
[DEBUG] [10/24/2019 23:05:06.744] [vcsvc-akka.actor.default-dispatcher-19] [CoordinatedShutdown(akka://vcsvc)] Performing phase [cluster-exiting-done] with [1] tasks: [exiting-completed]
[INFO] [10/24/2019 23:05:06.744] [vcsvc-akka.actor.default-dispatcher-21] [akka.cluster.Cluster(akka://vcsvc)] Cluster Node [akka://vcsvc@192.168.42.176:2551] - Exiting completed
[INFO] [10/24/2019 23:05:06.745] [vcsvc-akka.actor.default-dispatcher-21] [akka.cluster.Cluster(akka://vcsvc)] Cluster Node [akka://vcsvc@192.168.42.176:2551] - Shutting down...
[INFO] [10/24/2019 23:05:06.746] [vcsvc-akka.actor.default-dispatcher-21] [akka.cluster.Cluster(akka://vcsvc)] Cluster Node [akka://vcsvc@192.168.42.176:2551] - Successfully shut down
[DEBUG] [10/24/2019 23:05:06.746] [vcsvc-akka.actor.default-dispatcher-19] [CoordinatedShutdown(akka://vcsvc)] Performing phase [cluster-shutdown] with [1] tasks: [wait-shutdown]
[DEBUG] [10/24/2019 23:05:06.752] [vcsvc-akka.actor.default-dispatcher-21] [CoordinatedShutdown(akka://vcsvc)] Performing phase [before-actor-system-terminate] with [1] tasks: [shutdownNoOp]
[ INFO] 24-10-19 23:05:06:752 [vcsvc-akka.actor.default-dispatcher-21] OrchestratorEntrypoint:194 Pre-shutdown requires no actions. Continuing with shutdown.
[DEBUG] [10/24/2019 23:05:06.753] [vcsvc-akka.actor.default-dispatcher-21] [CoordinatedShutdown(akka://vcsvc)] Performing phase [actor-system-terminate] with [1] tasks: [terminate-system]
[INFO] [10/24/2019 23:05:06.758] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka://vcsvc@192.168.42.176:2551/system/remoting-terminator] Shutting down remote daemon.
[INFO] [10/24/2019 23:05:06.760] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka://vcsvc@192.168.42.176:2551/system/remoting-terminator] Remote daemon shut down; proceeding with flushing remote transports.
[DEBUG] [10/24/2019 23:05:06.760] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.remote.artery.tcp.ArteryTcpTransport(akka://vcsvc)] Shutting down [akka://vcsvc@192.168.42.176:2551#-1733688541202605010]
[DEBUG] [10/24/2019 23:05:06.765] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka.serialization.Serialization(akka://vcsvc)] Using serializer [akka.remote.serialization.ArteryMessageSerializer] for message [akka.remote.artery.ActorSystemTerminating]
[DEBUG] [10/24/2019 23:05:07.140] [vcsvc-akka.actor.default-dispatcher-4] [akka://vcsvc@192.168.42.176:2551/system/IO-TCP/selectors/$a/1] New connection accepted
[DEBUG] [10/24/2019 23:05:07.784] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka://vcsvc/system/StreamSupervisor-0/remote-17-0-ignoreSink] Aborting tcp connection to 192.168.186.11:2551 because of upstream failure: akka.remote.artery.ArteryTransport$ShutdownSignal$
[DEBUG] [10/24/2019 23:05:07.786] [vcsvc-akka.remote.default-remote-dispatcher-5] [akka://vcsvc/system/StreamSupervisor-0/remote-18-0-ignoreSink] Aborting tcp connection to 192.168.186.11:2551 because of upstream failure: akka.remote.artery.ArteryTransport$ShutdownSignal$
[WARN] [10/24/2019 23:05:07.787] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.stream.Log(akka://vcsvc/system/StreamSupervisor-0)] [outbound connection to [akka://vcsvc@192.168.186.11:2551], control stream] Upstream failed, cause: StreamTcpException: The connection has been aborted
[WARN] [10/24/2019 23:05:07.789] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka.stream.Log(akka://vcsvc/system/StreamSupervisor-0)] [outbound connection to [akka://vcsvc@192.168.186.11:2551], message stream] Upstream failed, cause: StreamTcpException: The connection has been aborted
[DEBUG] [10/24/2019 23:05:07.794] [vcsvc-akka.actor.default-dispatcher-4] [akka://vcsvc@192.168.42.176:2551/system/IO-TCP/selectors/$a/0] Unbinding endpoint /192.168.42.176:2551
[DEBUG] [10/24/2019 23:05:07.795] [vcsvc-akka.actor.default-dispatcher-4] [akka://vcsvc@192.168.42.176:2551/system/IO-TCP/selectors/$a/0] Unbound endpoint /192.168.42.176:2551, stopping listener
[INFO] [10/24/2019 23:05:07.797] [vcsvc-akka.remote.default-remote-dispatcher-6] [akka://vcsvc@192.168.42.176:2551/system/remoting-terminator] Remoting shut down.
[DEBUG] [10/24/2019 23:05:07.798] [vcsvc-akka.actor.default-dispatcher-4] [EventStream] shutting down: StandardOutLogger

Sorry about the timestamps above not aligning. Kubernetes saw the service hadn’t joined and restarted it. I grabbed a second log segment from the same point where the first stopped before the restart.

fxgai · October 25, 2019, 1:36am

I had some difficulties getting a akka cluster to start up on my low spec laptop (running minikube for Kubernetes). The problem in my case was that the kubernetes health checks were failing before the nodes had really had a chance to complete (because my machine is so underpowered). So kubernetes was killing my node pods over and over in a vain attempt to get them working, but actually causing the problem. In my case, disabling the health check resolved my issue.

Yours looks like a different problem to what I experienced, but my thought was just that perhaps adjusting the kubernetes health / readiness checks to have very long duration (so as to not interfere in cluster formation), may make it easier to see where any root problem is.

jackpines · October 25, 2019, 2:42pm

Thanks for that, David (@fxgai). Though I’m actually running K8 in AWS and doubt this is a problem with underpowered servers, I have noticed that the behavior is the same whether I keep or remove “health” from the paths I’ve included again, below:

      health-check: {
        # Ready health check returns 200 when cluster membership is in the following states.
        # Intended to be used to indicate this node is ready for user traffic so Up/WeaklyUp
        # Valid values: "Joining", "WeaklyUp", "Up", "Leaving", "Exiting", "Down", "Removed"
        ready-states: ["Up", "WeaklyUp"]

        readiness-path: "health/ready"
        liveness-path: "health/alive"
      }

In my K8 deployment.yaml, I have the following:

          readinessProbe:
            httpGet:
              path: /ready
              port: management
          livenessProbe:
            httpGet:
              path: /alive
              port: management
          ports:
            - containerPort: 8558
              protocol: TCP
              name: management
            - containerPort: 2551
              protocol: TCP
              name: remoting

Any thoughts on this configuration?

jackpines · October 25, 2019, 4:27pm

I’ve now tried iterations with readiness- and liveness-path as presented below with no change in outcome:

        readiness-path: "health/ready"
        liveness-path: "health/alive"

        readiness-path: "/ready"
        liveness-path: "/alive"

        readiness-path: "ready"
        liveness-path: "alive"

fxgai · October 28, 2019, 2:07am

To “disable” the health and readiness checks, I was thinking to set an initialDelaySeconds value, say “initialDelaySeconds: 300” (5 minutes), so kubernetes won’t restart your pods for at least that long.

(As an aside, I see in the latest kubernetes version a new “startup” probe has been added, that could seemingly be used instead for the purpose of delaying the start of the health/readiness probes.
Configure Liveness, Readiness and Startup Probes | Kubernetes)

jackpines · October 28, 2019, 4:32pm

So, it turns out that the reason the second node was unable to respond to the join success event (we saw that happening in the logs) was due to a problem with the akka.remote configuration. This one was not obvious to us due to all of the documentation and sample code of Lightbend’s/Akka’s directing us to use akka.remote.artery. For reasons I’ve yet to identify, this works in a local Discovery situation but not in our K8 environment. Rather, there I needed to use akka.remote.netty.tcp. I’ll put the full configuration for clarity below.

Failing:

akka: {
  remote: {
    artery: {
      enabled: on
      transport: tcp
      canonical.port: 2552
    }
  }
}

Working:

akka: {
  remote: {
    netty.tcp: {
      hostname:  ${HOSTNAME}
      port: 2552
    }
  }
}

Hope that helps someone else avoid a week and a half of lost productivity someday.

TimMoore · December 2, 2019, 3:34am

The problem could be that you needed to set the canonical.hostname for Artery, rather than switching to the classic transport.

Try this:

akka: {
  remote: {
    artery: {
      enabled: on
      transport: tcp
      canonical.port: 2552
      canonical.hostname: ${HOSTNAME} // this is the only change
    }
  }
}

Topic		Replies	Views
Can't join cluster after upgrade to 2.6 (Artery is explicitly turned off) Akka Libraries	2	496	August 18, 2020
Akka Management Cluster Bootstrap K8S resolving question Akka Cluster akka-management	2	1127	May 31, 2019
Bootstrapping cluster locally - nodes not finding one another Akka Libraries java , akka-cluster , akka-management	0	681	May 15, 2022
Akka Cluster local discovery using akka-bootstrap and akka-discovery Akka Cluster akka , akka-http , akka-cluster , akka-management	1	1812	January 2, 2021
Issues trying to join a cluster locally using akka-bootstrap and akka-discovery Akka Cluster akka-cluster , akka-management	3	1055	January 19, 2021

Cluster join failing using kubernetes-api discovery

Related topics