state/apiserver: log API conn setup/teardown

state/apiserver/apiserver.go

 // Copyright 2013 Canonical Ltd.
 // Licensed under the AGPLv3, see LICENCE file for details.
 
 package apiserver
 
 import (
         "crypto/tls"
         "net"
         "net/http"
         "sync"
@@ skipping 65 matching lines @@
         srv.tomb.Kill(nil)
 }
 
 // Wait implements worker.Worker.Wait.
 func (srv *Server) Wait() error {
         return srv.tomb.Wait()
 }
 
 type requestNotifier struct {
         id    int64
-        mu    sync.Mutex
-        tag_  string
         start time.Time
+
+        mu   sync.Mutex
+        tag_ string
 }
 
 var globalCounter int64
 
 func newRequestNotifier() *requestNotifier {
         return &requestNotifier{
                 id:    atomic.AddInt64(&globalCounter, 1),
                 tag_:  "<unknown>",
                 start: time.Now(),
         }
@@ skipping 21 matching lines @@
 }
 
 func (n *requestNotifier) ServerReply(req rpc.Request, hdr *rpc.Header, body interface{}, timeSpent time.Duration) {
         if req.Type == "Pinger" && req.Action == "Ping" {
                 return
         }
         logger.Debugf("-> [%X] %s %s %s %s[%q].%s", n.id, n.tag(), timeSpent, jsoncodec.DumpRequest(hdr, body), req.Type, req.Id, req.Action)
 }
 
 func (n *requestNotifier) join(req *http.Request) {
-        logger.Debugf("[%X] API connection from %s", n.id, req.RemoteAddr)
+        logger.Infof("[%X] API connection from %s", n.id, req.RemoteAddr)
 }
 
 func (n *requestNotifier) leave() {
-        logger.Debugf("[%X] API connection terminated after %v", n.id, time.Since(n.start))
+        logger.Infof("[%X] API connection terminated after %v", n.id, time.Since(n.start))
 }
 
 func (n requestNotifier) ClientRequest(hdr *rpc.Header, body interface{}) {
 }
 
 func (n requestNotifier) ClientReply(req rpc.Request, hdr *rpc.Header, body interface{}) {
 }
 
 func (srv *Server) run(lis net.Listener) {
         defer srv.tomb.Done()
         defer srv.wg.Wait() // wait for any outstanding requests to complete.
         srv.wg.Add(1)
         go func() {
                 <-srv.tomb.Dying()
                 lis.Close()
                 srv.wg.Done()
         }()
         mux := http.NewServeMux()
         mux.HandleFunc("/", srv.apiHandler)
         mux.Handle("/charms", &charmsHandler{state: srv.state})
         // The error from http.Serve is not interesting.
         http.Serve(lis, mux)
 }
 
 func (srv *Server) apiHandler(w http.ResponseWriter, req *http.Request) {
-        var reqNotifier *requestNotifier
-        if logger.EffectiveLogLevel() <= loggo.DEBUG {
-                reqNotifier = newRequestNotifier()
-                reqNotifier.join(req)
-                defer reqNotifier.leave()
-        }
+        reqNotifier := newRequestNotifier()
+        reqNotifier.join(req)
+        defer reqNotifier.leave()
         wsServer := websocket.Server{
                 Handler: func(conn *websocket.Conn) {
                         srv.wg.Add(1)
                         defer srv.wg.Done()
                         // If we've got to this stage and the tomb is still
                         // alive, we know that any tomb.Kill must occur after we
                         // have called wg.Add, so we avoid the possibility of a
                         // handler goroutine running after Stop has returned.
                         if srv.tomb.Err() != tomb.ErrStillAlive {
                                 return
@@ skipping 10 matching lines @@
 func (srv *Server) Addr() string {
         return srv.addr.String()
 }
 
 func (srv *Server) serveConn(wsConn *websocket.Conn, reqNotifier *requestNotifier) error {
         codec := jsoncodec.NewWebsocket(wsConn)
         if loggo.GetLogger("juju.rpc.jsoncodec").EffectiveLogLevel() <= loggo.TRACE {
                 codec.SetLogging(true)
         }
         var notifier rpc.RequestNotifier
-        if reqNotifier != nil {
+        if logger.EffectiveLogLevel() <= loggo.DEBUG {
+                // Incur request monitoring overhead only if we
+                // know we'll need it.
                 notifier = reqNotifier
         }
         conn := rpc.NewConn(codec, notifier)
         conn.Serve(newStateServer(srv, conn, reqNotifier), serverError)
         conn.Start()
         select {
         case <-conn.Dead():
         case <-srv.tomb.Dying():
         }
         return conn.Close()
 }
 
 func serverError(err error) error {
         if err := common.ServerError(err); err != nil {
                 return err
         }
         return nil
 }
 
 var logRequests = true