diff --git a/alert/log.go b/alert/log.go index 825401e54..8ff6e1414 100644 --- a/alert/log.go +++ b/alert/log.go @@ -6,10 +6,6 @@ import ( var log = logging.MustGetLogger("alert") -func init() { - logging.SetFormatter(logging.MustStringFormatter("[%{level:.1s}] %{message}")) -} - func SetAlertLogger(l *logging.Logger) { log = l } diff --git a/cmd/daemon.go b/cmd/daemon.go index c7f0ef156..f587ceb70 100644 --- a/cmd/daemon.go +++ b/cmd/daemon.go @@ -117,7 +117,7 @@ func daemon() { // Create & start node n := NewNode() - l := p2p.NewDefaultListener("tcp", config.Config.LAddr) + l := p2p.NewDefaultListener("tcp", config.Config.LAddr, false) n.AddListener(l) n.Start() diff --git a/cmd/gen_account.go b/cmd/gen_account.go index 2e507f320..4dcb446f5 100644 --- a/cmd/gen_account.go +++ b/cmd/gen_account.go @@ -24,4 +24,5 @@ Account Private Key: %X base64.StdEncoding.EncodeToString(BinaryBytes(privAccount.PubKey)), privAccount.PrivKey, base64.StdEncoding.EncodeToString(BinaryBytes(privAccount.PrivKey))) + } diff --git a/cmd/log.go b/cmd/log.go index 3248cfdf6..856ec0458 100644 --- a/cmd/log.go +++ b/cmd/log.go @@ -2,15 +2,6 @@ package main import ( "github.com/op/go-logging" - "os" ) var log = logging.MustGetLogger("main") - -func init() { - // Customize the output format - logging.SetFormatter(logging.MustStringFormatter("[%{level:.4s}] %{time:2006-01-02T15:04:05} %{shortfile:-20s} %{message}")) - logBackend := logging.NewLogBackend(os.Stderr, "", 0) - logBackend.Color = true - logging.SetBackend(logBackend) -} diff --git a/cmd/main.go b/cmd/main.go index 161ab4c77..cb5d57ebf 100644 --- a/cmd/main.go +++ b/cmd/main.go @@ -20,6 +20,7 @@ Commands: daemon Run the tendermint node daemon gen_account Generate new account keypair gen_validator Generate new validator keypair + probe_upnp Test UPnP functionality tendermint --help for command options`) return @@ -32,5 +33,7 @@ tendermint --help for command options`) gen_account() case "gen_validator": gen_validator() + case "probe_upnp": + probe_upnp() } } diff --git a/cmd/probe_upnp.go b/cmd/probe_upnp.go new file mode 100644 index 000000000..927e25484 --- /dev/null +++ b/cmd/probe_upnp.go @@ -0,0 +1,24 @@ +package main + +import ( + "encoding/json" + "fmt" + + "github.com/tendermint/tendermint/p2p/upnp" +) + +func probe_upnp() { + + capabilities, err := upnp.Probe() + if err != nil { + fmt.Println("Probe failed: %v", err) + } else { + fmt.Println("Probe success!") + jsonBytes, err := json.Marshal(capabilities) + if err != nil { + panic(err) + } + fmt.Println(string(jsonBytes)) + } + +} diff --git a/common/logging.go b/common/logging.go index 91b08a1c6..0ce10c75d 100644 --- a/common/logging.go +++ b/common/logging.go @@ -11,10 +11,10 @@ var Log = logging.MustGetLogger("main") func init() { // Customize the output format - logging.SetFormatter(logging.MustStringFormatter("▶ %{level:.1s} 0x%{id:x} %{message}")) + logging.SetFormatter(logging.MustStringFormatter("[%{level:.4s}] %{shortfile:-20s} %{message}")) // Setup one stdout and one syslog backend. - logBackend := logging.NewLogBackend(os.Stderr, "", stdlog.LstdFlags|stdlog.Lshortfile) + logBackend := logging.NewLogBackend(os.Stderr, "", stdlog.LstdFlags) logBackend.Color = true syslogBackend, err := logging.NewSyslogBackend("") diff --git a/consensus/log.go b/consensus/log.go index 495f0bf21..fed9899b0 100644 --- a/consensus/log.go +++ b/consensus/log.go @@ -6,10 +6,6 @@ import ( var log = logging.MustGetLogger("consensus") -func init() { - logging.SetFormatter(logging.MustStringFormatter("[%{level:.1s}] %{message}")) -} - func SetConsensusLogger(l *logging.Logger) { log = l } diff --git a/p2p/connection.go b/p2p/connection.go index ce709bd11..ccc164471 100644 --- a/p2p/connection.go +++ b/p2p/connection.go @@ -163,7 +163,7 @@ func (c *MConnection) Send(chId byte, msg interface{}) bool { return false } - log.Debug("[%X][%v] Send: %v", chId, c, msg) + log.Debug("[%X] Send to %v: %v", chId, c, msg) // Send message to channel. channel, ok := c.channelsIdx[chId] @@ -190,7 +190,7 @@ func (c *MConnection) TrySend(chId byte, msg interface{}) bool { return false } - log.Debug("[%X][%v] TrySend: %v", chId, c, msg) + log.Debug("[%X] TrySend to %v: %v", chId, c, msg) // Send message to channel. channel, ok := c.channelsIdx[chId] diff --git a/p2p/listener.go b/p2p/listener.go index ea62cd030..7916a78b3 100644 --- a/p2p/listener.go +++ b/p2p/listener.go @@ -46,7 +46,7 @@ func splitHostPort(addr string) (host string, port int) { return host, port } -func NewDefaultListener(protocol string, lAddr string) Listener { +func NewDefaultListener(protocol string, lAddr string, requireUPNPHairpin bool) Listener { // Local listen IP & port lAddrIP, lAddrPort := splitHostPort(lAddr) @@ -61,12 +61,23 @@ func NewDefaultListener(protocol string, lAddr string) Listener { // Determine external address... var extAddr *NetAddress + // If the lAddrIP is INADDR_ANY, try UPnP - if false { - if lAddrIP == "" || lAddrIP == "0.0.0.0" { - extAddr = getUPNPExternalAddress(lAddrPort, listenerPort) + if lAddrIP == "" || lAddrIP == "0.0.0.0" { + if requireUPNPHairpin { + upnpCapabilities, err := upnp.Probe() + if err != nil { + log.Warning("Failed to probe UPNP: %v", err) + goto SKIP_UPNP + } + if !upnpCapabilities.Hairpin { + goto SKIP_UPNP + } } + extAddr = getUPNPExternalAddress(lAddrPort, listenerPort) } +SKIP_UPNP: + // Otherwise just use the local address... if extAddr == nil { extAddr = getNaiveExternalAddress(listenerPort) diff --git a/p2p/log.go b/p2p/log.go index fc3a2c08d..b7aeb67b3 100644 --- a/p2p/log.go +++ b/p2p/log.go @@ -6,11 +6,6 @@ import ( var log = logging.MustGetLogger("p2p") -func init() { - logging.SetFormatter(logging.MustStringFormatter("[%{level:.1s}] %{message}")) - logging.SetLevel(logging.DEBUG, "p2p") -} - func SetP2PLogger(l *logging.Logger) { log = l } diff --git a/p2p/switch_test.go b/p2p/switch_test.go index f195f83b4..a7063285f 100644 --- a/p2p/switch_test.go +++ b/p2p/switch_test.go @@ -75,7 +75,7 @@ func makeSwitchPair(t testing.TB, reactorsGenerator func() []Reactor) (*Switch, s2 := NewSwitch(reactorsGenerator()) // Create a listener for s1 - l := NewDefaultListener("tcp", ":8001") + l := NewDefaultListener("tcp", ":8001", true) // Dial the listener & add the connection to s2. lAddr := l.ExternalAddress() diff --git a/p2p/upnp/log.go b/p2p/upnp/log.go new file mode 100644 index 000000000..1d29ec9ed --- /dev/null +++ b/p2p/upnp/log.go @@ -0,0 +1,11 @@ +package upnp + +import ( + "github.com/op/go-logging" +) + +var log = logging.MustGetLogger("upnp") + +func SetUPNPLogger(l *logging.Logger) { + log = l +} diff --git a/p2p/upnp/probe.go b/p2p/upnp/probe.go new file mode 100644 index 000000000..9ff9ecf8b --- /dev/null +++ b/p2p/upnp/probe.go @@ -0,0 +1,109 @@ +package upnp + +import ( + "errors" + "fmt" + "net" + "time" +) + +type UPNPCapabilities struct { + PortMapping bool + Hairpin bool +} + +func makeUPNPListener(intPort int, extPort int) (NAT, net.Listener, net.IP, error) { + nat, err := Discover() + if err != nil { + return nil, nil, nil, errors.New(fmt.Sprintf("NAT upnp could not be discovered: %v", err)) + } + log.Debug("ourIP: %v", nat.(*upnpNAT).ourIP) + + ext, err := nat.GetExternalAddress() + if err != nil { + return nat, nil, nil, errors.New(fmt.Sprintf("External address error: %v", err)) + } + log.Debug("External address: %v", ext) + + port, err := nat.AddPortMapping("tcp", extPort, intPort, "Tendermint UPnP Probe", 0) + if err != nil { + return nat, nil, ext, errors.New(fmt.Sprintf("Port mapping error: %v", err)) + } + log.Debug("Port mapping mapped: %v", port) + + // also run the listener, open for all remote addresses. + listener, err := net.Listen("tcp", fmt.Sprintf(":%v", intPort)) + if err != nil { + return nat, nil, ext, errors.New(fmt.Sprintf("Error establishing listener: %v", err)) + } + return nat, listener, ext, nil +} + +func testHairpin(listener net.Listener, extAddr string) (supportsHairpin bool) { + // Listener + go func() { + inConn, err := listener.Accept() + if err != nil { + log.Info("Listener.Accept() error: %v", err) + return + } + log.Debug("Accepted incoming connection: %v -> %v", inConn.LocalAddr(), inConn.RemoteAddr()) + buf := make([]byte, 1024) + n, err := inConn.Read(buf) + if err != nil { + log.Info("Incoming connection read error: %v", err) + return + } + log.Debug("Incoming connection read %v bytes: %X", n, buf) + if string(buf) == "test data" { + supportsHairpin = true + return + } + }() + + // Establish outgoing + outConn, err := net.Dial("tcp", extAddr) + if err != nil { + log.Info("Outgoing connection dial error: %v", err) + return + } + + n, err := outConn.Write([]byte("test data")) + if err != nil { + log.Info("Outgoing connection write error: %v", err) + return + } + log.Debug("Outgoing connection wrote %v bytes", n) + + // Wait for data receipt + time.Sleep(1 * time.Second) + return +} + +func Probe() (caps UPNPCapabilities, err error) { + log.Debug("Probing for UPnP!") + + intPort, extPort := 8001, 8001 + + nat, listener, ext, err := makeUPNPListener(intPort, extPort) + if err != nil { + return + } + caps.PortMapping = true + + // Deferred cleanup + defer func() { + err = nat.DeletePortMapping("tcp", intPort, extPort) + if err != nil { + log.Warning("Port mapping delete error: %v", err) + } + listener.Close() + }() + + supportsHairpin := testHairpin(listener, fmt.Sprintf("%v:%v", ext, extPort)) + if supportsHairpin { + caps.Hairpin = true + } + + return +} diff --git a/p2p/upnp/upnp.go b/p2p/upnp/upnp.go index 2f3e7a9ab..7aff240ba 100644 --- a/p2p/upnp/upnp.go +++ b/p2p/upnp/upnp.go @@ -349,6 +349,9 @@ func (n *upnpNAT) AddPortMapping(protocol string, externalPort, internalPort int // TODO: check response to see if the port was forwarded // log.Println(message, response) + // JAE: + // body, err := ioutil.ReadAll(response.Body) + // fmt.Println(string(body), err) mappedExternalPort = externalPort _ = response return diff --git a/p2p/upnp/upnp_test.go b/p2p/upnp/upnp_test.go deleted file mode 100644 index f21f84fa4..000000000 --- a/p2p/upnp/upnp_test.go +++ /dev/null @@ -1,51 +0,0 @@ -package upnp - -import ( - "net" - "testing" - "time" -) - -/* -This is a manual test. -TODO: set up or find a service to probe open ports. -*/ -func _TestUPNP(t *testing.T) { - t.Log("hello!") - - nat, err := Discover() - if err != nil { - t.Fatalf("NAT upnp could not be discovered: %v", err) - } - - t.Log("ourIP: ", nat.(*upnpNAT).ourIP) - - ext, err := nat.GetExternalAddress() - if err != nil { - t.Fatalf("External address error: %v", err) - } - t.Logf("External address: %v", ext) - - port, err := nat.AddPortMapping("tcp", 8001, 8001, "testing", 0) - if err != nil { - t.Fatalf("Port mapping error: %v", err) - } - t.Logf("Port mapping mapped: %v", port) - - // also run the listener, open for all remote addresses. - listener, err := net.Listen("tcp", ":8001") - if err != nil { - panic(err) - } - - // now sleep for 10 seconds - time.Sleep(10 * time.Second) - - err = nat.DeletePortMapping("tcp", 8001, 8001) - if err != nil { - t.Fatalf("Port mapping delete error: %v", err) - } - t.Logf("Port mapping deleted") - - listener.Close() -} diff --git a/rpc/log.go b/rpc/log.go index 5a89e217a..3ea2b2344 100644 --- a/rpc/log.go +++ b/rpc/log.go @@ -6,10 +6,6 @@ import ( var log = logging.MustGetLogger("rpc") -func init() { - logging.SetFormatter(logging.MustStringFormatter("[%{level:.1s}] %{message}")) -} - func SetRPCLogger(l *logging.Logger) { log = l } diff --git a/state/log.go b/state/log.go index 63fbee78e..b07698c7b 100644 --- a/state/log.go +++ b/state/log.go @@ -6,10 +6,6 @@ import ( var log = logging.MustGetLogger("state") -func init() { - logging.SetFormatter(logging.MustStringFormatter("[%{level:.1s}] %{message}")) -} - func SetStateLogger(l *logging.Logger) { log = l }