[VOL-2471] Update library to use package logger
This commit consists of the following:
1) Add a GetLogLevel() API to make it easier to use specific
logger. There is also the V() API that kind of do something
similar.
2) Add a common.go file to some heavily used packages in order
to dynamically set their log level and also to a set a specific
logger per package.
3) Use a per package logger for some of the heavily used packages
for improved performance.
Change-Id: If22a2c82d87d808f305677a2e793f8064f33291e
diff --git a/pkg/db/kvstore/client.go b/pkg/db/kvstore/client.go
index 97fbec9..088593a 100644
--- a/pkg/db/kvstore/client.go
+++ b/pkg/db/kvstore/client.go
@@ -15,10 +15,6 @@
*/
package kvstore
-import (
- "github.com/opencord/voltha-lib-go/v2/pkg/log"
-)
-
const (
// Default timeout in seconds when making a kvstore request
defaultKVGetTimeout = 5
@@ -43,10 +39,6 @@
Lease int64
}
-func init() {
- log.AddPackage(log.JSON, log.WarnLevel, nil)
-}
-
// NewKVPair creates a new KVPair object
func NewKVPair(key string, value interface{}, session string, lease int64, version int64) *KVPair {
kv := new(KVPair)
diff --git a/pkg/db/kvstore/common.go b/pkg/db/kvstore/common.go
new file mode 100644
index 0000000..212b1d1
--- /dev/null
+++ b/pkg/db/kvstore/common.go
@@ -0,0 +1,35 @@
+/*
+ * Copyright 2020-present Open Networking Foundation
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+package kvstore
+
+import (
+ "github.com/opencord/voltha-lib-go/v2/pkg/log"
+)
+
+const (
+ logLevel = log.ErrorLevel
+)
+
+var logger log.Logger
+
+func init() {
+ // Setup this package so that it's log level can be modified at run time
+ var err error
+ logger, err = log.AddPackage(log.JSON, logLevel, log.Fields{"pkg": "kvstore"})
+ if err != nil {
+ panic(err)
+ }
+}
diff --git a/pkg/db/kvstore/consulclient.go b/pkg/db/kvstore/consulclient.go
index a94de4d..fd74d43 100644
--- a/pkg/db/kvstore/consulclient.go
+++ b/pkg/db/kvstore/consulclient.go
@@ -19,7 +19,7 @@
"bytes"
"context"
"errors"
- log "github.com/opencord/voltha-lib-go/v2/pkg/log"
+ "github.com/opencord/voltha-lib-go/v2/pkg/log"
"sync"
"time"
//log "ciena.com/coordinator/common"
@@ -53,7 +53,7 @@
config.WaitTime = duration
consul, err := consulapi.NewClient(config)
if err != nil {
- log.Error(err)
+ logger.Error(err)
return nil, err
}
@@ -65,7 +65,7 @@
// IsConnectionUp returns whether the connection to the Consul KV store is up
func (c *ConsulClient) IsConnectionUp(timeout int) bool {
- log.Error("Unimplemented function")
+ logger.Error("Unimplemented function")
return false
}
@@ -80,7 +80,7 @@
// For now we ignore meta data
kvps, _, err := kv.List(key, &queryOptions)
if err != nil {
- log.Error(err)
+ logger.Error(err)
return nil, err
}
m := make(map[string]*KVPair)
@@ -102,7 +102,7 @@
// For now we ignore meta data
kvp, _, err := kv.Get(key, &queryOptions)
if err != nil {
- log.Error(err)
+ logger.Error(err)
return nil, err
}
if kvp != nil {
@@ -121,7 +121,7 @@
var val []byte
var er error
if val, er = ToByte(value); er != nil {
- log.Error(er)
+ logger.Error(er)
return er
}
@@ -133,7 +133,7 @@
defer c.writeLock.Unlock()
_, err := kv.Put(&kvp, &writeOptions)
if err != nil {
- log.Error(err)
+ logger.Error(err)
return err
}
return nil
@@ -148,7 +148,7 @@
defer c.writeLock.Unlock()
_, err := kv.Delete(key, &writeOptions)
if err != nil {
- log.Error(err)
+ logger.Error(err)
return err
}
return nil
@@ -156,11 +156,11 @@
func (c *ConsulClient) deleteSession() {
if c.sessionID != "" {
- log.Debug("cleaning-up-session")
+ logger.Debug("cleaning-up-session")
session := c.consul.Session()
_, err := session.Destroy(c.sessionID, nil)
if err != nil {
- log.Errorw("error-cleaning-session", log.Fields{"session": c.sessionID, "error": err})
+ logger.Errorw("error-cleaning-session", log.Fields{"session": c.sessionID, "error": err})
}
}
c.sessionID = ""
@@ -177,17 +177,17 @@
for {
id, meta, err := session.Create(entry, nil)
if err != nil {
- log.Errorw("create-session-error", log.Fields{"error": err})
+ logger.Errorw("create-session-error", log.Fields{"error": err})
if retries == 0 {
return nil, "", err
}
} else if meta.RequestTime == 0 {
- log.Errorw("create-session-bad-meta-data", log.Fields{"meta-data": meta})
+ logger.Errorw("create-session-bad-meta-data", log.Fields{"meta-data": meta})
if retries == 0 {
return nil, "", errors.New("bad-meta-data")
}
} else if id == "" {
- log.Error("create-session-nil-id")
+ logger.Error("create-session-nil-id")
if retries == 0 {
return nil, "", errors.New("ID-nil")
}
@@ -198,7 +198,7 @@
if retries > 0 {
retries--
}
- log.Debug("retrying-session-create-after-a-second-delay")
+ logger.Debug("retrying-session-create-after-a-second-delay")
time.Sleep(time.Duration(1) * time.Second)
}
}
@@ -225,7 +225,7 @@
var val []byte
var er error
if val, er = ToByte(value); er != nil {
- log.Error(er)
+ logger.Error(er)
return nil, er
}
@@ -238,17 +238,17 @@
reservationSuccessful := false
defer func() {
if !reservationSuccessful {
- log.Debug("deleting-session")
+ logger.Debug("deleting-session")
c.deleteSession()
}
}()
session, sessionID, err := c.createSession(ttl, -1)
if err != nil {
- log.Errorw("no-session-created", log.Fields{"error": err})
+ logger.Errorw("no-session-created", log.Fields{"error": err})
return "", errors.New("no-session-created")
}
- log.Debugw("session-created", log.Fields{"session-id": sessionID})
+ logger.Debugw("session-created", log.Fields{"session-id": sessionID})
c.sessionID = sessionID
c.session = session
@@ -257,11 +257,11 @@
kvp := consulapi.KVPair{Key: key, Value: val, Session: c.sessionID}
result, _, err := kv.Acquire(&kvp, nil)
if err != nil {
- log.Errorw("error-acquiring-keys", log.Fields{"error": err})
+ logger.Errorw("error-acquiring-keys", log.Fields{"error": err})
return nil, err
}
- log.Debugw("key-acquired", log.Fields{"key": key, "status": result})
+ logger.Debugw("key-acquired", log.Fields{"key": key, "status": result})
// Irrespective whether we were successful in acquiring the key, let's read it back and see if it's us.
m, err := c.Get(key, defaultKVGetTimeout)
@@ -269,7 +269,7 @@
return nil, err
}
if m != nil {
- log.Debugw("response-received", log.Fields{"key": m.Key, "m.value": string(m.Value.([]byte)), "value": value})
+ logger.Debugw("response-received", log.Fields{"key": m.Key, "m.value": string(m.Value.([]byte)), "value": value})
if m.Key == key && isEqual(m.Value, value) {
// My reservation is successful - register it. For now, support is only for 1 reservation per key
// per session.
@@ -299,11 +299,11 @@
kvp = consulapi.KVPair{Key: key, Value: value.([]byte), Session: c.sessionID}
result, _, err = kv.Release(&kvp, nil)
if err != nil {
- log.Errorw("cannot-release-reservation", log.Fields{"key": key, "error": err})
+ logger.Errorw("cannot-release-reservation", log.Fields{"key": key, "error": err})
return err
}
if !result {
- log.Errorw("cannot-release-reservation", log.Fields{"key": key})
+ logger.Errorw("cannot-release-reservation", log.Fields{"key": key})
}
delete(c.keyReservations, key)
}
@@ -390,14 +390,14 @@
c.writeLock.Lock()
defer c.writeLock.Unlock()
if watchedChannelsContexts, ok = c.watchedChannelsContext[key]; !ok {
- log.Errorw("key-has-no-watched-context-or-channel", log.Fields{"key": key})
+ logger.Errorw("key-has-no-watched-context-or-channel", log.Fields{"key": key})
return
}
// Look for the channels
var pos = -1
for i, chCtxMap := range watchedChannelsContexts {
if chCtxMap.channel == ch {
- log.Debug("channel-found")
+ logger.Debug("channel-found")
chCtxMap.cancel()
//close the channel
close(ch)
@@ -409,7 +409,7 @@
if pos >= 0 {
c.watchedChannelsContext[key] = append(c.watchedChannelsContext[key][:pos], c.watchedChannelsContext[key][pos+1:]...)
}
- log.Debugw("watched-channel-exiting", log.Fields{"key": key, "channel": c.watchedChannelsContext[key]})
+ logger.Debugw("watched-channel-exiting", log.Fields{"key": key, "channel": c.watchedChannelsContext[key]})
}
func (c *ConsulClient) isKVEqual(kv1 *consulapi.KVPair, kv2 *consulapi.KVPair) bool {
@@ -430,7 +430,7 @@
}
func (c *ConsulClient) listenForKeyChange(watchContext context.Context, key string, ch chan *Event) {
- log.Debugw("start-watching-channel", log.Fields{"key": key, "channel": ch})
+ logger.Debugw("start-watching-channel", log.Fields{"key": key, "channel": ch})
defer c.CloseWatch(key, ch)
duration := GetDuration(defaultKVGetTimeout)
@@ -441,7 +441,7 @@
// Get the existing value, if any
previousKVPair, meta, err := kv.Get(key, &queryOptions)
if err != nil {
- log.Debug(err)
+ logger.Debug(err)
}
lastIndex := meta.LastIndex
@@ -456,30 +456,30 @@
pair, meta, err = kv.Get(key, waitOptions)
select {
case <-watchContext.Done():
- log.Debug("done-event-received-exiting")
+ logger.Debug("done-event-received-exiting")
return
default:
if err != nil {
- log.Warnw("error-from-watch", log.Fields{"error": err})
+ logger.Warnw("error-from-watch", log.Fields{"error": err})
ch <- NewEvent(CONNECTIONDOWN, key, []byte(""), -1)
} else {
- log.Debugw("index-state", log.Fields{"lastindex": lastIndex, "newindex": meta.LastIndex, "key": key})
+ logger.Debugw("index-state", log.Fields{"lastindex": lastIndex, "newindex": meta.LastIndex, "key": key})
}
}
if err != nil {
- log.Debug(err)
+ logger.Debug(err)
// On error, block for 10 milliseconds to prevent endless loop
time.Sleep(10 * time.Millisecond)
} else if meta.LastIndex <= lastIndex {
- log.Info("no-index-change-or-negative")
+ logger.Info("no-index-change-or-negative")
} else {
- log.Debugw("update-received", log.Fields{"pair": pair})
+ logger.Debugw("update-received", log.Fields{"pair": pair})
if pair == nil {
ch <- NewEvent(DELETE, key, []byte(""), -1)
} else if !c.isKVEqual(pair, previousKVPair) {
// Push the change onto the channel if the data has changed
// For now just assume it's a PUT change
- log.Debugw("pair-details", log.Fields{"session": pair.Session, "key": pair.Key, "value": pair.Value})
+ logger.Debugw("pair-details", log.Fields{"session": pair.Session, "key": pair.Key, "value": pair.Value})
ch <- NewEvent(PUT, pair.Key, pair.Value, -1)
}
previousKVPair = pair
@@ -500,7 +500,7 @@
// Clear the sessionID
if _, err := c.consul.Session().Destroy(c.sessionID, &writeOptions); err != nil {
- log.Errorw("error-closing-client", log.Fields{"error": err})
+ logger.Errorw("error-closing-client", log.Fields{"error": err})
}
}
diff --git a/pkg/db/kvstore/etcdclient.go b/pkg/db/kvstore/etcdclient.go
index 3ae767c..234bf05 100644
--- a/pkg/db/kvstore/etcdclient.go
+++ b/pkg/db/kvstore/etcdclient.go
@@ -50,7 +50,7 @@
DialTimeout: duration,
})
if err != nil {
- log.Error(err)
+ logger.Error(err)
return nil, err
}
@@ -82,7 +82,7 @@
resp, err := c.ectdAPI.Get(ctx, key, v3Client.WithPrefix())
cancel()
if err != nil {
- log.Error(err)
+ logger.Error(err)
return nil, err
}
m := make(map[string]*KVPair)
@@ -102,7 +102,7 @@
resp, err := c.ectdAPI.Get(ctx, key)
cancel()
if err != nil {
- log.Error(err)
+ logger.Error(err)
return nil, err
}
for _, ev := range resp.Kvs {
@@ -143,13 +143,13 @@
if err != nil {
switch err {
case context.Canceled:
- log.Warnw("context-cancelled", log.Fields{"error": err})
+ logger.Warnw("context-cancelled", log.Fields{"error": err})
case context.DeadlineExceeded:
- log.Warnw("context-deadline-exceeded", log.Fields{"error": err})
+ logger.Warnw("context-deadline-exceeded", log.Fields{"error": err})
case v3rpcTypes.ErrEmptyKey:
- log.Warnw("etcd-client-error", log.Fields{"error": err})
+ logger.Warnw("etcd-client-error", log.Fields{"error": err})
default:
- log.Warnw("bad-endpoints", log.Fields{"error": err})
+ logger.Warnw("bad-endpoints", log.Fields{"error": err})
}
return err
}
@@ -171,10 +171,10 @@
// delete the key
if _, err := c.ectdAPI.Delete(ctx, key); err != nil {
- log.Errorw("failed-to-delete-key", log.Fields{"key": key, "error": err})
+ logger.Errorw("failed-to-delete-key", log.Fields{"key": key, "error": err})
return err
}
- log.Debugw("key(s)-deleted", log.Fields{"key": key})
+ logger.Debugw("key(s)-deleted", log.Fields{"key": key})
return nil
}
@@ -199,7 +199,7 @@
resp, err := c.ectdAPI.Grant(ctx, ttl)
if err != nil {
- log.Error(err)
+ logger.Error(err)
return nil, err
}
// Register the lease id
@@ -212,7 +212,7 @@
defer func() {
if !reservationSuccessful {
if err = c.ReleaseReservation(key); err != nil {
- log.Error("cannot-release-lease")
+ logger.Error("cannot-release-lease")
}
}
}()
@@ -270,7 +270,7 @@
for key, leaseID := range c.keyReservations {
_, err := c.ectdAPI.Revoke(ctx, *leaseID)
if err != nil {
- log.Errorw("cannot-release-reservation", log.Fields{"key": key, "error": err})
+ logger.Errorw("cannot-release-reservation", log.Fields{"key": key, "error": err})
return err
}
delete(c.keyReservations, key)
@@ -281,7 +281,7 @@
// ReleaseReservation releases reservation for a specific key.
func (c *EtcdClient) ReleaseReservation(key string) error {
// Get the leaseid using the key
- log.Debugw("Release-reservation", log.Fields{"key": key})
+ logger.Debugw("Release-reservation", log.Fields{"key": key})
var ok bool
var leaseID *v3Client.LeaseID
c.writeLock.Lock()
@@ -296,7 +296,7 @@
if leaseID != nil {
_, err := c.ectdAPI.Revoke(ctx, *leaseID)
if err != nil {
- log.Error(err)
+ logger.Error(err)
return err
}
delete(c.keyReservations, key)
@@ -322,7 +322,7 @@
if leaseID != nil {
_, err := c.ectdAPI.KeepAliveOnce(ctx, *leaseID)
if err != nil {
- log.Errorw("lease-may-have-expired", log.Fields{"error": err})
+ logger.Errorw("lease-may-have-expired", log.Fields{"error": err})
return err
}
} else {
@@ -349,7 +349,7 @@
// Changing the log field (from channelMaps) as the underlying logger cannot format the map of channels into a
// json format.
- log.Debugw("watched-channels", log.Fields{"len": len(channelMaps)})
+ logger.Debugw("watched-channels", log.Fields{"len": len(channelMaps)})
// Launch a go routine to listen for updates
go c.listenForKeyChange(channel, ch, cancel)
@@ -406,17 +406,17 @@
defer c.writeLock.Unlock()
if watchedChannels, ok = c.getChannelMaps(key); !ok {
- log.Warnw("key-has-no-watched-channels", log.Fields{"key": key})
+ logger.Warnw("key-has-no-watched-channels", log.Fields{"key": key})
return
}
// Look for the channels
var pos = -1
for i, chMap := range watchedChannels {
if t, ok := chMap[ch]; ok {
- log.Debug("channel-found")
+ logger.Debug("channel-found")
// Close the etcd watcher before the client channel. This should close the etcd channel as well
if err := t.Close(); err != nil {
- log.Errorw("watcher-cannot-be-closed", log.Fields{"key": key, "error": err})
+ logger.Errorw("watcher-cannot-be-closed", log.Fields{"key": key, "error": err})
}
pos = i
break
@@ -428,11 +428,11 @@
if pos >= 0 {
channelMaps = c.removeChannelMap(key, pos)
}
- log.Infow("watcher-channel-exiting", log.Fields{"key": key, "channel": channelMaps})
+ logger.Infow("watcher-channel-exiting", log.Fields{"key": key, "channel": channelMaps})
}
func (c *EtcdClient) listenForKeyChange(channel v3Client.WatchChan, ch chan<- *Event, cancel context.CancelFunc) {
- log.Debug("start-listening-on-channel ...")
+ logger.Debug("start-listening-on-channel ...")
defer cancel()
defer close(ch)
for resp := range channel {
@@ -440,7 +440,7 @@
ch <- NewEvent(getEventType(ev), ev.Kv.Key, ev.Kv.Value, ev.Kv.Version)
}
}
- log.Debug("stop-listening-on-channel ...")
+ logger.Debug("stop-listening-on-channel ...")
}
func getEventType(event *v3Client.Event) int {
@@ -458,7 +458,7 @@
c.writeLock.Lock()
defer c.writeLock.Unlock()
if err := c.ectdAPI.Close(); err != nil {
- log.Errorw("error-closing-client", log.Fields{"error": err})
+ logger.Errorw("error-closing-client", log.Fields{"error": err})
}
}