Initial steps to fix Issue #936

Use utils.Errorf instead of utils.Debugf

AUTHORS

@@ -95,6 +95,7 @@ Joseph Anthony Pasquale Holsten <joseph@josephholsten.com>
 Julien Barbier <write0@gmail.com>
 Jérôme Petazzoni <jerome.petazzoni@dotcloud.com>
 Karan Lyons <karan@karanlyons.com>
+Karl Grzeszczak <karl@karlgrz.com>
 Kawsar Saiyeed <kawsar.saiyeed@projiris.com>
 Keli Hu <dev@keli.hu>
 Ken Cochrane <kencochrane@gmail.com>

api.go

@@ -70,8 +70,11 @@ func httpError(w http.ResponseWriter, err error) {
 	} else if strings.Contains(err.Error(), "hasn't been activated") {
 		statusCode = http.StatusForbidden
 	}	
-	utils.Debugf("[error %d] %s", statusCode, err)
+	
+	if err != nil {
+		utils.Errorf("HTTP Error: statusCode=%d %s", statusCode, err.Error())
 		http.Error(w, err.Error(), statusCode)		
+	}	
 }
 
 func writeJSON(w http.ResponseWriter, code int, v interface{}) error {
@@ -102,7 +105,7 @@ func getBoolParam(value string) (bool, error) {
 func matchesContentType(contentType, expectedType string) bool {
 	mimetype, _, err := mime.ParseMediaType(contentType)
 	if err != nil {
-		utils.Debugf("Error parsing media type: %s error: %s", contentType, err.Error())
+		utils.Errorf("Error parsing media type: %s error: %s", contentType, err.Error())
 	}
 	return err == nil && mimetype == expectedType
 }
@@ -147,7 +150,7 @@ func getContainersExport(srv *Server, version float64, w http.ResponseWriter, r
 	name := vars["name"]
 
 	if err := srv.ContainerExport(name, w); err != nil {
-		utils.Debugf("%s", err)
+		utils.Errorf("%s", err)
 		return err
 	}
 	return nil
@@ -192,7 +195,7 @@ func getEvents(srv *Server, version float64, w http.ResponseWriter, r *http.Requ
 		_, err = wf.Write(b)
 		if err != nil {
 			// On error, evict the listener
-			utils.Debugf("%s", err)
+			utils.Errorf("%s", err)
 			srv.Lock()
 			delete(srv.listeners, r.RemoteAddr)
 			srv.Unlock()
@@ -347,7 +350,7 @@ func postCommit(srv *Server, version float64, w http.ResponseWriter, r *http.Req
 	}
 	config := &Config{}
 	if err := json.NewDecoder(r.Body).Decode(config); err != nil {
-		utils.Debugf("%s", err)
+		utils.Errorf("%s", err)
 	}
 	repo := r.Form.Get("repo")
 	tag := r.Form.Get("tag")
@@ -792,7 +795,7 @@ func wsContainersAttach(srv *Server, version float64, w http.ResponseWriter, r *
 		defer ws.Close()
 
 		if err := srv.ContainerAttach(name, logs, stream, stdin, stdout, stderr, ws, ws, ws); err != nil {
-			utils.Debugf("Error: %s", err)
+			utils.Errorf("Error: %s", err)
 		}
 	})
 	h.ServeHTTP(w, r)
@@ -938,7 +941,7 @@ func postContainersCopy(srv *Server, version float64, w http.ResponseWriter, r *
 	}
 
 	if err := srv.ContainerCopy(name, copyData.Resource, w); err != nil {
-		utils.Debugf("%s", err.Error())
+		utils.Errorf("%s", err.Error())
 		return err
 	}
 	return nil
@@ -983,7 +986,7 @@ func makeHttpHandler(srv *Server, logging bool, localMethod string, localRoute s
 		}
 
 		if err := handlerFunc(srv, version, w, r, mux.Vars(r)); err != nil {
-			utils.Debugf("Error: %s", err)
+			utils.Errorf("Error: %s", err)
 			httpError(w, err)
 		}
 	}

buildfile.go

@@ -176,7 +176,7 @@ func (b *buildFile) CmdEnv(args string) error {
 func (b *buildFile) CmdCmd(args string) error {
 	var cmd []string
 	if err := json.Unmarshal([]byte(args), &cmd); err != nil {
-		utils.Debugf("Error unmarshalling: %s, setting cmd to /bin/sh -c", err)
+		utils.Errorf("Error unmarshalling: %s, setting cmd to /bin/sh -c", err)
 		cmd = []string{"/bin/sh", "-c", args}
 	}
 	if err := b.commit("", cmd, fmt.Sprintf("CMD %v", cmd)); err != nil {
@@ -296,7 +296,7 @@ func (b *buildFile) addContext(container *Container, orig, dest string) error {
 		}
 		// First try to unpack the source as an archive
 	} else if err := UntarPath(origPath, destPath); err != nil {
-		utils.Debugf("Couldn't untar %s to %s: %s", origPath, destPath, err)
+		utils.Errorf("Couldn't untar %s to %s: %s", origPath, destPath, err)
 		// If that fails, just copy it as a regular file
 		if err := os.MkdirAll(path.Dir(destPath), 0755); err != nil {
 			return err

commands.go

@@ -418,7 +418,7 @@ func (cli *DockerCli) CmdVersion(args ...string) error {
 	var out APIVersion
 	err = json.Unmarshal(body, &out)
 	if err != nil {
-		utils.Debugf("Error unmarshal: body: %s, err: %s\n", body, err)
+		utils.Errorf("Error unmarshal: body: %s, err: %s\n", body, err)
 		return err
 	}
 	if out.Version != "" {
@@ -1533,7 +1533,7 @@ func (cli *DockerCli) CmdRun(args ...string) error {
 	if config.AttachStdin || config.AttachStdout || config.AttachStderr {
 		if config.Tty {
 			if err := cli.monitorTtySize(runResult.ID); err != nil {
-				utils.Debugf("Error monitoring TTY size: %s\n", err)
+				utils.Errorf("Error monitoring TTY size: %s\n", err)
 			}
 		}
 
@@ -1798,11 +1798,11 @@ func (cli *DockerCli) hijack(method, path string, setRawTerminal bool, in io.Rea
 		}
 		if tcpc, ok := rwc.(*net.TCPConn); ok {
 			if err := tcpc.CloseWrite(); err != nil {
-				utils.Debugf("Couldn't send EOF: %s\n", err)
+				utils.Errorf("Couldn't send EOF: %s\n", err)
 			}
 		} else if unixc, ok := rwc.(*net.UnixConn); ok {
 			if err := unixc.CloseWrite(); err != nil {
-				utils.Debugf("Couldn't send EOF: %s\n", err)
+				utils.Errorf("Couldn't send EOF: %s\n", err)
 			}
 		}
 		// Discard errors due to pipe interruption
@@ -1811,14 +1811,14 @@ func (cli *DockerCli) hijack(method, path string, setRawTerminal bool, in io.Rea
 
 	if stdout != nil {
 		if err := <-receiveStdout; err != nil {
-			utils.Debugf("Error receiveStdout: %s", err)
+			utils.Errorf("Error receiveStdout: %s", err)
 			return err
 		}
 	}
 
 	if !cli.isTerminal {
 		if err := <-sendStdin; err != nil {
-			utils.Debugf("Error sendStdin: %s", err)
+			utils.Errorf("Error sendStdin: %s", err)
 			return err
 		}
 	}
@@ -1832,7 +1832,7 @@ func (cli *DockerCli) getTtySize() (int, int) {
 	}
 	ws, err := term.GetWinsize(cli.terminalFd)
 	if err != nil {
-		utils.Debugf("Error getting size: %s", err)
+		utils.Errorf("Error getting size: %s", err)
 		if ws == nil {
 			return 0, 0
 		}
@@ -1849,7 +1849,7 @@ func (cli *DockerCli) resizeTty(id string) {
 	v.Set("h", strconv.Itoa(height))
 	v.Set("w", strconv.Itoa(width))
 	if _, _, err := cli.call("POST", "/containers/"+id+"/resize?"+v.Encode(), nil); err != nil {
-		utils.Debugf("Error resize: %s", err)
+		utils.Errorf("Error resize: %s", err)
 	}
 }
 

container.go

@@ -461,7 +461,7 @@ func (container *Container) Attach(stdin io.ReadCloser, stdinCloser io.Closer, s
 					_, err = io.Copy(cStdin, stdin)
 				}
 				if err != nil {
-					utils.Debugf("[error] attach stdin: %s\n", err)
+					utils.Errorf("[error] attach stdin: %s\n", err)
 				}
 				// Discard error, expecting pipe error
 				errors <- nil
@@ -486,7 +486,7 @@ func (container *Container) Attach(stdin io.ReadCloser, stdinCloser io.Closer, s
 				}
 				_, err := io.Copy(stdout, cStdout)
 				if err != nil {
-					utils.Debugf("[error] attach stdout: %s\n", err)
+					utils.Errorf("[error] attach stdout: %s\n", err)
 				}
 				errors <- err
 			}()
@@ -498,7 +498,7 @@ func (container *Container) Attach(stdin io.ReadCloser, stdinCloser io.Closer, s
 			}
 
 			if cStdout, err := container.StdoutPipe(); err != nil {
-				utils.Debugf("Error stdout pipe")
+				utils.Errorf("Error stdout pipe")
 			} else {
 				io.Copy(&utils.NopWriter{}, cStdout)
 			}
@@ -522,7 +522,7 @@ func (container *Container) Attach(stdin io.ReadCloser, stdinCloser io.Closer, s
 				}
 				_, err := io.Copy(stderr, cStderr)
 				if err != nil {
-					utils.Debugf("[error] attach stderr: %s\n", err)
+					utils.Errorf("[error] attach stderr: %s\n", err)
 				}
 				errors <- err
 			}()
@@ -534,7 +534,7 @@ func (container *Container) Attach(stdin io.ReadCloser, stdinCloser io.Closer, s
 			}
 
 			if cStderr, err := container.StderrPipe(); err != nil {
-				utils.Debugf("Error stdout pipe")
+				utils.Errorf("Error stdout pipe")
 			} else {
 				io.Copy(&utils.NopWriter{}, cStderr)
 			}
@@ -553,7 +553,7 @@ func (container *Container) Attach(stdin io.ReadCloser, stdinCloser io.Closer, s
 		for i := 0; i < nJobs; i += 1 {
 			utils.Debugf("Waiting for job %d/%d\n", i+1, nJobs)
 			if err := <-errors; err != nil {
-				utils.Debugf("Job %d returned error %s. Aborting all jobs\n", i+1, err)
+				utils.Errorf("Job %d returned error %s. Aborting all jobs\n", i+1, err)
 				return err
 			}
 			utils.Debugf("Job %d completed successfully\n", i+1)
@@ -958,12 +958,12 @@ func (container *Container) monitor(hostConfig *HostConfig) {
 	// If the command does not exists, try to wait via lxc
 	if container.cmd == nil {
 		if err := container.waitLxc(); err != nil {
-			utils.Debugf("%s: Process: %s", container.ID, err)
+			utils.Errorf("%s: Process: %s", container.ID, err)
 		}
 	} else {
 		if err := container.cmd.Wait(); err != nil {
 			// Discard the error as any signals or non 0 returns will generate an error
-			utils.Debugf("%s: Process: %s", container.ID, err)
+			utils.Errorf("%s: Process: %s", container.ID, err)
 		}
 	}
 	utils.Debugf("Process finished")
@@ -984,19 +984,19 @@ func (container *Container) monitor(hostConfig *HostConfig) {
 	container.releaseNetwork()
 	if container.Config.OpenStdin {
 		if err := container.stdin.Close(); err != nil {
-			utils.Debugf("%s: Error close stdin: %s", container.ID, err)
+			utils.Errorf("%s: Error close stdin: %s", container.ID, err)
 		}
 	}
 	if err := container.stdout.CloseWriters(); err != nil {
-		utils.Debugf("%s: Error close stdout: %s", container.ID, err)
+		utils.Errorf("%s: Error close stdout: %s", container.ID, err)
 	}
 	if err := container.stderr.CloseWriters(); err != nil {
-		utils.Debugf("%s: Error close stderr: %s", container.ID, err)
+		utils.Errorf("%s: Error close stderr: %s", container.ID, err)
 	}
 
 	if container.ptyMaster != nil {
 		if err := container.ptyMaster.Close(); err != nil {
-			utils.Debugf("%s: Error closing Pty master: %s", container.ID, err)
+			utils.Errorf("%s: Error closing Pty master: %s", container.ID, err)
 		}
 	}
 

mount.go

@@ -12,7 +12,7 @@ import (
 
 func Unmount(target string) error {
 	if err := exec.Command("auplink", target, "flush").Run(); err != nil {
-		utils.Debugf("[warning]: couldn't run auplink before unmount: %s", err)
+		utils.Errorf("[warning]: couldn't run auplink before unmount: %s", err)
 	}
 	if err := syscall.Unmount(target, 0); err != nil {
 		return err

network_proxy.go

@@ -103,7 +103,7 @@ func (proxy *TCPProxy) Run() {
 	for {
 		client, err := proxy.listener.Accept()
 		if err != nil {
-			utils.Debugf("Stopping proxy on tcp/%v for tcp/%v (%v)", proxy.frontendAddr, proxy.backendAddr, err.Error())
+			utils.Errorf("Stopping proxy on tcp/%v for tcp/%v (%v)", proxy.frontendAddr, proxy.backendAddr, err.Error())
 			return
 		}
 		go proxy.clientLoop(client.(*net.TCPConn), quit)
@@ -205,7 +205,7 @@ func (proxy *UDPProxy) Run() {
 			// NOTE: Apparently ReadFrom doesn't return
 			// ECONNREFUSED like Read do (see comment in
 			// UDPProxy.replyLoop)
-			utils.Debugf("Stopping proxy on udp/%v for udp/%v (%v)", proxy.frontendAddr, proxy.backendAddr, err.Error())
+			utils.Errorf("Stopping proxy on udp/%v for udp/%v (%v)", proxy.frontendAddr, proxy.backendAddr, err.Error())
 			break
 		}
 

runtime.go

@@ -235,7 +235,7 @@ func (runtime *Runtime) restore() error {
 			fmt.Printf("\b%c", wheel[i%4])
 		}
 		if err != nil {
-			utils.Debugf("Failed to load container %v: %v", id, err)
+			utils.Errorf("Failed to load container %v: %v", id, err)
 			continue
 		}
 		utils.Debugf("Loaded container %v", container.ID)

server.go

@@ -429,7 +429,7 @@ func (srv *Server) pullImage(r *registry.Registry, out io.Writer, imgID, endpoin
 
 		// ensure no two downloads of the same layer happen at the same time
 		if err := srv.poolAdd("pull", "layer:"+id); err != nil {
-			utils.Debugf("Image (id: %s) pull is already running, skipping: %v", id, err)
+			utils.Errorf("Image (id: %s) pull is already running, skipping: %v", id, err)
 			return nil
 		}
 		defer srv.poolRemove("pull", "layer:"+id)
@@ -478,7 +478,7 @@ func (srv *Server) pullRepository(r *registry.Registry, out io.Writer, localName
 	utils.Debugf("Retrieving the tag list")
 	tagsList, err := r.GetRemoteTags(repoData.Endpoints, remoteName, repoData.Tokens)
 	if err != nil {
-		utils.Debugf("%v", err)
+		utils.Errorf("%v", err)
 		return err
 	}
 
@@ -526,7 +526,7 @@ func (srv *Server) pullRepository(r *registry.Registry, out io.Writer, localName
 
 			// ensure no two downloads of the same image happen at the same time
 			if err := srv.poolAdd("pull", "img:"+img.ID); err != nil {
-				utils.Debugf("Image (id: %s) pull is already running, skipping: %v", img.ID, err)
+				utils.Errorf("Image (id: %s) pull is already running, skipping: %v", img.ID, err)
 				if parallel {
 					errors <- nil
 				}
@@ -1191,25 +1191,25 @@ func (srv *Server) ContainerAttach(name string, logs, stream, stdin, stdout, std
 		cLog, err := container.ReadLog("json")
 		if err != nil && os.IsNotExist(err) {
 			// Legacy logs
-			utils.Debugf("Old logs format")
+			utils.Errorf("Old logs format")
 			if stdout {
 				cLog, err := container.ReadLog("stdout")
 				if err != nil {
-					utils.Debugf("Error reading logs (stdout): %s", err)
+					utils.Errorf("Error reading logs (stdout): %s", err)
 				} else if _, err := io.Copy(outStream, cLog); err != nil {
-					utils.Debugf("Error streaming logs (stdout): %s", err)
+					utils.Errorf("Error streaming logs (stdout): %s", err)
 				}
 			}
 			if stderr {
 				cLog, err := container.ReadLog("stderr")
 				if err != nil {
-					utils.Debugf("Error reading logs (stderr): %s", err)
+					utils.Errorf("Error reading logs (stderr): %s", err)
 				} else if _, err := io.Copy(errStream, cLog); err != nil {
-					utils.Debugf("Error streaming logs (stderr): %s", err)
+					utils.Errorf("Error streaming logs (stderr): %s", err)
 				}
 			}
 		} else if err != nil {
-			utils.Debugf("Error reading logs (json): %s", err)
+			utils.Errorf("Error reading logs (json): %s", err)
 		} else {
 			dec := json.NewDecoder(cLog)
 			for {
@@ -1218,7 +1218,7 @@ func (srv *Server) ContainerAttach(name string, logs, stream, stdin, stdout, std
 				if err := dec.Decode(l); err == io.EOF {
 					break
 				} else if err != nil {
-					utils.Debugf("Error streaming logs: %s", err)
+					utils.Errorf("Error streaming logs: %s", err)
 					break
 				}
 				if l.Stream == "stdout" && stdout {

utils/utils.go

@@ -45,13 +45,9 @@ func Download(url string, stderr io.Writer) (*http.Response, error) {
 	return resp, nil
 }
 
-// Debug function, if the debug flag is set, then display. Do nothing otherwise
-// If Docker is in damon mode, also send the debug info on the socket
-func Debugf(format string, a ...interface{}) {
-	if os.Getenv("DEBUG") != "" {
-
+func logf(level string, format string, a ...interface{}) {
 	// Retrieve the stack infos
-		_, file, line, ok := runtime.Caller(1)
+	_, file, line, ok := runtime.Caller(2)
 	if !ok {
 		file = "<unknown>"
 		line = -1
@@ -59,10 +55,21 @@ func Debugf(format string, a ...interface{}) {
 		file = file[strings.LastIndex(file, "/")+1:]
 	}
 
-		fmt.Fprintf(os.Stderr, fmt.Sprintf("[debug] %s:%d %s\n", file, line, format), a...)
+	fmt.Fprintf(os.Stderr, fmt.Sprintf("[%s] %s:%d %s\n", level, file, line, format), a...)
+}
+
+// Debug function, if the debug flag is set, then display. Do nothing otherwise
+// If Docker is in damon mode, also send the debug info on the socket
+func Debugf(format string, a ...interface{}) {
+	if os.Getenv("DEBUG") != "" {
+		logf("debug", format, a...)
 	}
 }
 
+func Errorf(format string, a ...interface{}) {
+	logf("error", format, a...)
+}
+
 // Reader with progress bar
 type progressReader struct {
 	reader       io.ReadCloser // Stream to read from
@@ -319,7 +326,7 @@ func NewWriteBroadcaster() *WriteBroadcaster {
 
 func GetTotalUsedFds() int {
 	if fds, err := ioutil.ReadDir(fmt.Sprintf("/proc/%d/fd", os.Getpid())); err != nil {
-		Debugf("Error opening /proc/%d/fd: %s", os.Getpid(), err)
+		Errorf("Error opening /proc/%d/fd: %s", os.Getpid(), err)
 	} else {
 		return len(fds)
 	}
@@ -771,7 +778,7 @@ func IsGIT(str string) bool {
 func GetResolvConf() ([]byte, error) {
 	resolv, err := ioutil.ReadFile("/etc/resolv.conf")
 	if err != nil {
-		Debugf("Error openning resolv.conf: %s", err)
+		Errorf("Error openning resolv.conf: %s", err)
 		return nil, err
 	}
 	return resolv, nil