diff --git a/datagram_test.go b/datagram_test.go index 4455642..f7bf7a7 100644 --- a/datagram_test.go +++ b/datagram_test.go @@ -2,7 +2,6 @@ package sam3 import ( "fmt" - "log" "testing" "time" ) @@ -123,7 +122,7 @@ func ExampleDatagramSession() { fmt.Println(err.Error()) return } - log.Println("Got message: '" + string(buf[:n]) + "'") + fmt.Println("Got message: '" + string(buf[:n]) + "'") fmt.Println("Got message: " + string(buf[:n])) return diff --git a/go.mod b/go.mod index c9965a2..709e1ae 100644 --- a/go.mod +++ b/go.mod @@ -3,6 +3,6 @@ module github.com/eyedeekay/sam3 go 1.12 require ( - github.com/eyedeekay/i2pkeys v0.33.7 - github.com/sirupsen/logrus v1.9.3 // indirect + github.com/eyedeekay/i2pkeys v0.33.8 + github.com/sirupsen/logrus v1.9.3 ) diff --git a/go.sum b/go.sum index 6034aa0..c11afc9 100644 --- a/go.sum +++ b/go.sum @@ -1,13 +1,18 @@ github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= -github.com/eyedeekay/i2pkeys v0.33.7 h1:cxqHSkl6b2lHyPJUtIQZBiipYf7NQVYqM1d3ub0MI4k= -github.com/eyedeekay/i2pkeys v0.33.7/go.mod h1:W9KCm9lqZ+Ozwl3dwcgnpPXAML97+I8Jiht7o5A8YBM= +github.com/eyedeekay/i2pkeys v0.33.8 h1:f3llyruchFqs1QwCacBYbShArKPpMSSOqo/DVZXcfVs= +github.com/eyedeekay/i2pkeys v0.33.8/go.mod h1:W9KCm9lqZ+Ozwl3dwcgnpPXAML97+I8Jiht7o5A8YBM= +github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ= github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/testify v1.7.0 h1:nwc3DEeHmmLAfoZucVR881uASk0Mfjw8xYJ99tb5CcY= github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8 h1:0A+M6Uqn+Eje4kHMK80dtF3JCXC4ykBgQG4Fe06QRhQ= golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c h1:dUUwHk2QECo/6vqA44rthZ8ie2QXMNeKRTHCNY2nXvo= gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= diff --git a/primary_datagram_test.go b/primary_datagram_test.go index 6bd1ec2..7d3e1c7 100644 --- a/primary_datagram_test.go +++ b/primary_datagram_test.go @@ -2,7 +2,6 @@ package sam3 import ( "fmt" - "log" "testing" "time" ) @@ -140,7 +139,7 @@ func ExamplePrimaryDatagramSession() { fmt.Println(err.Error()) return } - log.Println("Got message: '" + string(buf[:n]) + "'") + fmt.Println("Got message: '" + string(buf[:n]) + "'") fmt.Println("Got message: " + string(buf[:n])) return diff --git a/sam3.go b/sam3.go index 7c33bd3..9e9df69 100644 --- a/sam3.go +++ b/sam3.go @@ -6,6 +6,7 @@ import ( "bytes" "errors" "fmt" + "github.com/sirupsen/logrus" "io" "math/rand" "net" @@ -52,40 +53,49 @@ func RandString() string { for i := range b { b[i] = letters[rand.Intn(len(letters))] } + log.WithField("randomString", string(b)).Debug("Generated random string") return string(b) } // Creates a new controller for the I2P routers SAM bridge. func NewSAM(address string) (*SAM, error) { + log.WithField("address", address).Debug("Creating new SAM instance") var s SAM // TODO: clean this up conn, err := net.Dial("tcp", address) if err != nil { + log.WithError(err).Error("Failed to dial SAM address") return nil, fmt.Errorf("error dialing to address '%s': %w", address, err) } if _, err := conn.Write(s.Config.HelloBytes()); err != nil { + log.WithError(err).Error("Failed to write hello message") conn.Close() return nil, fmt.Errorf("error writing to address '%s': %w", address, err) } buf := make([]byte, 256) n, err := conn.Read(buf) if err != nil { + log.WithError(err).Error("Failed to read SAM response") conn.Close() return nil, fmt.Errorf("error reading onto buffer: %w", err) } if strings.Contains(string(buf[:n]), "HELLO REPLY RESULT=OK") { + log.Debug("SAM hello successful") s.Config.I2PConfig.SetSAMAddress(address) s.conn = conn //s.Config.I2PConfig.DestinationKeys = nil s.resolver, err = NewSAMResolver(&s) if err != nil { + log.WithError(err).Error("Failed to create SAM resolver") return nil, fmt.Errorf("error creating resolver: %w", err) } return &s, nil } else if string(buf[:n]) == "HELLO REPLY RESULT=NOVERSION\n" { + log.Error("SAM bridge does not support SAMv3") conn.Close() return nil, errors.New("That SAM bridge does not support SAMv3.") } else { + log.WithField("response", string(buf[:n])).Error("Unexpected SAM response") conn.Close() return nil, errors.New(string(buf[:n])) } @@ -93,27 +103,35 @@ func NewSAM(address string) (*SAM, error) { func (sam *SAM) Keys() (k *i2pkeys.I2PKeys) { //TODO: copy them? + log.Debug("Retrieving SAM keys") k = &sam.Config.I2PConfig.DestinationKeys return } // read public/private keys from an io.Reader func (sam *SAM) ReadKeys(r io.Reader) (err error) { + log.Debug("Reading keys from io.Reader") var keys i2pkeys.I2PKeys keys, err = i2pkeys.LoadKeysIncompat(r) if err == nil { + log.Debug("Keys loaded successfully") sam.Config.I2PConfig.DestinationKeys = keys } + log.WithError(err).Error("Failed to load keys") return } // if keyfile fname does not exist func (sam *SAM) EnsureKeyfile(fname string) (keys i2pkeys.I2PKeys, err error) { + log.WithError(err).Error("Failed to load keys") if fname == "" { // transient keys, err = sam.NewKeys() if err == nil { sam.Config.I2PConfig.DestinationKeys = keys + log.WithFields(logrus.Fields{ + "keys": keys, + }).Debug("Generated new transient keys") } } else { // persistent @@ -129,6 +147,7 @@ func (sam *SAM) EnsureKeyfile(fname string) (keys i2pkeys.I2PKeys, err error) { if err == nil { err = i2pkeys.StoreKeysIncompat(keys, f) f.Close() + log.Debug("Generated and saved new keys") } } } else if err == nil { @@ -139,10 +158,14 @@ func (sam *SAM) EnsureKeyfile(fname string) (keys i2pkeys.I2PKeys, err error) { keys, err = i2pkeys.LoadKeysIncompat(f) if err == nil { sam.Config.I2PConfig.DestinationKeys = keys + log.Debug("Loaded existing keys from file") } } } } + if err != nil { + log.WithError(err).Error("Failed to ensure keyfile") + } return } @@ -150,16 +173,19 @@ func (sam *SAM) EnsureKeyfile(fname string) (keys i2pkeys.I2PKeys, err error) { // who has the private keys can send messages from. The public keys are the I2P // desination (the address) that anyone can send messages to. func (sam *SAM) NewKeys(sigType ...string) (i2pkeys.I2PKeys, error) { + log.WithField("sigType", sigType).Debug("Generating new keys") sigtmp := "" if len(sigType) > 0 { sigtmp = sigType[0] } if _, err := sam.conn.Write([]byte("DEST GENERATE " + sigtmp + "\n")); err != nil { + log.WithError(err).Error("Failed to write DEST GENERATE command") return i2pkeys.I2PKeys{}, fmt.Errorf("error with writing in SAM: %w", err) } buf := make([]byte, 8192) n, err := sam.conn.Read(buf) if err != nil { + log.WithError(err).Error("Failed to read SAM response for key generation") return i2pkeys.I2PKeys{}, fmt.Errorf("error with reading in SAM: %w", err) } s := bufio.NewScanner(bytes.NewReader(buf[:n])) @@ -177,15 +203,18 @@ func (sam *SAM) NewKeys(sigType ...string) (i2pkeys.I2PKeys, error) { } else if strings.HasPrefix(text, "PRIV=") { priv = text[5:] } else { + log.Error("Failed to parse keys from SAM response") return i2pkeys.I2PKeys{}, errors.New("Failed to parse keys.") } } + log.Debug("Successfully generated new keys") return NewKeys(I2PAddr(pub), priv), nil } // Performs a lookup, probably this order: 1) routers known addresses, cached // addresses, 3) by asking peers in the I2P network. func (sam *SAM) Lookup(name string) (i2pkeys.I2PAddr, error) { + log.WithField("name", name).Debug("Looking up address") return sam.resolver.Resolve(name) } @@ -195,10 +224,12 @@ func (sam *SAM) Lookup(name string) (i2pkeys.I2PAddr, error) { // setting extra to something else than []string{}. // This sam3 instance is now a session func (sam *SAM) newGenericSession(style, id string, keys i2pkeys.I2PKeys, options []string, extras []string) (net.Conn, error) { + log.WithFields(logrus.Fields{"style": style, "id": id}).Debug("Creating new generic session") return sam.newGenericSessionWithSignature(style, id, keys, Sig_NONE, options, extras) } func (sam *SAM) newGenericSessionWithSignature(style, id string, keys i2pkeys.I2PKeys, sigType string, options []string, extras []string) (net.Conn, error) { + log.WithFields(logrus.Fields{"style": style, "id": id, "sigType": sigType}).Debug("Creating new generic session with signature") return sam.newGenericSessionWithSignatureAndPorts(style, id, "0", "0", keys, sigType, options, extras) } @@ -208,6 +239,7 @@ func (sam *SAM) newGenericSessionWithSignature(style, id string, keys i2pkeys.I2 // setting extra to something else than []string{}. // This sam3 instance is now a session func (sam *SAM) newGenericSessionWithSignatureAndPorts(style, id, from, to string, keys i2pkeys.I2PKeys, sigType string, options []string, extras []string) (net.Conn, error) { + log.WithFields(logrus.Fields{"style": style, "id": id, "from": from, "to": to, "sigType": sigType}).Debug("Creating new generic session with signature and ports") optStr := GenerateOptionString(options) @@ -221,13 +253,18 @@ func (sam *SAM) newGenericSessionWithSignatureAndPorts(style, id, from, to strin tp = " TO_PORT=" + to } scmsg := []byte("SESSION CREATE STYLE=" + style + fp + tp + " ID=" + id + " DESTINATION=" + keys.String() + " " + optStr + strings.Join(extras, " ") + "\n") + + log.WithField("message", string(scmsg)).Debug("Sending SESSION CREATE message") + for m, i := 0, 0; m != len(scmsg); i++ { if i == 15 { + log.Error("Failed to write SESSION CREATE message after 15 attempts") conn.Close() return nil, errors.New("writing to SAM failed") } n, err := conn.Write(scmsg[m:]) if err != nil { + log.WithError(err).Error("Failed to write to SAM connection") conn.Close() return nil, fmt.Errorf("writing to connection failed: %w", err) } @@ -236,12 +273,15 @@ func (sam *SAM) newGenericSessionWithSignatureAndPorts(style, id, from, to strin buf := make([]byte, 4096) n, err := conn.Read(buf) if err != nil { + log.WithError(err).Error("Failed to read SAM response") conn.Close() return nil, fmt.Errorf("reading from connection failed: %w", err) } text := string(buf[:n]) + log.WithField("response", text).Debug("Received SAM response") if strings.HasPrefix(text, session_OK) { if keys.String() != text[len(session_OK):len(text)-1] { + log.Error("SAM created a tunnel with different keys than requested") conn.Close() return nil, errors.New("SAMv3 created a tunnel with keys other than the ones we asked it for") }