Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Improve logging #327

Merged
merged 1 commit into from
Aug 29, 2022
Merged

Improve logging #327

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 5 additions & 4 deletions poc-cb-net/cmd/admin-web/admin-web.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -318,13 +318,13 @@ func getExistingNetworkInfo(etcdClient *clientv3.Client) error {

// Get all peers
CBLogger.Debugf("Get - %v", etcdkey.Peer)
resp, etcdErr := etcdClient.Get(context.Background(), etcdkey.Peer, clientv3.WithPrefix())
CBLogger.Tracef("etcdResp: %v", resp)
getResp, etcdErr := etcdClient.Get(context.Background(), etcdkey.Peer, clientv3.WithPrefix())
if etcdErr != nil {
CBLogger.Error(etcdErr)
}
CBLogger.Tracef("GetResponse: %#v", getResp)

for _, kv := range resp.Kvs {
for _, kv := range getResp.Kvs {
CBLogger.Tracef("CLADNet ID: %v", kv.Key)
CBLogger.Tracef("A peer of the CLADNet: %v", kv.Value)
CBLogger.Debug("Send a peer of CLADNet to admin-web frontend")
Expand All @@ -341,7 +341,7 @@ func getExistingNetworkInfo(etcdClient *clientv3.Client) error {

}

if resp.Count == 0 {
if getResp.Count == 0 {
CBLogger.Debug("no networking rule of CLADNet exists")
}

Expand All @@ -352,6 +352,7 @@ func getExistingNetworkInfo(etcdClient *clientv3.Client) error {
CBLogger.Error(err)
return err
}
CBLogger.Tracef("GetResponse: %#v", respMultiSpec)

if len(respMultiSpec.Kvs) != 0 {
var cladnetSpecificationList []string
Expand Down
49 changes: 31 additions & 18 deletions poc-cb-net/cmd/agent/agent.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -324,11 +324,14 @@ func checkConnectivity(data string, etcdClient *clientv3.Client) {
// Put the network status of the CLADNet to the etcd
// Key: /registry/cloud-adaptive-network/status/information/{cladnet-id}/{host-id}
keyStatusInformation := fmt.Sprint(etcdkey.StatusInformation + "/" + cladnetID + "/" + hostID)
CBLogger.Debugf("Put - %v", keyStatusInformation)

strNetworkStatus, _ := json.Marshal(networkStatus)
_, err := etcdClient.Put(context.Background(), keyStatusInformation, string(strNetworkStatus))
putResp, err := etcdClient.Put(context.Background(), keyStatusInformation, string(strNetworkStatus))
if err != nil {
CBLogger.Error(err)
}
CBLogger.Tracef("PutResponse: %#v", putResp)

CBLogger.Debug("End.........")
}
Expand Down Expand Up @@ -383,10 +386,13 @@ func initializeAgent(etcdClient *clientv3.Client) {
CBLogger.Trace(currentHostNetworkInformation)

keyHostNetworkInformation := fmt.Sprint(etcdkey.HostNetworkInformation + "/" + cladnetID + "/" + hostID)
CBLogger.Debugf("Put - %v", keyHostNetworkInformation)

if _, err := etcdClient.Put(context.TODO(), keyHostNetworkInformation, currentHostNetworkInformation); err != nil {
putResp, err := etcdClient.Put(context.TODO(), keyHostNetworkInformation, currentHostNetworkInformation)
if err != nil {
CBLogger.Error(err)
}
CBLogger.Tracef("PutResponse: %#v", putResp)

CBLogger.Debug("End.........")
}
Expand All @@ -399,12 +405,14 @@ func updatePeerState(state string, etcdClient *clientv3.Client) {

keyPeer := fmt.Sprint(etcdkey.Peer + "/" + CBNet.CLADNetID + "/" + CBNet.HostID)

CBLogger.Debugf("Put \"%v\"", keyPeer)
CBLogger.Debugf("Put - %v", keyPeer)
doc, _ := json.Marshal(tempPeer)

if _, err := etcdClient.Put(context.TODO(), keyPeer, string(doc)); err != nil {
putResp, err := etcdClient.Put(context.TODO(), keyPeer, string(doc))
if err != nil {
CBLogger.Error(err)
}
CBLogger.Debugf("PutResponse: %#v", putResp)

CBLogger.Debug("End.........")
}
Expand Down Expand Up @@ -449,22 +457,24 @@ func initializeSecret(etcdClient *clientv3.Client) {

// Acquire lock (or wait to have it)
CBLogger.Debug("Acquire a lock")
// Time trying to acquire a lock
start := time.Now()
if err := lock.Lock(ctx); err != nil {
CBLogger.Error(err)
}
CBLogger.Tracef("Acquired lock for '%s'", keyPrefix)
CBLogger.Tracef("Lock acquired for '%s'", keyPrefix)

// Get the secret
keySecret := fmt.Sprint(etcdkey.Secret + "/" + cladnetID)
CBLogger.Debugf("Get - %v", keySecret)
resp, etcdErr := etcdClient.Get(context.TODO(), keySecret, clientv3.WithPrefix())
CBLogger.Tracef("GetResponse: %v", resp)
getResp, etcdErr := etcdClient.Get(context.TODO(), keySecret, clientv3.WithPrefix())
CBLogger.Tracef("GetResponse: %#v", getResp)
if etcdErr != nil {
CBLogger.Error(etcdErr)
}

// Set the other hosts' secrets
for _, kv := range resp.Kvs {
for _, kv := range getResp.Kvs {
// Key
key := string(kv.Key)
CBLogger.Tracef("Key: %v", key)
Expand Down Expand Up @@ -505,7 +515,10 @@ func initializeSecret(etcdClient *clientv3.Client) {
if err := lock.Unlock(ctx); err != nil {
CBLogger.Error(err)
}
CBLogger.Tracef("Released lock for '%s'", keyPrefix)
CBLogger.Tracef("Lock released for '%s'", keyPrefix)
// Elapsed time from the time trying to acquire a lock
elapsed := time.Since(start)
CBLogger.Tracef("Elapsed time for locking: %s", elapsed)

CBLogger.Debug("End.........")
}
Expand Down Expand Up @@ -604,14 +617,14 @@ func getRuleType(etcdClient *clientv3.Client) (string, error) {

// Get a ruleType from the specification of Cloud Adaptive Network
keyCLADNetSpec := fmt.Sprint(etcdkey.CLADNetSpecification + "/" + CBNet.CLADNetID)
CBLogger.Tracef("Get - %v", keyCLADNetSpec)
CBLogger.Debugf("Get - %v", keyCLADNetSpec)

respCLADNetSpec, etcdErr := etcdClient.Get(context.Background(), keyCLADNetSpec)
if etcdErr != nil {
CBLogger.Error(etcdErr)
return "", etcdErr
}
CBLogger.Tracef("GetResponse: %v", respCLADNetSpec)
CBLogger.Tracef("GetResponse: %#v", respCLADNetSpec)

var cladnetSpec model.CLADNetSpecification
if err := json.Unmarshal(respCLADNetSpec.Kvs[0].Value, &cladnetSpec); err != nil {
Expand Down Expand Up @@ -681,7 +694,7 @@ func updateNetworkingRule(thisPeer model.Peer, otherPeers map[string]model.Peer,
}

func updatePeerInNetworkingRule(thisPeer model.Peer, otherPeer model.Peer, ruleType string, etcdClient *clientv3.Client) {
CBLogger.Trace("Start.........")
CBLogger.Debug("Start.........")

networkingRule := CBNet.NetworkingRule

Expand Down Expand Up @@ -719,7 +732,7 @@ func updatePeerInNetworkingRule(thisPeer model.Peer, otherPeer model.Peer, ruleT
CBLogger.Tracef("TransactionResponse: %#v", txnResp)
CBLogger.Tracef("ResponseHeader: %#v", txnResp.Header)

CBLogger.Trace("End.........")
CBLogger.Debug("End.........")
}

func main() {
Expand Down Expand Up @@ -795,7 +808,7 @@ func main() {
if err := lock.Lock(ctx); err != nil {
CBLogger.Error(err)
}
CBLogger.Tracef("Acquired lock for '%s'", keyPrefix)
CBLogger.Tracef("Lock acquired for '%s'", keyPrefix)

wg.Add(1)
// Watch all peers
Expand All @@ -808,13 +821,13 @@ func main() {
keyPeersInCLADNet := fmt.Sprint(etcdkey.Peer + "/" + CBNet.CLADNetID)
CBLogger.Debugf("Get - %v", keyPeersInCLADNet)

resp, respErr := etcdClient.Get(context.TODO(), keyPeersInCLADNet, clientv3.WithPrefix())
CBLogger.Tracef("etcdResp: %v", resp)
getResp, respErr := etcdClient.Get(context.TODO(), keyPeersInCLADNet, clientv3.WithPrefix())
CBLogger.Tracef("GetResponse: %#v", getResp)
if respErr != nil {
CBLogger.Error(respErr)
}

for _, kv := range resp.Kvs {
for _, kv := range getResp.Kvs {
key := string(kv.Key)
CBLogger.Tracef("Key : %v", key)
CBLogger.Tracef("The peer: %v", string(kv.Value))
Expand All @@ -833,7 +846,7 @@ func main() {
if err := lock.Unlock(ctx); err != nil {
CBLogger.Error(err)
}
CBLogger.Tracef("Released lock for '%s'", keyPrefix)
CBLogger.Tracef("Lock released for '%s'", keyPrefix)

// Turn up the virtual network interface (i.e., TUN device) for Cloud Adaptive Network
handleCommand(cmdtype.Up, etcdClient)
Expand Down
51 changes: 38 additions & 13 deletions poc-cb-net/cmd/controller/controller.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -110,14 +110,16 @@ func init() {
}

func watchHostNetworkInformation(wg *sync.WaitGroup, etcdClient *clientv3.Client) {
CBLogger.Debug("Start.........")
defer wg.Done()
// Watch "/registry/cloud-adaptive-network/host-network-information"
CBLogger.Debugf("Start to watch \"%v\"", etcdkey.HostNetworkInformation)

// Create a session to acquire a lock
session, _ := concurrency.NewSession(etcdClient)
defer session.Close()

// Watch "/registry/cloud-adaptive-network/host-network-information"
CBLogger.Debugf("Start to watch \"%v\"", etcdkey.HostNetworkInformation)

watchChan2 := etcdClient.Watch(context.Background(), etcdkey.HostNetworkInformation, clientv3.WithPrefix())
for watchResponse := range watchChan2 {
for _, event := range watchResponse.Events {
Expand Down Expand Up @@ -160,20 +162,24 @@ func watchHostNetworkInformation(wg *sync.WaitGroup, etcdClient *clientv3.Client

// Acquire a lock (or wait to have it) to update peer
CBLogger.Debug("Acquire a lock")
if err := lock.Lock(ctx); err != nil {
// Time trying to acquire a lock
start := time.Now()
err = lock.Lock(ctx)
if err != nil {
CBLogger.Errorf("Could NOT acquire lock for '%v', error: %v", keyPrefix, err)
}
CBLogger.Tracef("Acquired lock for '%s'", keyPrefix)
CBLogger.Tracef("Lock acquired for '%s'", keyPrefix)

// Create a key of peer
keyPeer := fmt.Sprint(etcdkey.Peer + "/" + parsedCLADNetID + "/" + parsedHostID)

// Get a peer
CBLogger.Tracef("Key: %v", keyPeer)
CBLogger.Debugf("Get - %v", keyPeer)
respRule, respRuleErr := etcdClient.Get(context.TODO(), keyPeer)
if respRuleErr != nil {
CBLogger.Error(respRuleErr)
}
CBLogger.Tracef("GetResponse: %#v", respRule)

var peer model.Peer

Expand All @@ -184,7 +190,8 @@ func watchHostNetworkInformation(wg *sync.WaitGroup, etcdClient *clientv3.Client

} else { // Update the host's configuration

if err := json.Unmarshal(respRule.Kvs[0].Value, &peer); err != nil {
err = json.Unmarshal(respRule.Kvs[0].Value, &peer)
if err != nil {
CBLogger.Error(err)
}

Expand All @@ -198,16 +205,21 @@ func watchHostNetworkInformation(wg *sync.WaitGroup, etcdClient *clientv3.Client
CBLogger.Tracef("Value: %#v", peer)

doc, _ := json.Marshal(peer)
if _, err := etcdClient.Put(context.TODO(), keyPeer, string(doc)); err != nil {
putResp, err := etcdClient.Put(context.TODO(), keyPeer, string(doc))
if err != nil {
CBLogger.Error(err)
}
CBLogger.Tracef("PutResponse: %#v", putResp)

// Release a lock to update peer
CBLogger.Debug("Release a lock")
if err := lock.Unlock(ctx); err != nil {
CBLogger.Error(err)
}
CBLogger.Tracef("Released lock for '%s'", keyPrefix)
CBLogger.Tracef("Lock released for '%s'", keyPrefix)
// Elapsed time from the time trying to acquire a lock
elapsed := time.Since(start)
CBLogger.Tracef("Elapsed time for locking: %s", elapsed)
}

case mvccpb.DELETE: // The watched key has been deleted.
Expand All @@ -217,11 +229,11 @@ func watchHostNetworkInformation(wg *sync.WaitGroup, etcdClient *clientv3.Client
}
}
}
CBLogger.Debugf("End to watch \"%v\"", etcdkey.HostNetworkInformation)
CBLogger.Debug("End.........")
}

func tryToAcquireWorkload(etcdClient *clientv3.Client, key string, revision int64) bool {
CBLogger.Debugf("Start.........")
CBLogger.Debug("Start.........")
// Key to lease temporally by which each cb-network controller can distinguish each updated value
keyToLease := fmt.Sprintf("lease%s-%d", key, revision)
// fmt.Printf("%#v\n", keyPrefix)
Expand All @@ -234,6 +246,8 @@ func tryToAcquireWorkload(etcdClient *clientv3.Client, key string, revision int6
CBLogger.Errorf("'lease.Grant' error: %#v", grantErr)
}

CBLogger.Debugf("Transaction (compare-and-swap(CAS)) - %v", keyToLease)

messageToCheck := fmt.Sprintf("Vanished in %d sec", ttl)
txResp, err2 := etcdClient.Txn(context.TODO()).
If(clientv3.Compare(clientv3.Value(keyToLease), "=", messageToCheck)).
Expand All @@ -245,7 +259,7 @@ func tryToAcquireWorkload(etcdClient *clientv3.Client, key string, revision int6
CBLogger.Errorf("transaction error: %#v", err2)
}

CBLogger.Tracef("txResp: %v\n", txResp)
CBLogger.Tracef("TransactionResponse: %#v", txResp)
isAcquired := !txResp.Succeeded

if isAcquired {
Expand All @@ -270,11 +284,14 @@ func getDefaultInterfaceInfo(networkInterfaces []model.NetworkInterface) (ipAddr
}

func getIpv4AddressSpace(etcdClient *clientv3.Client, key string) (string, error) {
CBLogger.Debug("Start.........")

CBLogger.Debugf("Get - %v", key)
respSpec, errSpec := etcdClient.Get(context.Background(), key)
if errSpec != nil {
CBLogger.Error(errSpec)
}
CBLogger.Tracef("GetResponse: %#v", respSpec)

var tempSpec model.CLADNetSpecification

Expand All @@ -287,12 +304,16 @@ func getIpv4AddressSpace(etcdClient *clientv3.Client, key string) (string, error
}
CBLogger.Tracef("TempSpec: %v", tempSpec)
// Get an IPv4 address space of CLADNet
CBLogger.Debug("End.........")
return tempSpec.Ipv4AddressSpace, nil
}
CBLogger.Debug("End.........")
return "", errors.New("no cloud adaptive network exists")
}

func assignIPAddressToPeer(ipCIDR string, numberOfIPsAssigned uint32) (string, string, error) {
CBLogger.Debug("Start.........")

// Get IPNet struct from string
_, ipv4Net, errParseCIDR := net.ParseCIDR(ipCIDR)
if errParseCIDR != nil {
Expand Down Expand Up @@ -333,13 +354,16 @@ func assignIPAddressToPeer(ipCIDR string, numberOfIPsAssigned uint32) (string, s
if ipCandidate >= lastIP {
errStr := fmt.Sprintf("IP (%v) is out of ipv4Net's range (%v)", ip.String(), ipv4Net.IP.String())
CBLogger.Errorf(errStr)
CBLogger.Debug("End.........")
return peerIPv4CIDR, peerIPAddress, errors.New(errStr)
}
CBLogger.Debug("End.........")

return peerIPv4CIDR, peerIPAddress, nil
}

func allocatePeer(cladnetID string, hostID string, hostName string, hostIPv4CIDR string, hostIP string, hostPublicIP string, etcdClient *clientv3.Client) model.Peer {
CBLogger.Debug("Start.........")

// Create a key of the CLADNet specification
keyCLADNetSpecificationOfCLADNet := fmt.Sprint(etcdkey.CLADNetSpecification + "/" + cladnetID)
Expand All @@ -354,11 +378,12 @@ func allocatePeer(cladnetID string, hostID string, hostName string, hostIPv4CIDR
keyPeersInCLADNet := fmt.Sprint(etcdkey.Peer + "/" + cladnetID)

// Get the number of peers
CBLogger.Tracef("Key: %v", keyPeersInCLADNet)
CBLogger.Debugf("Get - %v", keyPeersInCLADNet)
resp, respErr := etcdClient.Get(context.TODO(), keyPeersInCLADNet, clientv3.WithPrefix(), clientv3.WithCountOnly())
if respErr != nil {
CBLogger.Error(respErr)
}
CBLogger.Tracef("GetResponse: %#v", resp)

state := netstate.Configuring
peerIPv4CIDR, peerIPAddress, err := assignIPAddressToPeer(cladnetIpv4AddressSpace, uint32(resp.Count+2))
Expand All @@ -381,8 +406,8 @@ func allocatePeer(cladnetID string, hostID string, hostName string, hostIPv4CIDR
State: state,
}

CBLogger.Debug("End.........")
return peer

}

func main() {
Expand Down
Loading