cwtch/testing/cwtch_peer_server_integration_test.go

package testing

import (
	"crypto/rand"
	app2 "cwtch.im/cwtch/app"
	"cwtch.im/cwtch/app/utils"
	"cwtch.im/cwtch/event"
	"cwtch.im/cwtch/model"
	"cwtch.im/cwtch/model/attr"
	"cwtch.im/cwtch/model/constants"
	"cwtch.im/cwtch/peer"
	"cwtch.im/cwtch/protocol/connections"
	"encoding/base64"
	"encoding/json"
	"fmt"
	"git.openprivacy.ca/openprivacy/connectivity/tor"
	"git.openprivacy.ca/openprivacy/log"
	mrand "math/rand"
	"os"
	"os/user"
	"path"
	"runtime"
	"runtime/pprof"
	"testing"
	"time"
)

var (
	aliceLines = []string{"Hello, I'm Alice", "bye"}
	bobLines   = []string{"Hi, my name is Bob.", "toodles", "welcome"}
	carolLines = []string{"Howdy, thanks!"}
)

func printAndCountVerifedTimeline(t *testing.T, timeline []model.Message) int {
	numVerified := 0
	for _, message := range timeline {
		fmt.Printf("%v %v> %s\n", message.Timestamp, message.PeerID, message.Message)
		numVerified++
	}
	return numVerified
}

func waitForPeerGroupConnection(t *testing.T, peer peer.CwtchPeer, serverAddr string) {
	peerName, _ := peer.GetScopedZonedAttribute(attr.LocalScope, attr.ProfileZone, constants.Name)
	for {
		fmt.Printf("%v checking group connection...\n", peerName)
		state, ok := peer.GetPeerState(serverAddr)
		if ok {
			fmt.Printf("Waiting for Peer %v to join group %v - state: %v\n", peerName, serverAddr, state)
			if state == connections.FAILED {
				t.Fatalf("%v could not connect to %v", peer.GetOnion(), serverAddr)
			}
			if state != connections.SYNCED {
				fmt.Printf("peer %v  %v waiting connect to group %v, currently: %v\n", peerName, peer.GetOnion(), serverAddr, connections.ConnectionStateName[state])
				time.Sleep(time.Second * 5)
				continue
			} else {
				fmt.Printf("peer %v  %v CONNECTED to group %v\n", peerName, peer.GetOnion(), serverAddr)
				break
			}
		}
		time.Sleep(time.Second * 2)
	}
	return
}

func waitForPeerPeerConnection(t *testing.T, peera peer.CwtchPeer, peerb peer.CwtchPeer) {
	for {
		state, ok := peera.GetPeerState(peerb.GetOnion())
		if ok {
			//log.Infof("Waiting for Peer %v to peer with peer: %v - state: %v\n", peera.GetProfile().Name, peerb.GetProfile().Name, state)
			if state == connections.FAILED {
				t.Fatalf("%v could not connect to %v", peera.GetOnion(), peerb.GetOnion())
			}
			if state != connections.AUTHENTICATED {
				fmt.Printf("peer %v waiting connect to peer %v, currently: %v\n", peera.GetOnion(), peerb.GetOnion(), connections.ConnectionStateName[state])
				time.Sleep(time.Second * 5)
				continue
			} else {
				peerAName, _ := peera.GetScopedZonedAttribute(attr.LocalScope, attr.ProfileZone, constants.Name)
				peerBName, _ := peerb.GetScopedZonedAttribute(attr.LocalScope, attr.ProfileZone, constants.Name)
				fmt.Printf("%v CONNECTED and AUTHED to %v\n", peerAName, peerBName)
				break
			}
		}
	}
	return
}

func TestCwtchPeerIntegration(t *testing.T) {
	numGoRoutinesStart := runtime.NumGoroutine()

	log.AddEverythingFromPattern("connectivity")
	log.SetLevel(log.LevelDebug)
	log.ExcludeFromPattern("connection/connection")
	log.ExcludeFromPattern("outbound/3dhauthchannel")
	log.ExcludeFromPattern("event/eventmanager")
	log.ExcludeFromPattern("tapir")
	os.Mkdir("tordir", 0700)
	dataDir := path.Join("tordir", "tor")
	os.MkdirAll(dataDir, 0700)

	// we don't need real randomness for the port, just to avoid a possible conflict...
	mrand.Seed(int64(time.Now().Nanosecond()))
	socksPort := mrand.Intn(1000) + 9051
	controlPort := mrand.Intn(1000) + 9052

	// generate a random password
	key := make([]byte, 64)
	_, err := rand.Read(key)
	if err != nil {
		panic(err)
	}

	tor.NewTorrc().WithSocksPort(socksPort).WithOnionTrafficOnly().WithHashedPassword(base64.StdEncoding.EncodeToString(key)).WithControlPort(controlPort).Build("tordir/tor/torrc")
	acn, err := tor.NewTorACNWithAuth("./tordir", path.Join("..", "tor"), controlPort, tor.HashedPasswordAuthenticator{Password: base64.StdEncoding.EncodeToString(key)})
	if err != nil {
		t.Fatalf("Could not start Tor: %v", err)
	}
	pid, _ := acn.GetPID()
	t.Logf("Tor pid: %v", pid)
	acn.WaitTillBootstrapped()
	defer acn.Close()
	// ***** Cwtch Server management *****

	const ServerKeyBundleBase64 = "eyJLZXlzIjp7ImJ1bGxldGluX2JvYXJkX29uaW9uIjoibmZoeHp2enhpbnJpcGdkaDR0Mm00eGN5M2NyZjZwNGNiaGVjdGdja3VqM2lkc2pzYW90Z293YWQiLCJwcml2YWN5X3Bhc3NfcHVibGljX2tleSI6IjVwd2hQRGJ0c0EvdFI3ZHlUVUkzakpZZnM1L3Jaai9iQ1ZWZEpTc0Jtbk09IiwidG9rZW5fc2VydmljZV9vbmlvbiI6ImVvd25mcTRsNTZxMmU0NWs0bW03MjdsanJod3Z0aDZ5ZWN0dWV1bXB4emJ5cWxnbXVhZm1qdXFkIn0sIlNpZ25hdHVyZSI6IlY5R3NPMHNZWFJ1bGZxdzdmbGdtclVxSTBXS0JlSFIzNjIvR3hGbWZPekpEZjJaRks2ck9jNVRRR1ZxVWIrbXIwV2xId0pwdXh0UW1JRU9KNkplYkNRPT0ifQ=="
	const ServerAddr = "nfhxzvzxinripgdh4t2m4xcy3crf6p4cbhectgckuj3idsjsaotgowad"
	serverKeyBundle, _ := base64.StdEncoding.DecodeString(ServerKeyBundleBase64)

	app := app2.NewApp(acn, "./storage")

	usr, _ := user.Current()
	cwtchDir := path.Join(usr.HomeDir, ".cwtch")
	os.Mkdir(cwtchDir, 0700)
	os.RemoveAll(path.Join(cwtchDir, "testing"))
	os.Mkdir(path.Join(cwtchDir, "testing"), 0700)

	numGoRoutinesPostAppStart := runtime.NumGoroutine()

	// ***** cwtchPeer setup *****

	fmt.Println("Creating Alice...")
	app.CreateTaggedPeer("Alice", "asdfasdf", "test")

	fmt.Println("Creating Bob...")
	app.CreateTaggedPeer("Bob", "asdfasdf", "test")

	fmt.Println("Creating Carol...")
	app.CreateTaggedPeer("Carol", "asdfasdf", "test")

	alice := utils.WaitGetPeer(app, "Alice")
	fmt.Println("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())
	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())
	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)
	time.Sleep(waitTime)
	numGoRoutinesPostPeerStart := runtime.NumGoroutine()
	fmt.Println("** Wait Done!")

	// ***** Peering, server joining, group creation / invite *****

	fmt.Println("Alice peering with Bob...")
	// Simulate Alice Adding Bob
	alice2bobConversationID, err := alice.NewContactConversation(bob.GetOnion(), model.DefaultP2PAccessControl(), true)
	if err != nil {
		t.Fatalf("error adding conversaiton %v", alice2bobConversationID)
	}
	alice.PeerWithOnion(bob.GetOnion())

	fmt.Println("Alice peering with Carol...")
	// Simulate Alice Adding Carol
	alice2carolConversationID, err := alice.NewContactConversation(carol.GetOnion(), model.DefaultP2PAccessControl(), true)
	if err != nil {
		t.Fatalf("error adding conversaiton %v", alice2carolConversationID)
	}
	alice.PeerWithOnion(carol.GetOnion())

	// Simulate Alice Creating a Group
	fmt.Println("Alice joining server...")
	if err := alice.AddServer(string(serverKeyBundle)); err != nil {
		t.Fatalf("Failed to Add Server Bundle %v", err)
	}
	err = alice.JoinServer(ServerAddr)
	if err != nil {
		t.Fatalf("alice cannot join server %v %v", ServerAddr, err)
	}

	fmt.Println("Creating group on ", ServerAddr, "...")
	aliceGroupConversationID, err := alice.StartGroup("Our Cool Testing Group", ServerAddr)
	fmt.Printf("Created group: %v!\n", aliceGroupConversationID)
	if err != nil {
		t.Errorf("Failed to init group: %v", err)
		return
	}

	fmt.Println("Waiting for alice to join server...")

	waitForPeerGroupConnection(t, alice, ServerAddr)

	fmt.Println("Waiting for alice and Bob to peer...")
	waitForPeerPeerConnection(t, alice, bob)
	// Need to add contact else SetContactAuth fails on peer peer doesnt exist
	// Normal flow would be Bob app monitors for the new connection (a new connection state change to Auth
	//   and the adds the user to peer, and then approves or blocks it
	// Simulate Bob adding Alice
	bob2aliceConversationID, err := bob.NewContactConversation(alice.GetOnion(), model.DefaultP2PAccessControl(), true)
	if err != nil {
		t.Fatalf("error adding conversaiton %v", bob2aliceConversationID)
	}
	bob.AddServer(string(serverKeyBundle))

	waitForPeerPeerConnection(t, alice, carol)
	// Simulate Carol adding Alice
	carol2aliceConversationID, err := carol.NewContactConversation(alice.GetOnion(), model.DefaultP2PAccessControl(), true)
	if err != nil {
		t.Fatalf("error adding conversaiton %v", carol2aliceConversationID)
	}
	carol.AddServer(string(serverKeyBundle))

	fmt.Println("Alice and Bob getVal public.name...")

	alice.SendScopedZonedGetValToContact(bob.GetOnion(), attr.PublicScope, attr.ProfileZone, constants.Name)
	bob.SendScopedZonedGetValToContact(alice.GetOnion(), attr.PublicScope, attr.ProfileZone, constants.Name)

	alice.SendScopedZonedGetValToContact(carol.GetOnion(), attr.PublicScope, attr.ProfileZone, constants.Name)
	carol.SendScopedZonedGetValToContact(alice.GetOnion(), attr.PublicScope, attr.ProfileZone, constants.Name)

	// This used to be 10, but increasing it to 30 because this is now causing frequent issues
	// Probably related to latency/throughput problems in the underlying tor network.
	time.Sleep(30 * time.Second)

	aliceName, err := bob.GetConversationAttribute(bob2aliceConversationID, attr.PublicScope.ConstructScopedZonedPath(attr.ProfileZone.ConstructZonedPath(constants.Name)))
	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)

	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)

	aliceName, err = carol.GetConversationAttribute(carol2aliceConversationID, attr.PublicScope.ConstructScopedZonedPath(attr.ProfileZone.ConstructZonedPath(constants.Name)))
	if err != nil || aliceName != "Alice" {
		t.Fatalf("carol GetKeyVal error for alice peer.name %v: %v\n", aliceName, err)
	}

	carolName, err := alice.GetConversationAttribute(alice2carolConversationID, attr.PublicScope.ConstructScopedZonedPath(attr.ProfileZone.ConstructZonedPath(constants.Name)))
	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)

	fmt.Println("Alice inviting Bob to group...")
	err = alice.SendInviteToConversation(alice2bobConversationID, aliceGroupConversationID)
	if err != nil {
		t.Fatalf("Error for Alice inviting Bob to group: %v", err)
	}

	time.Sleep(time.Second * 5)

	// Alice invites Bob to the Group...
	message, _, err := alice.GetChannelMessage(alice2bobConversationID, 0, 1)
	t.Logf("Alice message from Bob %v %v", message, err)
	var overlayMessage model.MessageWrapper
	json.Unmarshal([]byte(message), &overlayMessage)
	t.Logf("Parsed Overlay Message: %v", overlayMessage)
	err = bob.ImportBundle(overlayMessage.Data)
	t.Logf("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)
	}
	bobGroupConversationID := 3
	waitForPeerGroupConnection(t, bob, ServerAddr)

	numGoRoutinesPostServerConnect := runtime.NumGoroutine()

	// ***** Conversation *****
	t.Logf("Starting conversation in group...")
	checkSendMessageToGroup(t, alice, aliceGroupConversationID, aliceLines[0])
	checkSendMessageToGroup(t, bob, bobGroupConversationID, bobLines[0])
	checkSendMessageToGroup(t, alice, aliceGroupConversationID, aliceLines[1])
	checkSendMessageToGroup(t, bob, bobGroupConversationID, bobLines[1])

	//fmt.Println("Alice inviting Carol to group...")
	//err = alice.InviteOnionToGroup(carol.GetOnion(), groupID)
	//if err != nil {
	//	t.Fatalf("Error for Alice inviting Carol to group: %v", err)
	//}
	//time.Sleep(time.Second * 60) // Account for some token acquisition in Alice and Bob flows.
	//fmt.Println("Carol examining groups and accepting invites...")
	//for _, message := range carol.GetContact(alice.GetOnion()).Timeline.GetMessages() {
	//	fmt.Printf("Found message from Alice: %v", message.Message)
	//	if strings.HasPrefix(message.Message, "torv3") {
	//		gid, err := carol.ImportGroup(message.Message)
	//		if err == nil {
	//			fmt.Printf("Carol found invite...now accepting %v...", gid)
	//			carol.AcceptInvite(gid)
	//		} else {
	//			t.Fatalf("Carol could not accept invite...%v", gid)
	//		}
	//	}
	//}
	//
	//fmt.Println("Shutting down Alice...")
	//app.ShutdownPeer(alice.GetOnion())
	//time.Sleep(time.Second * 5)
	numGoRoutinesPostAlice := runtime.NumGoroutine()
	//
	//fmt.Println("Carol joining server...")
	//carol.JoinServer(ServerAddr)
	//waitForPeerGroupConnection(t, carol, groupID)
	numGoRoutinesPostCarolConnect := runtime.NumGoroutine()
	//
	//fmt.Printf("%v> %v", bobName, bobLines[2])
	//bob.SendMessage(groupID, bobLines[2])
	//// Bob should have enough tokens so we don't need to account for
	//// token acquisition here...
	//
	//fmt.Printf("%v> %v", carolName, carolLines[0])
	//carol.SendMessage(groupID, carolLines[0])
	//time.Sleep(time.Second * 30) // we need to account for spam-based token acquisition, but everything should
	//// be warmed-up and delays should be pretty small.
	//
	//// ***** Verify Test *****
	//
	//fmt.Println("Final syncing time...")
	//time.Sleep(time.Second * 30)
	//
	//alicesGroup := alice.GetGroup(groupID)
	//if alicesGroup == nil {
	//	t.Error("aliceGroup == nil")
	//	return
	//}
	//
	//fmt.Printf("Alice's TimeLine:\n")
	//aliceVerified := printAndCountVerifedTimeline(t, alicesGroup.GetTimeline())
	//if aliceVerified != 4 {
	//	t.Errorf("Alice did not have 4 verified messages")
	//}
	//
	//bobsGroup := bob.GetGroup(groupID)
	//if bobsGroup == nil {
	//	t.Error("bobGroup == nil")
	//	return
	//}
	//fmt.Printf("Bob's TimeLine:\n")
	//bobVerified := printAndCountVerifedTimeline(t, bobsGroup.GetTimeline())
	//if bobVerified != 6 {
	//	t.Errorf("Bob did not have 6 verified messages")
	//}
	//
	//carolsGroup := carol.GetGroup(groupID)
	//fmt.Printf("Carol's TimeLine:\n")
	//carolVerified := printAndCountVerifedTimeline(t, carolsGroup.GetTimeline())
	//if carolVerified != 6 {
	//	t.Errorf("Carol did not have 6 verified messages")
	//}
	//
	//if len(alicesGroup.GetTimeline()) != 4 {
	//	t.Errorf("Alice's timeline does not have all messages")
	//} else {
	//	// check message 0,1,2,3
	//	alicesGroup.Timeline.Sort()
	//	aliceGroupTimeline := alicesGroup.GetTimeline()
	//	if aliceGroupTimeline[0].Message != aliceLines[0] || aliceGroupTimeline[1].Message != bobLines[0] ||
	//		aliceGroupTimeline[2].Message != aliceLines[1] || aliceGroupTimeline[3].Message != bobLines[1] {
	//		t.Errorf("Some of Alice's timeline messages did not have the expected content!")
	//	}

	checkMessage(t, alice, aliceGroupConversationID, 1, aliceLines[0])
	checkMessage(t, alice, aliceGroupConversationID, 2, bobLines[0])
	checkMessage(t, alice, aliceGroupConversationID, 3, aliceLines[1])
	checkMessage(t, alice, aliceGroupConversationID, 4, bobLines[1])

	time.Sleep(time.Second * 30)

	checkMessage(t, bob, bobGroupConversationID, 1, aliceLines[0])
	checkMessage(t, bob, bobGroupConversationID, 2, bobLines[0])
	checkMessage(t, bob, bobGroupConversationID, 3, aliceLines[1])
	checkMessage(t, bob, bobGroupConversationID, 4, bobLines[1])

	//}
	//
	//if len(bobsGroup.GetTimeline()) != 6 {
	//	t.Errorf("Bob's timeline does not have all messages")
	//} else {
	//	// check message 0,1,2,3,4,5
	//	bobsGroup.Timeline.Sort()
	//	bobGroupTimeline := bobsGroup.GetTimeline()
	//	if bobGroupTimeline[0].Message != aliceLines[0] || bobGroupTimeline[1].Message != bobLines[0] ||
	//		bobGroupTimeline[2].Message != aliceLines[1] || bobGroupTimeline[3].Message != bobLines[1] ||
	//		bobGroupTimeline[4].Message != bobLines[2] || bobGroupTimeline[5].Message != carolLines[0] {
	//		t.Errorf("Some of Bob's timeline messages did not have the expected content!")
	//	}
	//}
	//
	//if len(carolsGroup.GetTimeline()) != 6 {
	//	t.Errorf("Carol's timeline does not have all messages")
	//} else {
	//	// check message 0,1,2,3,4,5
	//	carolsGroup.Timeline.Sort()
	//	carolGroupTimeline := carolsGroup.GetTimeline()
	//	if carolGroupTimeline[0].Message != aliceLines[0] || carolGroupTimeline[1].Message != bobLines[0] ||
	//		carolGroupTimeline[2].Message != aliceLines[1] || carolGroupTimeline[3].Message != bobLines[1] ||
	//		carolGroupTimeline[4].Message != carolLines[0] || carolGroupTimeline[5].Message != bobLines[2] {
	//		t.Errorf("Some of Carol's timeline messages did not have the expected content!")
	//	}
	//}

	fmt.Println("Shutting down Bob...")
	app.ShutdownPeer(bob.GetOnion())
	time.Sleep(time.Second * 3)
	numGoRoutinesPostBob := runtime.NumGoroutine()

	fmt.Println("Shutting down Carol...")
	app.ShutdownPeer(carol.GetOnion())
	time.Sleep(time.Second * 3)
	numGoRoutinesPostCarol := runtime.NumGoroutine()

	fmt.Println("Shutting down apps...")
	fmt.Printf("app Shutdown: %v\n", runtime.NumGoroutine())
	app.Shutdown()

	time.Sleep(2 * time.Second)

	fmt.Printf("Done shutdown: %v\n", runtime.NumGoroutine())
	numGoRoutinesPostAppShutdown := runtime.NumGoroutine()

	fmt.Println("Shutting down ACN...")
	// acn.Close() TODO: ACN Now gets closed automatically with defer...attempting to close twice results in a dead lock...
	time.Sleep(time.Second * 2)  // Server ^^ has a 5 second loop attempting reconnect before exiting
	time.Sleep(time.Second * 30) // the network status plugin might keep goroutines alive for a minute before killing them
	numGoRoutinesPostACN := runtime.NumGoroutine()

	// Printing out the current goroutines
	// Very useful if we are leaking any.
	pprof.Lookup("goroutine").WriteTo(os.Stdout, 1)

	fmt.Printf("numGoRoutinesStart: %v\nnumGoRoutinesPostAppStart: %v\nnumGoRoutinesPostPeerStart: %v\nnumGoRoutinesPostPeerAndServerConnect: %v\n"+
		"numGoRoutinesPostAlice: %v\nnumGoRoutinesPostCarolConnect: %v\nnumGoRoutinesPostBob: %v\nnumGoRoutinesPostCarol: %v\nnumGoRoutinesPostAppShutdown: %v\nnumGoRoutinesPostACN: %v\n",
		numGoRoutinesStart, numGoRoutinesPostAppStart, numGoRoutinesPostPeerStart, numGoRoutinesPostServerConnect,
		numGoRoutinesPostAlice, numGoRoutinesPostCarolConnect, numGoRoutinesPostBob, numGoRoutinesPostCarol, numGoRoutinesPostAppShutdown, numGoRoutinesPostACN)

	if numGoRoutinesStart != numGoRoutinesPostACN {
		t.Errorf("Number of GoRoutines at start (%v) does not match number of goRoutines after cleanup of peers and servers (%v), clean up failed, leak detected!", numGoRoutinesStart, numGoRoutinesPostACN)
	}

}

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)
	err := profile.SendMessage(id, message)
	if err != nil {
		t.Fatalf("Alice failed to send a message to the group: %v", err)
	}
	time.Sleep(time.Second * 10)
}

func checkMessage(t *testing.T, profile peer.CwtchPeer, id int, messageID int, expected string) {
	message, _, err := profile.GetChannelMessage(id, 0, messageID)
	if err != nil {
		t.Fatalf("unexpected message %v expected: %v got error: %v", profile.GetOnion(), expected, err)
	}
	if message != expected {
		t.Fatalf("unexpected message %v expected: %v got: [%v]", profile.GetOnion(), expected, message)
	}
}