]> Cypherpunks.ru repositories - govpn.git/commitdiff
Refactor govpn common package
authorBruno Clermont <bruno@robotinfra.com>
Wed, 8 Feb 2017 10:41:10 +0000 (18:41 +0800)
committerSergey Matveev <stargrave@stargrave.org>
Sat, 25 Feb 2017 08:27:52 +0000 (11:27 +0300)
- unexposed type and values that aren't consumed outside package
- golint fixes
- switch logging to logrus
- add more logging messages
- improve usage as a library: no more `panic` or `os.Exit`, return `error` instead
- evalute/raise nearly all possible `error` values

src/cypherpunks.ru/govpn/common.go
src/cypherpunks.ru/govpn/egd.go
src/cypherpunks.ru/govpn/handshake.go
src/cypherpunks.ru/govpn/identity.go
src/cypherpunks.ru/govpn/peer.go
src/cypherpunks.ru/govpn/stats.go
src/cypherpunks.ru/govpn/verifier.go

index 67774b1d3ccbaab4ee27548451a269e9fb26eadc..ca629c06317ec50f4c5f3608e18846bdd29459a4 100644 (file)
@@ -21,10 +21,14 @@ package govpn
 import (
        "encoding/hex"
        "encoding/json"
+       "io"
+       "os"
+       "os/signal"
        "runtime"
        "strings"
        "time"
 
+       "github.com/Sirupsen/logrus"
        "github.com/pkg/errors"
 )
 
@@ -36,15 +40,19 @@ const (
        // ProtocolALL is TCP+UDP transport protocol
        ProtocolALL
 
-       EtherSize = 14
+       etherSize = 14
        // MTUMax is maximum MTU size of Ethernet packet
-       MTUMax = 9000 + EtherSize + 1
+       MTUMax = 9000 + etherSize + 1
        // MTUDefault is default MTU size of Ethernet packet
-       MTUDefault = 1500 + EtherSize + 1
+       MTUDefault = 1500 + etherSize + 1
 
-       ENV_IFACE  = "GOVPN_IFACE"
-       ENV_REMOTE = "GOVPN_REMOTE"
+       environmentKeyInterface = "GOVPN_IFACE"
+       environmentKeyRemote    = "GOVPN_REMOTE"
 
+       wrapIoReadFull            = "io.ReadFull %q"
+       wrapBlake2bNew256         = "blake2b.New256"
+       wrapEnclessDecode         = "EnclessDecode"
+       wrapEnclessEncode         = "EnclessEncode"
        wrapNewProtocolFromString = "NewProtocolFromString"
 )
 
@@ -56,6 +64,8 @@ var (
                ProtocolTCP: "tcp",
                ProtocolALL: "all",
        }
+       logger        = logrus.StandardLogger()
+       logFuncPrefix = "govpn."
        // TimeoutDefault is default timeout value for various network operations
        TimeoutDefault = 60 * time.Second
 )
@@ -136,6 +146,38 @@ func SliceZero(data []byte) {
        }
 }
 
+// VersionGet return version of GoVPN
 func VersionGet() string {
        return "GoVPN version " + Version + " built with " + runtime.Version()
 }
+
+// CatchSignalShutdown return a channel.
+// that channel will get a SIG_INT or SIG_KILL signal is received
+// this is intended to be used to stop a client/server
+func CatchSignalShutdown() chan interface{} {
+       shutdownChan := make(chan interface{}, 1)
+       go func() {
+               termSignal := make(chan os.Signal, 1)
+               signal.Notify(termSignal, os.Interrupt, os.Kill)
+               sig := <-termSignal
+               logger.WithFields(logrus.Fields{
+                       "func":   logFuncPrefix + "CatchSignalShutdown",
+                       "signal": sig.String(),
+               }).Debug("Catch signal, shutting down")
+               shutdownChan <- sig
+       }()
+       return shutdownChan
+}
+
+// SetLogger set the Logger used by this library.
+// by default logrus StdLogger is used.
+func SetLogger(l *logrus.Logger) {
+       logger = l
+}
+
+// CloseLog log an error if a io.Closer fail to Close
+func CloseLog(c io.Closer, l *logrus.Logger, fields logrus.Fields) {
+       if err := c.Close(); err != nil {
+               logrus.WithFields(fields).WithError(err).Error("Couldn't close connection")
+       }
+}
index deb92af7406ba43120f613136eb7187f3a539682..647c2c9623177dcdc3d9866d07e35f0c9735bf64 100644 (file)
@@ -1,6 +1,6 @@
 /*
 GoVPN -- simple secure free software virtual private network daemon
-Copyright (C) 2014-2017 Sergey Matveev <stargrave@stargrave.org>
+Copyright (C) 2014-2016 Sergey Matveev <stargrave@stargrave.org>
 
 This program is free software: you can redistribute it and/or modify
 it under the terms of the GNU General Public License as published by
@@ -22,6 +22,9 @@ import (
        "crypto/rand"
        "io"
        "net"
+
+       "github.com/Sirupsen/logrus"
+       "github.com/pkg/errors"
 )
 
 // Rand is a source of entropy
@@ -34,11 +37,17 @@ type EGDRand string
 func (egdPath EGDRand) Read(b []byte) (int, error) {
        conn, err := net.Dial("unix", string(egdPath))
        if err != nil {
-               return 0, err
+               return 0, errors.Wrapf(err, "net.Dial unix:%q", string(egdPath))
+       }
+       defer CloseLog(conn, logger, logrus.Fields{"func": logFuncPrefix + "EGDRand.Read"})
+       n, err := conn.Write([]byte{0x02, byte(len(b))})
+       if err != nil {
+               return 0, errors.Wrapf(err, "conn.Write unix:%q", string(egdPath))
+       }
+       if n, err = io.ReadFull(conn, b); err != nil {
+               return 0, errors.Wrapf(err, wrapIoReadFull, string(egdPath))
        }
-       defer conn.Close()
-       conn.Write([]byte{0x02, byte(len(b))})
-       return io.ReadFull(conn, b)
+       return n, nil
 }
 
 // EGDInit sets random source to a EGD socket
index 27057708f9149f6c236643b9344ff3f5060e19f7..bc963d1204d7d914202d2731df51e1cdb550f0d5 100644 (file)
@@ -22,12 +22,13 @@ import (
        "crypto/subtle"
        "encoding/binary"
        "io"
-       "log"
        "time"
 
        "chacha20"
+       "github.com/Sirupsen/logrus"
        "github.com/agl/ed25519"
        "github.com/agl/ed25519/extra25519"
+       "github.com/pkg/errors"
        "golang.org/x/crypto/blake2b"
        "golang.org/x/crypto/curve25519"
 )
@@ -37,6 +38,8 @@ const (
        RSize = 8
        // SSize is size in bytes of shared secret half
        SSize = 32
+
+       wrapIDTag = "idTag id:%q timeSync:%d"
 )
 
 // Handshake is state of a handshake/negotiation between client and server
@@ -55,6 +58,16 @@ type Handshake struct {
        sClient  *[SSize]byte
 }
 
+// LogFields return a logrus compatible logging context
+func (h *Handshake) LogFields() logrus.Fields {
+       const prefix = "hs_"
+       return logrus.Fields{
+               prefix + "remote":    h.addr,
+               prefix + "last_ping": h.LastPing.String(),
+               prefix + "id":        h.Conf.ID.String(),
+       }
+}
+
 func keyFromSecrets(server, client []byte) *[SSize]byte {
        k := new([SSize]byte)
        for i := 0; i < SSize; i++ {
@@ -98,18 +111,18 @@ func (h *Handshake) rNonceNext(count uint64) *[16]byte {
        return nonce
 }
 
-func dhKeypairGen() (*[32]byte, *[32]byte) {
+func dhKeypairGen() (*[32]byte, *[32]byte, error) {
        priv := new([32]byte)
        pub := new([32]byte)
        repr := new([32]byte)
        reprFound := false
        for !reprFound {
                if _, err := io.ReadFull(Rand, priv[:]); err != nil {
-                       log.Fatalln("Error reading random for DH private key:", err)
+                       return nil, nil, errors.Wrapf(err, wrapIoReadFull, "Rand")
                }
                reprFound = extra25519.ScalarBaseMult(pub, repr, priv)
        }
-       return priv, repr
+       return priv, repr, nil
 }
 
 func dhKeyGen(priv, pub *[32]byte) *[32]byte {
@@ -135,30 +148,37 @@ func NewHandshake(addr string, conn io.Writer, conf *PeerConf) *Handshake {
 }
 
 // Generate ID tag from client identification and data.
-func idTag(id *PeerID, timeSync int, data []byte) []byte {
+func idTag(id *PeerID, timeSync int, data []byte) ([]byte, error) {
        enc := make([]byte, 8)
        copy(enc, data)
        AddTimeSync(timeSync, enc)
        mac, err := blake2b.New256(id[:])
        if err != nil {
-               panic(err)
+               return nil, errors.Wrap(err, wrapBlake2bNew256)
+       }
+       if _, err = mac.Write(enc); err != nil {
+               return nil, errors.Wrap(err, "mac.Write")
        }
-       mac.Write(enc)
        sum := mac.Sum(nil)
-       return sum[len(sum)-8:]
+       return sum[len(sum)-8:], nil
 }
 
 // HandshakeStarts start handshake's procedure from the client.
 // It is the entry point for starting the handshake procedure.
 // First handshake packet will be sent immediately.
-func HandshakeStart(addr string, conn io.Writer, conf *PeerConf) *Handshake {
+func HandshakeStart(addr string, conn io.Writer, conf *PeerConf) (*Handshake, error) {
        state := NewHandshake(addr, conn, conf)
-       var dhPubRepr *[32]byte
-       state.dhPriv, dhPubRepr = dhKeypairGen()
+       var (
+               dhPubRepr *[32]byte
+               err       error
+       )
+       if state.dhPriv, dhPubRepr, err = dhKeypairGen(); err != nil {
+               return nil, errors.Wrap(err, "dhKeypairGen")
+       }
 
        state.rNonce = new([16]byte)
        if _, err := io.ReadFull(Rand, state.rNonce[8:]); err != nil {
-               log.Fatalln("Error reading random for nonce:", err)
+               return nil, errors.Wrapf(err, wrapIoReadFull, "Rand")
        }
        var enc []byte
        if conf.Noise {
@@ -168,26 +188,30 @@ func HandshakeStart(addr string, conn io.Writer, conf *PeerConf) *Handshake {
        }
        copy(enc, dhPubRepr[:])
        if conf.Encless {
-               var err error
                enc, err = EnclessEncode(state.dsaPubH, state.rNonce, enc)
                if err != err {
-                       panic(err)
+                       return nil, errors.Wrap(err, wrapEnclessDecode)
                }
        } else {
                chacha20.XORKeyStream(enc, enc, state.rNonce, state.dsaPubH)
        }
+       tag, err := idTag(state.Conf.ID, state.Conf.TimeSync, state.rNonce[8:])
+       if err != nil {
+               return nil, errors.Wrapf(err, wrapIDTag, state.Conf.ID.String(), state.Conf.TimeSync)
+       }
        data := append(state.rNonce[8:], enc...)
-       data = append(data, idTag(state.Conf.ID, state.Conf.TimeSync, state.rNonce[8:])...)
-       state.conn.Write(data)
-       return state
+       data = append(data, tag...)
+       if _, err = state.conn.Write(data); err != nil {
+               return nil, errors.Wrap(err, "state.conn.Write")
+       }
+       return state, nil
 }
 
 // Server processes handshake message on the server side.
 // This function is intended to be called on server's side.
 // If this is the final handshake message, then new Peer object
-// will be created and used as a transport. If no mutually
-// authenticated Peer is ready, then return nil.
-func (h *Handshake) Server(data []byte) *Peer {
+// will be created and used as a transport.
+func (h *Handshake) Server(data []byte) (*Peer, error) {
        // R + ENC(H(DSAPub), R, El(CDHPub)) + IDtag
        if h.rNonce == nil && ((!h.Conf.Encless && len(data) >= 48) ||
                (h.Conf.Encless && len(data) == EnclessEnlargeSize+h.Conf.MTU)) {
@@ -203,8 +227,7 @@ func (h *Handshake) Server(data []byte) *Peer {
                                data[RSize:len(data)-8],
                        )
                        if err != nil {
-                               log.Println("Unable to decode packet from", h.addr, err)
-                               return nil
+                               return nil, errors.Wrap(err, wrapEnclessDecode)
                        }
                        copy(cDHRepr[:], out)
                } else {
@@ -213,7 +236,10 @@ func (h *Handshake) Server(data []byte) *Peer {
 
                // Generate DH keypair
                var dhPubRepr *[32]byte
-               h.dhPriv, dhPubRepr = dhKeypairGen()
+               var err error
+               if h.dhPriv, dhPubRepr, err = dhKeypairGen(); err != nil {
+                       return nil, errors.Wrap(err, "dhKeypairGen")
+               }
 
                // Compute shared key
                cDH := new([32]byte)
@@ -221,13 +247,12 @@ func (h *Handshake) Server(data []byte) *Peer {
                h.key = dhKeyGen(h.dhPriv, cDH)
 
                var encPub []byte
-               var err error
                if h.Conf.Encless {
                        encPub = make([]byte, h.Conf.MTU)
                        copy(encPub, dhPubRepr[:])
                        encPub, err = EnclessEncode(h.dsaPubH, h.rNonceNext(1), encPub)
                        if err != nil {
-                               panic(err)
+                               return nil, errors.Wrap(err, wrapEnclessEncode)
                        }
                } else {
                        encPub = make([]byte, 32)
@@ -237,11 +262,11 @@ func (h *Handshake) Server(data []byte) *Peer {
                // Generate R* and encrypt them
                h.rServer = new([RSize]byte)
                if _, err = io.ReadFull(Rand, h.rServer[:]); err != nil {
-                       log.Fatalln("Error reading random for R:", err)
+                       return nil, errors.Wrapf(err, wrapIoReadFull, "Rand")
                }
                h.sServer = new([SSize]byte)
                if _, err = io.ReadFull(Rand, h.sServer[:]); err != nil {
-                       log.Fatalln("Error reading random for S:", err)
+                       return nil, errors.Wrapf(err, wrapIoReadFull, "Rand")
                }
                var encRs []byte
                if h.Conf.Noise && !h.Conf.Encless {
@@ -255,16 +280,24 @@ func (h *Handshake) Server(data []byte) *Peer {
                if h.Conf.Encless {
                        encRs, err = EnclessEncode(h.key, h.rNonce, encRs)
                        if err != nil {
-                               panic(err)
+                               return nil, errors.Wrap(err, wrapEnclessEncode)
                        }
                } else {
                        chacha20.XORKeyStream(encRs, encRs, h.rNonce, h.key)
                }
 
+               tag, err := idTag(h.Conf.ID, h.Conf.TimeSync, encPub)
+               if err != nil {
+                       return nil, errors.Wrapf(err, wrapIDTag, h.Conf.ID.String(), h.Conf.TimeSync)
+               }
+
                // Send that to client
-               h.conn.Write(append(encPub, append(
-                       encRs, idTag(h.Conf.ID, h.Conf.TimeSync, encPub)...,
+               _, err = h.conn.Write(append(encPub, append(
+                       encRs, tag...,
                )...))
+               if err != nil {
+                       return nil, errors.Wrap(err, "conn.Write")
+               }
                h.LastPing = time.Now()
        } else
        // ENC(K, R+1, RS + RC + SC + Sign(DSAPriv, K)) + IDtag
@@ -279,8 +312,7 @@ func (h *Handshake) Server(data []byte) *Peer {
                                data[:len(data)-8],
                        )
                        if err != nil {
-                               log.Println("Unable to decode packet from", h.addr, err)
-                               return nil
+                               return nil, errors.Wrap(err, wrapEnclessDecode)
                        }
                        dec = dec[:RSize+RSize+SSize+ed25519.SignatureSize]
                } else {
@@ -293,14 +325,12 @@ func (h *Handshake) Server(data []byte) *Peer {
                        )
                }
                if subtle.ConstantTimeCompare(dec[:RSize], h.rServer[:]) != 1 {
-                       log.Println("Invalid server's random number with", h.addr)
-                       return nil
+                       return nil, errors.New("Invalid server's random number")
                }
                sign := new([ed25519.SignatureSize]byte)
                copy(sign[:], dec[RSize+RSize+SSize:])
                if !ed25519.Verify(h.Conf.Verifier.Pub, h.key[:], sign) {
-                       log.Println("Invalid signature from", h.addr)
-                       return nil
+                       return nil, errors.New("Invalid signature")
                }
 
                // Send final answer to client
@@ -314,26 +344,33 @@ func (h *Handshake) Server(data []byte) *Peer {
                if h.Conf.Encless {
                        enc, err = EnclessEncode(h.key, h.rNonceNext(2), enc)
                        if err != nil {
-                               panic(err)
+                               return nil, errors.Wrap(err, wrapEnclessEncode)
                        }
                } else {
                        chacha20.XORKeyStream(enc, enc, h.rNonceNext(2), h.key)
                }
-               h.conn.Write(append(enc, idTag(h.Conf.ID, h.Conf.TimeSync, enc)...))
+               tag, err := idTag(h.Conf.ID, h.Conf.TimeSync, enc)
+               if err != nil {
+                       return nil, errors.Wrapf(err, wrapIDTag, h.Conf.ID.String(), h.Conf.TimeSync)
+               }
+               if _, err = h.conn.Write(append(enc, tag...)); err != nil {
+                       return nil, errors.Wrap(err, "conn.Write")
+               }
 
                // Switch peer
-               peer := newPeer(
+               peer, err := newPeer(
                        false,
                        h.addr,
                        h.conn,
                        h.Conf,
                        keyFromSecrets(h.sServer[:], dec[RSize+RSize:RSize+RSize+SSize]))
+               if err != nil {
+                       return nil, errors.Wrap(err, "newPeer")
+               }
                h.LastPing = time.Now()
-               return peer
-       } else {
-               log.Println("Invalid handshake message from", h.addr)
+               return peer, nil
        }
-       return nil
+       return nil, nil
 }
 
 // Client processes handshake message on the client side.
@@ -341,7 +378,7 @@ func (h *Handshake) Server(data []byte) *Peer {
 // If this is the final handshake message, then new Peer object
 // will be created and used as a transport. If no mutually
 // authenticated Peer is ready, then return nil.
-func (h *Handshake) Client(data []byte) *Peer {
+func (h *Handshake) Client(data []byte) (*Peer, error) {
        // ENC(H(DSAPub), R+1, El(SDHPub)) + ENC(K, R, RS + SS) + IDtag
        if h.rServer == nil && h.key == nil &&
                ((!h.Conf.Encless && len(data) >= 80) ||
@@ -357,8 +394,7 @@ func (h *Handshake) Client(data []byte) *Peer {
                                data[:len(data)/2],
                        )
                        if err != nil {
-                               log.Println("Unable to decode packet from", h.addr, err)
-                               return nil
+                               return nil, errors.Wrap(err, wrapEnclessDecode)
                        }
                        copy(sDHRepr[:], tmp[:32])
                } else {
@@ -376,8 +412,7 @@ func (h *Handshake) Client(data []byte) *Peer {
                if h.Conf.Encless {
                        tmp, err = EnclessDecode(h.key, h.rNonce, data[len(data)/2:len(data)-8])
                        if err != nil {
-                               log.Println("Unable to decode packet from", h.addr, err)
-                               return nil
+                               return nil, errors.Wrap(err, wrapEnclessDecode)
                        }
                        copy(h.rServer[:], tmp[:RSize])
                        copy(h.sServer[:], tmp[RSize:RSize+SSize])
@@ -391,11 +426,11 @@ func (h *Handshake) Client(data []byte) *Peer {
                // Generate R* and signature and encrypt them
                h.rClient = new([RSize]byte)
                if _, err = io.ReadFull(Rand, h.rClient[:]); err != nil {
-                       log.Fatalln("Error reading random for R:", err)
+                       return nil, errors.Wrapf(err, wrapIoReadFull, "Rand")
                }
                h.sClient = new([SSize]byte)
                if _, err = io.ReadFull(Rand, h.sClient[:]); err != nil {
-                       log.Fatalln("Error reading random for S:", err)
+                       return nil, errors.Wrapf(err, wrapIoReadFull, "Rand")
                }
                sign := ed25519.Sign(h.Conf.DSAPriv, h.key[:])
 
@@ -412,14 +447,21 @@ func (h *Handshake) Client(data []byte) *Peer {
                if h.Conf.Encless {
                        enc, err = EnclessEncode(h.key, h.rNonceNext(1), enc)
                        if err != nil {
-                               panic(err)
+                               return nil, errors.Wrap(err, wrapEnclessEncode)
                        }
                } else {
                        chacha20.XORKeyStream(enc, enc, h.rNonceNext(1), h.key)
                }
 
+               tag, err := idTag(h.Conf.ID, h.Conf.TimeSync, enc)
+               if err != nil {
+                       return nil, errors.Wrapf(err, wrapIDTag, h.Conf.ID.String(), h.Conf.TimeSync)
+               }
+
                // Send that to server
-               h.conn.Write(append(enc, idTag(h.Conf.ID, h.Conf.TimeSync, enc)...))
+               if _, err = h.conn.Write(append(enc, tag...)); err != nil {
+                       return nil, errors.Wrap(err, "conn.Write")
+               }
                h.LastPing = time.Now()
        } else
        // ENC(K, R+2, RC) + IDtag
@@ -431,8 +473,7 @@ func (h *Handshake) Client(data []byte) *Peer {
                if h.Conf.Encless {
                        dec, err = EnclessDecode(h.key, h.rNonceNext(2), data[:len(data)-8])
                        if err != nil {
-                               log.Println("Unable to decode packet from", h.addr, err)
-                               return nil
+                               return nil, errors.Wrap(err, wrapEnclessDecode)
                        }
                        dec = dec[:RSize]
                } else {
@@ -440,22 +481,24 @@ func (h *Handshake) Client(data []byte) *Peer {
                        chacha20.XORKeyStream(dec, data[:RSize], h.rNonceNext(2), h.key)
                }
                if subtle.ConstantTimeCompare(dec, h.rClient[:]) != 1 {
-                       log.Println("Invalid client's random number with", h.addr)
-                       return nil
+                       return nil, errors.New("Invalid client's random number")
                }
 
                // Switch peer
-               peer := newPeer(
+               peer, err := newPeer(
                        true,
                        h.addr,
                        h.conn,
                        h.Conf,
                        keyFromSecrets(h.sServer[:], h.sClient[:]),
                )
+               if err != nil {
+                       return nil, errors.Wrap(err, "newPeer")
+               }
                h.LastPing = time.Now()
-               return peer
-       } else {
-               log.Println("Invalid handshake stage from", h.addr)
+               return peer, nil
        }
-       return nil
+
+       // no peer yet, no error
+       return nil, nil
 }
index 59c20f1d93941e8ba647b3889cd9f12680ec81fc..83e0282522df6bc74b97fb151847ae41888650c1 100644 (file)
@@ -22,11 +22,13 @@ import (
        "crypto/subtle"
        "encoding/base64"
        "encoding/binary"
+       "encoding/hex"
        "hash"
-       "log"
        "sync"
        "time"
 
+       "github.com/Sirupsen/logrus"
+       "github.com/pkg/errors"
        "golang.org/x/crypto/blake2b"
 )
 
@@ -59,40 +61,70 @@ type MACCache struct {
        l     sync.RWMutex
 }
 
+// Length returns size of MACCache
+func (mc *MACCache) Length() int {
+       return len(mc.cache)
+}
+
 // NewMACCache returns a new MACCache instance
 func NewMACCache() *MACCache {
        return &MACCache{cache: make(map[PeerID]*MACAndTimeSync)}
 }
 
 // Update removes disappeared keys, add missing ones with initialized MACs.
-func (mc *MACCache) Update(peers *map[PeerID]*PeerConf) {
+func (mc *MACCache) Update(peers *map[PeerID]*PeerConf) error {
        mc.l.Lock()
+       defer mc.l.Unlock()
+       fields := logrus.Fields{
+               "func":  logFuncPrefix + "MACCache.Update",
+               "peers": len(*peers),
+       }
+       logger.WithFields(fields).WithField("size", mc.Length()).Debug("Clean old keys")
        for pid := range mc.cache {
                if _, exists := (*peers)[pid]; !exists {
-                       log.Println("Cleaning key:", pid)
+                       logger.WithFields(fields).WithField("pid", pid).Debug("Cleaning key")
                        delete(mc.cache, pid)
                }
        }
+       logger.WithFields(fields).WithField("size", mc.Length()).Debug("Cleaned, add/update new key")
        for pid, pc := range *peers {
                if _, exists := mc.cache[pid]; exists {
+                       logger.WithFields(fields).WithFields(
+                               logrus.Fields{
+                                       "pid":    pid.String(),
+                                       "old_ts": mc.cache[pid].ts,
+                                       "new_ts": pc.TimeSync,
+                               }).Debug("Rest timesync")
                        mc.cache[pid].ts = pc.TimeSync
                } else {
-                       log.Println("Adding key", pid)
+                       before := time.Now()
                        mac, err := blake2b.New256(pid[:])
                        if err != nil {
-                               panic(err)
+                               return errors.Wrap(err, wrapBlake2bNew256)
                        }
+                       logger.WithFields(fields).WithFields(logrus.Fields{
+                               "pid":     pid.String(),
+                               "ts":      pc.TimeSync,
+                               "elapsed": time.Now().Sub(before).String(),
+                       }).Debug("Adding key")
                        mc.cache[pid] = &MACAndTimeSync{
                                mac: mac,
                                ts:  pc.TimeSync,
                        }
                }
        }
-       mc.l.Unlock()
+       logger.WithFields(fields).WithField("size", mc.Length()).Debug("Finish")
+       return nil
 }
 
 // AddTimeSync XORs timestamp with data if timeSync > 0
 func AddTimeSync(ts int, data []byte) {
+       fields := logrus.Fields{
+               "func":      logFuncPrefix + "AddTimeSync",
+               "ts":        ts,
+               "data_size": len(data),
+               "data":      hex.EncodeToString(data),
+       }
        if ts == 0 {
                return
        }
@@ -101,32 +133,52 @@ func AddTimeSync(ts int, data []byte) {
        for i := 0; i < 8; i++ {
                data[i] ^= buf[i]
        }
+       logger.WithFields(fields).WithField("after", hex.EncodeToString(data)).Debug("Done")
 }
 
 // Find tries to find peer's identity (that equals to MAC)
 // by taking first blocksize sized bytes from data at the beginning
 // as plaintext and last bytes as cyphertext.
-func (mc *MACCache) Find(data []byte) *PeerID {
-       if len(data) < 8*2 {
-               return nil
+func (mc *MACCache) Find(data []byte) (*PeerID, error) {
+       const minimumSize = 8 * 2
+       lenData := len(data)
+       fields := logrus.Fields{
+               "func": logFuncPrefix + "MACCache.Find",
+               "data": lenData,
+               "size": mc.Length(),
+       }
+       logger.WithFields(fields).Debug("Starting")
+       if lenData < minimumSize {
+               return nil, errors.Errorf("MAC is too small %d, minimum %d", lenData, minimumSize)
        }
        buf := make([]byte, 8)
        sum := make([]byte, 32)
        mc.l.RLock()
+       defer mc.l.RUnlock()
        for pid, mt := range mc.cache {
+               loopFields := logrus.Fields{"pid": pid.String()}
+               logger.WithFields(loopFields).Debug("process")
                copy(buf, data)
                AddTimeSync(mt.ts, buf)
                mt.l.Lock()
                mt.mac.Reset()
-               mt.mac.Write(buf)
+               logger.WithFields(fields).WithField("buf", hex.EncodeToString(buf)).Debug("mt.mac.Write")
+               if _, err := mt.mac.Write(buf); err != nil {
+                       mt.l.Unlock()
+                       return nil, errors.Wrap(err, "mt.mac.Write")
+               }
+               logger.WithFields(fields).WithField("buf", hex.EncodeToString(buf[:0])).Debug("mt.mac.Sum")
                mt.mac.Sum(sum[:0])
                mt.l.Unlock()
-               if subtle.ConstantTimeCompare(sum[len(sum)-8:], data[len(data)-8:]) == 1 {
+
+               if subtle.ConstantTimeCompare(sum[len(sum)-8:], data[lenData-8:]) == 1 {
+                       logger.WithFields(fields).WithFields(loopFields).Debug("Matching peer")
                        ppid := PeerID(pid)
-                       mc.l.RUnlock()
-                       return &ppid
+                       return &ppid, nil
                }
+
+               logger.WithFields(fields).WithFields(loopFields).Debug("Not matching peer")
        }
-       mc.l.RUnlock()
-       return nil
+       logger.WithFields(fields).Debug("Couldn't find matching peer ID")
+       return nil, nil
 }
index 78881e33e5e95201dd42e81609b023cb82ce4708..2995163c75de516dbb8b24370dde3b1c2e8524b0 100644 (file)
@@ -1,6 +1,6 @@
 /*
 GoVPN -- simple secure free software virtual private network daemon
-Copyright (C) 2014-2017 Sergey Matveev <stargrave@stargrave.org>
+Copyright (C) 2014-2016 Sergey Matveev <stargrave@stargrave.org>
 
 This program is free software: you can redistribute it and/or modify
 it under the terms of the GNU General Public License as published by
@@ -23,34 +23,36 @@ import (
        "crypto/subtle"
        "encoding/binary"
        "io"
-       "log"
        "sync"
        "sync/atomic"
        "time"
 
        "chacha20"
+       "github.com/Sirupsen/logrus"
+       "github.com/pkg/errors"
        "golang.org/x/crypto/blake2b"
        "golang.org/x/crypto/poly1305"
 )
 
 const (
        // NonceSize is nonce size
-       NonceSize       = 8
-       NonceBucketSize = 256
-       TagSize         = poly1305.TagSize
-       // S20BS is ChaCha20's internal blocksize in bytes
-       S20BS = 64
+       NonceSize                 = 8
+       nonceBucketSize           = 256
+       tagSize                   = poly1305.TagSize
+       chacha20InternalBlockSize = 64
        // MaxBytesPerKey is maximal amount of bytes transferred with single key (4 GiB)
        MaxBytesPerKey uint64 = 1 << 32
        // Heartbeat rate, relative to Timeout
-       TimeoutHeartbeat = 4
+       timeoutHeartbeat = 4
        // MinPktLength is minimal valid packet length
        MinPktLength = 1 + 16 + 8
-       // Padding byte
-       PadByte = byte(0x80)
+       // padding byte
+       padByte = byte(0x80)
+
+       logPrefixPeer = "peer_"
 )
 
-func newNonces(key *[32]byte, i uint64) chan *[NonceSize]byte {
+func newNonces(key *[32]byte, i uint64) (chan *[NonceSize]byte, error) {
        macKey := make([]byte, 32)
        chacha20.XORKeyStream(macKey, make([]byte, 32), new([16]byte), key)
        mac, err := blake2b.New256(macKey)
@@ -58,7 +60,7 @@ func newNonces(key *[32]byte, i uint64) chan *[NonceSize]byte {
                panic(err)
        }
        sum := make([]byte, mac.Size())
-       nonces := make(chan *[NonceSize]byte, NonceBucketSize*3)
+       nonces := make(chan *[NonceSize]byte, nonceBucketSize*3)
        go func() {
                for {
                        buf := new([NonceSize]byte)
@@ -71,7 +73,7 @@ func newNonces(key *[32]byte, i uint64) chan *[NonceSize]byte {
                        i += 2
                }
        }()
-       return nonces
+       return nonces, nil
 }
 
 // Peer is a GoVPN peer (client)
@@ -89,9 +91,10 @@ type Peer struct {
        HeartbeatSent   uint64
 
        // Basic
-       Addr string
-       ID   *PeerID
-       Conn io.Writer `json:"-"`
+       Addr     string
+       ID       *PeerID
+       Conn     io.Writer `json:"-"`
+       Protocol Protocol
 
        // Traffic behaviour
        NoiseEnable bool
@@ -110,7 +113,7 @@ type Peer struct {
        // Receiver
        BusyR    sync.Mutex `json:"-"`
        bufR     []byte
-       tagR     *[TagSize]byte
+       tagR     *[tagSize]byte
        keyAuthR *[SSize]byte
        nonceR   *[16]byte
        pktSizeR int
@@ -129,13 +132,36 @@ type Peer struct {
        // Transmitter
        BusyT    sync.Mutex `json:"-"`
        bufT     []byte
-       tagT     *[TagSize]byte
+       tagT     *[tagSize]byte
        keyAuthT *[SSize]byte
        nonceT   *[16]byte
        frameT   []byte
        noncesT  chan *[NonceSize]byte
 }
 
+// LogFields return a logrus compatible Fields to identity a single peer in logs
+func (p *Peer) LogFields() logrus.Fields {
+       return logrus.Fields{
+               logPrefixPeer + "addr":        p.Addr,
+               logPrefixPeer + "id":          p.ID.String(),
+               logPrefixPeer + "established": p.Established.String(),
+               logPrefixPeer + "last_ping":   p.LastPing.String(),
+       }
+}
+
+// ConfigurationLogFields return a logrus compatible Fields with the settings of
+// a single peer. Complement LogFields() for extra debugging details.
+func (p *Peer) ConfigurationLogFields() logrus.Fields {
+       return logrus.Fields{
+               logPrefixPeer + "timeout":  p.Timeout.String(),
+               logPrefixPeer + "protocol": p.Protocol.String(),
+               logPrefixPeer + "noise":    p.NoiseEnable,
+               logPrefixPeer + "cpr":      p.CPR,
+               logPrefixPeer + "mtu":      p.MTU,
+               logPrefixPeer + "encless":  p.Encless,
+       }
+}
+
 func (p *Peer) String() string {
        return p.ID.String() + ":" + p.Addr
 }
@@ -166,7 +192,7 @@ func cprCycleCalculate(conf *PeerConf) time.Duration {
        return time.Second / time.Duration(rate)
 }
 
-func newPeer(isClient bool, addr string, conn io.Writer, conf *PeerConf, key *[SSize]byte) *Peer {
+func newPeer(isClient bool, addr string, conn io.Writer, conf *PeerConf, key *[SSize]byte) (*Peer, error) {
        now := time.Now()
        timeout := conf.Timeout
 
@@ -176,10 +202,10 @@ func newPeer(isClient bool, addr string, conn io.Writer, conf *PeerConf, key *[S
                noiseEnable = true
                timeout = cprCycle
        } else {
-               timeout = timeout / TimeoutHeartbeat
+               timeout = timeout / timeoutHeartbeat
        }
 
-       bufSize := S20BS + 2*conf.MTU
+       bufSize := chacha20InternalBlockSize + 2*conf.MTU
        if conf.Encless {
                bufSize += EnclessEnlargeSize
                noiseEnable = true
@@ -204,22 +230,35 @@ func newPeer(isClient bool, addr string, conn io.Writer, conf *PeerConf, key *[S
 
                bufR:     make([]byte, bufSize),
                bufT:     make([]byte, bufSize),
-               tagR:     new([TagSize]byte),
-               tagT:     new([TagSize]byte),
+               tagR:     new([tagSize]byte),
+               tagT:     new([tagSize]byte),
                keyAuthR: new([SSize]byte),
                nonceR:   new([16]byte),
                keyAuthT: new([SSize]byte),
                nonceT:   new([16]byte),
        }
 
+       var err error
        if isClient {
-               peer.noncesT = newNonces(peer.key, 1+2)
-               peer.noncesR = newNonces(peer.key, 0+2)
-               peer.noncesExpect = newNonces(peer.key, 0+2)
+               if peer.noncesT, err = newNonces(peer.key, 1+2); err != nil {
+                       return nil, err
+               }
+               if peer.noncesR, err = newNonces(peer.key, 0+2); err != nil {
+                       return nil, err
+               }
+               if peer.noncesExpect, err = newNonces(peer.key, 0+2); err != nil {
+                       return nil, err
+               }
        } else {
-               peer.noncesT = newNonces(peer.key, 0+2)
-               peer.noncesR = newNonces(peer.key, 1+2)
-               peer.noncesExpect = newNonces(peer.key, 1+2)
+               if peer.noncesT, err = newNonces(peer.key, 0+2); err != nil {
+                       return nil, err
+               }
+               if peer.noncesR, err = newNonces(peer.key, 1+2); err != nil {
+                       return nil, err
+               }
+               if peer.noncesExpect, err = newNonces(peer.key, 1+2); err != nil {
+                       return nil, err
+               }
        }
 
        peer.NonceExpect = make([]byte, NonceSize)
@@ -227,55 +266,63 @@ func newPeer(isClient bool, addr string, conn io.Writer, conf *PeerConf, key *[S
        copy(peer.NonceExpect, nonce[:])
 
        var i int
-       peer.nonceBucketL = make(map[[NonceSize]byte]struct{}, NonceBucketSize)
-       for i = 0; i < NonceBucketSize; i++ {
+       peer.nonceBucketL = make(map[[NonceSize]byte]struct{}, nonceBucketSize)
+       for i = 0; i < nonceBucketSize; i++ {
                nonce = <-peer.noncesR
                peer.nonceBucketL[*nonce] = struct{}{}
        }
-       peer.nonceBucketM = make(map[[NonceSize]byte]struct{}, NonceBucketSize)
-       for i = 0; i < NonceBucketSize; i++ {
+       peer.nonceBucketM = make(map[[NonceSize]byte]struct{}, nonceBucketSize)
+       for i = 0; i < nonceBucketSize; i++ {
                nonce = <-peer.noncesR
                peer.nonceBucketM[*nonce] = struct{}{}
        }
-       peer.nonceBucketH = make(map[[NonceSize]byte]struct{}, NonceBucketSize)
-       for i = 0; i < NonceBucketSize; i++ {
+       peer.nonceBucketH = make(map[[NonceSize]byte]struct{}, nonceBucketSize)
+       for i = 0; i < nonceBucketSize; i++ {
                nonce = <-peer.noncesR
                peer.nonceBucketH[*nonce] = struct{}{}
        }
 
-       return &peer
+       return &peer, nil
 }
 
 // EthProcess processes incoming Ethernet packet.
 // ready channel is TAPListen's synchronization channel used to tell him
 // that he is free to receive new packets. Encrypted and authenticated
 // packets will be sent to remote Peer side immediately.
-func (p *Peer) EthProcess(data []byte) {
-       if len(data) > p.MTU-1 { // 1 is for padding byte
-               log.Println("Padded data packet size", len(data)+1, "is bigger than MTU", p.MTU, p)
-               return
+func (p *Peer) EthProcess(data []byte) error {
+       const paddingSize = 1
+       lenData := len(data)
+       if lenData > p.MTU-paddingSize {
+               logger.WithFields(p.LogFields()).WithFields(p.ConfigurationLogFields()).WithFields(
+                       logrus.Fields{
+                               "func":        logFuncPrefix + "Peer.EthProcess",
+                               "padding":     paddingSize,
+                               "packet_size": lenData,
+                       }).Warning("Ignore padded data packet larger than MTU")
+               return nil
        }
        p.BusyT.Lock()
+       defer p.BusyT.Unlock()
 
        // Zero size is a heartbeat packet
        SliceZero(p.bufT)
-       if len(data) == 0 {
-               p.bufT[S20BS+0] = PadByte
+       if lenData == 0 {
+               p.bufT[chacha20InternalBlockSize+0] = padByte
                p.HeartbeatSent++
        } else {
                // Copy payload to our internal buffer and we are ready to
                // accept the next one
-               copy(p.bufT[S20BS:], data)
-               p.bufT[S20BS+len(data)] = PadByte
-               p.BytesPayloadOut += uint64(len(data))
+               copy(p.bufT[chacha20InternalBlockSize:], data)
+               p.bufT[chacha20InternalBlockSize+lenData] = padByte
+               p.BytesPayloadOut += uint64(lenData)
        }
 
        if p.NoiseEnable && !p.Encless {
-               p.frameT = p.bufT[S20BS : S20BS+p.MTU-TagSize]
+               p.frameT = p.bufT[chacha20InternalBlockSize : chacha20InternalBlockSize+p.MTU-tagSize]
        } else if p.Encless {
-               p.frameT = p.bufT[S20BS : S20BS+p.MTU]
+               p.frameT = p.bufT[chacha20InternalBlockSize : chacha20InternalBlockSize+p.MTU]
        } else {
-               p.frameT = p.bufT[S20BS : S20BS+len(data)+1+NonceSize]
+               p.frameT = p.bufT[chacha20InternalBlockSize : chacha20InternalBlockSize+lenData+1+NonceSize]
        }
        copy(p.frameT[len(p.frameT)-NonceSize:], (<-p.noncesT)[:])
        var out []byte
@@ -284,41 +331,49 @@ func (p *Peer) EthProcess(data []byte) {
                var err error
                out, err = EnclessEncode(p.key, p.nonceT, p.frameT[:len(p.frameT)-NonceSize])
                if err != nil {
-                       panic(err)
+                       return errors.Wrap(err, wrapEnclessEncode)
                }
                out = append(out, p.frameT[len(p.frameT)-NonceSize:]...)
        } else {
                chacha20.XORKeyStream(
-                       p.bufT[:S20BS+len(p.frameT)-NonceSize],
-                       p.bufT[:S20BS+len(p.frameT)-NonceSize],
+                       p.bufT[:chacha20InternalBlockSize+len(p.frameT)-NonceSize],
+                       p.bufT[:chacha20InternalBlockSize+len(p.frameT)-NonceSize],
                        p.nonceT,
                        p.key,
                )
                copy(p.keyAuthT[:], p.bufT[:SSize])
                poly1305.Sum(p.tagT, p.frameT, p.keyAuthT)
-               atomic.AddUint64(&p.BytesOut, uint64(len(p.frameT)+TagSize))
+               atomic.AddUint64(&p.BytesOut, uint64(len(p.frameT)+tagSize))
                out = append(p.tagT[:], p.frameT...)
        }
        p.FramesOut++
-       p.Conn.Write(out)
-       p.BusyT.Unlock()
+       _, err := p.Conn.Write(out)
+       return errors.Wrap(err, "p.Conn.Write")
 }
 
 // PktProcess processes data of a single packet
 func (p *Peer) PktProcess(data []byte, tap io.Writer, reorderable bool) bool {
-       if len(data) < MinPktLength {
+       lenData := len(data)
+       fields := logrus.Fields{
+               "func":        logFuncPrefix + "Peer.PktProcess",
+               "reorderable": reorderable,
+               "data":        lenData,
+       }
+       if lenData < MinPktLength {
+               logger.WithFields(p.LogFields()).WithFields(fields).WithField("minimum_packet_Length", MinPktLength).Debug("Ignore packet smaller than allowed minimum")
                return false
        }
-       if !p.Encless && len(data) > len(p.bufR)-S20BS {
+       if !p.Encless && lenData > len(p.bufR)-chacha20InternalBlockSize {
                return false
        }
        var out []byte
-       p.BusyR.Lock()
-       copy(p.nonceR[8:], data[len(data)-NonceSize:])
+       p.BusyR.Lock() // TODO use defer to unlock?
+       copy(p.nonceR[8:], data[lenData-NonceSize:])
        if p.Encless {
                var err error
-               out, err = EnclessDecode(p.key, p.nonceR, data[:len(data)-NonceSize])
+               out, err = EnclessDecode(p.key, p.nonceR, data[:lenData-NonceSize])
                if err != nil {
+                       logger.WithFields(p.LogFields()).WithError(err).Debug("Failed to decode encless")
                        p.FramesUnauth++
                        p.BusyR.Unlock()
                        return false
@@ -327,25 +382,25 @@ func (p *Peer) PktProcess(data []byte, tap io.Writer, reorderable bool) bool {
                for i := 0; i < SSize; i++ {
                        p.bufR[i] = 0
                }
-               copy(p.bufR[S20BS:], data[TagSize:])
+               copy(p.bufR[chacha20InternalBlockSize:], data[tagSize:])
                chacha20.XORKeyStream(
-                       p.bufR[:S20BS+len(data)-TagSize-NonceSize],
-                       p.bufR[:S20BS+len(data)-TagSize-NonceSize],
+                       p.bufR[:chacha20InternalBlockSize+lenData-tagSize-NonceSize],
+                       p.bufR[:chacha20InternalBlockSize+lenData-tagSize-NonceSize],
                        p.nonceR,
                        p.key,
                )
                copy(p.keyAuthR[:], p.bufR[:SSize])
-               copy(p.tagR[:], data[:TagSize])
-               if !poly1305.Verify(p.tagR, data[TagSize:], p.keyAuthR) {
+               copy(p.tagR[:], data[:tagSize])
+               if !poly1305.Verify(p.tagR, data[tagSize:], p.keyAuthR) {
                        p.FramesUnauth++
                        p.BusyR.Unlock()
                        return false
                }
-               out = p.bufR[S20BS : S20BS+len(data)-TagSize-NonceSize]
+               out = p.bufR[chacha20InternalBlockSize : chacha20InternalBlockSize+lenData-tagSize-NonceSize]
        }
 
        if reorderable {
-               copy(p.nonceRecv[:], data[len(data)-NonceSize:])
+               copy(p.nonceRecv[:], data[lenData-NonceSize:])
                _, foundL := p.nonceBucketL[p.nonceRecv]
                _, foundM := p.nonceBucketM[p.nonceRecv]
                _, foundH := p.nonceBucketH[p.nonceRecv]
@@ -371,13 +426,13 @@ func (p *Peer) PktProcess(data []byte, tap io.Writer, reorderable bool) bool {
                        p.nonceBucketL, p.nonceBucketM = p.nonceBucketM, p.nonceBucketH
                        p.nonceBucketH = make(map[[NonceSize]byte]struct{})
                        var nonce *[NonceSize]byte
-                       for i := 0; i < NonceBucketSize; i++ {
+                       for i := 0; i < nonceBucketSize; i++ {
                                nonce = <-p.noncesR
                                p.nonceBucketH[*nonce] = struct{}{}
                        }
                }
        } else {
-               if subtle.ConstantTimeCompare(data[len(data)-NonceSize:], p.NonceExpect) != 1 {
+               if subtle.ConstantTimeCompare(data[lenData-NonceSize:], p.NonceExpect) != 1 {
                        p.FramesDup++
                        p.BusyR.Unlock()
                        return false
@@ -386,9 +441,9 @@ func (p *Peer) PktProcess(data []byte, tap io.Writer, reorderable bool) bool {
        }
 
        p.FramesIn++
-       atomic.AddUint64(&p.BytesIn, uint64(len(data)))
+       atomic.AddUint64(&p.BytesIn, uint64(lenData))
        p.LastPing = time.Now()
-       p.pktSizeR = bytes.LastIndexByte(out, PadByte)
+       p.pktSizeR = bytes.LastIndexByte(out, padByte)
        if p.pktSizeR == -1 {
                p.BusyR.Unlock()
                return false
@@ -416,6 +471,11 @@ func (p *Peer) PktProcess(data []byte, tap io.Writer, reorderable bool) bool {
 func PeerTapProcessor(peer *Peer, tap *TAP, terminator chan struct{}) {
        var data []byte
        var now time.Time
+       var err error
+       fields := logrus.Fields{
+               "func": logFuncPrefix + "PeerTapProcessor",
+               "tap":  tap.Name,
+       }
        lastSent := time.Now()
        heartbeat := time.NewTicker(peer.Timeout)
        if peer.CPRCycle == time.Duration(0) {
@@ -427,11 +487,15 @@ func PeerTapProcessor(peer *Peer, tap *TAP, terminator chan struct{}) {
                        case <-heartbeat.C:
                                now = time.Now()
                                if lastSent.Add(peer.Timeout).Before(now) {
-                                       peer.EthProcess(nil)
+                                       if err = peer.EthProcess(nil); err != nil {
+                                               logger.WithFields(fields).WithFields(peer.LogFields()).WithError(err).Warn("Can't process nil ethernet packet")
+                                       }
                                        lastSent = now
                                }
                        case data = <-tap.Sink:
-                               peer.EthProcess(data)
+                               if err = peer.EthProcess(data); err != nil {
+                                       logger.WithFields(fields).WithFields(peer.LogFields()).WithError(err).Warn("Can't process ethernet packet")
+                               }
                                lastSent = time.Now()
                        }
                }
@@ -443,11 +507,15 @@ func PeerTapProcessor(peer *Peer, tap *TAP, terminator chan struct{}) {
                        case <-terminator:
                                break CPRProcessor
                        case data = <-tap.Sink:
-                               peer.EthProcess(data)
+                               if err = peer.EthProcess(data); err != nil {
+                                       logger.WithFields(fields).WithFields(peer.LogFields()).WithError(err).Warn("Can't process ethernet packet")
+                               }
                        default:
                        }
                        if data == nil {
-                               peer.EthProcess(nil)
+                               if err = peer.EthProcess(nil); err != nil {
+                                       logger.WithFields(fields).WithFields(peer.LogFields()).WithError(err).Warn("Can't process nil ethernet packet")
+                               }
                        }
                        time.Sleep(peer.CPRCycle)
                }
index d80c581b4d22766e300dc96c8b86f8f26ee44828..01e321d48e415eb470159491c449d1739ade9785 100644 (file)
@@ -1,6 +1,6 @@
 /*
 GoVPN -- simple secure free software virtual private network daemon
-Copyright (C) 2014-2017 Sergey Matveev <stargrave@stargrave.org>
+Copyright (C) 2014-2016 Sergey Matveev <stargrave@stargrave.org>
 
 This program is free software: you can redistribute it and/or modify
 it under the terms of the GNU General Public License as published by
@@ -20,15 +20,14 @@ package govpn
 
 import (
        "encoding/json"
-       "log"
        "net"
        "time"
-)
 
-const (
-       RWTimeout = 10 * time.Second
+       "github.com/Sirupsen/logrus"
 )
 
+const rwTimeout = 10 * time.Second
+
 // KnownPeers map of all connected GoVPN peers
 type KnownPeers map[string]**Peer
 
@@ -38,29 +37,46 @@ type KnownPeers map[string]**Peer
 // argument is a reference to the map with references to the peers as
 // values. Map is used here because of ease of adding and removing
 // elements in it.
-func StatsProcessor(statsPort net.Listener, peers *KnownPeers) {
+func StatsProcessor(stats string, peers *KnownPeers) {
        var conn net.Conn
-       var err error
-       var data []byte
        buf := make([]byte, 2<<8)
+       fields := logrus.Fields{
+               "func":    logFuncPrefix + "StatsProcessor",
+               "bufsize": len(buf),
+               "port":    stats,
+       }
+
+       logger.WithFields(fields).WithField("port", stats).Debug("Stats are going to listen")
+       statsPort, err := net.Listen("tcp", stats)
+       if err != nil {
+               logger.WithError(err).WithField("stats", stats).Error("Can't listen stats server")
+               return
+       }
+
        for {
                conn, err = statsPort.Accept()
                if err != nil {
-                       log.Println("Error during accepting connection", err.Error())
+                       logger.WithFields(fields).WithError(err).Error("Couldn't accept connection")
                        continue
                }
-               conn.SetDeadline(time.Now().Add(RWTimeout))
-               conn.Read(buf)
-               conn.Write([]byte("HTTP/1.0 200 OK\r\nContent-Type: application/json\r\n\r\n"))
-               var peersList []*Peer
-               for _, peer := range *peers {
-                       peersList = append(peersList, *peer)
+               deadLine := time.Now().Add(rwTimeout)
+               if err = conn.SetDeadline(deadLine); err != nil {
+                       logger.WithFields(fields).WithField("deadline", deadLine.String()).WithError(err).Error("Couldn't set deadline")
+               } else if _, err = conn.Read(buf); err != nil {
+                       logger.WithFields(fields).WithError(err).Error("Couldn't read buffer")
+               } else if _, err = conn.Write([]byte("HTTP/1.0 200 OK\r\nContent-Type: application/json\r\n\r\n")); err != nil {
+                       logger.WithFields(fields).WithError(err).Error("Couldn't write HTTP headers")
+               } else {
+                       var peersList []*Peer
+                       for _, peer := range *peers {
+                               peersList = append(peersList, *peer)
+                       }
+                       if err = json.NewEncoder(conn).Encode(peersList); err != nil {
+                               logger.WithFields(fields).WithField("peers", len(peersList)).WithError(err).Error("Couldn't encode to JSON")
+                       }
                }
-               data, err = json.Marshal(peersList)
-               if err != nil {
-                       panic(err)
+               if err = conn.Close(); err != nil {
+                       logger.WithFields(fields).WithError(err).Error("Couldn't close connection")
                }
-               conn.Write(data)
-               conn.Close()
        }
 }
index d5976ec8529aa059222219e809055bb8c2018153..00ba6322eae8d640ccde58860a503631a8d30596 100644 (file)
@@ -21,28 +21,30 @@ package govpn
 import (
        "bytes"
        "encoding/base64"
-       "errors"
        "fmt"
        "hash"
        "io/ioutil"
-       "log"
        "os"
        "strings"
        "syscall"
 
-       "cypherpunks.ru/balloon"
        "github.com/agl/ed25519"
+       "github.com/pkg/errors"
        "golang.org/x/crypto/blake2b"
        "golang.org/x/crypto/ssh/terminal"
+
+       "cypherpunks.ru/balloon"
 )
 
 const (
-       // DefaultS is default Balloon space cost
+       // DefaultS default Balloon space cost
        DefaultS = 1 << 20 / 32
-       // DefaultT is default Balloon time cost
+       // DefaultT default Balloon time cost
        DefaultT = 1 << 4
-       // DefaultP is default Balloon number of jobs
+       // DefaultP default Balloon number of job
        DefaultP = 2
+
+       wrapDecodeString = "base64.RawStdEncoding.DecodeString"
 )
 
 // Verifier is used to authenticate a peer
@@ -60,26 +62,30 @@ func VerifierNew(s, t, p int, id *PeerID) *Verifier {
        return &Verifier{S: s, T: t, P: p, ID: id}
 }
 
-func blake2bKeyless() hash.Hash {
-       h, err := blake2b.New256(nil)
+// PasswordApply applies the password: create Ed25519 keypair based on it,
+// saves public key in verifier.
+func (v *Verifier) PasswordApply(password string) (*[ed25519.PrivateKeySize]byte, error) {
+       // TODO: there is an extremely weird bug, `balloon.H` panic if I the `hash.Hash`
+       // outside the `hasher` function.
+       var err error
+       hasher := func() hash.Hash {
+               var nilHash hash.Hash
+               nilHash, err = blake2b.New256(nil)
+               return nilHash
+       }
+       r := balloon.H(hasher, []byte(password), v.ID[:], v.S, v.T, v.P)
        if err != nil {
-               panic(err)
+               return nil, errors.Wrap(err, wrapBlake2bNew256)
        }
-       return h
-}
 
-// PasswordApply applies the password: create Ed25519 keypair based on it,
-// saves public key in verifier.
-func (v *Verifier) PasswordApply(password string) *[ed25519.PrivateKeySize]byte {
-       r := balloon.H(blake2bKeyless, []byte(password), v.ID[:], v.S, v.T, v.P)
        defer SliceZero(r)
        src := bytes.NewBuffer(r)
        pub, prv, err := ed25519.GenerateKey(src)
        if err != nil {
-               log.Fatalln("Unable to generate Ed25519 keypair", err)
+               return nil, errors.Wrap(err, "ed25519.GenerateKey")
        }
        v.Pub = pub
-       return prv
+       return prv, nil
 }
 
 // VerifierFromString parses either short or long verifier form.
@@ -90,12 +96,15 @@ func VerifierFromString(input string) (*Verifier, error) {
        }
        var s, t, p int
        n, err := fmt.Sscanf(ss[2], "s=%d,t=%d,p=%d", &s, &t, &p)
-       if n != 3 || err != nil {
+       if err != nil {
+               return nil, errors.Wrap(err, "fmt.Sscanf")
+       }
+       if n != 3 {
                return nil, errors.New("Invalid verifier parameters")
        }
        salt, err := base64.RawStdEncoding.DecodeString(ss[3])
        if err != nil {
-               return nil, err
+               return nil, errors.Wrap(err, wrapDecodeString)
        }
        v := Verifier{S: s, T: t, P: p}
        id := new([IDSize]byte)
@@ -105,7 +114,7 @@ func VerifierFromString(input string) (*Verifier, error) {
        if len(ss) == 5 {
                pub, err := base64.RawStdEncoding.DecodeString(ss[4])
                if err != nil {
-                       return nil, err
+                       return nil, errors.Wrap(err, wrapDecodeString)
                }
                v.Pub = new([ed25519.PublicKeySize]byte)
                copy(v.Pub[:], pub)
@@ -134,23 +143,33 @@ func (v *Verifier) LongForm() string {
 // KeyRead reads the key either from text file (if path is specified), or
 // from the terminal.
 func KeyRead(path string) (string, error) {
+       const (
+               emptyString       = ""
+               wrapOsStderrWrite = "os.Stderr.Write"
+       )
        var p []byte
        var err error
        var pass string
-       if path == "" {
-               os.Stderr.Write([]byte("Passphrase:"))
+       if path == emptyString {
+               if _, err = os.Stderr.Write([]byte("Passphrase:")); err != nil {
+                       return emptyString, errors.Wrap(err, wrapOsStderrWrite)
+               }
                p, err = terminal.ReadPassword(int(uintptr(syscall.Stdin)))
-               os.Stderr.Write([]byte("\n"))
+               if err != nil {
+                       return emptyString, errors.Wrap(err, "terminal.ReadPassword")
+               }
+               if _, err = os.Stderr.Write([]byte("\n")); err != nil {
+                       return emptyString, errors.Wrap(err, wrapOsStderrWrite)
+               }
                pass = string(p)
        } else {
-               p, err = ioutil.ReadFile(path)
+               if p, err = ioutil.ReadFile(path); err != nil {
+                       return emptyString, errors.Wrap(err, "ioutil.ReadFile")
+               }
                pass = strings.TrimRight(string(p), "\n")
        }
-       if err != nil {
-               return "", err
-       }
        if len(pass) == 0 {
-               return "", errors.New("Empty passphrase submitted")
+               return emptyString, errors.New("Empty passphrase submitted")
        }
-       return pass, err
+       return pass, nil
 }