device: combine debug and info log levels into 'verbose'

There are very few cases, if any, in which a user only wants one of
these levels, so combine it into a single level.

While we're at it, reduce indirection on the loggers by using an empty
function rather than a nil function pointer. It's not like we have
retpolines anyway, and we were always calling through a function with a
branch prior, so this seems like a net gain.

Signed-off-by: Jason A. Donenfeld <Jason@zx2c4.com>

diff --git a/device/device.go b/device/device.go
index 27c42f2cc018dc1f2b111001b29643a3f88f8b67..ebcbd9efd0fef9cf15e5bde9177686969fdd38d4 100644 (file)
--- a/device/device.go
+++ b/device/device.go
@@ -177,7 +177,7 @@ func deviceUpdateState(device *Device) {
        switch newIsUp {
        case true:
                if err := device.BindUpdate(); err != nil {
-                       device.errorf("Unable to update bind: %v", err)
+                       device.log.Errorf("Unable to update bind: %v", err)
                        device.isUp.Set(false)
                        break
                }
@@ -303,7 +303,7 @@ func NewDevice(tunDevice tun.Device, logger *Logger) *Device {
        device.tun.device = tunDevice
        mtu, err := device.tun.device.MTU()
        if err != nil {
-               device.errorf("Trouble determining MTU, assuming default: %v", err)
+               device.log.Errorf("Trouble determining MTU, assuming default: %v", err)
                mtu = DefaultMTU
        }
        device.tun.mtu = int32(mtu)
@@ -397,7 +397,7 @@ func (device *Device) Close() {
                return
        }
 
-       device.infof("Device closing")
+       device.log.Verbosef("Device closing")
        device.state.changing.Set(true)
        device.state.Lock()
        defer device.state.Unlock()
@@ -422,7 +422,7 @@ func (device *Device) Close() {
        device.rate.limiter.Close()
 
        device.state.changing.Set(false)
-       device.infof("Interface closed")
+       device.log.Verbosef("Interface closed")
 }
 
 func (device *Device) Wait() chan struct{} {
@@ -562,7 +562,7 @@ func (device *Device) BindUpdate() error {
                go device.RoutineReceiveIncoming(ipv4.Version, netc.bind)
                go device.RoutineReceiveIncoming(ipv6.Version, netc.bind)
 
-               device.debugf("UDP bind has been updated")
+               device.log.Verbosef("UDP bind has been updated")
        }
 
        return nil

diff --git a/device/device_test.go b/device/device_test.go
index caae2b839fb8aa073f0aa641347ff98b9dcdfb98..ecc43926b3fae32b1d1b9ba256a5797cb14531d1 100644 (file)
--- a/device/device_test.go
+++ b/device/device_test.go
@@ -148,7 +148,7 @@ NextAttempt:
                        } else {
                                p.ip = net.ParseIP("1.0.0.2")
                        }
-                       level := LogLevelDebug
+                       level := LogLevelVerbose
                        if _, ok := tb.(*testing.B); ok && !testing.Verbose() {
                                level = LogLevelError
                        }

diff --git a/device/logger.go b/device/logger.go
index 6869a2433970604474159a801eef3088c95f3fdc..76019298411237310d6e0e2c1dd9e6775df2f84d 100644 (file)
--- a/device/logger.go
+++ b/device/logger.go
@@ -16,53 +16,33 @@ import (
 // They do not require a trailing newline in the format.
 // If nil, that level of logging will be silent.
 type Logger struct {
-       Debugf func(format string, args ...interface{})
-       Infof  func(format string, args ...interface{})
-       Errorf func(format string, args ...interface{})
+       Verbosef func(format string, args ...interface{})
+       Errorf   func(format string, args ...interface{})
 }
 
 // Log levels for use with NewLogger.
 const (
        LogLevelSilent = iota
        LogLevelError
-       LogLevelInfo
-       LogLevelDebug
+       LogLevelVerbose
 )
 
+// Function for use in Logger for discarding logged lines.
+func DiscardLogf(format string, args ...interface{}) {}
+
 // NewLogger constructs a Logger that writes to stdout.
 // It logs at the specified log level and above.
 // It decorates log lines with the log level, date, time, and prepend.
 func NewLogger(level int, prepend string) *Logger {
-       logger := new(Logger)
+       logger := &Logger{DiscardLogf, DiscardLogf}
        logf := func(prefix string) func(string, ...interface{}) {
                return log.New(os.Stdout, prefix+": "+prepend, log.Ldate|log.Ltime).Printf
        }
-       if level >= LogLevelDebug {
-               logger.Debugf = logf("DEBUG")
-       }
-       if level >= LogLevelInfo {
-               logger.Infof = logf("INFO")
+       if level >= LogLevelVerbose {
+               logger.Verbosef = logf("DEBUG")
        }
        if level >= LogLevelError {
                logger.Errorf = logf("ERROR")
        }
        return logger
 }
-
-func (device *Device) debugf(format string, args ...interface{}) {
-       if device.log.Debugf != nil {
-               device.log.Debugf(format, args...)
-       }
-}
-
-func (device *Device) infof(format string, args ...interface{}) {
-       if device.log.Infof != nil {
-               device.log.Infof(format, args...)
-       }
-}
-
-func (device *Device) errorf(format string, args ...interface{}) {
-       if device.log.Errorf != nil {
-               device.log.Errorf(format, args...)
-       }
-}

diff --git a/device/noise-protocol.go b/device/noise-protocol.go
index df520d016e1f51de3e3380578db4631d4d27a758..5669381cb03159dac5bc96bc0c255da90061218a 100644 (file)
--- a/device/noise-protocol.go
+++ b/device/noise-protocol.go
@@ -319,11 +319,11 @@ func (device *Device) ConsumeMessageInitiation(msg *MessageInitiation) *Peer {
        flood := time.Since(handshake.lastInitiationConsumption) <= HandshakeInitationRate
        handshake.mutex.RUnlock()
        if replay {
-               device.debugf("%v - ConsumeMessageInitiation: handshake replay @ %v", peer, timestamp)
+               device.log.Verbosef("%v - ConsumeMessageInitiation: handshake replay @ %v", peer, timestamp)
                return nil
        }
        if flood {
-               device.debugf("%v - ConsumeMessageInitiation: handshake flood", peer)
+               device.log.Verbosef("%v - ConsumeMessageInitiation: handshake flood", peer)
                return nil
        }
 

diff --git a/device/peer.go b/device/peer.go
index 46edaeb8e3745f780cfaeb82ba055c48c49e87e3..5324ae471031ca36efc201b1850abe08b6e09724 100644 (file)
--- a/device/peer.go
+++ b/device/peer.go
@@ -190,7 +190,7 @@ func (peer *Peer) Start() {
        }
 
        device := peer.device
-       device.debugf("%v - Starting...", peer)
+       device.log.Verbosef("%v - Starting...", peer)
 
        // reset routine state
 
@@ -278,7 +278,7 @@ func (peer *Peer) Stop() {
        peer.routines.Lock()
        defer peer.routines.Unlock()
 
-       peer.device.debugf("%v - Stopping...", peer)
+       peer.device.log.Verbosef("%v - Stopping...", peer)
 
        peer.timersStop()
 

diff --git a/device/receive.go b/device/receive.go
index 38d018c022d3c3d50c9ab575b811c60d00f7e3bb..a8e55ccfd90172354545641cd5cd61ae9ce5ce1d 100644 (file)
--- a/device/receive.go
+++ b/device/receive.go
@@ -79,12 +79,12 @@ func (peer *Peer) keepKeyFreshReceiving() {
  */
 func (device *Device) RoutineReceiveIncoming(IP int, bind conn.Bind) {
        defer func() {
-               device.debugf("Routine: receive incoming IPv%d - stopped", IP)
+               device.log.Verbosef("Routine: receive incoming IPv%d - stopped", IP)
                device.queue.decryption.wg.Done()
                device.net.stopping.Done()
        }()
 
-       device.debugf("Routine: receive incoming IPv%d - started", IP)
+       device.log.Verbosef("Routine: receive incoming IPv%d - started", IP)
 
        // receive datagrams until conn is closed
 
@@ -112,7 +112,7 @@ func (device *Device) RoutineReceiveIncoming(IP int, bind conn.Bind) {
                        if errors.Is(err, conn.NetErrClosed) {
                                return
                        }
-                       device.errorf("Failed to receive packet: %v", err)
+                       device.log.Errorf("Failed to receive packet: %v", err)
                        if deathSpiral < 10 {
                                deathSpiral++
                                time.Sleep(time.Second / 3)
@@ -199,7 +199,7 @@ func (device *Device) RoutineReceiveIncoming(IP int, bind conn.Bind) {
                        okay = len(packet) == MessageCookieReplySize
 
                default:
-                       device.debugf("Received message with unknown type")
+                       device.log.Verbosef("Received message with unknown type")
                }
 
                if okay {
@@ -221,10 +221,10 @@ func (device *Device) RoutineReceiveIncoming(IP int, bind conn.Bind) {
 func (device *Device) RoutineDecryption() {
        var nonce [chacha20poly1305.NonceSize]byte
        defer func() {
-               device.debugf("Routine: decryption worker - stopped")
+               device.log.Verbosef("Routine: decryption worker - stopped")
                device.state.stopping.Done()
        }()
-       device.debugf("Routine: decryption worker - started")
+       device.log.Verbosef("Routine: decryption worker - started")
 
        for elem := range device.queue.decryption.c {
                // split message into fields
@@ -256,14 +256,14 @@ func (device *Device) RoutineHandshake() {
        var ok bool
 
        defer func() {
-               device.debugf("Routine: handshake worker - stopped")
+               device.log.Verbosef("Routine: handshake worker - stopped")
                device.state.stopping.Done()
                if elem.buffer != nil {
                        device.PutMessageBuffer(elem.buffer)
                }
        }()
 
-       device.debugf("Routine: handshake worker - started")
+       device.log.Verbosef("Routine: handshake worker - started")
 
        for {
                if elem.buffer != nil {
@@ -293,7 +293,7 @@ func (device *Device) RoutineHandshake() {
                        reader := bytes.NewReader(elem.packet)
                        err := binary.Read(reader, binary.LittleEndian, &reply)
                        if err != nil {
-                               device.debugf("Failed to decode cookie reply")
+                               device.log.Verbosef("Failed to decode cookie reply")
                                return
                        }
 
@@ -308,9 +308,9 @@ func (device *Device) RoutineHandshake() {
                        // consume reply
 
                        if peer := entry.peer; peer.isRunning.Get() {
-                               device.debugf("Receiving cookie response from %s", elem.endpoint.DstToString())
+                               device.log.Verbosef("Receiving cookie response from %s", elem.endpoint.DstToString())
                                if !peer.cookieGenerator.ConsumeReply(&reply) {
-                                       device.debugf("Could not decrypt invalid cookie response")
+                                       device.log.Verbosef("Could not decrypt invalid cookie response")
                                }
                        }
 
@@ -321,7 +321,7 @@ func (device *Device) RoutineHandshake() {
                        // check mac fields and maybe ratelimit
 
                        if !device.cookieChecker.CheckMAC1(elem.packet) {
-                               device.debugf("Received packet with invalid mac1")
+                               device.log.Verbosef("Received packet with invalid mac1")
                                continue
                        }
 
@@ -344,7 +344,7 @@ func (device *Device) RoutineHandshake() {
                        }
 
                default:
-                       device.errorf("Invalid packet ended up in the handshake queue")
+                       device.log.Errorf("Invalid packet ended up in the handshake queue")
                        continue
                }
 
@@ -359,7 +359,7 @@ func (device *Device) RoutineHandshake() {
                        reader := bytes.NewReader(elem.packet)
                        err := binary.Read(reader, binary.LittleEndian, &msg)
                        if err != nil {
-                               device.errorf("Failed to decode initiation message")
+                               device.log.Errorf("Failed to decode initiation message")
                                continue
                        }
 
@@ -367,7 +367,7 @@ func (device *Device) RoutineHandshake() {
 
                        peer := device.ConsumeMessageInitiation(&msg)
                        if peer == nil {
-                               device.infof("Received invalid initiation message from %s", elem.endpoint.DstToString())
+                               device.log.Verbosef("Received invalid initiation message from %s", elem.endpoint.DstToString())
                                continue
                        }
 
@@ -379,7 +379,7 @@ func (device *Device) RoutineHandshake() {
                        // update endpoint
                        peer.SetEndpointFromPacket(elem.endpoint)
 
-                       device.debugf("%v - Received handshake initiation", peer)
+                       device.log.Verbosef("%v - Received handshake initiation", peer)
                        atomic.AddUint64(&peer.stats.rxBytes, uint64(len(elem.packet)))
 
                        peer.SendHandshakeResponse()
@@ -392,7 +392,7 @@ func (device *Device) RoutineHandshake() {
                        reader := bytes.NewReader(elem.packet)
                        err := binary.Read(reader, binary.LittleEndian, &msg)
                        if err != nil {
-                               device.errorf("Failed to decode response message")
+                               device.log.Errorf("Failed to decode response message")
                                continue
                        }
 
@@ -400,14 +400,14 @@ func (device *Device) RoutineHandshake() {
 
                        peer := device.ConsumeMessageResponse(&msg)
                        if peer == nil {
-                               device.infof("Received invalid response message from %s", elem.endpoint.DstToString())
+                               device.log.Verbosef("Received invalid response message from %s", elem.endpoint.DstToString())
                                continue
                        }
 
                        // update endpoint
                        peer.SetEndpointFromPacket(elem.endpoint)
 
-                       device.debugf("%v - Received handshake response", peer)
+                       device.log.Verbosef("%v - Received handshake response", peer)
                        atomic.AddUint64(&peer.stats.rxBytes, uint64(len(elem.packet)))
 
                        // update timers
@@ -420,7 +420,7 @@ func (device *Device) RoutineHandshake() {
                        err = peer.BeginSymmetricSession()
 
                        if err != nil {
-                               device.errorf("%v - Failed to derive keypair: %v", peer, err)
+                               device.log.Errorf("%v - Failed to derive keypair: %v", peer, err)
                                continue
                        }
 
@@ -440,7 +440,7 @@ func (peer *Peer) RoutineSequentialReceiver() {
        var elem *QueueInboundElement
 
        defer func() {
-               device.debugf("%v - Routine: sequential receiver - stopped", peer)
+               device.log.Verbosef("%v - Routine: sequential receiver - stopped", peer)
                peer.routines.stopping.Done()
                if elem != nil {
                        device.PutMessageBuffer(elem.buffer)
@@ -448,7 +448,7 @@ func (peer *Peer) RoutineSequentialReceiver() {
                }
        }()
 
-       device.debugf("%v - Routine: sequential receiver - started", peer)
+       device.log.Verbosef("%v - Routine: sequential receiver - started", peer)
 
        for {
                if elem != nil {
@@ -499,7 +499,7 @@ func (peer *Peer) RoutineSequentialReceiver() {
                // check for keepalive
 
                if len(elem.packet) == 0 {
-                       device.debugf("%v - Receiving keepalive packet", peer)
+                       device.log.Verbosef("%v - Receiving keepalive packet", peer)
                        continue
                }
                peer.timersDataReceived()
@@ -527,7 +527,7 @@ func (peer *Peer) RoutineSequentialReceiver() {
 
                        src := elem.packet[IPv4offsetSrc : IPv4offsetSrc+net.IPv4len]
                        if device.allowedips.LookupIPv4(src) != peer {
-                               device.infof("IPv4 packet with disallowed source address from %v", peer)
+                               device.log.Verbosef("IPv4 packet with disallowed source address from %v", peer)
                                continue
                        }
 
@@ -552,12 +552,12 @@ func (peer *Peer) RoutineSequentialReceiver() {
 
                        src := elem.packet[IPv6offsetSrc : IPv6offsetSrc+net.IPv6len]
                        if device.allowedips.LookupIPv6(src) != peer {
-                               device.infof("IPv6 packet with disallowed source address from %v", peer)
+                               device.log.Verbosef("IPv6 packet with disallowed source address from %v", peer)
                                continue
                        }
 
                default:
-                       device.infof("Packet with invalid IP version from %v", peer)
+                       device.log.Verbosef("Packet with invalid IP version from %v", peer)
                        continue
                }
 
@@ -566,12 +566,12 @@ func (peer *Peer) RoutineSequentialReceiver() {
                offset := MessageTransportOffsetContent
                _, err := device.tun.device.Write(elem.buffer[:offset+len(elem.packet)], offset)
                if err != nil && !device.isClosed.Get() {
-                       device.errorf("Failed to write packet to TUN device: %v", err)
+                       device.log.Errorf("Failed to write packet to TUN device: %v", err)
                }
                if len(peer.queue.inbound) == 0 {
                        err := device.tun.device.Flush()
                        if err != nil {
-                               peer.device.errorf("Unable to flush packets: %v", err)
+                               peer.device.log.Errorf("Unable to flush packets: %v", err)
                        }
                }
        }

diff --git a/device/send.go b/device/send.go
index 8cf985d2703c8bbdb698c6fca2622fec7ecc477d..2d9af789a6ff86f5b875ecf8cc5238e9862ff30b 100644 (file)
--- a/device/send.go
+++ b/device/send.go
@@ -99,7 +99,7 @@ func (peer *Peer) SendKeepalive() bool {
        elem.packet = nil
        select {
        case peer.queue.nonce <- elem:
-               peer.device.debugf("%v - Sending keepalive packet", peer)
+               peer.device.log.Verbosef("%v - Sending keepalive packet", peer)
                return true
        default:
                peer.device.PutMessageBuffer(elem.buffer)
@@ -128,11 +128,11 @@ func (peer *Peer) SendHandshakeInitiation(isRetry bool) error {
        peer.handshake.lastSentHandshake = time.Now()
        peer.handshake.mutex.Unlock()
 
-       peer.device.debugf("%v - Sending handshake initiation", peer)
+       peer.device.log.Verbosef("%v - Sending handshake initiation", peer)
 
        msg, err := peer.device.CreateMessageInitiation(peer)
        if err != nil {
-               peer.device.errorf("%v - Failed to create initiation message: %v", peer, err)
+               peer.device.log.Errorf("%v - Failed to create initiation message: %v", peer, err)
                return err
        }
 
@@ -147,7 +147,7 @@ func (peer *Peer) SendHandshakeInitiation(isRetry bool) error {
 
        err = peer.SendBuffer(packet)
        if err != nil {
-               peer.device.errorf("%v - Failed to send handshake initiation: %v", peer, err)
+               peer.device.log.Errorf("%v - Failed to send handshake initiation: %v", peer, err)
        }
        peer.timersHandshakeInitiated()
 
@@ -159,11 +159,11 @@ func (peer *Peer) SendHandshakeResponse() error {
        peer.handshake.lastSentHandshake = time.Now()
        peer.handshake.mutex.Unlock()
 
-       peer.device.debugf("%v - Sending handshake response", peer)
+       peer.device.log.Verbosef("%v - Sending handshake response", peer)
 
        response, err := peer.device.CreateMessageResponse(peer)
        if err != nil {
-               peer.device.errorf("%v - Failed to create response message: %v", peer, err)
+               peer.device.log.Errorf("%v - Failed to create response message: %v", peer, err)
                return err
        }
 
@@ -175,7 +175,7 @@ func (peer *Peer) SendHandshakeResponse() error {
 
        err = peer.BeginSymmetricSession()
        if err != nil {
-               peer.device.errorf("%v - Failed to derive keypair: %v", peer, err)
+               peer.device.log.Errorf("%v - Failed to derive keypair: %v", peer, err)
                return err
        }
 
@@ -185,19 +185,19 @@ func (peer *Peer) SendHandshakeResponse() error {
 
        err = peer.SendBuffer(packet)
        if err != nil {
-               peer.device.errorf("%v - Failed to send handshake response: %v", peer, err)
+               peer.device.log.Errorf("%v - Failed to send handshake response: %v", peer, err)
        }
        return err
 }
 
 func (device *Device) SendHandshakeCookie(initiatingElem *QueueHandshakeElement) error {
 
-       device.debugf("Sending cookie response for denied handshake message for %v", initiatingElem.endpoint.DstToString())
+       device.log.Verbosef("Sending cookie response for denied handshake message for %v", initiatingElem.endpoint.DstToString())
 
        sender := binary.LittleEndian.Uint32(initiatingElem.packet[4:8])
        reply, err := device.cookieChecker.CreateReply(initiatingElem.packet, sender, initiatingElem.endpoint.DstToBytes())
        if err != nil {
-               device.errorf("Failed to create cookie reply: %v", err)
+               device.log.Errorf("Failed to create cookie reply: %v", err)
                return err
        }
 
@@ -226,11 +226,11 @@ func (peer *Peer) keepKeyFreshSending() {
  */
 func (device *Device) RoutineReadFromTUN() {
        defer func() {
-               device.debugf("Routine: TUN reader - stopped")
+               device.log.Verbosef("Routine: TUN reader - stopped")
                device.state.stopping.Done()
        }()
 
-       device.debugf("Routine: TUN reader - started")
+       device.log.Verbosef("Routine: TUN reader - started")
 
        var elem *QueueOutboundElement
 
@@ -248,7 +248,7 @@ func (device *Device) RoutineReadFromTUN() {
 
                if err != nil {
                        if !device.isClosed.Get() {
-                               device.errorf("Failed to read packet from TUN device: %v", err)
+                               device.log.Errorf("Failed to read packet from TUN device: %v", err)
                                device.Close()
                        }
                        device.PutMessageBuffer(elem.buffer)
@@ -281,7 +281,7 @@ func (device *Device) RoutineReadFromTUN() {
                        peer = device.allowedips.LookupIPv6(dst)
 
                default:
-                       device.debugf("Received packet with unknown IP version")
+                       device.log.Verbosef("Received packet with unknown IP version")
                }
 
                if peer == nil {
@@ -333,14 +333,14 @@ func (peer *Peer) RoutineNonce() {
 
        defer func() {
                flush()
-               device.debugf("%v - Routine: nonce worker - stopped", peer)
+               device.log.Verbosef("%v - Routine: nonce worker - stopped", peer)
                peer.queue.packetInNonceQueueIsAwaitingKey.Set(false)
                device.queue.encryption.wg.Done() // no more writes from us
                close(peer.queue.outbound)        // no more writes to this channel
                peer.routines.stopping.Done()
        }()
 
-       device.debugf("%v - Routine: nonce worker - started", peer)
+       device.log.Verbosef("%v - Routine: nonce worker - started", peer)
 
 NextPacket:
        for {
@@ -385,11 +385,11 @@ NextPacket:
 
                                // wait for key to be established
 
-                               device.debugf("%v - Awaiting keypair", peer)
+                               device.log.Verbosef("%v - Awaiting keypair", peer)
 
                                select {
                                case <-peer.signals.newKeypairArrived:
-                                       device.debugf("%v - Obtained awaited keypair", peer)
+                                       device.log.Verbosef("%v - Obtained awaited keypair", peer)
 
                                case <-peer.signals.flushNonceQueue:
                                        device.PutMessageBuffer(elem.buffer)
@@ -453,8 +453,8 @@ func (device *Device) RoutineEncryption() {
 
        var nonce [chacha20poly1305.NonceSize]byte
 
-       defer device.debugf("Routine: encryption worker - stopped")
-       device.debugf("Routine: encryption worker - started")
+       defer device.log.Verbosef("Routine: encryption worker - stopped")
+       device.log.Verbosef("Routine: encryption worker - started")
 
        for elem := range device.queue.encryption.c {
                // populate header fields
@@ -497,8 +497,8 @@ func (peer *Peer) RoutineSequentialSender() {
 
        device := peer.device
 
-       defer device.debugf("%v - Routine: sequential sender - stopped", peer)
-       device.debugf("%v - Routine: sequential sender - started", peer)
+       defer device.log.Verbosef("%v - Routine: sequential sender - stopped", peer)
+       device.log.Verbosef("%v - Routine: sequential sender - started", peer)
 
        for elem := range peer.queue.outbound {
                elem.Lock()
@@ -526,7 +526,7 @@ func (peer *Peer) RoutineSequentialSender() {
                device.PutMessageBuffer(elem.buffer)
                device.PutOutboundElement(elem)
                if err != nil {
-                       device.errorf("%v - Failed to send data packet: %v", peer, err)
+                       device.log.Errorf("%v - Failed to send data packet: %v", peer, err)
                        continue
                }
 

diff --git a/device/timers.go b/device/timers.go
index ddc47ad2628a8a993c82fb66ca3d4826b3918167..25bef8c53b6ee9f2d1694da0ed9c109fb08489c1 100644 (file)
--- a/device/timers.go
+++ b/device/timers.go
@@ -78,7 +78,7 @@ func (peer *Peer) timersActive() bool {
 
 func expiredRetransmitHandshake(peer *Peer) {
        if atomic.LoadUint32(&peer.timers.handshakeAttempts) > MaxTimerHandshakes {
-               peer.device.debugf("%s - Handshake did not complete after %d attempts, giving up", peer, MaxTimerHandshakes+2)
+               peer.device.log.Verbosef("%s - Handshake did not complete after %d attempts, giving up", peer, MaxTimerHandshakes+2)
 
                if peer.timersActive() {
                        peer.timers.sendKeepalive.Del()
@@ -97,7 +97,7 @@ func expiredRetransmitHandshake(peer *Peer) {
                }
        } else {
                atomic.AddUint32(&peer.timers.handshakeAttempts, 1)
-               peer.device.debugf("%s - Handshake did not complete after %d seconds, retrying (try %d)", peer, int(RekeyTimeout.Seconds()), atomic.LoadUint32(&peer.timers.handshakeAttempts)+1)
+               peer.device.log.Verbosef("%s - Handshake did not complete after %d seconds, retrying (try %d)", peer, int(RekeyTimeout.Seconds()), atomic.LoadUint32(&peer.timers.handshakeAttempts)+1)
 
                /* We clear the endpoint address src address, in case this is the cause of trouble. */
                peer.Lock()
@@ -121,7 +121,7 @@ func expiredSendKeepalive(peer *Peer) {
 }
 
 func expiredNewHandshake(peer *Peer) {
-       peer.device.debugf("%s - Retrying handshake because we stopped hearing back after %d seconds", peer, int((KeepaliveTimeout + RekeyTimeout).Seconds()))
+       peer.device.log.Verbosef("%s - Retrying handshake because we stopped hearing back after %d seconds", peer, int((KeepaliveTimeout + RekeyTimeout).Seconds()))
        /* We clear the endpoint address src address, in case this is the cause of trouble. */
        peer.Lock()
        if peer.endpoint != nil {
@@ -133,7 +133,7 @@ func expiredNewHandshake(peer *Peer) {
 }
 
 func expiredZeroKeyMaterial(peer *Peer) {
-       peer.device.debugf("%s - Removing all keys, since we haven't received a new one in %d seconds", peer, int((RejectAfterTime * 3).Seconds()))
+       peer.device.log.Verbosef("%s - Removing all keys, since we haven't received a new one in %d seconds", peer, int((RejectAfterTime * 3).Seconds()))
        peer.ZeroAndFlushAll()
 }
 

diff --git a/device/tun.go b/device/tun.go
index 97f12761f9133277b8c26fc58798d29806f149ca..ae5cae1e4d36e53fc8f19767c7cfaf6b3c4446f3 100644 (file)
--- a/device/tun.go
+++ b/device/tun.go
@@ -15,37 +15,37 @@ const DefaultMTU = 1420
 
 func (device *Device) RoutineTUNEventReader() {
        setUp := false
-       device.debugf("Routine: event worker - started")
+       device.log.Verbosef("Routine: event worker - started")
 
        for event := range device.tun.device.Events() {
                if event&tun.EventMTUUpdate != 0 {
                        mtu, err := device.tun.device.MTU()
                        old := atomic.LoadInt32(&device.tun.mtu)
                        if err != nil {
-                               device.errorf("Failed to load updated MTU of device: %v", err)
+                               device.log.Errorf("Failed to load updated MTU of device: %v", err)
                        } else if int(old) != mtu {
                                if mtu+MessageTransportSize > MaxMessageSize {
-                                       device.infof("MTU updated: %v (too large)", mtu)
+                                       device.log.Verbosef("MTU updated: %v (too large)", mtu)
                                } else {
-                                       device.infof("MTU updated: %v", mtu)
+                                       device.log.Verbosef("MTU updated: %v", mtu)
                                }
                                atomic.StoreInt32(&device.tun.mtu, int32(mtu))
                        }
                }
 
                if event&tun.EventUp != 0 && !setUp {
-                       device.infof("Interface set up")
+                       device.log.Verbosef("Interface set up")
                        setUp = true
                        device.Up()
                }
 
                if event&tun.EventDown != 0 && setUp {
-                       device.infof("Interface set down")
+                       device.log.Verbosef("Interface set down")
                        setUp = false
                        device.Down()
                }
        }
 
-       device.debugf("Routine: event worker - stopped")
+       device.log.Verbosef("Routine: event worker - stopped")
        device.state.stopping.Done()
 }

diff --git a/device/uapi.go b/device/uapi.go
index 76b6fb8262afe24e669956c6206e8ac6f37e66cd..148a7a2706ba08753b488e98ab26adf512e4ecaf 100644 (file)
--- a/device/uapi.go
+++ b/device/uapi.go
@@ -130,7 +130,7 @@ func (device *Device) IpcSetOperation(r io.Reader) (err error) {
 
        defer func() {
                if err != nil {
-                       device.errorf("%v", err)
+                       device.log.Errorf("%v", err)
                }
        }()
 
@@ -188,7 +188,7 @@ func (device *Device) handleDeviceLine(key, value string) error {
                if err != nil {
                        return ipcErrorf(ipc.IpcErrorInvalid, "failed to set private_key: %w", err)
                }
-               device.debugf("UAPI: Updating private key")
+               device.log.Verbosef("UAPI: Updating private key")
                device.SetPrivateKey(sk)
 
        case "listen_port":
@@ -198,7 +198,7 @@ func (device *Device) handleDeviceLine(key, value string) error {
                }
 
                // update port and rebind
-               device.debugf("UAPI: Updating listen port")
+               device.log.Verbosef("UAPI: Updating listen port")
 
                device.net.Lock()
                device.net.port = uint16(port)
@@ -214,7 +214,7 @@ func (device *Device) handleDeviceLine(key, value string) error {
                        return ipcErrorf(ipc.IpcErrorInvalid, "invalid fwmark: %w", err)
                }
 
-               device.debugf("UAPI: Updating fwmark")
+               device.log.Verbosef("UAPI: Updating fwmark")
                if err := device.BindSetMark(uint32(mark)); err != nil {
                        return ipcErrorf(ipc.IpcErrorPortInUse, "failed to update fwmark: %w", err)
                }
@@ -223,7 +223,7 @@ func (device *Device) handleDeviceLine(key, value string) error {
                if value != "true" {
                        return ipcErrorf(ipc.IpcErrorInvalid, "failed to set replace_peers, invalid value: %v", value)
                }
-               device.debugf("UAPI: Removing all peers")
+               device.log.Verbosef("UAPI: Removing all peers")
                device.RemoveAllPeers()
 
        default:
@@ -265,7 +265,7 @@ func (device *Device) handlePublicKeyLine(peer *ipcSetPeer, value string) error
                if err != nil {
                        return ipcErrorf(ipc.IpcErrorInvalid, "failed to create new peer: %w", err)
                }
-               device.debugf("%v - UAPI: Created", peer.Peer)
+               device.log.Verbosef("%v - UAPI: Created", peer.Peer)
        }
        return nil
 }
@@ -289,14 +289,14 @@ func (device *Device) handlePeerLine(peer *ipcSetPeer, key, value string) error
                        return ipcErrorf(ipc.IpcErrorInvalid, "failed to set remove, invalid value: %v", value)
                }
                if !peer.dummy {
-                       device.debugf("%v - UAPI: Removing", peer.Peer)
+                       device.log.Verbosef("%v - UAPI: Removing", peer.Peer)
                        device.RemovePeer(peer.handshake.remoteStatic)
                }
                peer.Peer = &Peer{}
                peer.dummy = true
 
        case "preshared_key":
-               device.debugf("%v - UAPI: Updating preshared key", peer.Peer)
+               device.log.Verbosef("%v - UAPI: Updating preshared key", peer.Peer)
 
                peer.handshake.mutex.Lock()
                err := peer.handshake.presharedKey.FromHex(value)
@@ -307,7 +307,7 @@ func (device *Device) handlePeerLine(peer *ipcSetPeer, key, value string) error
                }
 
        case "endpoint":
-               device.debugf("%v - UAPI: Updating endpoint", peer.Peer)
+               device.log.Verbosef("%v - UAPI: Updating endpoint", peer.Peer)
                endpoint, err := conn.CreateEndpoint(value)
                if err != nil {
                        return ipcErrorf(ipc.IpcErrorInvalid, "failed to set endpoint %v: %w", value, err)
@@ -317,7 +317,7 @@ func (device *Device) handlePeerLine(peer *ipcSetPeer, key, value string) error
                peer.endpoint = endpoint
 
        case "persistent_keepalive_interval":
-               device.debugf("%v - UAPI: Updating persistent keepalive interval", peer.Peer)
+               device.log.Verbosef("%v - UAPI: Updating persistent keepalive interval", peer.Peer)
 
                secs, err := strconv.ParseUint(value, 10, 16)
                if err != nil {
@@ -337,7 +337,7 @@ func (device *Device) handlePeerLine(peer *ipcSetPeer, key, value string) error
                }
 
        case "replace_allowed_ips":
-               device.debugf("%v - UAPI: Removing all allowedips", peer.Peer)
+               device.log.Verbosef("%v - UAPI: Removing all allowedips", peer.Peer)
                if value != "true" {
                        return ipcErrorf(ipc.IpcErrorInvalid, "failed to replace allowedips, invalid value: %v", value)
                }
@@ -347,7 +347,7 @@ func (device *Device) handlePeerLine(peer *ipcSetPeer, key, value string) error
                device.allowedips.RemoveByPeer(peer.Peer)
 
        case "allowed_ip":
-               device.debugf("%v - UAPI: Adding allowedip", peer.Peer)
+               device.log.Verbosef("%v - UAPI: Adding allowedip", peer.Peer)
 
                _, network, err := net.ParseCIDR(value)
                if err != nil {
@@ -409,12 +409,12 @@ func (device *Device) IpcHandle(socket net.Conn) {
                                return
                        }
                        if nextByte != '\n' {
-                               err = ipcErrorf(ipc.IpcErrorInvalid, "trailing character in UAPI get: %c", nextByte)
+                               err = ipcErrorf(ipc.IpcErrorInvalid, "trailing character in UAPI get: %q", nextByte)
                                break
                        }
                        err = device.IpcGetOperation(buffered.Writer)
                default:
-                       device.errorf("invalid UAPI operation: %v", op)
+                       device.log.Errorf("invalid UAPI operation: %v", op)
                        return
                }
 
@@ -425,7 +425,7 @@ func (device *Device) IpcHandle(socket net.Conn) {
                        status = ipcErrorf(ipc.IpcErrorUnknown, "other UAPI error: %w", err)
                }
                if status != nil {
-                       device.errorf("%v", status)
+                       device.log.Errorf("%v", status)
                        fmt.Fprintf(buffered, "errno=%d\n\n", status.ErrorCode())
                } else {
                        fmt.Fprintf(buffered, "errno=0\n\n")

diff --git a/main.go b/main.go
index 3d7f23fc2d13e7a46126038b7c591f87c96916df..40c8070cf336ad869a18ab61a1ae364857445c2a 100644 (file)
--- a/main.go
+++ b/main.go
@@ -95,16 +95,14 @@ func main() {
 
        logLevel := func() int {
                switch os.Getenv("LOG_LEVEL") {
-               case "debug":
-                       return device.LogLevelDebug
-               case "info":
-                       return device.LogLevelInfo
+               case "verbose", "debug":
+                       return device.LogLevelVerbose
                case "error":
                        return device.LogLevelError
                case "silent":
                        return device.LogLevelSilent
                }
-               return device.LogLevelInfo
+               return device.LogLevelError
        }()
 
        // open TUN device (or use supplied fd)
@@ -143,8 +141,7 @@ func main() {
                fmt.Sprintf("(%s) ", interfaceName),
        )
 
-       logger.Infof("Starting wireguard-go version %v", device.WireGuardGoVersion)
-       logger.Debugf("Debug log enabled")
+       logger.Verbosef("Starting wireguard-go version %s", device.WireGuardGoVersion)
 
        if err != nil {
                logger.Errorf("Failed to create TUN device: %v", err)
@@ -224,7 +221,7 @@ func main() {
 
        device := device.NewDevice(tun, logger)
 
-       logger.Infof("Device started")
+       logger.Verbosef("Device started")
 
        errs := make(chan error)
        term := make(chan os.Signal, 1)
@@ -246,7 +243,7 @@ func main() {
                }
        }()
 
-       logger.Infof("UAPI listener started")
+       logger.Verbosef("UAPI listener started")
 
        // wait for program to terminate
 
@@ -264,5 +261,5 @@ func main() {
        uapi.Close()
        device.Close()
 
-       logger.Infof("Shutting down")
+       logger.Verbosef("Shutting down")
 }

diff --git a/main_windows.go b/main_windows.go
index fea1b161657ec9e6a12f8d1995e7e67ab2dfcc00..82a333d238df0f1e7c5640ac9e5d098e3354feb6 100644 (file)
--- a/main_windows.go
+++ b/main_windows.go
@@ -31,11 +31,10 @@ func main() {
        fmt.Fprintln(os.Stderr, "Warning: this is a test program for Windows, mainly used for debugging this Go package. For a real WireGuard for Windows client, the repo you want is <https://git.zx2c4.com/wireguard-windows/>, which includes this code as a module.")
 
        logger := device.NewLogger(
-               device.LogLevelDebug,
+               device.LogLevelVerbose,
                fmt.Sprintf("(%s) ", interfaceName),
        )
-       logger.Infof("Starting wireguard-go version %v", device.WireGuardGoVersion)
-       logger.Debugf("Debug log enabled")
+       logger.Verbosef("Starting wireguard-go version %s", device.WireGuardGoVersion)
 
        tun, err := tun.CreateTUN(interfaceName, 0)
        if err == nil {
@@ -50,7 +49,7 @@ func main() {
 
        device := device.NewDevice(tun, logger)
        device.Up()
-       logger.Infof("Device started")
+       logger.Verbosef("Device started")
 
        uapi, err := ipc.UAPIListen(interfaceName)
        if err != nil {
@@ -71,7 +70,7 @@ func main() {
                        go device.IpcHandle(conn)
                }
        }()
-       logger.Infof("UAPI listener started")
+       logger.Verbosef("UAPI listener started")
 
        // wait for program to terminate
 
@@ -90,5 +89,5 @@ func main() {
        uapi.Close()
        device.Close()
 
-       logger.Infof("Shutting down")
+       logger.Verbosef("Shutting down")
 }

diff --git a/tests/netns.sh b/tests/netns.sh
index 02d428b1474097ffa523bd7f18276f44379b9480..2f2a2cd2b7c6a70bd6a96833288e80452addd4cf 100755 (executable)
--- a/tests/netns.sh
+++ b/tests/netns.sh
@@ -36,7 +36,7 @@ netns0="wg-test-$$-0"
 netns1="wg-test-$$-1"
 netns2="wg-test-$$-2"
 program=$1
-export LOG_LEVEL="info"
+export LOG_LEVEL="verbose"
 
 pretty() { echo -e "\x1b[32m\x1b[1m[+] ${1:+NS$1: }${2}\x1b[0m" >&3; }
 pp() { pretty "" "$*"; "$@"; }