Merge branch 'log-system-improvement' into 'main'

Streamline Logging to be more useful for using the proto-kms

See merge request !10

go.mod

@@ -4,6 +4,7 @@ go 1.20
 
 require (
 	github.com/google/uuid v1.3.0
+	github.com/sirupsen/logrus v1.9.3
 	google.golang.org/grpc v1.56.2
 	google.golang.org/protobuf v1.31.0
 )

go.sum

+github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
+github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
+github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
 github.com/golang/protobuf v1.5.0/go.mod h1:FsONVRAS9T7sI+LIUmWTfcYkHO4aIWwzhcaSAoJOfIk=
 github.com/golang/protobuf v1.5.3 h1:KhyjKVUg7Usr/dYsdSqoFveMYd5ko72D+zANwlG1mmg=
 github.com/golang/protobuf v1.5.3/go.mod h1:XVQd3VNwM+JqD3oG2Ue2ip4fOMUkwXdXDdiuN0vRsmY=
@@ -5,8 +8,16 @@ github.com/google/go-cmp v0.5.5/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/
 github.com/google/go-cmp v0.5.9 h1:O2Tfq5qg4qc4AmwVlvv0oLiVAGB7enBSJ2x2DqQFi38=
 github.com/google/uuid v1.3.0 h1:t6JiXgmwXMjEs8VusXIJk2BXHsn+wx8BZdTaoZ5fu7I=
 github.com/google/uuid v1.3.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo=
+github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
+github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
+github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ=
+github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ=
+github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
+github.com/stretchr/testify v1.7.0 h1:nwc3DEeHmmLAfoZucVR881uASk0Mfjw8xYJ99tb5CcY=
+github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
 golang.org/x/net v0.9.0 h1:aWJ/m6xSmxWBx+V0XRHTlrYrPG56jKsLdTFmsSsCzOM=
 golang.org/x/net v0.9.0/go.mod h1:d48xBJpPfHeWQsugry2m+kC02ZBRGRgulfHnEXEuWns=
+golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.7.0 h1:3jlCCIQZPdOYu1h8BkNvLz8Kgwtae2cagcG/VamtZRU=
 golang.org/x/sys v0.7.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/text v0.9.0 h1:2sjJmO8cDvYveuX97RDLsxlyUxLl+GHoLxBiRdHllBE=
@@ -20,3 +31,6 @@ google.golang.org/protobuf v1.26.0-rc.1/go.mod h1:jlhhOSvTdKEhbULTjvd4ARK9grFBp0
 google.golang.org/protobuf v1.26.0/go.mod h1:9q0QmTI4eRPtz6boOQmLYwt+qCgq0jsYwAQnmE0givc=
 google.golang.org/protobuf v1.31.0 h1:g0LDEJHgrBl9N9r17Ru3sqWhkIx2NB67okBHPwC7hs8=
 google.golang.org/protobuf v1.31.0/go.mod h1:HV8QOd/L58Z+nl8r43ehVNZIU/HEI6OcFqwMG9pJV4I=
+gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
+gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c h1:dUUwHk2QECo/6vqA44rthZ8ie2QXMNeKRTHCNY2nXvo=
+gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=

kms/kms-keystore.go

@@ -3,9 +3,10 @@ package kms
 import (
 	"errors"
 	"fmt"
-	"log"
 	"sync"
 
+	log "github.com/sirupsen/logrus"
+
 	"code.fbi.h-da.de/danet/proto-kms/quantumlayer"
 )
 
@@ -36,7 +37,7 @@ func (ks *kmsKeyStore) addKey(bulkKeyId int64, keyToadd []byte) {
 	defer ks.keyStoreMutex.Unlock()
 	// test for collisions
 	if _, notThere := ks.keyStore[newKeyElement.keyID]; notThere {
-		log.Printf("Whop: addKey collission of key id %s for bulkKeyID %d", newKeyElement.keyID, bulkKeyId)
+		log.Errorf("Whop: addKey collission of key id %s for bulkKeyID %d", newKeyElement.keyID, bulkKeyId)
 		return
 	}
 	// ok to add

kms/kms.go

@@ -7,10 +7,12 @@ package kms
 import (
 	"crypto/rand"
 	"encoding/binary"
-	"log"
+	"io"
 	"sync"
 	"time"
 
+	log "github.com/sirupsen/logrus"
+
 	pbETSI "code.fbi.h-da.de/danet/proto-kms/api/gen/proto/go/kmsetsi"
 	pbIC "code.fbi.h-da.de/danet/proto-kms/api/gen/proto/go/kmsintercom"
 	"code.fbi.h-da.de/danet/proto-kms/quantumlayer"
@@ -60,7 +62,27 @@ type QuantumElement struct {
 	keyStoreRemote *kmsKeyStore // the keys th remote entity (peer) has produced and are ready to use
 }
 
-func NewEKMS(kmsName string, kmsUUID uuid.UUID) (newEKMS *EKMS) {
+func NewEKMS(kmsName string, kmsUUID uuid.UUID, logOutput io.Writer, logLevel log.Level, logInJson bool) (newEKMS *EKMS) {
+
+	/*
+	 * Setup logging
+	 */
+	//What level
+	log.SetLevel(logLevel)
+	// Where to send log out put
+	log.SetOutput(logOutput)
+	// and plain-text (standard) or json
+	if !logInJson {
+		log.SetFormatter(&log.TextFormatter{})
+	} else {
+		log.SetFormatter(&log.JSONFormatter{})
+	}
+	// print code function if level is set to Trace
+	if logLevel == log.TraceLevel {
+		log.SetReportCaller(true)
+	} else {
+		log.SetReportCaller(false)
+	}
 
 	return &EKMS{
 		kmsName:                 kmsName,
@@ -72,10 +94,10 @@ func NewEKMS(kmsName string, kmsUUID uuid.UUID) (newEKMS *EKMS) {
 	}
 }
 
-func (kms *EKMS) AddQuantumElement(kmsUDPAddrr string) *QuantumElement {
+func (kms *EKMS) AddQuantumElement(kmsUDPAddrr string, logOutput io.Writer, logLevel log.Level, logInJson bool) *QuantumElement {
 
 	//Get an emulated Quantumlayer
-	ql := quantumlayer.NewQuantumlayerEmuPRNG()
+	ql := quantumlayer.NewQuantumlayerEmuPRNG(logOutput, logLevel, logInJson)
 	ql.Configure(kmsUDPAddrr)
 	ql.PowerOn()
 
@@ -96,7 +118,7 @@ func (kms *EKMS) AddQuantumElement(kmsUDPAddrr string) *QuantumElement {
 	var randError error
 	qle.QlID, randError = kms.GenerateNewQleID()
 	if randError != nil {
-		log.Fatalf("GenerateNewQleID: %s", randError)
+		log.Fatalf("%s: GenerateNewQleID: %s", kms.kmsName, randError)
 		return nil
 	}
 
@@ -113,27 +135,28 @@ func (kms *EKMS) GlobalKeyHandler(waitTime time.Duration) error {
 	// feed this into the corresponding key buffers of the kmss
 	for {
 		for currentQE := range kms.QuantumElements {
-			log.Printf("%s GlobalKeyHandler reading...\n", kms.kmsName)
+			log.Debugf("%s GlobalKeyHandler reading...\n", kms.kmsName)
 
 			bulkKeysLocal, err := kms.QuantumElements[currentQE].QuantumElementLink.GetKeyBatchLocal()
 			if err != nil {
-				log.Printf("%s failed to retrieve local bulkkeys with error %s", kms.kmsName, err)
+				log.Errorf("%s failed to retrieve local bulkkeys with error %s", kms.kmsName, err)
 			} else {
 				// process bulkKeysLocal
-				log.Printf("%s produced %d bytes of key locally", kms.kmsName, bulkKeysLocal.BulkKeyLength)
+				log.Debugf("%s produced %d bytes of key locally", kms.kmsName, bulkKeysLocal.BulkKeyLength)
 				kms.QuantumElements[currentQE].keyStoreLocal.KeyChopper256Bit(&bulkKeysLocal)
 
 			}
 
 			bulkKeysRemote, err := kms.QuantumElements[currentQE].QuantumElementLink.GetKeyBatchPeer()
 			if err != nil {
-				log.Printf("%s failed to retrieve remote bulkkeys with error %s", kms.kmsName, err)
+				log.Errorf("%s failed to retrieve remote bulkkeys with error %s", kms.kmsName, err)
 			} else {
 				// process bulkKeysRemote
-				log.Printf("%s received %d bytes of key from remote peer", kms.kmsName, bulkKeysRemote.BulkKeyLength)
+				log.Debugf("%s received %d bytes of key from remote peer", kms.kmsName, bulkKeysRemote.BulkKeyLength)
 				kms.QuantumElements[currentQE].keyStoreRemote.KeyChopper256Bit(&bulkKeysRemote)
 			}
 		}
+		// TODO: Better approach required than a sleep timer!
 		time.Sleep(waitTime)
 	}
 }
@@ -142,7 +165,7 @@ func (kms *EKMS) GlobalKeyHandler(waitTime time.Duration) error {
 // However, when being used a potential other caller might received the same qlElementId
 // TODO/XXX: This would be collision and must be eventually avoided
 func (kms *EKMS) GenerateNewQleID() (uint32, error) {
-	for { // this needs a condiction to stop!
+	for { // this needs a condition to stop!
 		// create buffer for uint32, so reserve 4 bytes
 		buf := make([]byte, 4)
 
@@ -166,7 +189,7 @@ func (kms *EKMS) GenerateNewQleID() (uint32, error) {
 func (kms *EKMS) AddPeer(kmsPeerSocket string, servingQLE *QuantumElement) {
 	//check if peer exists
 	if _, there := kms.KmsPeers[kmsPeerSocket]; there {
-		log.Printf("Trying to add existing peer %s", kmsPeerSocket)
+		log.Errorf("Trying to add existing peer %s", kmsPeerSocket)
 		return
 	}
 	peer := NewKmsPeer(servingQLE, kms.externalNotifierKMSPeer)
@@ -186,7 +209,7 @@ func (kms *EKMS) RemovePeer(kmsPeerSocket string) {
 		delete(kms.KmsPeers, kmsPeerSocket)
 		return
 	}
-	log.Printf("Can not find a peer with socekt: %s", kmsPeerSocket)
+	log.Errorf("%s: Can not find a peer with socket: %s", kms.kmsName, kmsPeerSocket)
 	return
 }
 

kms/kmsetsi.go

@@ -6,10 +6,11 @@ import (
 	"errors"
 	"flag"
 	"fmt"
-	"log"
 	"net"
 	"os/exec"
 
+	log "github.com/sirupsen/logrus"
+
 	pb "code.fbi.h-da.de/danet/proto-kms/api/gen/proto/go/kmsetsi"
 	"google.golang.org/grpc"
 	"google.golang.org/grpc/codes"
@@ -27,7 +28,7 @@ type etsiServer struct {
 }
 
 func (es *etsiServer) ETSICapabilities(ctx context.Context, in *pb.ETSICapabilitiesRequest) (capReply *pb.ETSICapabilitiesReply, err error) {
-	log.Printf("Received: %v", in.GetMyKmsName())
+	log.Debugf("Received: %v", in.GetMyKmsName())
 
 	return &pb.ETSICapabilitiesReply{
 		PeerKmsName: "whatever",
@@ -52,7 +53,7 @@ func (es *etsiServer) ETSIGetQuantumInterfaces(ctx context.Context, in *pb.ETSIK
 
 func (es *etsiServer) ETSIAddKMSPeer(ctx context.Context, in *pb.ETSIKMSPeerRequest) (*pb.ETSIKMSPeerReply, error) {
 	//determine the kms structure to call
-	log.Printf("AddKMSPeer called.")
+	log.Debugf("AddKMSPeer called.")
 
 	// Check first if KmsLocalQLEId is actually one of ours...
 	qleID := in.KmsLocalQLEId
@@ -112,6 +113,7 @@ func (es *etsiServer) ETSIGetEncryptKeys256Bit(ctx context.Context, in *pb.ETSIG
 		es.visitedKeys[randomKey] = true
 	}
 
+	// TODO: Remove/move ssh-kind prototype code below
 	keyAsString := base64.StdEncoding.EncodeToString(randomKey.key)
 	// push the key to the encryptor via ssh
 	ssh := "ssh"
@@ -121,7 +123,7 @@ func (es *etsiServer) ETSIGetEncryptKeys256Bit(ctx context.Context, in *pb.ETSIG
 	cmd := exec.Command(ssh, args...)
 	err = cmd.Run()
 	if err != nil {
-		log.Println("could not execute command")
+		log.Errorf("could not execute ssh command with parameters")
 		return nil, status.Errorf(codes.Internal, "%v", err)
 	}
 
@@ -145,7 +147,7 @@ func StartETSI(listenAddr string, callingKMS *EKMS) {
 		handlingEkms: callingKMS,
 		visitedKeys:  make(map[*kmsKSElement]bool),
 	})
-	log.Printf("server listening at %v", lis.Addr())
+	log.Infof("server listening at %v", lis.Addr())
 	if err := s.Serve(lis); err != nil {
 		log.Fatalf("failed to serve: %v", err)
 	}

kms/kmsintercom.go

@@ -4,9 +4,10 @@ import (
 	"context"
 	"flag"
 	"fmt"
-	"log"
 	"net"
 
+	log "github.com/sirupsen/logrus"
+
 	pb "code.fbi.h-da.de/danet/proto-kms/api/gen/proto/go/kmsintercom"
 	"google.golang.org/grpc"
 )
@@ -16,7 +17,7 @@ type kmsTalkerServer struct {
 }
 
 func (s *kmsTalkerServer) InterComCapabilities(ctx context.Context, in *pb.InterComCapabilitiesRequest) (capReply *pb.InterComCapabilitiesReply, err error) {
-	log.Printf("Received: %v", in.GetMyKmsName())
+	log.Debugf("Received: %v", in.GetMyKmsName())
 
 	return &pb.InterComCapabilitiesReply{
 		PeerKmsName: "whatever",
@@ -39,7 +40,7 @@ func StartInterComm(interComPort int) {
 	}
 	s := grpc.NewServer()
 	pb.RegisterKmsTalkerServer(s, &kmsTalkerServer{})
-	log.Printf("server listening at %v", lis.Addr())
+	log.Infof("server listening at %v", lis.Addr())
 	if err := s.Serve(lis); err != nil {
 		log.Fatalf("failed to serve: %v", err)
 	}

kms/kmspeers.go

@@ -4,11 +4,12 @@ import (
 	"context"
 	"encoding/base64"
 	"fmt"
-	"log"
 	"net"
 	"os/exec"
 	"time"
 
+	log "github.com/sirupsen/logrus"
+
 	pb "code.fbi.h-da.de/danet/proto-kms/api/gen/proto/go/kmsetsi"
 	"github.com/google/uuid"
 	"google.golang.org/grpc"
@@ -53,12 +54,12 @@ func NewKmsPeer(servQLE *QuantumElement, in chan string) (peer kmsPeer) {
 
 // Handles everything with respect to a specific KMS peer
 func (ph *kmsPeer) PeerHandler(kmsName string) {
-	log.Printf("%s started PeerHandler for %s:", kmsName, ph.tcpSocketStr)
+	log.Infof("%s started PeerHandler for %s:", kmsName, ph.tcpSocketStr)
 
 	// contact peer
 	newPeerConn, err := grpc.Dial(ph.tcpSocketStr, grpc.WithTransportCredentials(insecure.NewCredentials()))
 	if err != nil {
-		log.Printf("did not connect: %v", err)
+		log.Errorf("%s: did not connect: %v", kmsName, err)
 		ph.peerStatus = KmsPeerDown
 		return
 	}
@@ -71,7 +72,7 @@ func (ph *kmsPeer) PeerHandler(kmsName string) {
 	defer cancel()
 	r, err := c.ETSICapabilities(ctx, &pb.ETSICapabilitiesRequest{MyKmsName: kmsName})
 	if err != nil {
-		log.Printf("could not greet: %v", err)
+		log.Errorf("%s: could not greet: %v", kmsName, err)
 		ph.peerStatus = KmsPeerDown
 		// Send notification about change
 		if ph.externalNotifierKMSPeer != nil {
@@ -102,7 +103,7 @@ func (ph *kmsPeer) PeerHandler(kmsName string) {
 
 	encryptKeyRequest, err := c.ETSIGetEncryptKeys256Bit(ctx, &pb.ETSIGetEncryptKeys256BitRequest{Amount: 1})
 	if err != nil {
-		log.Println("could not request a encryption key: ", err)
+		log.Errorf("%s: could not request a encryption key: %s", kmsName, err)
 		ph.peerStatus = KmsPeerDown
 		// Send notification about change
 		if ph.externalNotifierKMSPeer != nil {
@@ -114,8 +115,9 @@ func (ph *kmsPeer) PeerHandler(kmsName string) {
 	// check if key is in remoteKeyStore
 	if key, ok := ph.servingQLE.keyStoreRemote.keyStore[encryptKeyRequest.KeyID]; ok {
 		keyAsString := base64.StdEncoding.EncodeToString(key.key)
-		log.Printf("Agreed Key: %s", keyAsString)
+		log.Debugf("Agreed Key: %s", keyAsString)
 
+		// TODO: Remove/move ssh-kind prototype code below
 		// push the key to the encryptor via ssh
 		ssh := "ssh"
 		complexArg := fmt.Sprintf("(rc=$(sed \"12 c PresharedKey = %s\" /etc/wireguard/wg0.conf); echo \"$rc\" > /etc/wireguard/wg0.conf)", keyAsString)
@@ -124,7 +126,7 @@ func (ph *kmsPeer) PeerHandler(kmsName string) {
 		cmd := exec.Command(ssh, args...)
 		err := cmd.Run()
 		if err != nil {
-			log.Println("could not execute command")
+			log.Errorf("%s: could not execute ssh command with parameters", kmsName)
 			return
 		}
 	}

main_test.go

@@ -5,11 +5,13 @@ package main
 
 import (
 	"flag"
-	"log"
 	"net"
+	"os"
 	"testing"
 	"time"
 
+	log "github.com/sirupsen/logrus"
+
 	"code.fbi.h-da.de/danet/proto-kms/kms"
 	"github.com/google/uuid"
 )
@@ -50,11 +52,11 @@ func TestMain(m *testing.M) {
 	log.Println("Welcome to the proto-kms called: ", ql1Name)
 
 	if selfTesting == true {
-		log.Printf("%s in self-testing mode", ql1Name)
+		log.Infof("%s in self-testing mode", ql1Name)
 		go emulatedKMS(ql2Name, udpQL2AddrString, udpQL1AddrString)
 		emulatedKMS(ql1Name, udpQL1AddrString, udpQL2AddrString)
 	} else {
-		log.Printf("%s in regular operations mode", ql1Name)
+		log.Infof("%s in regular operations mode", ql1Name)
 		emulatedKMS(ql1Name, udpQL1AddrString, udpQL2AddrString)
 	}
 
@@ -63,14 +65,14 @@ func TestMain(m *testing.M) {
 
 func emulatedKMS(myName string, myUDPAddr string, peerUDPAddr string) {
 	// Attach to eKMS
-	emuKMS := kms.NewEKMS(myName, uuid.New())
+	emuKMS := kms.NewEKMS(myName, uuid.New(), os.Stdout, log.DebugLevel, false)
 
 	// Fire up Quantum LinK
-	myQL := emuKMS.AddQuantumElement(myUDPAddr)
+	myQL := emuKMS.AddQuantumElement(myUDPAddr, os.Stdout, log.ErrorLevel, false)
 
 	udpQL2Addr, err := net.ResolveUDPAddr("udp", peerUDPAddr)
 	if err != nil {
-		log.Fatalf("QuantumlayerEmuPRNG UDP failure: %s", err)
+		log.Fatalf("%s: QuantumlayerEmuPRNG UDP failure: %s", myName, err)
 		return
 	}
 

quantumlayer/quantumlayer-emu-prng.go

@@ -9,17 +9,19 @@ package quantumlayer
  * transmitted to the other end.
  *
  */
-
 import (
 	"context"
 	"crypto/rand"
 	"encoding/json"
 	"errors"
-	"log"
+	"io"
 	"math/big"
 	"net"
 	"sync"
 	"time"
+
+	"github.com/sirupsen/logrus"
+	logi "github.com/sirupsen/logrus"
 )
 
 type QuantumPayloadElement struct {
@@ -43,7 +45,32 @@ type QuantumlayerEmuPRNG struct {
 	qlPeerMutex      sync.Mutex
 }
 
-func NewQuantumlayerEmuPRNG() (newql *QuantumlayerEmuPRNG) {
+// We use our own logrus instance, as we would like to have different log levels for different parts.
+var log = logrus.New()
+
+func NewQuantumlayerEmuPRNG(logOutput io.Writer, logLevel logi.Level, logInJson bool) (newql *QuantumlayerEmuPRNG) {
+	/*
+	 * Setup logging
+	 */
+
+	//What level
+	log.SetLevel(logLevel)
+	// Where to send log out put
+	log.SetOutput(logOutput)
+	// and plain-text (standard) or json
+	if !logInJson {
+		log.SetFormatter(&logi.TextFormatter{})
+	} else {
+		log.SetFormatter(&logi.JSONFormatter{})
+	}
+	// print code function if level is set to Trace
+	if logLevel == logi.TraceLevel {
+		log.SetReportCaller(true)
+	} else {
+		log.SetReportCaller(false)
+	}
+
+	// Return PRNG Quantum Layer
 	return &QuantumlayerEmuPRNG{
 		configured:       false,
 		poweron:          false,
@@ -77,28 +104,28 @@ func (qlemuprng *QuantumlayerEmuPRNG) Configure(localQLAddress ...string) {
 func (qlemuprng *QuantumlayerEmuPRNG) PowerOn() {
 	if qlemuprng.configured == false {
 		// nothing do here move on
-		log.Printf("Sorry, the quantum layer is not configured for action. You've missed Configure()")
+		log.Errorf("QuantumlayerEmuPRNG: Sorry, the quantum layer is not configured for action. You've missed Configure()")
 		return
 	}
 	//qlemuprng.poweron = false
-	log.Println("QuantumlayerEmuPRNG is powering on...charging.")
+	log.Infof("QuantumlayerEmuPRNG: is powering on...charging.")
 
 	// serve UDP incoming
 	if qlemuprng.udpSrvConn == nil {
 		go func() {
 			// Get UDP server part going...
-			log.Printf("localQLAddress is %s", qlemuprng.localQLAddress)
+			log.Debugf("QuantumlayerEmuPRNG: localQLAddress is %s", qlemuprng.localQLAddress)
 
 			// This reads random numbers from other Quantum end
 			udpSrvPort, err := net.ResolveUDPAddr("udp", qlemuprng.localQLAddress)
 			if err != nil {
-				log.Fatalf("QuantumlayerEmuPRNG UDP failure: %s", err)
+				log.Fatalf("QuantumlayerEmuPRNG: UDP failure: %s", err)
 				return
 			}
 
 			qlemuprng.udpSrvConn, err = net.ListenUDP("udp", udpSrvPort)
 			if err != nil {
-				log.Fatalf("QuantumlayerEmuPRNG UDP failure: %s", err)
+				log.Fatalf("QuantumlayerEmuPRNG: UDP failure: %s", err)
 				return
 			}
 			defer qlemuprng.udpSrvConn.Close()
@@ -106,20 +133,20 @@ func (qlemuprng *QuantumlayerEmuPRNG) PowerOn() {
 			// Retrieve local UDP address and store it for further actions.
 			qlemuprng.qlLocalPort = qlemuprng.udpSrvConn.LocalAddr().(*net.UDPAddr)
 
-			log.Printf("QuantumlayerEmuPRNG: started server, waiting for incoming rands on port %s \n", qlemuprng.udpSrvConn.LocalAddr().(*net.UDPAddr).String())
+			log.Infof("QuantumlayerEmuPRNG: started server, waiting for incoming rands on port %s \n", qlemuprng.udpSrvConn.LocalAddr().(*net.UDPAddr).String())
 			inBuffer := make([]byte, 1500)
 			for {
 				// Buffer for reading from "Quantum link"
 				n, addr, err := qlemuprng.udpSrvConn.ReadFromUDP(inBuffer)
 				if err != nil {
-					log.Printf("QuantumlayerEmuPRNG: Could not read from UDP: %s", err)
+					log.Errorf("QuantumlayerEmuPRNG: Could not read from UDP: %s", err)
 				} else {
-					log.Printf("QuantumlayerEmuPRNG: read %d bytes from %s\n", n, addr)
+					log.Debugf("QuantumlayerEmuPRNG: read %d bytes from %s\n", n, addr)
 
 					// Check if sender of datagram is qlPeer
 					// Warning this is not checking the validity of the sender, i.e., spoofing is possible
 					if addr.String() == qlemuprng.qlPeer {
-						log.Printf("QuantumlayerEmuPRNG: Peer %s listed", addr)
+						log.Debugf("QuantumlayerEmuPRNG: Peer %s listed", addr)
 						//dumb the received data into the channel and carry on
 						// TODO/XXX: no vetting for anything
 						// Unmarshall out of JSON
@@ -129,7 +156,7 @@ func (qlemuprng *QuantumlayerEmuPRNG) PowerOn() {
 							qlemuprng.incomingRandNums <- inQBuffer
 						}
 					} else {
-						log.Printf("QuantumlayerEmuPRNG: Peer %s NOT listed", addr)
+						log.Infof("QuantumlayerEmuPRNG: Peer %s NOT listed", addr)
 					}
 				}
 			}
@@ -143,14 +170,14 @@ func (qlemuprng *QuantumlayerEmuPRNG) PowerOn() {
 	// Ready, set, go!
 	qlemuprng.poweron = true
 
-	log.Println("QuantumlayerEmuPRNG is charged and powered on.")
+	log.Infof("QuantumlayerEmuPRNG: is charged and powered on.")
 }
 
 // Power off the quantum layer, i.e., close the communication ports for the
 // other quantum module
 func (qlemuprng *QuantumlayerEmuPRNG) PowerOff() {
 	qlemuprng.poweron = false
-	log.Println("QuantumlayerEmuPRNG is powered off...discharging.")
+	log.Println("QuantumlayerEmuPRNG: is powered off...discharging.")
 }
 
 func (qlemuprng *QuantumlayerEmuPRNG) AddPeer(addr *net.UDPAddr) {
@@ -184,15 +211,16 @@ func (qlemuprng *QuantumlayerEmuPRNG) AddPeer(addr *net.UDPAddr) {
 					// XXX/TODO: error must be handled
 					jsonPayload, err := json.Marshal(qpe)
 					if err != nil {
-						log.Printf("json.Marshal error %s", err)
+						log.Errorf("QuantumlayerEmuPRNG: json.Marshal error %s", err)
 					}
 
 					_, _, err = qlemuprng.udpSrvConn.WriteMsgUDP(jsonPayload, nil, addr)
 					if err != nil {
-						log.Fatalf("WriteMsgUDPAddrPort failed: %s", err)
+						log.Fatalf("QuantumlayerEmuPRNG: WriteMsgUDPAddrPort failed: %s", err)
 					}
 					qlemuprng.outgoingRandNums <- qpe
 				}
+				// TODO: This sleep timer has to replaced by something for clever.
 				time.Sleep(5 * time.Second)
 			}
 		}
@@ -294,7 +322,7 @@ func (store *NumberStore) GetBatch() (batch []byte) {
 	defer store.mu.Unlock()
 
 	if store.topOfStorage != 0 {
-		log.Println("Have Storage in my belly")
+		log.Debugf("QuantumlayerEmuPRNG: Have Storage in my belly")
 	}
 	// prepare to return full batch of numbers
 	batchReturn := make([]byte, store.topOfStorage)