Skip to content

FAILED: ClusterAssociationTests.test_down_self_shouldChangeMembershipSelfToBeDown #377

@ktoso

Description

@ktoso

Suspecting bad test construction -- expect within an eventually is always "bad"

22:56:12 /code/Tests/DistributedActorsTests/Cluster/AssociationClusteredTests.swift:266: error: ClusterAssociationTests.test_down_self_shouldChangeMembershipSelfToBeDown : failed - 
22:56:12         try shouldNotThrow {
22:56:12             ^~~~~~~~~~~~~~~
22:56:12 error: Unexpected throw captured
22:56:12             try self.testKit(first).eventually(within: .seconds(3)) {
22:56:12                                    ^~~~~~~~~~~
22:56:12 error: No result within 3s for block at /code/Tests/DistributedActorsTests/Cluster/AssociationClusteredTests.swift:278. Queried 1 times, within 3s. Last error: 
22:56:12                 let firstMembership = try localProbe.expectMessage()
22:56:12                                                     ^~~~~~~~~~~~~~
22:56:12 error: Did not receive message of type [Membership] within [3s], error: noMessagesInQueue
22:56:12 <EXPR>:0: error: ClusterAssociationTests.test_down_self_shouldChangeMembershipSelfToBeDown : threw error "unexpectedErrorWasThrown"
22:56:12 ------------------------------------- ActorSystem(first, sact://first@localhost:9001) ------------------------------------------------
22:56:12 Captured log [first][2020-01-17 13:56:08.8480] [Timers.swift:163][/system/receptionist] [trace] Started timer [TimerKey(receptionist/sync)] with generation [0]
22:56:12 // metadata:
22:56:12 // "tag": timers
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8480] [ActorShell+Children.swift:345][/system/cluster] [debug] Spawning [DistributedActors.Behavior<DistributedActors.SWIM.Message>.setup((Function))], on path: [/system/cluster/swim]
22:56:12 Captured log [first][2020-01-17 13:56:08.8480] [ClusterEventStream.swift:43][/system/clusterEvents] [trace] Successfully subscribed [ActorRef<Cluster.Event>(/system/replicator/$sub-DistributedActors.Cluster.Event-y)], offering membership snapshot
22:56:12 Captured log [first][2020-01-17 13:56:08.8480] [ActorShell+Children.swift:345][/system/cluster] [debug] Spawning [DistributedActors.Behavior<DistributedActors.Cluster.Event>.setup((Function))], on path: [/system/cluster/leadership]
22:56:12 Captured log [first][2020-01-17 13:56:08.8480] [ClusterShell.swift:352][/system/cluster] [info] Binding to: [sact://first@localhost:9001]
22:56:12 Captured log [first][2020-01-17 13:56:08.8480] [ClusterEventStream.swift:43][/system/clusterEvents] [trace] Successfully subscribed [ActorRef<Cluster.Event>(/system/nodeDeathWatcher/$sub-DistributedActors.Cluster.Event-y)], offering membership snapshot
22:56:12 Captured log [first][2020-01-17 13:56:08.8490] [Timers.swift:163][/system/cluster/swim] [trace] Started timer [TimerKey(swim/periodic-ping)] with generation [0]
22:56:12 // metadata:
22:56:12 // "tag": timers
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8490] [Leadership.swift:136][/system/cluster/leadership] [trace] Spawned /system/cluster/leadership to run LowestAddressMember(minimumNumberOfMembersToDecide: 2, loseLeadershipIfBelowMinNrOfMembers: false)
22:56:12 Captured log [first][2020-01-17 13:56:08.8490] [Leadership.swift:259][/system/cluster/leadership] [info] Not enough members [1/2] to run election, members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)]
22:56:12 Captured log [first][2020-01-17 13:56:08.8490] [ClusterEventStream.swift:43][/system/clusterEvents] [trace] Successfully subscribed [ActorRef<Cluster.Event>(/system/cluster/leadership)], offering membership snapshot
22:56:12 Captured log [first][2020-01-17 13:56:08.8500] [ClusterShell.swift:363][/system/cluster] [info] Bound to [IPv4]127.0.0.1/127.0.0.1:9001
22:56:12 Captured log [first][2020-01-17 13:56:08.8500] [ActorShell+Children.swift:345][/system/cluster] [debug] Spawning [DistributedActors.Behavior<DistributedActors.ConvergentGossip<DistributedActors.Cluster.Gossip>.Message>.setup((Function))], on path: [/system/cluster/gossip]
22:56:12 Captured log [first][2020-01-17 13:56:08.8500] [ConvergentGossip.swift:128][/system/cluster/gossip] [trace] Schedule next gossip round in 1s
22:56:12 Captured log [first][2020-01-17 13:56:08.8500] [Timers.swift:163][/system/cluster/gossip] [trace] Started timer [TimerKey(periodic-gossip)] with generation [0]
22:56:12 // metadata:
22:56:12 // "tag": timers
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8510] [ClusterShell.swift:492][/system/cluster] [trace] Local membership version is [.happenedBefore] to incoming gossip; Merge resulted in 1 changes.
22:56:12 // metadata:
22:56:12 // "gossip/before": Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://first@localhost:9001 observed versions:
22:56:12 // ), membership: Membership(count: 0, leader: [.none], members: []))
22:56:12 // "gossip/incoming": Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://first@localhost:9001 observed versions:
22:56:12 //         uniqueNode:sact://first@localhost:9001 @ 1
22:56:12 // ), membership: Membership(count: 1, leader: [.none], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)]))
22:56:12 // "gossip/now": Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://first@localhost:9001 observed versions:
22:56:12 //         uniqueNode:sact://first@localhost:9001 @ 2
22:56:12 // ), membership: Membership(count: 1, leader: [.none], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)]))
22:56:12 // "membership/changes": ["Cluster.MembershipChange(node: sact://first@localhost:9001, replaced: [nil], fromStatus: joining, toStatus: joining)"]
22:56:12 // "tag": membership
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8510] [ConvergentGossip.swift:90][/system/cluster/gossip] [trace] Gossip payload updated: Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12     sact://first@localhost:9001 observed versions:
22:56:12         uniqueNode:sact://first@localhost:9001 @ 2
22:56:12 ), membership: Membership(count: 1, leader: [.none], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)]))
22:56:12 // metadata:
22:56:12 // "actor/message": Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://first@localhost:9001 observed versions:
22:56:12 //         uniqueNode:sact://first@localhost:9001 @ 2
22:56:12 // ), membership: Membership(count: 1, leader: [.none], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)]))
22:56:12 // "gossip/previousPayload": [nil]
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8510] [ClusterEventStream.swift:60][/system/clusterEvents] [trace] Published event membershipChange(sact://first@localhost:9001 :: [joining] -> [joining]) to 3 subscribers
22:56:12 // metadata:
22:56:12 // "eventStream/subscribers": ["/system/replicator/$sub-DistributedActors.Cluster.Event-y", "/system/nodeDeathWatcher/$sub-DistributedActors.Cluster.Event-y", "/system/cluster/leadership"]
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8510] [CRDTReplicatorShell.swift:108][/system/replicator] [trace] Ignoring cluster event membershipChange(sact://first@localhost:9001 :: [joining] -> [joining]), only interested in >= .up events
22:56:12 // metadata:
22:56:12 // "crdt/replicator": /system/replicator
22:56:12 // "crdt/replicator/remoteReplicators": []
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8520] [Leadership.swift:259][/system/cluster/leadership] [info] Not enough members [1/2] to run election, members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)]
22:56:12 Captured log [first][2020-01-17 13:56:08.8570] [ClusterShell.swift:648][/system/cluster] [info] Accept association with [sact://second:1913043227@localhost:9002]!
22:56:12 Captured log [first][2020-01-17 13:56:08.8570] [ClusterEventStream.swift:60][/system/clusterEvents] [trace] Published event membershipChange(sact://second@localhost:9002 :: [unknown] -> [joining]) to 3 subscribers
22:56:12 // metadata:
22:56:12 // "eventStream/subscribers": ["/system/replicator/$sub-DistributedActors.Cluster.Event-y", "/system/nodeDeathWatcher/$sub-DistributedActors.Cluster.Event-y", "/system/cluster/leadership"]
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8570] [ConvergentGossip.swift:90][/system/cluster/gossip] [trace] Gossip payload updated: Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12     sact://first@localhost:9001 observed versions:
22:56:12         uniqueNode:sact://first@localhost:9001 @ 3
22:56:12 ), membership: Membership(count: 2, leader: [.none], members: [Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable), Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)]))
22:56:12 // metadata:
22:56:12 // "actor/message": Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://first@localhost:9001 observed versions:
22:56:12 //         uniqueNode:sact://first@localhost:9001 @ 3
22:56:12 // ), membership: Membership(count: 2, leader: [.none], members: [Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable), Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)]))
22:56:12 // "gossip/previousPayload": [Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://first@localhost:9001 observed versions:
22:56:12 //         uniqueNode:sact://first@localhost:9001 @ 2
22:56:12 // ), membership: Membership(count: 1, leader: [.none], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)]))]
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8570] [CRDTReplicatorShell.swift:108][/system/replicator] [trace] Ignoring cluster event membershipChange(sact://second@localhost:9002 :: [unknown] -> [joining]), only interested in >= .up events
22:56:12 // metadata:
22:56:12 // "crdt/replicator": /system/replicator
22:56:12 // "crdt/replicator/remoteReplicators": []
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8580] [Leadership.swift:316][/system/cluster/leadership] [debug] Selected new leader: [[nil] -> [Member(sact://first@localhost:9001, status: joining, reachability: reachable)]]
22:56:12 // metadata:
22:56:12 // "membership": Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable), Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)])
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8580] [ConvergentGossip.swift:73][/system/cluster/gossip] [trace] Added peer: ActorRef<ConvergentGossip<DistributedActors.Cluster.Gossip>.Message>(sact://second@localhost:9002/system/cluster/gossip), total peers: [1]: [ActorRef<ConvergentGossip<DistributedActors.Cluster.Gossip>.Message>(sact://second@localhost:9002/system/cluster/gossip)]
22:56:12 Captured log [first][2020-01-17 13:56:08.8580] [ClusterShellState.swift:421][/system/cluster] [info] Leader change: LeadershipChange(oldLeader: nil, newLeader: Optional(Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)))
22:56:12 // metadata:
22:56:12 // "membership/count": 2
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8580] [ClusterShellState.swift:459][/system/cluster] [trace] Membership updated Membership sact://first@localhost:9001:
22:56:12   LEADER: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)]
22:56:12   [sact://first:3168526929@localhost:9001] STATUS: [joining]
22:56:12   [sact://second:1913043227@localhost:9002] STATUS: [joining],
22:56:12   by leadershipChange(DistributedActors.Cluster.LeadershipChange(oldLeader: nil, newLeader: Optional(Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable))))
22:56:12 Captured log [first][2020-01-17 13:56:08.8590] [ClusterShell.swift:709][/system/cluster] [info] Leader moving member: Cluster.MembershipChange(node: sact://second@localhost:9002, replaced: [nil], fromStatus: joining, toStatus: up)
22:56:12 Captured log [first][2020-01-17 13:56:08.8590] [ConvergentGossip.swift:90][/system/cluster/gossip] [trace] Gossip payload updated: Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12     sact://first@localhost:9001 observed versions:
22:56:12         uniqueNode:sact://first@localhost:9001 @ 4
22:56:12 ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable), Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)]))
22:56:12 // metadata:
22:56:12 // "actor/message": Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://first@localhost:9001 observed versions:
22:56:12 //         uniqueNode:sact://first@localhost:9001 @ 4
22:56:12 // ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable), Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)]))
22:56:12 // "gossip/previousPayload": [Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://first@localhost:9001 observed versions:
22:56:12 //         uniqueNode:sact://first@localhost:9001 @ 3
22:56:12 // ), membership: Membership(count: 2, leader: [.none], members: [Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable), Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)]))]
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8590] [ClusterShell.swift:709][/system/cluster] [info] Leader moving member: Cluster.MembershipChange(node: sact://first@localhost:9001, replaced: [nil], fromStatus: joining, toStatus: up)
22:56:12 Captured log [first][2020-01-17 13:56:08.8590] [ClusterEventStream.swift:60][/system/clusterEvents] [trace] Published event membershipChange(sact://second@localhost:9002 :: [joining] -> [     up]) to 3 subscribers
22:56:12 // metadata:
22:56:12 // "eventStream/subscribers": ["/system/replicator/$sub-DistributedActors.Cluster.Event-y", "/system/nodeDeathWatcher/$sub-DistributedActors.Cluster.Event-y", "/system/cluster/leadership"]
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8590] [ConvergentGossip.swift:90][/system/cluster/gossip] [trace] Gossip payload updated: Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12     sact://first@localhost:9001 observed versions:
22:56:12         uniqueNode:sact://first@localhost:9001 @ 4
22:56:12 ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: up, reachability: reachable, upNumber: 1), Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)]))
22:56:12 // metadata:
22:56:12 // "actor/message": Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://first@localhost:9001 observed versions:
22:56:12 //         uniqueNode:sact://first@localhost:9001 @ 4
22:56:12 // ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: up, reachability: reachable, upNumber: 1), Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)]))
22:56:12 // "gossip/previousPayload": [Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://first@localhost:9001 observed versions:
22:56:12 //         uniqueNode:sact://first@localhost:9001 @ 4
22:56:12 // ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable), Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)]))]
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8590] [ClusterEventStream.swift:60][/system/clusterEvents] [trace] Published event membershipChange(sact://first@localhost:9001 :: [joining] -> [     up]) to 3 subscribers
22:56:12 // metadata:
22:56:12 // "eventStream/subscribers": ["/system/replicator/$sub-DistributedActors.Cluster.Event-y", "/system/nodeDeathWatcher/$sub-DistributedActors.Cluster.Event-y", "/system/cluster/leadership"]
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8590] [ClusterEventStream.swift:60][/system/clusterEvents] [trace] Published event leadershipChange(DistributedActors.Cluster.LeadershipChange(oldLeader: nil, newLeader: Optional(Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)))) to 3 subscribers
22:56:12 // metadata:
22:56:12 // "eventStream/subscribers": ["/system/replicator/$sub-DistributedActors.Cluster.Event-y", "/system/nodeDeathWatcher/$sub-DistributedActors.Cluster.Event-y", "/system/cluster/leadership"]
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8600] [CRDTReplicatorShell.swift:93][/system/replicator] [trace] Skip adding member Member(sact://first@localhost:9001, status: up, reachability: reachable) to replicator because it is the same as local node
22:56:12 // metadata:
22:56:12 // "crdt/replicator": /system/replicator
22:56:12 // "crdt/replicator/remoteReplicators": [ActorRef<CRDT.Replicator.Message>(sact://second@localhost:9002/system/replicator)]
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8600] [ConvergentGossip.swift:90][/system/cluster/gossip] [trace] Gossip payload updated: Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12     sact://first@localhost:9001 observed versions:
22:56:12         uniqueNode:sact://first@localhost:9001 @ 4
22:56:12 ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: up, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: up, reachability: reachable, upNumber: 1), Member(sact://first:3168526929@localhost:9001, status: up, reachability: reachable, upNumber: 1)]))
22:56:12 // metadata:
22:56:12 // "actor/message": Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://first@localhost:9001 observed versions:
22:56:12 //         uniqueNode:sact://first@localhost:9001 @ 4
22:56:12 // ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: up, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: up, reachability: reachable, upNumber: 1), Member(sact://first:3168526929@localhost:9001, status: up, reachability: reachable, upNumber: 1)]))
22:56:12 // "gossip/previousPayload": [Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://first@localhost:9001 observed versions:
22:56:12 //         uniqueNode:sact://first@localhost:9001 @ 4
22:56:12 // ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: up, reachability: reachable, upNumber: 1), Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)]))]
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8600] [ConvergentGossip.swift:90][/system/cluster/gossip] [trace] Gossip payload updated: Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12     sact://first@localhost:9001 observed versions:
22:56:12         uniqueNode:sact://first@localhost:9001 @ 5
22:56:12 ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: up, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: up, reachability: reachable, upNumber: 1), Member(sact://first:3168526929@localhost:9001, status: up, reachability: reachable, upNumber: 1)]))
22:56:12 // metadata:
22:56:12 // "actor/message": Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://first@localhost:9001 observed versions:
22:56:12 //         uniqueNode:sact://first@localhost:9001 @ 5
22:56:12 // ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: up, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: up, reachability: reachable, upNumber: 1), Member(sact://first:3168526929@localhost:9001, status: up, reachability: reachable, upNumber: 1)]))
22:56:12 // "gossip/previousPayload": [Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://first@localhost:9001 observed versions:
22:56:12 //         uniqueNode:sact://first@localhost:9001 @ 4
22:56:12 // ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: up, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: up, reachability: reachable, upNumber: 1), Member(sact://first:3168526929@localhost:9001, status: up, reachability: reachable, upNumber: 1)]))]
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.8660] [SWIMShell.swift:424][/system/cluster/swim] [trace] Requesting handshake with sact://second@localhost:9002
22:56:12 Captured log [first][2020-01-17 13:56:08.8660] [ClusterShell.swift:557][/system/cluster] [debug] Attempted associating with already associated node: [sact://second@localhost:9002], existing association: [associated(AssociatedState(channel: SocketChannel { BaseSocket { fd=23 }, active = true, localAddress = Optional([IPv4]127.0.0.1/127.0.0.1:9001), remoteAddress = Optional([IPv4]127.0.0.1/127.0.0.1:57986) }, selfNode: sact://first@localhost:9001, remoteNode: sact://second@localhost:9002))]
22:56:12 Captured log [first][2020-01-17 13:56:08.8670] [SWIMShell.swift:145][/system/cluster/swim] [trace] Sending ping to [ActorRef<SWIM.Message>(sact://second@localhost:9002/system/cluster/swim)] with payload [membership([DistributedActors.SWIMMember(ref: ActorRef<SWIM.Message>(sact://second@localhost:9002/system/cluster/swim), status: DistributedActors.SWIM.Status.alive(incarnation: 0), protocolPeriod: 0), DistributedActors.SWIMMember(ref: ActorRef<SWIM.Message>(/system/cluster/swim), status: DistributedActors.SWIM.Status.alive(incarnation: 0), protocolPeriod: 0)])]
22:56:12 Captured log [first][2020-01-17 13:56:08.8700] [SWIMShell.swift:234][/system/cluster/swim] [trace] Received ack from [ActorRef<SWIM.Message>(sact://second@localhost:9002/system/cluster/swim)] with incarnation [0] and payload [membership([DistributedActors.SWIMMember(ref: ActorRef<SWIM.Message>(/system/cluster/swim), status: DistributedActors.SWIM.Status.alive(incarnation: 0), protocolPeriod: 0), DistributedActors.SWIMMember(ref: ActorRef<SWIM.Message>(sact://second@localhost:9002/system/cluster/swim), status: DistributedActors.SWIM.Status.alive(incarnation: 0), protocolPeriod: 0)])]
22:56:12 Captured log [first][2020-01-17 13:56:08.8700] [SWIMShell.swift:366][/system/cluster/swim] [trace] Ignoring gossip about member [sact://second:1913043227@localhost:9002], incoming: [alive(incarnation: 0)] does not supersede current: [alive(incarnation: 0)]
22:56:12 Captured log [first][2020-01-17 13:56:08.9540] [ClusterShell.swift:964][/system/cluster] [info] Cluster membership change: [sact://first@localhost:9001 :: [     up] -> [   down]], membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: down, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: up, reachability: reachable, upNumber: 1), Member(sact://first:3168526929@localhost:9001, status: down, reachability: reachable, upNumber: 1)])
22:56:12 Captured log [first][2020-01-17 13:56:08.9540] [ClusterShell.swift:971][/system/cluster] [warning] Self node was determined [.down]!
22:56:12 // metadata:
22:56:12 // "cluster/membership": Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: down, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: up, reachability: reachable, upNumber: 1), Member(sact://first:3168526929@localhost:9001, status: down, reachability: reachable, upNumber: 1)])
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.9540] [ConvergentGossip.swift:90][/system/cluster/gossip] [trace] Gossip payload updated: Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12     sact://first@localhost:9001 observed versions:
22:56:12         uniqueNode:sact://first@localhost:9001 @ 5
22:56:12 ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: down, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: up, reachability: reachable, upNumber: 1), Member(sact://first:3168526929@localhost:9001, status: down, reachability: reachable, upNumber: 1)]))
22:56:12 // metadata:
22:56:12 // "actor/message": Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://first@localhost:9001 observed versions:
22:56:12 //         uniqueNode:sact://first@localhost:9001 @ 5
22:56:12 // ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: down, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: up, reachability: reachable, upNumber: 1), Member(sact://first:3168526929@localhost:9001, status: down, reachability: reachable, upNumber: 1)]))
22:56:12 // "gossip/previousPayload": [Gossip(owner: sact://first:3168526929@localhost:9001, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://first@localhost:9001 observed versions:
22:56:12 //         uniqueNode:sact://first@localhost:9001 @ 5
22:56:12 // ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: up, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: up, reachability: reachable, upNumber: 1), Member(sact://first:3168526929@localhost:9001, status: up, reachability: reachable, upNumber: 1)]))]
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.9540] [ClusterEventStream.swift:60][/system/clusterEvents] [trace] Published event membershipChange(sact://first@localhost:9001 :: [     up] -> [   down]) to 3 subscribers
22:56:12 // metadata:
22:56:12 // "eventStream/subscribers": ["/system/replicator/$sub-DistributedActors.Cluster.Event-y", "/system/nodeDeathWatcher/$sub-DistributedActors.Cluster.Event-y", "/system/cluster/leadership"]
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.9550] [SWIMShell.swift:289][/system/cluster/swim] [trace] Confirming .dead member [sact://first:3168526929@localhost:9001]
22:56:12 Captured log [first][2020-01-17 13:56:08.9550] [SWIMShell.swift:305][/system/cluster/swim] [warning] Marked [SWIMMember(ref: ActorRef<SWIM.Message>(/system/cluster/swim), status: DistributedActors.SWIM.Status.alive(incarnation: 0), protocolPeriod: 0)] as DEAD. Node was previously alive, and now forced DEAD. Current period [0].
22:56:12 Captured log [first][2020-01-17 13:56:08.9550] [Leadership.swift:259][/system/cluster/leadership] [info] Not enough members [1/2] to run election, members: [Member(sact://second:1913043227@localhost:9002, status: up, reachability: reachable, upNumber: 1)]
22:56:12 Captured log [first][2020-01-17 13:56:08.9550] [Leadership.swift:298][/system/cluster/leadership] [trace] Removing leader [Member(sact://first@localhost:9001, status: down, reachability: reachable)], not enough members to elect new leader.
22:56:12 Captured log [first][2020-01-17 13:56:08.9560] [Timers.swift:118][/system/receptionist] [trace] Cancel timer [TimerKey(receptionist/sync)] with generation [0]
22:56:12 // metadata:
22:56:12 // "tag": timers
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.9560] [Timers.swift:118][/system/cluster/swim] [trace] Cancel timer [TimerKey(swim/periodic-ping)] with generation [0]
22:56:12 // metadata:
22:56:12 // "tag": timers
22:56:12 
22:56:12 Captured log [first][2020-01-17 13:56:08.9560] [Timers.swift:118][/system/cluster/gossip] [trace] Cancel timer [TimerKey(periodic-gossip)] with generation [0]
22:56:12 // metadata:
22:56:12 // "tag": timers
22:56:12 
22:56:12 ========================================================================================================================
22:56:12 ------------------------------------- ActorSystem(second, sact://second@localhost:9002) ------------------------------------------------
22:56:12 Captured log [second][2020-01-17 13:56:08.8500] [Timers.swift:163][/system/receptionist] [trace] Started timer [TimerKey(receptionist/sync)] with generation [0]
22:56:12 // metadata:
22:56:12 // "tag": timers
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:08.8510] [ActorShell+Children.swift:345][/system/cluster] [debug] Spawning [DistributedActors.Behavior<DistributedActors.SWIM.Message>.setup((Function))], on path: [/system/cluster/swim]
22:56:12 Captured log [second][2020-01-17 13:56:08.8510] [ActorShell+Children.swift:345][/system/cluster] [debug] Spawning [DistributedActors.Behavior<DistributedActors.Cluster.Event>.setup((Function))], on path: [/system/cluster/leadership]
22:56:12 Captured log [second][2020-01-17 13:56:08.8510] [ClusterShell.swift:352][/system/cluster] [info] Binding to: [sact://second@localhost:9002]
22:56:12 Captured log [second][2020-01-17 13:56:08.8520] [ClusterEventStream.swift:43][/system/clusterEvents] [trace] Successfully subscribed [ActorRef<Cluster.Event>(/system/replicator/$sub-DistributedActors.Cluster.Event-y)], offering membership snapshot
22:56:12 Captured log [second][2020-01-17 13:56:08.8520] [ClusterEventStream.swift:43][/system/clusterEvents] [trace] Successfully subscribed [ActorRef<Cluster.Event>(/system/nodeDeathWatcher/$sub-DistributedActors.Cluster.Event-y)], offering membership snapshot
22:56:12 Captured log [second][2020-01-17 13:56:08.8520] [Timers.swift:163][/system/cluster/swim] [trace] Started timer [TimerKey(swim/periodic-ping)] with generation [0]
22:56:12 // metadata:
22:56:12 // "tag": timers
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:08.8520] [Leadership.swift:136][/system/cluster/leadership] [trace] Spawned /system/cluster/leadership to run LowestAddressMember(minimumNumberOfMembersToDecide: 2, loseLeadershipIfBelowMinNrOfMembers: false)
22:56:12 Captured log [second][2020-01-17 13:56:08.8520] [Leadership.swift:259][/system/cluster/leadership] [info] Not enough members [1/2] to run election, members: [Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)]
22:56:12 Captured log [second][2020-01-17 13:56:08.8520] [ClusterEventStream.swift:43][/system/clusterEvents] [trace] Successfully subscribed [ActorRef<Cluster.Event>(/system/cluster/leadership)], offering membership snapshot
22:56:12 Captured log [second][2020-01-17 13:56:08.8530] [ClusterShell.swift:363][/system/cluster] [info] Bound to [IPv4]127.0.0.1/127.0.0.1:9002
22:56:12 Captured log [second][2020-01-17 13:56:08.8530] [ActorShell+Children.swift:345][/system/cluster] [debug] Spawning [DistributedActors.Behavior<DistributedActors.ConvergentGossip<DistributedActors.Cluster.Gossip>.Message>.setup((Function))], on path: [/system/cluster/gossip]
22:56:12 Captured log [second][2020-01-17 13:56:08.8530] [ConvergentGossip.swift:128][/system/cluster/gossip] [trace] Schedule next gossip round in 1s
22:56:12 Captured log [second][2020-01-17 13:56:08.8530] [Timers.swift:163][/system/cluster/gossip] [trace] Started timer [TimerKey(periodic-gossip)] with generation [0]
22:56:12 // metadata:
22:56:12 // "tag": timers
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:08.8540] [ConvergentGossip.swift:90][/system/cluster/gossip] [trace] Gossip payload updated: Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12     sact://second@localhost:9002 observed versions:
22:56:12         uniqueNode:sact://second@localhost:9002 @ 2
22:56:12 ), membership: Membership(count: 1, leader: [.none], members: [Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)]))
22:56:12 // metadata:
22:56:12 // "actor/message": Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://second@localhost:9002 observed versions:
22:56:12 //         uniqueNode:sact://second@localhost:9002 @ 2
22:56:12 // ), membership: Membership(count: 1, leader: [.none], members: [Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)]))
22:56:12 // "gossip/previousPayload": [nil]
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:08.8540] [ClusterShell.swift:492][/system/cluster] [trace] Local membership version is [.happenedBefore] to incoming gossip; Merge resulted in 1 changes.
22:56:12 // metadata:
22:56:12 // "gossip/before": Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://second@localhost:9002 observed versions:
22:56:12 // ), membership: Membership(count: 0, leader: [.none], members: []))
22:56:12 // "gossip/incoming": Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://second@localhost:9002 observed versions:
22:56:12 //         uniqueNode:sact://second@localhost:9002 @ 1
22:56:12 // ), membership: Membership(count: 1, leader: [.none], members: [Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)]))
22:56:12 // "gossip/now": Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://second@localhost:9002 observed versions:
22:56:12 //         uniqueNode:sact://second@localhost:9002 @ 2
22:56:12 // ), membership: Membership(count: 1, leader: [.none], members: [Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)]))
22:56:12 // "membership/changes": ["Cluster.MembershipChange(node: sact://second@localhost:9002, replaced: [nil], fromStatus: joining, toStatus: joining)"]
22:56:12 // "tag": membership
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:08.8540] [ClusterShell.swift:605][/system/cluster] [info] Extending handshake offer to sact://first@localhost:9001)
22:56:12 Captured log [second][2020-01-17 13:56:08.8540] [ClusterEventStream.swift:60][/system/clusterEvents] [trace] Published event membershipChange(sact://second@localhost:9002 :: [joining] -> [joining]) to 3 subscribers
22:56:12 // metadata:
22:56:12 // "eventStream/subscribers": ["/system/replicator/$sub-DistributedActors.Cluster.Event-y", "/system/nodeDeathWatcher/$sub-DistributedActors.Cluster.Event-y", "/system/cluster/leadership"]
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:08.8540] [CRDTReplicatorShell.swift:108][/system/replicator] [trace] Ignoring cluster event membershipChange(sact://second@localhost:9002 :: [joining] -> [joining]), only interested in >= .up events
22:56:12 // metadata:
22:56:12 // "crdt/replicator": /system/replicator
22:56:12 // "crdt/replicator/remoteReplicators": []
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:08.8540] [Leadership.swift:259][/system/cluster/leadership] [info] Not enough members [1/2] to run election, members: [Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)]
22:56:12 Captured log [second][2020-01-17 13:56:08.8610] [ClusterShell.swift:779][/system/cluster] [debug] Associated with: [sact://first:3168526929@localhost:9001]; Membership change: Cluster.MembershipChange(node: sact://first@localhost:9001, replaced: [nil], fromStatus: nil, toStatus: joining), resulting in: Membership(count: 2, leader: [.none], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable), Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)])
22:56:12 Captured log [second][2020-01-17 13:56:08.8610] [ConvergentGossip.swift:90][/system/cluster/gossip] [trace] Gossip payload updated: Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12     sact://second@localhost:9002 observed versions:
22:56:12         uniqueNode:sact://second@localhost:9002 @ 3
22:56:12 ), membership: Membership(count: 2, leader: [.none], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable), Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)]))
22:56:12 // metadata:
22:56:12 // "actor/message": Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://second@localhost:9002 observed versions:
22:56:12 //         uniqueNode:sact://second@localhost:9002 @ 3
22:56:12 // ), membership: Membership(count: 2, leader: [.none], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable), Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)]))
22:56:12 // "gossip/previousPayload": [Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://second@localhost:9002 observed versions:
22:56:12 //         uniqueNode:sact://second@localhost:9002 @ 2
22:56:12 // ), membership: Membership(count: 1, leader: [.none], members: [Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)]))]
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:08.8610] [ClusterEventStream.swift:60][/system/clusterEvents] [trace] Published event membershipChange(sact://first@localhost:9001 :: [unknown] -> [joining]) to 3 subscribers
22:56:12 // metadata:
22:56:12 // "eventStream/subscribers": ["/system/replicator/$sub-DistributedActors.Cluster.Event-y", "/system/nodeDeathWatcher/$sub-DistributedActors.Cluster.Event-y", "/system/cluster/leadership"]
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:08.8610] [CRDTReplicatorShell.swift:108][/system/replicator] [trace] Ignoring cluster event membershipChange(sact://first@localhost:9001 :: [unknown] -> [joining]), only interested in >= .up events
22:56:12 // metadata:
22:56:12 // "crdt/replicator": /system/replicator
22:56:12 // "crdt/replicator/remoteReplicators": []
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:08.8620] [Leadership.swift:316][/system/cluster/leadership] [debug] Selected new leader: [[nil] -> [Member(sact://first@localhost:9001, status: joining, reachability: reachable)]]
22:56:12 // metadata:
22:56:12 // "membership": Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)], members: [Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable), Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)])
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:08.8620] [ConvergentGossip.swift:73][/system/cluster/gossip] [trace] Added peer: ActorRef<ConvergentGossip<DistributedActors.Cluster.Gossip>.Message>(sact://first@localhost:9001/system/cluster/gossip), total peers: [1]: [ActorRef<ConvergentGossip<DistributedActors.Cluster.Gossip>.Message>(sact://first@localhost:9001/system/cluster/gossip)]
22:56:12 Captured log [second][2020-01-17 13:56:08.8620] [ClusterShellState.swift:421][/system/cluster] [info] Leader change: LeadershipChange(oldLeader: nil, newLeader: Optional(Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)))
22:56:12 // metadata:
22:56:12 // "membership/count": 2
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:08.8630] [ClusterShellState.swift:459][/system/cluster] [trace] Membership updated Membership sact://second@localhost:9002:
22:56:12   LEADER: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)]
22:56:12   [sact://first:3168526929@localhost:9001] STATUS: [joining]
22:56:12   [sact://second:1913043227@localhost:9002] STATUS: [joining],
22:56:12   by leadershipChange(DistributedActors.Cluster.LeadershipChange(oldLeader: nil, newLeader: Optional(Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable))))
22:56:12 Captured log [second][2020-01-17 13:56:08.8630] [ConvergentGossip.swift:90][/system/cluster/gossip] [trace] Gossip payload updated: Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12     sact://second@localhost:9002 observed versions:
22:56:12         uniqueNode:sact://second@localhost:9002 @ 4
22:56:12 ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable), Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)]))
22:56:12 // metadata:
22:56:12 // "actor/message": Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://second@localhost:9002 observed versions:
22:56:12 //         uniqueNode:sact://second@localhost:9002 @ 4
22:56:12 // ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable), Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)]))
22:56:12 // "gossip/previousPayload": [Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://second@localhost:9002 observed versions:
22:56:12 //         uniqueNode:sact://second@localhost:9002 @ 3
22:56:12 // ), membership: Membership(count: 2, leader: [.none], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable), Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)]))]
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:08.8630] [ConvergentGossip.swift:90][/system/cluster/gossip] [trace] Gossip payload updated: Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12     sact://second@localhost:9002 observed versions:
22:56:12         uniqueNode:sact://second@localhost:9002 @ 5
22:56:12 ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable), Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)]))
22:56:12 // metadata:
22:56:12 // "actor/message": Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://second@localhost:9002 observed versions:
22:56:12 //         uniqueNode:sact://second@localhost:9002 @ 5
22:56:12 // ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable), Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)]))
22:56:12 // "gossip/previousPayload": [Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://second@localhost:9002 observed versions:
22:56:12 //         uniqueNode:sact://second@localhost:9002 @ 4
22:56:12 // ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable), Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)]))]
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:08.8640] [ClusterEventStream.swift:60][/system/clusterEvents] [trace] Published event leadershipChange(DistributedActors.Cluster.LeadershipChange(oldLeader: nil, newLeader: Optional(Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable)))) to 3 subscribers
22:56:12 // metadata:
22:56:12 // "eventStream/subscribers": ["/system/replicator/$sub-DistributedActors.Cluster.Event-y", "/system/nodeDeathWatcher/$sub-DistributedActors.Cluster.Event-y", "/system/cluster/leadership"]
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:08.8640] [ClusterShell.swift:907][/system/cluster] [debug] Associated sact://first@localhost:9001, informing SWIM to monitor this node.
22:56:12 Captured log [second][2020-01-17 13:56:08.8640] [SWIMShell.swift:145][/system/cluster/swim] [trace] Sending ping to [ActorRef<SWIM.Message>(sact://first@localhost:9001/system/cluster/swim)] with payload [membership([DistributedActors.SWIMMember(ref: ActorRef<SWIM.Message>(/system/cluster/swim), status: DistributedActors.SWIM.Status.alive(incarnation: 0), protocolPeriod: 0)])]
22:56:12 Captured log [second][2020-01-17 13:56:08.8680] [SWIMShell.swift:234][/system/cluster/swim] [trace] Received ack from [ActorRef<SWIM.Message>(sact://first@localhost:9001/system/cluster/swim)] with incarnation [0] and payload [membership([DistributedActors.SWIMMember(ref: ActorRef<SWIM.Message>(sact://first@localhost:9001/system/cluster/swim), status: DistributedActors.SWIM.Status.alive(incarnation: 0), protocolPeriod: 0)])]
22:56:12 Captured log [second][2020-01-17 13:56:08.8680] [SWIMShell.swift:366][/system/cluster/swim] [trace] Ignoring gossip about member [sact://first:3168526929@localhost:9001], incoming: [alive(incarnation: 0)] does not supersede current: [alive(incarnation: 0)]
22:56:12 Captured log [second][2020-01-17 13:56:08.8690] [SWIMShell.swift:366][/system/cluster/swim] [trace] Ignoring gossip about member [sact://first:3168526929@localhost:9001], incoming: [alive(incarnation: 0)] does not supersede current: [alive(incarnation: 0)]
22:56:12 Captured log [second][2020-01-17 13:56:08.9570] [ConvergentGossip.swift:61][/system/cluster/gossip] [trace] Peer terminated: sact://first@localhost:9001/system/cluster/gossip, will not gossip to it anymore
22:56:12 Captured log [second][2020-01-17 13:56:09.8520] [SWIMShell.swift:259][/system/cluster/swim] [trace] Received periodic trigger to ping random member, among: 2
22:56:12 // metadata:
22:56:12 // "swim/incarnation": 0
22:56:12 // "swim/memberCount": 2
22:56:12 // "swim/protocolPeriod": 0
22:56:12 // "swim/suspectCount": 0
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:09.8530] [Timers.swift:118][/system/cluster/gossip] [trace] Cancel timer [TimerKey(periodic-gossip)] with generation [0]
22:56:12 // metadata:
22:56:12 // "tag": timers
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:09.8540] [ConvergentGossip.swift:112][/system/cluster/gossip] [trace] Sending gossip to []
22:56:12 // metadata:
22:56:12 // "actor/message": GossipEnvelope(payload: DistributedActors.Cluster.Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://second@localhost:9002 observed versions:
22:56:12 //         uniqueNode:sact://second@localhost:9002 @ 5
22:56:12 // ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable), Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)])))
22:56:12 // "gossip/peers": []
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:09.8540] [ConvergentGossip.swift:128][/system/cluster/gossip] [trace] Schedule next gossip round in 1s
22:56:12 Captured log [second][2020-01-17 13:56:09.8540] [Timers.swift:163][/system/cluster/gossip] [trace] Started timer [TimerKey(periodic-gossip)] with generation [1]
22:56:12 // metadata:
22:56:12 // "tag": timers
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:10.8530] [SWIMShell.swift:259][/system/cluster/swim] [trace] Received periodic trigger to ping random member, among: 2
22:56:12 // metadata:
22:56:12 // "swim/incarnation": 0
22:56:12 // "swim/memberCount": 2
22:56:12 // "swim/protocolPeriod": 1
22:56:12 // "swim/suspectCount": 0
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:10.8540] [Timers.swift:118][/system/cluster/gossip] [trace] Cancel timer [TimerKey(periodic-gossip)] with generation [1]
22:56:12 // metadata:
22:56:12 // "tag": timers
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:10.8540] [ConvergentGossip.swift:112][/system/cluster/gossip] [trace] Sending gossip to []
22:56:12 // metadata:
22:56:12 // "actor/message": GossipEnvelope(payload: DistributedActors.Cluster.Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://second@localhost:9002 observed versions:
22:56:12 //         uniqueNode:sact://second@localhost:9002 @ 5
22:56:12 // ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable), Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)])))
22:56:12 // "gossip/peers": []
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:10.8540] [ConvergentGossip.swift:128][/system/cluster/gossip] [trace] Schedule next gossip round in 1s
22:56:12 Captured log [second][2020-01-17 13:56:10.8540] [Timers.swift:163][/system/cluster/gossip] [trace] Started timer [TimerKey(periodic-gossip)] with generation [2]
22:56:12 // metadata:
22:56:12 // "tag": timers
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:11.8530] [SWIMShell.swift:259][/system/cluster/swim] [trace] Received periodic trigger to ping random member, among: 2
22:56:12 // metadata:
22:56:12 // "swim/incarnation": 0
22:56:12 // "swim/memberCount": 2
22:56:12 // "swim/protocolPeriod": 2
22:56:12 // "swim/suspectCount": 0
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:11.8550] [Timers.swift:118][/system/cluster/gossip] [trace] Cancel timer [TimerKey(periodic-gossip)] with generation [2]
22:56:12 // metadata:
22:56:12 // "tag": timers
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:11.8550] [ConvergentGossip.swift:112][/system/cluster/gossip] [trace] Sending gossip to []
22:56:12 // metadata:
22:56:12 // "actor/message": GossipEnvelope(payload: DistributedActors.Cluster.Gossip(owner: sact://second:1913043227@localhost:9002, seen: Cluster.Gossip.SeenTable(
22:56:12 //     sact://second@localhost:9002 observed versions:
22:56:12 //         uniqueNode:sact://second@localhost:9002 @ 5
22:56:12 // ), membership: Membership(count: 2, leader: [Member(sact://first@localhost:9001, status: joining, reachability: reachable)], members: [Member(sact://first:3168526929@localhost:9001, status: joining, reachability: reachable), Member(sact://second:1913043227@localhost:9002, status: joining, reachability: reachable)])))
22:56:12 // "gossip/peers": []
22:56:12 
22:56:12 Captured log [second][2020-01-17 13:56:11.8550] [ConvergentGossip.swift:128][/system/cluster/gossip] [trace] Schedule next gossip round in 1s
22:56:12 Captured log [second][2020-01-17 13:56:11.8550] [Timers.swift:163][/system/cluster/gossip] [trace] Started timer [TimerKey(periodic-gossip)] with generation [3]
22:56:12 // metadata:
22:56:12 // "tag": timers
22:56:12 
22:56:12 ========================================================================================================================
22:56:12 Test Case 'ClusterAssociationTests.test_down_self_shouldChangeMembershipSelfToBeDown' failed (3.285 seconds)
22:56:12 Test Suite 'ClusterAssociationTests' failed at 2020-01-17 13:56:12.132

Metadata

Metadata

Assignees

Labels

failed 💥Failed tickets are CI or benchmarking failures, should be investigated as soon as possiblet:cluster:all

Type

No type

Projects

No projects

Relationships

None yet

Development

No branches or pull requests

Issue actions