lib/connections: Consistent log levels & polish (fixes #4510)

GitHub-Pull-Request: https://github.com/syncthing/syncthing/pull/4511

lib/connections/kcp_dial.go

@@ -44,7 +44,6 @@ func (d *kcpDialer) Dial(id protocol.DeviceID, uri *url.URL) (internalConn, erro
 		conn, err = kcp.DialWithOptions(uri.Host, nil, 0, 0)
 	}
 	if err != nil {
-		l.Debugln(err)
 		conn.Close()
 		return internalConn{}, err
 	}

lib/connections/kcp_listen.go

@@ -59,7 +59,7 @@ func (t *kcpListener) Serve() {
 		t.mut.Lock()
 		t.err = err
 		t.mut.Unlock()
-		l.Infoln("listen (BEP/kcp):", err)
+		l.Infoln("Listen (BEP/kcp):", err)
 		return
 	}
 	filterConn := pfilter.NewPacketFilter(packetConn)
@@ -76,7 +76,7 @@ func (t *kcpListener) Serve() {
 		t.mut.Lock()
 		t.err = err
 		t.mut.Unlock()
-		l.Infoln("listen (BEP/kcp):", err)
+		l.Infoln("Listen (BEP/kcp):", err)
 		return
 	}
 
@@ -105,7 +105,7 @@ func (t *kcpListener) Serve() {
 		}
 		if err != nil {
 			if err, ok := err.(net.Error); !ok || !err.Timeout() {
-				l.Warnln("Accepting connection (BEP/kcp):", err)
+				l.Warnln("Listen (BEP/kcp): Accepting connection:", err)
 			}
 			continue
 		}

lib/connections/relay_dial.go

@@ -45,7 +45,7 @@ func (d *relayDialer) Dial(id protocol.DeviceID, uri *url.URL) (internalConn, er
 
 	err = dialer.SetTrafficClass(conn, d.cfg.Options().TrafficClass)
 	if err != nil {
-		l.Debugf("failed to set traffic class: %s", err)
+		l.Debugln("Dial (BEP/relay): setting traffic class:", err)
 	}
 
 	var tc *tls.Conn

lib/connections/relay_listen.go

@@ -50,7 +50,7 @@ func (t *relayListener) Serve() {
 		t.mut.Lock()
 		t.err = err
 		t.mut.Unlock()
-		l.Warnln("listen (BEP/relay):", err)
+		l.Warnln("Listen (BEP/relay):", err)
 		return
 	}
 
@@ -62,6 +62,9 @@ func (t *relayListener) Serve() {
 
 	oldURI := clnt.URI()
 
+	l.Infof("Relay listener (%v) starting", t)
+	defer l.Infof("Relay listener (%v) shutting down", t)
+
 	for {
 		select {
 		case inv, ok := <-invitations:
@@ -71,18 +74,18 @@ func (t *relayListener) Serve() {
 
 			conn, err := client.JoinSession(inv)
 			if err != nil {
-				l.Infoln("Joining relay session (BEP/relay):", err)
+				l.Infoln("Listen (BEP/relay): joining session:", err)
 				continue
 			}
 
 			err = dialer.SetTCPOptions(conn)
 			if err != nil {
-				l.Infoln(err)
+				l.Debugln("Listen (BEP/relay): setting tcp options:", err)
 			}
 
 			err = dialer.SetTrafficClass(conn, t.cfg.Options().TrafficClass)
 			if err != nil {
-				l.Debugf("failed to set traffic class: %s", err)
+				l.Debugln("Listen (BEP/relay): setting traffic class:", err)
 			}
 
 			var tc *tls.Conn
@@ -95,7 +98,7 @@ func (t *relayListener) Serve() {
 			err = tlsTimedHandshake(tc)
 			if err != nil {
 				tc.Close()
-				l.Infoln("TLS handshake (BEP/relay):", err)
+				l.Infoln("Listen (BEP/relay): TLS handshake:", err)
 				continue
 			}
 

lib/connections/service.go

@@ -369,7 +369,7 @@ func (s *Service) connect() {
 
 				uri, err := url.Parse(addr)
 				if err != nil {
-					l.Infof("Dialer for %s: %v", addr, err)
+					l.Infof("Parsing dialer address %s: %v", addr, err)
 					continue
 				}
 
@@ -382,11 +382,11 @@ func (s *Service) connect() {
 
 				dialerFactory, err := s.getDialerFactory(cfg, uri)
 				if err == errDisabled {
-					l.Debugln("Dialer for", uri, "is disabled")
+					l.Debugln(dialerFactory, "for", uri, "is disabled")
 					continue
 				}
 				if err != nil {
-					l.Infof("Dialer for %v: %v", uri, err)
+					l.Infof("%v for %v: %v", dialerFactory, uri, err)
 					continue
 				}
 
@@ -401,7 +401,7 @@ func (s *Service) connect() {
 
 				conn, err := dialer.Dial(deviceID, uri)
 				if err != nil {
-					l.Debugln("dial failed", deviceCfg.DeviceID, uri, err)
+					l.Debugf("%v for %v at %v: %v", dialerFactory, deviceCfg.DeviceID, uri, err)
 					continue
 				}
 
@@ -505,7 +505,7 @@ func (s *Service) CommitConfiguration(from, to config.Configuration) bool {
 
 		uri, err := url.Parse(addr)
 		if err != nil {
-			l.Infof("Listener for %s: %v", addr, err)
+			l.Infof("Parsing listener address %s: %v", addr, err)
 			continue
 		}
 
@@ -515,7 +515,7 @@ func (s *Service) CommitConfiguration(from, to config.Configuration) bool {
 			continue
 		}
 		if err != nil {
-			l.Infof("Listener for %v: %v", uri, err)
+			l.Infof("Getting listener factory for %v: %v", uri, err)
 			continue
 		}
 

lib/connections/tcp_dial.go

@@ -33,18 +33,17 @@ func (d *tcpDialer) Dial(id protocol.DeviceID, uri *url.URL) (internalConn, erro
 
 	conn, err := dialer.DialTimeout(uri.Scheme, uri.Host, 10*time.Second)
 	if err != nil {
-		l.Debugln(err)
 		return internalConn{}, err
 	}
 
 	err = dialer.SetTCPOptions(conn)
 	if err != nil {
-		l.Infoln(err)
+		l.Debugln("Dial (BEP/tcp): setting tcp options:", err)
 	}
 
 	err = dialer.SetTrafficClass(conn, d.cfg.Options().TrafficClass)
 	if err != nil {
-		l.Debugf("failed to set traffic class: %s", err)
+		l.Debugln("Dial (BEP/tcp): setting traffic class:", err)
 	}
 
 	tc := tls.Client(conn, d.tlsCfg)

lib/connections/tcp_listen.go

@@ -52,7 +52,7 @@ func (t *tcpListener) Serve() {
 		t.mut.Lock()
 		t.err = err
 		t.mut.Unlock()
-		l.Infoln("listen (BEP/tcp):", err)
+		l.Infoln("Listen (BEP/tcp):", err)
 		return
 	}
 
@@ -61,7 +61,7 @@ func (t *tcpListener) Serve() {
 		t.mut.Lock()
 		t.err = err
 		t.mut.Unlock()
-		l.Infoln("listen (BEP/tcp):", err)
+		l.Infoln("Listen (BEP/tcp):", err)
 		return
 	}
 	defer listener.Close()
@@ -95,27 +95,27 @@ func (t *tcpListener) Serve() {
 		}
 		if err != nil {
 			if err, ok := err.(*net.OpError); !ok || !err.Timeout() {
-				l.Warnln("Accepting connection (BEP/tcp):", err)
+				l.Warnln("Listen (BEP/tcp): Accepting connection:", err)
 			}
 			continue
 		}
 
-		l.Debugln("connect from", conn.RemoteAddr())
+		l.Debugln("Listen (BEP/tcp): connect from", conn.RemoteAddr())
 
 		err = dialer.SetTCPOptions(conn)
 		if err != nil {
-			l.Infoln(err)
+			l.Debugln("Listen (BEP/tcp): setting tcp options:", err)
 		}
 
 		err = dialer.SetTrafficClass(conn, t.cfg.Options().TrafficClass)
 		if err != nil {
-			l.Debugf("failed to set traffic class: %s", err)
+			l.Debugln("Listen (BEP/tcp): setting traffic class:", err)
 		}
 
 		tc := tls.Server(conn, t.tlsCfg)
 		err = tlsTimedHandshake(tc)
 		if err != nil {
-			l.Infoln("TLS handshake (BEP/tcp):", err)
+			l.Infoln("Listen (BEP/tcp): TLS handshake:", err)
 			tc.Close()
 			continue
 		}

lib/upnp/upnp.go

@@ -152,14 +152,14 @@ USER-AGENT: syncthing/1.0
 
 	socket, err := net.ListenMulticastUDP("udp4", intf, &net.UDPAddr{IP: ssdp.IP})
 	if err != nil {
-		l.Debugln(err)
+		l.Debugln("UPnP discovery: listening to udp multicast:", err)
 		return
 	}
 	defer socket.Close() // Make sure our socket gets closed
 
 	err = socket.SetDeadline(time.Now().Add(timeout))
 	if err != nil {
-		l.Infoln(err)
+		l.Debugln("UPnP discovery: setting socket deadline:", err)
 		return
 	}
 
@@ -168,7 +168,7 @@ USER-AGENT: syncthing/1.0
 	_, err = socket.WriteTo(search, ssdp)
 	if err != nil {
 		if e, ok := err.(net.Error); !ok || !e.Timeout() {
-			l.Infoln(err)
+			l.Debugln("UPnP discovery: sending search request:", err)
 		}
 		return
 	}
@@ -424,7 +424,7 @@ func soapRequest(url, service, function, message string) ([]byte, error) {
 
 	r, err := http.DefaultClient.Do(req)
 	if err != nil {
-		l.Debugln(err)
+		l.Debugln("SOAP do:", err)
 		return resp, err
 	}