Merge pull request #112 from ivan4th/v-style-logging

V style logging

Dockerfile

@@ -39,4 +39,4 @@ RUN ./autogen.sh \
 	&& make install \
 	&& make clean
 
-CMD ["/usr/local/bin/virtlet", "-logtostderr=true", "-libvirt-uri=qemu+tcp://libvirt/system", "-etcd-endpoint=http://etcd:2379"]
+CMD ["/bin/bash", "-c", "/usr/local/bin/virtlet -v=${VIRTLET_LOGLEVEL:-2} -logtostderr=true -libvirt-uri=qemu+tcp://libvirt/system -etcd-endpoint=http://etcd:2379"]

README.md

@@ -59,6 +59,13 @@ cd $(REPOSITORY_BASE_DIR)/contrib/docker-compose
 docker-compose up
 ```
 
+To set log verbosity level, use
+```sh
+VIRTLET_LOGLEVEL=3 docker-compose up
+```
+
+3 is currently highest verbosity level, the default being 2.
+
 Now you can follow instructions from next section.
 
 ### Kubernetes environment

cmd/fake-create-container/fake-create-container.go

@@ -21,6 +21,7 @@ import (
 	"fmt"
 	"os"
 
+	"github.com/davecgh/go-spew/spew"
 	"golang.org/x/net/context"
 	"google.golang.org/grpc"
 	kubeapi "k8s.io/kubernetes/pkg/kubelet/api/v1alpha1/runtime"
@@ -106,6 +107,6 @@ func main() {
 		os.Exit(1)
 	}
 
-	fmt.Printf("Got response: %#v\n", containerOut)
+	fmt.Printf("Got response: %s\n", spew.Sdump(containerOut))
 	fmt.Printf("Created container with ID: %s\n", *containerOut.ContainerId)
 }

cmd/fake-image-pull/fake-image-pull.go

@@ -21,6 +21,7 @@ import (
 	"fmt"
 	"os"
 
+	"github.com/davecgh/go-spew/spew"
 	"golang.org/x/net/context"
 	"google.golang.org/grpc"
 	kubeapi "k8s.io/kubernetes/pkg/kubelet/api/v1alpha1/runtime"
@@ -61,5 +62,5 @@ func main() {
 		os.Exit(1)
 	}
 
-	fmt.Printf("Got response: %#v\n", out)
+	fmt.Printf("Got response: %s\n", spew.Sdump(out))
 }

cmd/virtlet/virtlet.go

@@ -45,7 +45,7 @@ func main() {
 		glog.Errorf("Initializing server failed: %v", err)
 		os.Exit(1)
 	}
-	glog.Infof("Starting server on socket %s", *listen)
+	glog.V(1).Infof("Starting server on socket %s", *listen)
 	if err = server.Serve(*listen); err != nil {
 		glog.Errorf("Serving failed: %v", err)
 	}

contrib/docker-compose/docker-compose.yml

@@ -24,6 +24,8 @@ services:
     build: ../..
     # network_mode: host
     restart: always
+    environment:
+      - VIRTLET_LOGLEVEL
     volumes:
       - virtlet_data:/var/data/virtlet
       - /var/lib/virtlet:/var/lib/virtlet

glide.yaml

@@ -6,9 +6,11 @@ import:
   - context
 - package: google.golang.org/grpc
 - package: k8s.io/kubernetes
-  vcs: git
-  repo: git://github.com/kubernetes/kubernetes.git
   version: e72f26a3fff4f521d1da9f52b3ce82d4d0d5a401
+  repo: git://github.com/kubernetes/kubernetes.git
+  vcs: git
   subpackages:
   - pkg/kubelet/api/v1alpha1/runtime
   - api/v1alpha/runtime
+- package: github.com/davecgh/go-spew
+  version: ~1.0.0

pkg/bolttools/sandbox.go

@@ -23,6 +23,7 @@ import (
 	"time"
 
 	"github.com/boltdb/bolt"
+	"github.com/davecgh/go-spew/spew"
 	kubeapi "k8s.io/kubernetes/pkg/kubelet/api/v1alpha1/runtime"
 )
 
@@ -53,17 +54,17 @@ func (b *BoltClient) SetPodSandbox(config *kubeapi.PodSandboxConfig) error {
 
 	metadata := config.GetMetadata()
 	if metadata == nil {
-		return fmt.Errorf("sandbox config is missing Metadata attribute: %#v", config)
+		return fmt.Errorf("sandbox config is missing Metadata attribute: %s", spew.Sdump(config))
 	}
 
 	linuxSandbox := config.GetLinux()
 	if linuxSandbox == nil {
-		return fmt.Errorf("sandbox config is missing Linux attribute: %#v", config)
+		return fmt.Errorf("sandbox config is missing Linux attribute: %s", spew.Sdump(config))
 	}
 
 	namespaceOptions := linuxSandbox.GetNamespaceOptions()
 	if namespaceOptions == nil {
-		return fmt.Errorf("Linux sandbox config is missing Namespaces attribute: %#v", linuxSandbox)
+		return fmt.Errorf("Linux sandbox config is missing Namespaces attribute: %s", spew.Sdump(config))
 	}
 
 	err = b.db.Batch(func(tx *bolt.Tx) error {

pkg/download/download.go

@@ -53,7 +53,7 @@ func DownloadFile(fileUrl string) (string, string, error) {
 	}
 	defer fp.Close()
 
-	glog.Infof("Start downloading %s", fileUrl)
+	glog.V(2).Infof("Start downloading %s", fileUrl)
 
 	resp, err := http.Get(fileUrl)
 	if err != nil {
@@ -65,6 +65,6 @@ func DownloadFile(fileUrl string) (string, string, error) {
 	if err != nil {
 		return "", "", err
 	}
-	glog.Infof("Data from url %s saved in %s", fileUrl, filepath)
+	glog.V(2).Infof("Data from url %s saved in %s", fileUrl, filepath)
 	return filepath, shortName, nil
 }

pkg/libvirttools/storage_pool.go

@@ -62,7 +62,7 @@ func createPool(conn C.virConnectPtr, name string, path string, poolType string)
 	bPoolXML := []byte(poolXML)
 	cPoolXML := (*C.char)(unsafe.Pointer(&bPoolXML[0]))
 
-	glog.Infof("Creating storage pool (name: %s, path: %s)", name, path)
+	glog.V(2).Infof("Creating storage pool (name: %s, path: %s)", name, path)
 	var pool C.virStoragePoolPtr
 	if pool = C.virStoragePoolCreateXML(conn, cPoolXML, 0); pool == nil {
 		return nil, GetLastError()

pkg/libvirttools/storage_volume.go

@@ -78,7 +78,7 @@ func (LocalFilesystemBackend) CreateVol(pool C.virStoragePoolPtr, volName string
     <capacity unit="%s">%d</capacity>
 </volume>`
 	volXML = fmt.Sprintf(volXML, volName, capacityUnit, capacity)
-	glog.Infof("Create volume using XML description: %s", volXML)
+	glog.V(2).Infof("Create volume using XML description: %s", volXML)
 	cVolXML := C.CString(volXML)
 	defer C.free(unsafe.Pointer(cVolXML))
 	vol := C.virStorageVolCreateXML(pool, cVolXML, 0)

pkg/libvirttools/virtualization.go

@@ -138,7 +138,7 @@ func (v *VirtualizationTool) createVolumes(containerName string, mounts []*kubea
 	if len(mounts) == 0 {
 		return domXML, nil
 	}
-	glog.Infof("INPUT domain:\n%s\n\n", domXML)
+	glog.V(2).Infof("INPUT domain:\n%s\n\n", domXML)
 	domainXML := &Domain{}
 	err := xml.Unmarshal([]byte(domXML), domainXML)
 	if err != nil {
@@ -265,7 +265,7 @@ func (v *VirtualizationTool) CreateContainer(boltClient *bolttools.BoltClient, i
 			if domainID, err := v.GetDomainUUID(domain); err == nil {
 				//TODO: This is temp workaround for returning existent domain on create container call to overcome SyncPod issues
 				return domainID, nil
-				//glog.Infof("Removing domain with name: %s and id: %s", name, domainID)
+				//glog.V(2).Infof("Removing domain with name: %s and id: %s", name, domainID)
 				//v.RemoveContainer(domainID)
 			} else {
 				glog.Errorf("Failed to get UUID for domain with name: %s due to %v", name, err)
@@ -301,7 +301,7 @@ func (v *VirtualizationTool) CreateContainer(boltClient *bolttools.BoltClient, i
 	}
 
 	domXML = strings.Replace(domXML, "\"", "'", -1)
-	glog.Infof("Creating domain:\n%s", domXML)
+	glog.V(2).Infof("Creating domain:\n%s", domXML)
 	cDomXML := C.CString(domXML)
 	defer C.free(unsafe.Pointer(cDomXML))
 

pkg/manager/manager.go

@@ -23,6 +23,7 @@ import (
 	"strings"
 	"syscall"
 
+	"github.com/davecgh/go-spew/spew"
 	"github.com/golang/glog"
 	"golang.org/x/net/context"
 	"google.golang.org/grpc"
@@ -108,9 +109,9 @@ func (v *VirtletManager) RunPodSandbox(ctx context.Context, in *kubeapi.RunPodSa
 	config := in.GetConfig()
 	podId := config.GetMetadata().GetUid()
 	name := config.GetMetadata().GetName()
-	glog.Infof("RunPodSandbox called for pod %s (%s)", name, podId)
-	glog.Infof("Sandbox config labels: %v", config.GetLabels())
-	glog.Infof("Sandbox config annotations: %v", config.GetAnnotations())
+	glog.V(2).Infof("RunPodSandbox called for pod %s (%s)", name, podId)
+	glog.V(2).Infof("Sandbox config labels: %v", config.GetLabels())
+	glog.V(2).Infof("Sandbox config annotations: %v", config.GetAnnotations())
 	if err := v.boltClient.SetPodSandbox(config); err != nil {
 		glog.Errorf("Error when creating pod sandbox for pod %s (%s): %v", name, podId, err)
 		return nil, err
@@ -122,20 +123,22 @@ func (v *VirtletManager) RunPodSandbox(ctx context.Context, in *kubeapi.RunPodSa
 }
 
 func (v *VirtletManager) StopPodSandbox(ctx context.Context, in *kubeapi.StopPodSandboxRequest) (*kubeapi.StopPodSandboxResponse, error) {
-	glog.Infof("StopPodSandbox called for pod %s", in.GetPodSandboxId())
+	glog.V(2).Infof("StopPodSandbox called for pod %s", in.GetPodSandboxId())
 	response := &kubeapi.StopPodSandboxResponse{}
 	return response, nil
 }
 
 func (v *VirtletManager) RemovePodSandbox(ctx context.Context, in *kubeapi.RemovePodSandboxRequest) (*kubeapi.RemovePodSandboxResponse, error) {
 	podSandboxId := in.GetPodSandboxId()
-	glog.Infof("RemovePodSandbox called for pod %s", podSandboxId)
+	glog.V(2).Infof("RemovePodSandbox called for pod %s", podSandboxId)
 
 	if err := v.boltClient.RemovePodSandbox(podSandboxId); err != nil {
+		glog.Errorf("Error when removing pod sandbox '%s' status: %v", podSandboxId, err)
 		return nil, err
 	}
 
 	response := &kubeapi.RemovePodSandboxResponse{}
+	glog.V(3).Infof("RemovePodSandbox response: %s", spew.Sdump(response))
 	return response, nil
 }
 
@@ -147,17 +150,20 @@ func (v *VirtletManager) PodSandboxStatus(ctx context.Context, in *kubeapi.PodSa
 		return nil, err
 	}
 	response := &kubeapi.PodSandboxStatusResponse{Status: status}
+	glog.V(3).Infof("PodSandboxStatus response: %s", spew.Sdump(response))
 	return response, nil
 }
 
 func (v *VirtletManager) ListPodSandbox(ctx context.Context, in *kubeapi.ListPodSandboxRequest) (*kubeapi.ListPodSandboxResponse, error) {
 	filter := in.GetFilter()
+	glog.V(3).Infof("Listing sandboxes with filter: %s", spew.Sdump(filter))
 	podSandboxList, err := v.boltClient.ListPodSandbox(filter)
 	if err != nil {
-		glog.Errorf("Error when listing (with filter: %#v) pod sandboxes: %v", filter, err)
+		glog.Errorf("Error when listing (with filter: %s) pod sandboxes: %v", spew.Sdump(filter), err)
 		return nil, err
 	}
 	response := &kubeapi.ListPodSandboxResponse{Items: podSandboxList}
+	glog.V(3).Infof("ListPodSandbox response: %s", spew.Sdump(response))
 	return response, nil
 }
 
@@ -166,7 +172,7 @@ func (v *VirtletManager) CreateContainer(ctx context.Context, in *kubeapi.Create
 	imageName := config.GetImage().GetImage()
 	name := config.GetMetadata().GetName()
 
-	glog.Infof("CreateContainer called for name: %s", name)
+	glog.V(2).Infof("CreateContainer called for name: %s", name)
 
 	imageFilepath, err := v.boltClient.GetImageFilepath(imageName)
 	if err != nil {
@@ -182,12 +188,13 @@ func (v *VirtletManager) CreateContainer(ctx context.Context, in *kubeapi.Create
 	}
 
 	response := &kubeapi.CreateContainerResponse{ContainerId: &uuid}
+	glog.V(3).Infof("CreateContainer response: %s", spew.Sdump(response))
 	return response, nil
 }
 
 func (v *VirtletManager) StartContainer(ctx context.Context, in *kubeapi.StartContainerRequest) (*kubeapi.StartContainerResponse, error) {
 	containerId := in.GetContainerId()
-	glog.Infof("StartContainer called for containerID: %s", containerId)
+	glog.V(2).Infof("StartContainer called for containerID: %s", containerId)
 
 	if err := v.libvirtVirtualizationTool.StartContainer(containerId); err != nil {
 		glog.Errorf("Error when starting container %s: %v", containerId, err)
@@ -199,7 +206,7 @@ func (v *VirtletManager) StartContainer(ctx context.Context, in *kubeapi.StartCo
 
 func (v *VirtletManager) StopContainer(ctx context.Context, in *kubeapi.StopContainerRequest) (*kubeapi.StopContainerResponse, error) {
 	containerId := in.GetContainerId()
-	glog.Infof("StopContainer called for containerID: %s", containerId)
+	glog.V(2).Infof("StopContainer called for containerID: %s", containerId)
 
 	if err := v.libvirtVirtualizationTool.StopContainer(containerId); err != nil {
 		glog.Errorf("Error when stopping container %s: %v", containerId, err)
@@ -211,14 +218,15 @@ func (v *VirtletManager) StopContainer(ctx context.Context, in *kubeapi.StopCont
 
 func (v *VirtletManager) RemoveContainer(ctx context.Context, in *kubeapi.RemoveContainerRequest) (*kubeapi.RemoveContainerResponse, error) {
 	containerId := in.GetContainerId()
-	glog.Infof("RemoveContainer called for containerID: %s", containerId)
+	glog.V(2).Infof("RemoveContainer called for containerID: %s", containerId)
 
 	if err := v.libvirtVirtualizationTool.RemoveContainer(*in.ContainerId); err != nil {
 		glog.Errorf("Error when removing container '%s': %v", containerId, err)
 		return nil, err
 	}
 
 	if err := v.boltClient.RemoveContainer(containerId); err != nil {
+		glog.Errorf("Error when removing container '%s' from bolt: %v", containerId, err)
 		return nil, err
 	}
 
@@ -228,12 +236,14 @@ func (v *VirtletManager) RemoveContainer(ctx context.Context, in *kubeapi.Remove
 
 func (v *VirtletManager) ListContainers(ctx context.Context, in *kubeapi.ListContainersRequest) (*kubeapi.ListContainersResponse, error) {
 	filter := in.GetFilter()
+	glog.V(3).Infof("Listing containers with filter: %s", spew.Sdump(filter))
 	containers, err := v.libvirtVirtualizationTool.ListContainers(v.boltClient, filter)
 	if err != nil {
-		glog.Errorf("Error when listing containers with filter %#v: %v", filter, err)
+		glog.Errorf("Error when listing containers with filter %s: %v", spew.Sdump(filter), err)
 		return nil, err
 	}
 	response := &kubeapi.ListContainersResponse{Containers: containers}
+	glog.V(3).Infof("ListContainers response:\n%s\n", spew.Sdump(response))
 	return response, nil
 }
 
@@ -246,6 +256,7 @@ func (v *VirtletManager) ContainerStatus(ctx context.Context, in *kubeapi.Contai
 	}
 
 	response := &kubeapi.ContainerStatusResponse{Status: status}
+	glog.V(3).Infof("ContainerStatus response: %s", spew.Sdump(response))
 	return response, nil
 }
 
@@ -257,8 +268,10 @@ func (v *VirtletManager) ListImages(ctx context.Context, in *kubeapi.ListImagesR
 	images, err := v.libvirtImageTool.ListImages()
 	if err != nil {
 		glog.Errorf("Error when listing images: %v", err)
+		return nil, err
 	}
 	response := &kubeapi.ListImagesResponse{Images: images}
+	glog.V(3).Infof("ListImages response: %s", spew.Sdump(response))
 	return response, err
 }
 
@@ -280,6 +293,7 @@ func (v *VirtletManager) ImageStatus(ctx context.Context, in *kubeapi.ImageStatu
 	}
 
 	response := &kubeapi.ImageStatusResponse{Image: image}
+	glog.V(3).Infof("ImageStatus response: %s", spew.Sdump(response))
 	return response, err
 }
 
@@ -289,7 +303,7 @@ func stripTagFromImageName(name string) string {
 
 func (v *VirtletManager) PullImage(ctx context.Context, in *kubeapi.PullImageRequest) (*kubeapi.PullImageResponse, error) {
 	name := in.GetImage().GetImage()
-	glog.Infof("PullImage called for: %s", name)
+	glog.V(2).Infof("PullImage called for: %s", name)
 
 	name = stripTagFromImageName(name)
 
@@ -310,7 +324,7 @@ func (v *VirtletManager) PullImage(ctx context.Context, in *kubeapi.PullImageReq
 
 func (v *VirtletManager) RemoveImage(ctx context.Context, in *kubeapi.RemoveImageRequest) (*kubeapi.RemoveImageResponse, error) {
 	name := in.GetImage().GetImage()
-	glog.Infof("RemoveImage called for: %s", name)
+	glog.V(2).Infof("RemoveImage called for: %s", name)
 
 	filepath, err := v.boltClient.GetImageFilepath(name)
 	if err != nil {