Merge lp:~chipaca/ubuntu-push/lots-of-small-logging-changes into lp:ubuntu-push/automatic

[John Lenton]

A clean-up of a lot of small logging changes done during debugging.

A clean-up of a lot of small logging changes done during debugging.

[lp:~chipaca/ubuntu-push/lots-of-small-logging-changes]

357. By John Lenton on 2015-01-21

one more small logging change

[Bret Barker (noise)]

+1

review: Approve

[lp:~chipaca/ubuntu-push/lots-of-small-logging-changes]

358. By John Lenton on 2015-01-22

missed a capita-cased log line

=== modified file 'bus/connectivity/connectivity.go'
--- bus/connectivity/connectivity.go	2014-07-04 19:12:38 +0000
+++ bus/connectivity/connectivity.go	2015-01-21 17:26:27 +0000
@@ -82,7 +82,7 @@
 		// Get the current state.
 		initial = nm.GetState()
 		if initial == networkmanager.Unknown {
-			cs.log.Debugf("Failed to get state.")
+			cs.log.Debugf("failed to get state.")
 			goto Continue
 		}
 		cs.log.Debugf("got initial state of %s", initial)
@@ -143,17 +143,17 @@
 
 		case <-cs.timer.C:
 			if cs.currentState == networkmanager.ConnectedGlobal {
-				log.Debugf("May be connected; checking...")
+				log.Debugf("may be connected; checking...")
 				cs.webgetCh = make(chan bool)
 				go cs.webget(cs.webgetCh)
 			}
 
 		case connected := <-cs.webgetCh:
 			cs.timer.Reset(recheckTimeout)
-			log.Debugf("Connection check says: %t", connected)
+			log.Debugf("connection check says: %t", connected)
 			cs.webgetCh = nil
 			if connected && cs.lastSent == false {
-				log.Infof("Sending 'connected'.")
+				log.Debugf("sending 'connected'.")
 				cs.lastSent = true
 				break Loop
 			}
@@ -178,7 +178,7 @@
 	}
 
 Start:
-	log.Infof("Sending initial 'disconnected'.")
+	log.Debugf("Sending initial 'disconnected'.")
 	out <- false
 	cs.lastSent = false
 	cs.currentState = cs.start()

=== modified file 'bus/connectivity/webchecker.go'
--- bus/connectivity/webchecker.go	2014-03-20 12:24:33 +0000
+++ bus/connectivity/webchecker.go	2015-01-21 17:26:27 +0000
@@ -64,7 +64,7 @@
 func (wb *webchecker) Webcheck(ch chan<- bool) {
 	response, err := wb.cli.Get(wb.url)
 	if err != nil {
-		wb.log.Errorf("While GETting %s: %v", wb.url, err)
+		wb.log.Errorf("while GETting %s: %v", wb.url, err)
 		ch <- false
 		return
 	}
@@ -72,17 +72,17 @@
 	hash := md5.New()
 	_, err = io.CopyN(hash, response.Body, 1024)
 	if err != io.EOF {
-		wb.log.Errorf("Reading %s, expecting EOF, got: %v",
+		wb.log.Errorf("reading %s, expecting EOF, got: %v",
 			wb.url, err)
 		ch <- false
 		return
 	}
 	sum := fmt.Sprintf("%x", hash.Sum(nil))
 	if sum == wb.target {
-		wb.log.Infof("Connectivity check passed.")
+		wb.log.Infof("connectivity check passed.")
 		ch <- true
 	} else {
-		wb.log.Infof("Connectivity check failed: content mismatch.")
+		wb.log.Infof("connectivity check failed: content mismatch.")
 		ch <- false
 	}
 }

=== modified file 'bus/endpoint.go'
--- bus/endpoint.go	2014-09-08 15:48:00 +0000
+++ bus/endpoint.go	2015-01-21 17:26:27 +0000
@@ -110,7 +110,7 @@
 			return errors.New(msg)
 		}
 	}
-	endp.log.Infof("%#v dialed in.", name)
+	endp.log.Debugf("%#v dialed in.", name)
 	endp.bus = bus
 	endp.proxy = bus.Object(name, dbus.ObjectPath(endp.addr.Path))
 	return nil

=== modified file 'bus/systemimage/systemimage.go'
--- bus/systemimage/systemimage.go	2014-04-02 08:46:48 +0000
+++ bus/systemimage/systemimage.go	2015-01-21 17:26:27 +0000
@@ -57,7 +57,7 @@
 var _ SystemImage = &systemImage{} // ensures it conforms
 
 func (si *systemImage) Info() (*InfoResult, error) {
-	si.log.Debugf("Invoking Info")
+	si.log.Debugf("invoking Info")
 	res := &InfoResult{}
 	err := si.endp.Call("Info", bus.Args(), &res.BuildNumber, &res.Device, &res.Channel, &res.LastUpdate, &res.VersionDetail)
 	if err != nil {

=== modified file 'client/service/postal.go'
--- client/service/postal.go	2014-11-03 13:36:00 +0000
+++ client/service/postal.go	2015-01-21 17:26:27 +0000
@@ -244,7 +244,6 @@
 	for _, endp := range endps {
 		go func(name string, endp bus.Endpoint) {
 			util.NewAutoRedialer(endp).Redial()
-			svc.Log.Debugf("%s dialed in", name)
 			wg.Done()
 		}(endp.name, endp.endp)
 	}

=== modified file 'client/session/session.go'
--- client/session/session.go	2014-11-19 13:58:12 +0000
+++ client/session/session.go	2015-01-21 17:26:27 +0000
@@ -508,6 +508,7 @@
 		sess.proto.SetDeadline(time.Now().Add(deadAfter))
 		err = sess.proto.ReadMessage(&recv)
 		if err != nil {
+			sess.Log.Debugf("session aborting with error on read.")
 			sess.setState(Error)
 			return err
 		}
@@ -529,6 +530,7 @@
 			sess.Log.Errorf("server sent warning: %s", recv.Reason)
 		}
 		if err != nil {
+			sess.Log.Debugf("session aborting with error from handler.")
 			return err
 		}
 	}

=== modified file 'dependencies.tsv'
--- dependencies.tsv	2014-08-20 12:42:51 +0000
+++ dependencies.tsv	2015-01-21 17:26:27 +0000
@@ -1,5 +1,5 @@
 code.google.com/p/go-uuid	hg	7dda39b2e7d5e265014674c5af696ba4186679e9	11
 code.google.com/p/gosqlite	hg	74691fb6f83716190870cde1b658538dd4b18eb0	15
-launchpad.net/go-dbus/v1	bzr	[e-mail]-20140801110939-lzfql7fk76dt6ckd	128
+launchpad.net/go-dbus/v1	bzr	[e-mail]-20141023032446-s5icvsucwlv5o38a	129
 launchpad.net/go-xdg/v0	bzr	[e-mail]-20140208094800-gubd5md7cro3mtxa	10
 launchpad.net/gocheck	bzr	[e-mail]-20140225173054-xu9zlkf9kxhvow02	87

=== modified file 'launch_helper/kindpool.go'
--- launch_helper/kindpool.go	2014-11-05 12:07:53 +0000
+++ launch_helper/kindpool.go	2015-01-21 17:26:27 +0000
@@ -296,7 +296,7 @@
 	if err != nil {
 		pool.log.Errorf("unable to read output from %v helper: %v", args.AppId, err)
 	} else {
-		pool.log.Infof("%v helper output: %#v", args.AppId, payload)
+		pool.log.Infof("%v helper output: %s", args.AppId, payload)
 		res := &HelperResult{Input: args.Input}
 		err = json.Unmarshal(payload, &res.HelperOutput)
 		if err != nil {

=== modified file 'poller/poller.go'
--- poller/poller.go	2014-08-29 13:50:16 +0000
+++ poller/poller.go	2015-01-21 17:26:27 +0000
@@ -167,7 +167,7 @@
 		// the channel will produce a true for every
 		// wakeup, not only the one we asked for
 		now := time.Now()
-		p.log.Debugf("got woken up; time is %s", now)
+		p.log.Debugf("got woken up; time is %s (𝛥: %s)", now, now.Sub(t))
 		if !now.Before(t) {
 			break
 		}