From ac05caf009c9d88737613b440d63f66b9ea07eb3 Mon Sep 17 00:00:00 2001 From: Dan Ballard Date: Thu, 16 Dec 2021 19:07:08 -0500 Subject: [PATCH] change locking on engine.ephermeralServices; logify integ test; delete unused events --- event/common.go | 60 --------- peer/cwtch_peer.go | 2 +- protocol/connections/engine.go | 44 ++++--- testing/cwtch_peer_server_integration_test.go | 115 +++++++++--------- 4 files changed, 86 insertions(+), 135 deletions(-) diff --git a/event/common.go b/event/common.go index 6eb7d62..e8a51b0 100644 --- a/event/common.go +++ b/event/common.go @@ -55,10 +55,6 @@ const ( // GroupID: groupID (allows them to fetch from the peer) NewGroup = Type("NewGroup") - // GroupID - AcceptGroupInvite = Type("AcceptGroupInvite") - RejectGroupInvite = Type("RejectGroupInvite") - SendMessageToGroup = Type("SendMessagetoGroup") //Ciphertext, Signature: @@ -111,12 +107,6 @@ const ( // RemotePeer: The peer associated with the acknowledgement IndexedFailure = Type("IndexedFailure") - // UpdateMessageFlags will change the flags associated with a given message. - // Handle - // Message Index - // Flags - UpdateMessageFlags = Type("UpdateMessageFlags") - // attributes: // RemotePeer: [eg "chpr7qm6op5vfcg2pi4vllco3h6aa7exexc4rqwnlupqhoogx2zgd6qd"] // Error: string describing the error @@ -132,12 +122,6 @@ const ( // Password, NewPassword ChangePassword = Type("ChangePassword") - // Error(err), EventID - ChangePasswordError = Type("ChangePasswordError") - - // EventID - ChangePasswordSuccess = Type("ChangePasswordSuccess") - // a group has been successfully added or newly created // attributes: // Data [serialized *model.Group] @@ -149,26 +133,6 @@ const ( // GroupID DeleteGroup = Type("DeleteGroup") - // request to store a profile-wide attribute (good for e.g. per-profile settings like theme prefs) - // attributes: - // Key [eg "fontcolor"] - // Data [eg "red"] - SetAttribute = Type("SetAttribute") - - // request to store a per-contact attribute (e.g. display names for a peer) - // attributes: - // RemotePeer [eg ""] - // Key [eg "nick"] - // Data [eg "erinn"] - SetPeerAttribute = Type("SetPeerAttribute") - - // request to store a per-cwtch-group attribute (e.g. display name for a group) - // attributes: - // GroupID [eg ""] - // Key [eg "nick"] - // Data [eg "open privacy board"] - SetGroupAttribute = Type("SetGroupAttribute") - // PeerStateChange servers as a new incoming connection message as well, and can/is consumed by frontends to alert of new p2p connections // RemotePeer // ConnectionState @@ -180,9 +144,6 @@ const ( /***** Application client / service messages *****/ - // ProfileName, Password, Data(tag) - CreatePeer = Type("CreatePeer") - // app: Identity(onion), Created(bool) // service -> client: Identity(localId), Password, [Status(new/default=blank || from reload='running')], Created(bool) NewPeer = Type("NewPeer") @@ -192,20 +153,6 @@ const ( // Identity(onion) PeerDeleted = Type("PeerDeleted") - // Identity(onion), Data(pluginID) - AddPeerPlugin = Type("AddPeerPlugin") - - // Password - LoadProfiles = Type("LoadProfiles") - - // Client has reloaded, triggers NewPeer s then ReloadDone - ReloadClient = Type("ReloadClient") - - ReloadDone = Type("ReloadDone") - - // Identity - Ask service to resend all connection states - ReloadPeer = Type("ReloadPeer") - // Identity(onion) ShutdownPeer = Type("ShutdownPeer") @@ -218,9 +165,6 @@ const ( // Error(err) AppError = Type("AppError") - GetACNStatus = Type("GetACNStatus") - GetACNVersion = Type("GetACNVersion") - // Progress, Status ACNStatus = Type("ACNStatus") @@ -233,10 +177,6 @@ const ( // Onion: the local onion we attempt to check NetworkStatus = Type("NetworkError") - // Notify the UI that a Server has been added - // Onion = Server Onion - ServerCreated = Type("ServerAdded") - // For debugging. Allows test to emit a Syn and get a response Ack(eventID) when the subsystem is done processing a queue Syn = Type("Syn") Ack = Type("Ack") diff --git a/peer/cwtch_peer.go b/peer/cwtch_peer.go index 48e775c..f394fc5 100644 --- a/peer/cwtch_peer.go +++ b/peer/cwtch_peer.go @@ -434,7 +434,7 @@ func (cp *cwtchPeer) ImportGroup(exportedInvite string) (int, error) { cp.SetConversationAttribute(groupConversationID, attr.LocalScope.ConstructScopedZonedPath(attr.LegacyGroupZone.ConstructZonedPath(constants.GroupServer)), gci.ServerHost) cp.SetConversationAttribute(groupConversationID, attr.LocalScope.ConstructScopedZonedPath(attr.LegacyGroupZone.ConstructZonedPath(constants.GroupKey)), base64.StdEncoding.EncodeToString(gci.SharedKey)) cp.SetConversationAttribute(groupConversationID, attr.LocalScope.ConstructScopedZonedPath(attr.ProfileZone.ConstructZonedPath(constants.Name)), gci.GroupName) - cp.eventBus.Publish(event.NewEvent(event.NewGroup, map[event.Field]string{event.ConversationID: strconv.Itoa(groupConversationID), event.GroupServer: gci.ServerHost, event.GroupInvite: exportedInvite})) + cp.eventBus.Publish(event.NewEvent(event.NewGroup, map[event.Field]string{event.ConversationID: strconv.Itoa(groupConversationID), event.GroupServer: gci.ServerHost, event.GroupInvite: exportedInvite, event.GroupName: gci.GroupName})) cp.JoinServer(gci.ServerHost) } return groupConversationID, err diff --git a/protocol/connections/engine.go b/protocol/connections/engine.go index 58cc446..b8d9885 100644 --- a/protocol/connections/engine.go +++ b/protocol/connections/engine.go @@ -46,7 +46,8 @@ type engine struct { getValRequests sync.Map // [string]string eventID:Data // Nextgen Tapir Service - ephemeralServices sync.Map // string(onion) => tapir.Service + ephemeralServices map[string]tapir.Service //sync.Map // string(onion) => tapir.Service + ephemeralServicesLock sync.Mutex // Required for listen(), inaccessible from identity privateKey ed25519.PrivateKey @@ -72,6 +73,7 @@ func NewProtocolEngine(identity primitives.Identity, privateKey ed25519.PrivateK engine := new(engine) engine.identity = identity engine.privateKey = privateKey + engine.ephemeralServices = make(map[string]tapir.Service) engine.queue = event.NewQueue() go engine.eventHandler() @@ -150,7 +152,9 @@ func (e *engine) eventHandler() { } go e.peerWithTokenServer(ev.Data[event.GroupServer], ev.Data[event.ServerTokenOnion], ev.Data[event.ServerTokenY], signature) case event.LeaveServer: + e.ephemeralServicesLock.Lock() e.leaveServer(ev.Data[event.GroupServer]) + e.ephemeralServicesLock.Unlock() case event.DeleteContact: onion := ev.Data[event.RemotePeer] // We remove this peer from out blocklist which will prevent them from contacting us if we have "block unknown peers" turned on. @@ -275,14 +279,12 @@ func (e *engine) Shutdown() { e.shuttingDown = true e.service.Shutdown() - e.ephemeralServices.Range(func(_, service interface{}) bool { - connection, ok := service.(*tor.BaseOnionService) - if ok { - log.Infof("shutting down ephemeral service") - connection.Shutdown() - } - return true - }) + e.ephemeralServicesLock.Lock() + defer e.ephemeralServicesLock.Unlock() + for _, connection := range e.ephemeralServices { + log.Infof("shutting down ephemeral service") + connection.Shutdown() + } e.queue.Shutdown() } @@ -316,10 +318,10 @@ func (e *engine) peerWithOnion(onion string) { // peerWithTokenServer is the entry point for cwtchPeer - server relationships // needs to be run in a goroutine as will block on Open. func (e *engine) peerWithTokenServer(onion string, tokenServerOnion string, tokenServerY string, lastKnownSignature []byte) { - - service, exists := e.ephemeralServices.Load(onion) + e.ephemeralServicesLock.Lock() + defer e.ephemeralServicesLock.Unlock() + connection, exists := e.ephemeralServices[onion] if exists { - connection := service.(*tor.BaseOnionService) if conn, err := connection.GetConnection(onion); err == nil { // We are already peered and synced so return... // This will only not-trigger it lastKnownSignature has been wiped, which only happens when ResyncServer is called @@ -343,7 +345,7 @@ func (e *engine) peerWithTokenServer(onion string, tokenServerOnion string, toke Y := ristretto255.NewElement() Y.UnmarshalText([]byte(tokenServerY)) connected, err := ephemeralService.Connect(onion, NewTokenBoardClient(e.acn, Y, tokenServerOnion, lastKnownSignature, e.receiveGroupMessage, e.serverAuthed, e.serverSynced, e.ignoreOnShutdown(e.serverDisconnected))) - e.ephemeralServices.Store(onion, ephemeralService) + e.ephemeralServices[onion] = ephemeralService // If we are already connected...check if we are authed and issue an auth event // (This allows the ui to be stateless) if connected && err != nil { @@ -486,7 +488,6 @@ func (e *engine) receiveGroupMessage(server string, gm *groups.EncryptedGroupMes // sendMessageToGroup attempts to sent the given message to the given group id. func (e *engine) sendMessageToGroup(groupID string, server string, ct []byte, sig []byte, attempts int) { - // sending to groups can fail for a few reasons (slow server, not enough tokens, etc.) // rather than trying to keep all that logic in method we simply back-off and try again // but if we fail more than 5 times then we report back to the client so they can investigate other options. @@ -498,12 +499,14 @@ func (e *engine) sendMessageToGroup(groupID string, server string, ct []byte, si return } - es, ok := e.ephemeralServices.Load(server) - if es == nil || !ok { + e.ephemeralServicesLock.Lock() + ephemeralService, ok := e.ephemeralServices[server] + e.ephemeralServicesLock.Unlock() + + if ephemeralService == nil || !ok { e.eventManager.Publish(event.NewEvent(event.SendMessageToGroupError, map[event.Field]string{event.GroupID: groupID, event.GroupServer: server, event.Error: "server-not-found", event.Signature: base64.StdEncoding.EncodeToString(sig)})) return } - ephemeralService := es.(tapir.Service) conn, err := ephemeralService.WaitForCapabilityOrClose(server, groups.CwtchServerSyncedCapability) if err == nil { @@ -615,12 +618,15 @@ func (e *engine) handlePeerRetVal(hostname string, getValData, retValData []byte e.eventManager.Publish(event.NewEventList(event.NewRetValMessageFromPeer, event.RemotePeer, hostname, event.Scope, getVal.Scope, event.Path, getVal.Path, event.Exists, strconv.FormatBool(retVal.Exists), event.Data, retVal.Val)) } +// leaveServer disconnects from a server and deletes the ephemeral service +// REQUIREMENTS: must be called inside a block with e.ephemeralServicesLock.Lock() +// can't do it iself because is called from inside peerWithTokenServer which holds the lock func (e *engine) leaveServer(server string) { - es, ok := e.ephemeralServices.Load(server) + es, ok := e.ephemeralServices[server] if ok { ephemeralService := es.(tapir.Service) ephemeralService.Shutdown() - e.ephemeralServices.Delete(server) + delete(e.ephemeralServices, server) } } diff --git a/testing/cwtch_peer_server_integration_test.go b/testing/cwtch_peer_server_integration_test.go index dddff4f..7d0a525 100644 --- a/testing/cwtch_peer_server_integration_test.go +++ b/testing/cwtch_peer_server_integration_test.go @@ -13,7 +13,6 @@ import ( "cwtch.im/cwtch/protocol/connections" "encoding/base64" "encoding/json" - "fmt" "git.openprivacy.ca/openprivacy/connectivity/tor" "git.openprivacy.ca/openprivacy/log" _ "github.com/mutecomm/go-sqlcipher/v4" @@ -36,18 +35,18 @@ var ( func waitForConnection(t *testing.T, peer peer.CwtchPeer, addr string, target connections.ConnectionState) { peerName, _ := peer.GetScopedZonedAttribute(attr.LocalScope, attr.ProfileZone, constants.Name) for { - fmt.Printf("%v checking connection...\n", peerName) + log.Infof("%v checking connection...\n", peerName) state := peer.GetPeerState(addr) - fmt.Printf("Waiting for Peer %v to %v - state: %v\n", peerName, addr, state) + log.Infof("Waiting for Peer %v to %v - state: %v\n", peerName, addr, state) if state == connections.FAILED { t.Fatalf("%v could not connect to %v", peer.GetOnion(), addr) } if state != target { - fmt.Printf("peer %v %v waiting connect %v, currently: %v\n", peerName, peer.GetOnion(), addr, connections.ConnectionStateName[state]) + log.Infof("peer %v %v waiting connect %v, currently: %v\n", peerName, peer.GetOnion(), addr, connections.ConnectionStateName[state]) time.Sleep(time.Second * 5) continue } else { - fmt.Printf("peer %v %v CONNECTED to %v\n", peerName, peer.GetOnion(), addr) + log.Infof("peer %v %v CONNECTED to %v\n", peerName, peer.GetOnion(), addr) break } } @@ -106,41 +105,41 @@ func TestCwtchPeerIntegration(t *testing.T) { // ***** cwtchPeer setup ***** - fmt.Println("Creating Alice...") + log.Infoln("Creating Alice...") app.CreateTaggedPeer("Alice", "asdfasdf", "test") - fmt.Println("Creating Bob...") + log.Infoln("Creating Bob...") app.CreateTaggedPeer("Bob", "asdfasdf", "test") - fmt.Println("Creating Carol...") + log.Infoln("Creating Carol...") app.CreateTaggedPeer("Carol", "asdfasdf", "test") alice := utils.WaitGetPeer(app, "Alice") - fmt.Println("Alice created:", alice.GetOnion()) + log.Infoln("Alice created:", alice.GetOnion()) alice.SetScopedZonedAttribute(attr.PublicScope, attr.ProfileZone, constants.Name, "Alice") alice.AutoHandleEvents([]event.Type{event.PeerStateChange, event.ServerStateChange, event.NewGroupInvite, event.NewRetValMessageFromPeer}) bob := utils.WaitGetPeer(app, "Bob") - fmt.Println("Bob created:", bob.GetOnion()) + log.Infoln("Bob created:", bob.GetOnion()) bob.SetScopedZonedAttribute(attr.PublicScope, attr.ProfileZone, constants.Name, "Bob") bob.AutoHandleEvents([]event.Type{event.PeerStateChange, event.ServerStateChange, event.NewGroupInvite, event.NewRetValMessageFromPeer}) carol := utils.WaitGetPeer(app, "Carol") - fmt.Println("Carol created:", carol.GetOnion()) + log.Infoln("Carol created:", carol.GetOnion()) carol.SetScopedZonedAttribute(attr.PublicScope, attr.ProfileZone, constants.Name, "Carol") carol.AutoHandleEvents([]event.Type{event.PeerStateChange, event.ServerStateChange, event.NewGroupInvite, event.NewRetValMessageFromPeer}) app.LaunchPeers() waitTime := time.Duration(60) * time.Second - t.Logf("** Waiting for Alice, Bob, and Carol to connect with onion network... (%v)\n", waitTime) + log.Infof("** Waiting for Alice, Bob, and Carol to connect with onion network... (%v)\n", waitTime) time.Sleep(waitTime) numGoRoutinesPostPeerStart := runtime.NumGoroutine() - fmt.Println("** Wait Done!") + log.Infof("** Wait Done!") // ***** Peering, server joining, group creation / invite ***** - fmt.Println("Alice peering with Bob...") + log.Infoln("Alice peering with Bob...") // Simulate Alice Adding Bob alice2bobConversationID, err := alice.NewContactConversation(bob.GetOnion(), model.DefaultP2PAccessControl(), true) if err != nil { @@ -151,7 +150,7 @@ func TestCwtchPeerIntegration(t *testing.T) { t.Fatalf("error adding conversaiton %v", bob2aliceConversationID) } - t.Logf("Alice peering with Carol...") + log.Infof("Alice peering with Carol...") // Simulate Alice Adding Carol alice2carolConversationID, err := alice.NewContactConversation(carol.GetOnion(), model.DefaultP2PAccessControl(), true) if err != nil { @@ -170,7 +169,7 @@ func TestCwtchPeerIntegration(t *testing.T) { waitForConnection(t, bob, alice.GetOnion(), connections.AUTHENTICATED) waitForConnection(t, carol, alice.GetOnion(), connections.AUTHENTICATED) - t.Logf("Alice and Bob getVal public.name...") + log.Infof("Alice and Bob getVal public.name...") alice.SendScopedZonedGetValToContact(alice2bobConversationID, attr.PublicScope, attr.ProfileZone, constants.Name) bob.SendScopedZonedGetValToContact(bob2aliceConversationID, attr.PublicScope, attr.ProfileZone, constants.Name) @@ -186,13 +185,13 @@ func TestCwtchPeerIntegration(t *testing.T) { if err != nil || aliceName != "Alice" { t.Fatalf("Bob: alice GetKeyVal error on alice peer.name %v: %v\n", aliceName, err) } - fmt.Printf("Bob has alice's name as '%v'\n", aliceName) + log.Infof("Bob has alice's name as '%v'\n", aliceName) bobName, err := alice.GetConversationAttribute(alice2bobConversationID, attr.PublicScope.ConstructScopedZonedPath(attr.ProfileZone.ConstructZonedPath(constants.Name))) if err != nil || bobName != "Bob" { t.Fatalf("Alice: bob GetKeyVal error on bob peer.name %v: %v \n", bobName, err) } - fmt.Printf("Alice has bob's name as '%v'\n", bobName) + log.Infof("Alice has bob's name as '%v'\n", bobName) aliceName, err = carol.GetConversationAttribute(carol2aliceConversationID, attr.PublicScope.ConstructScopedZonedPath(attr.ProfileZone.ConstructZonedPath(constants.Name))) if err != nil || aliceName != "Alice" { @@ -203,37 +202,33 @@ func TestCwtchPeerIntegration(t *testing.T) { if err != nil || carolName != "Carol" { t.Fatalf("alice GetKeyVal error, carol peer.name: %v: %v\n", carolName, err) } - fmt.Printf("Alice has carol's name as '%v'\n", carolName) + log.Infof("Alice has carol's name as '%v'\n", carolName) // Group Testing // Simulate Alice Creating a Group - fmt.Println("Alice joining server...") + log.Infoln("Alice joining server...") if _, err := alice.AddServer(string(serverKeyBundle)); err != nil { t.Fatalf("Failed to Add Server Bundle %v", err) } - bob.AddServer(string(serverKeyBundle)) + // Ading here will require resync carol.AddServer(string(serverKeyBundle)) - t.Logf("Waiting for alice to join server...") - err = alice.JoinServer(ServerAddr) - if err != nil { - t.Fatalf("alice cannot join server %v %v", ServerAddr, err) - } + log.Infof("Waiting for alice to join server...") waitForConnection(t, alice, ServerAddr, connections.SYNCED) // Creating a Group - t.Logf("Creating group on %v...", ServerAddr) + log.Infof("Creating group on %v...", ServerAddr) aliceGroupConversationID, err := alice.StartGroup("Our Cool Testing Group", ServerAddr) - t.Logf("Created group: %v!\n", aliceGroupConversationID) + log.Infof("Created group: %v!\n", aliceGroupConversationID) if err != nil { t.Errorf("Failed to init group: %v", err) return } // Invites - fmt.Println("Alice inviting Bob to group...") + log.Infoln("Alice inviting Bob to group...") err = alice.SendInviteToConversation(alice2bobConversationID, aliceGroupConversationID) if err != nil { t.Fatalf("Error for Alice inviting Bob to group: %v", err) @@ -242,25 +237,22 @@ func TestCwtchPeerIntegration(t *testing.T) { // Alice invites Bob to the Group... message, _, err := bob.GetChannelMessage(bob2aliceConversationID, 0, 1) - t.Logf("Alice message to Bob %v %v", message, err) + log.Infof("Alice message to Bob %v %v", message, err) var overlayMessage model.MessageWrapper json.Unmarshal([]byte(message), &overlayMessage) - t.Logf("Parsed Overlay Message: %v", overlayMessage) + log.Infof("Parsed Overlay Message: %v", overlayMessage) err = bob.ImportBundle(overlayMessage.Data) - t.Logf("Result of Bob Importing the Bundle from Alice: %v", err) + log.Infof("Result of Bob Importing the Bundle from Alice: %v", err) - t.Logf("Waiting for Bob to join connect to group server...") - err = bob.JoinServer(ServerAddr) // for some unrealism we skip "discovering the server from the event bus - if err != nil { - t.Fatalf("alice cannot join server %v %v", ServerAddr, err) - } + log.Infof("Waiting for Bob to join connect to group server...") + time.Sleep(2 * time.Second) bobGroupConversationID := 3 waitForConnection(t, bob, ServerAddr, connections.SYNCED) numGoRoutinesPostServerConnect := runtime.NumGoroutine() // ***** Conversation ***** - t.Logf("Starting conversation in group...") + log.Infof("Starting conversation in group...") checkSendMessageToGroup(t, alice, aliceGroupConversationID, aliceLines[0]) checkSendMessageToGroup(t, bob, bobGroupConversationID, bobLines[0]) checkSendMessageToGroup(t, alice, aliceGroupConversationID, aliceLines[1]) @@ -268,23 +260,25 @@ func TestCwtchPeerIntegration(t *testing.T) { // Alice invites Bob to the Group... message, _, err = carol.GetChannelMessage(carol2aliceConversationID, 0, 1) - t.Logf("Alice message to Carol %v %v", message, err) + log.Infof("Alice message to Carol %v %v", message, err) json.Unmarshal([]byte(message), &overlayMessage) - t.Logf("Parsed Overlay Message: %v", overlayMessage) + log.Infof("Parsed Overlay Message: %v", overlayMessage) err = carol.ImportBundle(overlayMessage.Data) - t.Logf("Result of Carol Importing the Bundle from Alice: %v", err) + log.Infof("Result of Carol Importing the Bundle from Alice: %v", err) - t.Logf("Waiting for Carol to join connect to group server...") - err = carol.JoinServer(ServerAddr) // for some unrealism we skip "discovering the server from the event bus - if err != nil { - t.Fatalf("carol cannot join server %v %v", ServerAddr, err) - } + log.Infof("Waiting for Carol to join connect to group server...") + carol.ResyncServer(ServerAddr) + time.Sleep(2 * time.Second) carolGroupConversationID := 3 waitForConnection(t, carol, ServerAddr, connections.SYNCED) numGoRoutinesPostCarolConnect := runtime.NumGoroutine() - t.Logf("Shutting down Alice...") + messages, err := alice.GetMostRecentMessages(aliceGroupConversationID, 0, 0, 20) + log.Infof("Alice messages") + for i, msg := range messages { + log.Infof("alice message %v: %v", i, msg) + } // Check Alice Timeline checkMessage(t, alice, aliceGroupConversationID, 1, aliceLines[0]) @@ -292,6 +286,7 @@ func TestCwtchPeerIntegration(t *testing.T) { checkMessage(t, alice, aliceGroupConversationID, 3, aliceLines[1]) checkMessage(t, alice, aliceGroupConversationID, 4, bobLines[1]) + log.Infof("Shutting down Alice...") app.ShutdownPeer(alice.GetOnion()) time.Sleep(time.Second * 3) numGoRoutinesPostAlice := runtime.NumGoroutine() @@ -300,6 +295,11 @@ func TestCwtchPeerIntegration(t *testing.T) { checkSendMessageToGroup(t, bob, bobGroupConversationID, bobLines[2]) time.Sleep(time.Second * 30) + messages, err = bob.GetMostRecentMessages(aliceGroupConversationID, 0, 0, 20) + log.Infof("Bob messages") + for i, msg := range messages { + log.Infof("bob message %v: %v", i, msg) + } // Check Bob Timeline checkMessage(t, bob, bobGroupConversationID, 1, aliceLines[0]) checkMessage(t, bob, bobGroupConversationID, 2, bobLines[0]) @@ -309,6 +309,11 @@ func TestCwtchPeerIntegration(t *testing.T) { checkMessage(t, bob, bobGroupConversationID, 6, bobLines[2]) // Check Carol Timeline + messages, err = carol.GetMostRecentMessages(aliceGroupConversationID, 0, 0, 20) + log.Infof("Carol messages") + for i, msg := range messages { + log.Infof("carol message %v: %v", i, msg) + } checkMessage(t, carol, carolGroupConversationID, 1, aliceLines[0]) checkMessage(t, carol, carolGroupConversationID, 2, bobLines[0]) checkMessage(t, carol, carolGroupConversationID, 3, aliceLines[1]) @@ -316,25 +321,25 @@ func TestCwtchPeerIntegration(t *testing.T) { checkMessage(t, carol, carolGroupConversationID, 5, carolLines[0]) checkMessage(t, carol, carolGroupConversationID, 6, bobLines[2]) - t.Logf("Shutting down Bob...") + log.Infof("Shutting down Bob...") app.ShutdownPeer(bob.GetOnion()) time.Sleep(time.Second * 3) numGoRoutinesPostBob := runtime.NumGoroutine() - t.Logf("Shutting down Carol...") + log.Infof("Shutting down Carol...") app.ShutdownPeer(carol.GetOnion()) time.Sleep(time.Second * 3) numGoRoutinesPostCarol := runtime.NumGoroutine() - t.Logf("Shutting down apps...") - fmt.Printf("app Shutdown: %v\n", runtime.NumGoroutine()) + log.Infof("Shutting down apps...") + log.Infof("app Shutdown: %v\n", runtime.NumGoroutine()) app.Shutdown() time.Sleep(2 * time.Second) - t.Logf("Done shutdown: %v\n", runtime.NumGoroutine()) + log.Infof("Done shutdown: %v\n", runtime.NumGoroutine()) - t.Logf("Shutting down ACN...") + log.Infof("Shutting down ACN...") acn.Restart() // kill all active tor connections... // acn.Close() TODO: ACN Now gets closed automatically with defer...attempting to close twice results in a dead lock... time.Sleep(time.Second * 30) // the network status plugin might keep goroutines alive for a minute before killing them @@ -345,7 +350,7 @@ func TestCwtchPeerIntegration(t *testing.T) { // Very useful if we are leaking any. pprof.Lookup("goroutine").WriteTo(os.Stdout, 1) - t.Logf("numGoRoutinesStart: %v\nnumGoRoutinesPostAppStart: %v\nnumGoRoutinesPostPeerStart: %v\nnumGoRoutinesPostPeerAndServerConnect: %v\n"+ + log.Infof("numGoRoutinesStart: %v\nnumGoRoutinesPostAppStart: %v\nnumGoRoutinesPostPeerStart: %v\nnumGoRoutinesPostPeerAndServerConnect: %v\n"+ "numGoRoutinesPostAlice: %v\nnumGoRoutinesPostCarolConnect: %v\nnumGoRoutinesPostBob: %v\nnumGoRoutinesPostCarol: %v\nnumGoRoutinesPostAppShutdown: %v", numGoRoutinesStart, numGoRoutinesPostAppStart, numGoRoutinesPostPeerStart, numGoRoutinesPostServerConnect, numGoRoutinesPostAlice, numGoRoutinesPostCarolConnect, numGoRoutinesPostBob, numGoRoutinesPostCarol, numGoRoutinesPostAppShutdown) @@ -359,7 +364,7 @@ func TestCwtchPeerIntegration(t *testing.T) { // Utility function for sending a message from a peer to a group func checkSendMessageToGroup(t *testing.T, profile peer.CwtchPeer, id int, message string) { name, _ := profile.GetScopedZonedAttribute(attr.PublicScope, attr.ProfileZone, constants.Name) - t.Logf("%v> %v\n", name, message) + log.Infof("%v> %v\n", name, message) err := profile.SendMessage(id, message) if err != nil { t.Fatalf("Alice failed to send a message to the group: %v", err)