all: update use of ln

cmd/route-cli/main.go

@@ -31,6 +31,7 @@ var allScopes = []string{
 	"token:get", "token:getall", "token:put", "token:delete", "token:deactivate",
 	"route:get", "route:getall", "route:put", "route:delete",
 	"connect",
+	"admin",
 }
 
 var whoami string
@@ -123,10 +124,21 @@ func handle(w http.ResponseWriter, r *http.Request) {
 
 func main() {
 	cmdline := kingpin.MustParse(app.Parse(os.Args[1:]))
+	ctx, cancel := context.WithCancel(context.Background())
+	defer cancel()
 
+retry_netrc:
 	n, err := netrc.Parse(*netrcPath)
 	if err != nil {
-		ln.Fatal(ln.F{"err": err, "action": "netrc.Parse"})
+		_, err := os.Stat(*netrcPath)
+		if err == os.ErrNotExist {
+			fout, err := os.Create(*netrcPath)
+			if err != nil {
+				ln.FatalErr(ctx, err, ln.Action("creating netrc"), ln.F{"path": *netrcPath})
+			}
+			fout.Close()
+			goto retry_netrc
+		}
 	}
 	_ = n
 
@@ -134,30 +146,30 @@ func main() {
 	case "test-server":
 		http.HandleFunc("/", handle)
 
-		ln.Fatal(ln.F{"err": http.ListenAndServe(*testServerAddr, nil), "action": "test_server"})
+		ln.FatalErr(ctx, http.ListenAndServe(*testServerAddr, nil), ln.Action("test server listenAndServe"))
 
 	case "generate-key":
 		key, err := routecrypto.GenerateKey()
 		if err != nil {
-			ln.Fatal(ln.F{"err": err, "action": "routecrypto.GenerateKey"})
+			ln.FatalErr(ctx, err, ln.Action("generating encryption key"))
 		}
 
 		fmt.Println("Your key is:", routecrypto.ShowKey(key))
 	case "token generate-root":
 		key, err := routecrypto.ParseKey(*tokenGenerateKey)
 		if err != nil {
-			ln.Fatal(ln.F{"err": err, "action": "routecrypto.ParseKey"})
+			ln.FatalErr(ctx, err, ln.Action("parsing encryption key"))
 		}
 		db, err := database.NewBoltStorage(*tokenGenerateDatabasePath, key)
 		if err != nil {
-			ln.Fatal(ln.F{"err": err, "action": "database.NewBoltStorage"})
+			ln.FatalErr(ctx, err, ln.Action("opening routed database"))
 		}
 
 		tBody := uuid.New()
 
 		_, err = db.PutToken(context.Background(), tBody, *tokenGenerateUsername, *tokenGenerateScopes)
 		if err != nil {
-			ln.Fatal(ln.F{"err": err, "action": "db.PutToken"})
+			ln.FatalErr(ctx, err, ln.Action("add newly created token to database"))
 		}
 		defer db.Close()
 
@@ -166,7 +178,7 @@ func main() {
 		n.AddMachine(*grpcServer, *tokenGenerateUsername, tBody)
 		err = n.Save()
 		if err != nil {
-			ln.Fatal(ln.F{"err": err, "action": "n.Save"})
+			ln.FatalErr(ctx, err, ln.Action("add machine to netrc"))
 		}
 
 		return
@@ -182,7 +194,7 @@ func main() {
 		grpc.WithTransportCredentials(connCreds),
 		grpc.WithPerRPCCredentials(creds))
 	if err != nil {
-		ln.Fatal(ln.F{"err": err, "action": "grpc.Dial"})
+		ln.FatalErr(ctx, err, ln.Action("dialing grpc server"), ln.F{"hostname": *grpcServer})
 	}
 
 	rc := proto.NewRoutesClient(conn)
@@ -195,19 +207,21 @@ func main() {
 
 	switch cmdline {
 	case "route create":
-		idr, err := rc.Put(context.Background(), &proto.Route{Host: *routesCreateDomain})
+		idr, err := rc.Put(ctx, &proto.Route{Host: *routesCreateDomain})
 		if err != nil {
-			ln.Fatal(ln.F{"err": err, "action": "rc.Put"})
+			ln.FatalErr(ctx, err, ln.Action("create new route"))
 		}
 
-		fmt.Println(idr.Id)
+		fmt.Println("created route with id " + idr.Id)
+
+		return
 
 	case "route inspect":
 		r, err := rc.Get(context.Background(), &proto.GetRouteRequest{
 			Host: *routesCreateDomain,
 		})
 		if err != nil {
-			ln.Fatal(ln.F{"err": err, "action": "rc.Get"})
+			ln.FatalErr(ctx, err, ln.Action("get single route"), ln.F{"domain": *routesCreateDomain})
 		}
 
 		json.NewEncoder(os.Stdout).Encode(r)
@@ -218,7 +232,7 @@ func main() {
 	case "route list":
 		rts, err := rc.GetAll(context.Background(), &proto.Nil{})
 		if err != nil {
-			ln.Fatal(ln.F{"err": err, "action": "rc.GetAll"})
+			ln.FatalErr(ctx, err, ln.Action("get all routes"))
 		}
 
 		table := tablewriter.NewWriter(os.Stdout)
@@ -235,7 +249,7 @@ func main() {
 	case "route rm":
 		_, err := rc.Delete(context.Background(), &proto.Route{Id: *routesRmID})
 		if err != nil {
-			ln.Fatal(ln.F{"err": err, "action": "rc.Delete"})
+			ln.FatalErr(ctx, err, ln.Action("remove single route"), ln.F{"id": *routesRmID})
 		}
 
 	case "backend list":
@@ -244,7 +258,7 @@ func main() {
 			User:   *backendListUser,
 		})
 		if err != nil {
-			ln.Fatal(ln.F{"err": err, "action": "list backends"})
+			ln.FatalErr(ctx, err, ln.Action("list backends"))
 		}
 
 		table := tablewriter.NewWriter(os.Stdout)
@@ -259,7 +273,7 @@ func main() {
 	case "backend kill":
 		_, err := bc.Kill(context.Background(), &proto.BackendID{Id: *backendKillID})
 		if err != nil {
-			ln.Fatal(ln.F{"err": err, "action": "attempt to kill backend", "backend_id": *backendKillID})
+			ln.FatalErr(ctx, err, ln.Action("attempt to kill backend"), ln.F{"backend_id": *backendKillID})
 		}
 
 		fmt.Println("killed backend " + *backendKillID)

cmd/route-httpagent/main.go

@@ -1,9 +1,9 @@
 package main
 
 import (
+	"context"
 	"crypto/tls"
 	"flag"
-	"os"
 
 	"git.xeserv.us/xena/route/lib/tun2"
 	"github.com/Xe/ln"
@@ -34,9 +34,6 @@ func main() {
 	client, _ := tun2.NewClient(cfg)
 	err := client.Connect()
 	if err != nil {
-		ln.Error(err, ln.F{
+		ln.FatalErr(context.Background(), err, ln.Action("http agent is now running"))
-			"action": "client_running",
-		})
-		os.Exit(1)
 	}
 }

cmd/routed/main.go

@@ -1,9 +1,9 @@
 package main
 
 import (
+	"context"
 	"crypto/tls"
 	"flag"
-	"log"
 	"math/rand"
 	"net"
 	"net/http"
@@ -25,26 +25,29 @@ func main() {
 	flag.Parse()
 	flagenv.Parse()
 	rand.Seed(time.Now().Unix())
+	ctx, cancel := context.WithCancel(context.Background())
+	defer cancel()
 
 	certKey, _ := routecrypto.ParseKey(*sslCertKey)
 
 	scfg := server.Config{}
 	err := env.Parse(&scfg)
 	if err != nil {
-		ln.Fatal(ln.F{"err": err, "action": "env.Parse()"})
+		ln.FatalErr(ctx, err, ln.Action("parsing environment for config"))
 	}
 	scfg.CertKey = certKey
 
 	s, err := server.New(scfg)
 	if err != nil {
-		log.Fatal(err)
+		ln.FatalErr(ctx, err, ln.Action("create server instance"))
 	}
 
 	go setupTLS(s, scfg)
 
+	// listen on HTTP listener
 	l, err := net.Listen("tcp", scfg.WebAddr)
 	if err != nil {
-		log.Fatal(err)
+		ln.FatalErr(ctx, err, ln.Action("listening on HTTP port"), ln.F{"addr": scfg.WebAddr})
 	}
 	defer l.Close()
 
@@ -65,5 +68,7 @@ func setupTLS(s *server.Server, scfg server.Config) {
 		},
 	}
 
+	for {
 		hs.ListenAndServeTLS("", "")
+	}
 }

internal/database/boltdb.go

@@ -56,7 +56,7 @@ func (b *BoltDBStorage) GetRoute(ctx context.Context, host string) (Route, error
 	r := Route{}
 	err := b.db.One("Hostname", host, &r)
 	if err != nil {
-		ln.Error(err, ln.F{"err": err, "action": "route_get_route"})
+		ln.Error(ctx, err, ln.F{"err": err, "action": "route_get_route"})
 
 		switch err {
 		case storm.ErrNotFound:

internal/server/common.go

@@ -49,7 +49,7 @@ func (s *Server) getAuth(ctx context.Context, scope string) (database.Token, err
 }
 
 func handleError(ctx context.Context, clitok database.Token, err error, f ln.F) error {
-	ln.Error(err, f, clitok.F())
+	ln.Error(ctx, err, f, clitok)
 
 	return err
 }

internal/server/route.go

@@ -26,7 +26,7 @@ func (r *Route) Get(ctx context.Context, req *proto.GetRouteRequest) (*proto.Rou
 
 	val, err := r.db.GetRoute(ctx, req.Host)
 	if err != nil {
-		ln.Error(err, ln.F{"action": "Route.Get"})
+		ln.Error(ctx, err, ln.F{"action": "Route.Get"})
 
 		return nil, err
 	}
@@ -47,7 +47,7 @@ func (r *Route) GetAll(ctx context.Context, req *proto.Nil) (*proto.GetAllRoutes
 
 	routes, err := r.db.GetAllRoutes(ctx, clitok.Owner)
 	if err != nil {
-		ln.Error(err, ln.F{"action": "Route.GetAll"})
+		ln.Error(ctx, err, ln.F{"action": "Route.GetAll"})
 
 		return nil, err
 	}
@@ -76,12 +76,12 @@ func (r *Route) Put(ctx context.Context, rt *proto.Route) (*proto.IDResponse, er
 
 	drt, err := r.db.PutRoute(ctx, rt.Host, clitok.Owner)
 	if err != nil {
-		ln.Error(err, ln.F{"action": "Route.Put"})
+		ln.Error(ctx, err, ln.F{"action": "Route.Put"})
 
 		return nil, err
 	}
 
-	ln.Log(drt.F(), ln.F{"action": "Route.Put_success"})
+	ln.Log(ctx, drt, ln.F{"action": "Route.Put_success"})
 
 	return &proto.IDResponse{
 		Id: drt.ID,
@@ -96,7 +96,7 @@ func (r *Route) Delete(ctx context.Context, rt *proto.Route) (*proto.IDResponse,
 
 	drt, err := r.db.GetRoute(ctx, rt.Host)
 	if err != nil {
-		ln.Error(err, ln.F{"action": "Route.Delete_getRoute_verify"})
+		ln.Error(ctx, err, ln.F{"action": "Route.Delete_getRoute_verify"})
 
 		return nil, err
 	}
@@ -112,7 +112,7 @@ func (r *Route) Delete(ctx context.Context, rt *proto.Route) (*proto.IDResponse,
 		handleError(ctx, clitok, ErrNotAuthorized, f)
 	}
 
-	ln.Log(f, drt.F())
+	ln.Log(ctx, f, drt)
 
 	return &proto.IDResponse{Id: rt.Id}, nil
 }

lib/tun2/connection.go

@@ -50,14 +50,18 @@ func (c *Connection) F() ln.F {
 // Ping ends a "ping" to the client. If the client doesn't respond or the connection
 // dies, then the connection needs to be cleaned up.
 func (c *Connection) Ping() error {
+	ctx, cancel := context.WithTimeout(context.Background(), 1*time.Second)
+	defer cancel()
+
 	req, err := http.NewRequest("GET", "http://backend/health", nil)
 	if err != nil {
 		panic(err)
 	}
+	req = req.WithContext(ctx)
 
 	_, err = c.RoundTrip(req)
 	if err != nil {
-		ln.Error(err, c.F(), ln.F{"action": "ping_roundtrip"})
+		ln.Error(ctx, err, c, ln.Action("pinging the backend"))
 		return err
 	}
 
@@ -67,20 +71,20 @@ func (c *Connection) Ping() error {
 }
 
 // OpenStream creates a new stream (connection) to the backend server.
-func (c *Connection) OpenStream() (net.Conn, error) {
+func (c *Connection) OpenStream(ctx context.Context) (net.Conn, error) {
 	if !c.usable {
 		return nil, ErrNoSuchBackend
 	}
 
 	err := c.conn.SetDeadline(time.Now().Add(time.Second))
 	if err != nil {
-		ln.Error(err, c.F())
+		ln.Error(ctx, err, c)
 		return nil, err
 	}
 
 	stream, err := c.session.OpenStream()
 	if err != nil {
-		ln.Error(err, c.F())
+		ln.Error(ctx, err, c)
 		return nil, err
 	}
 
@@ -117,7 +121,7 @@ var (
 // RoundTrip forwards a HTTP request to the remote backend and then returns the
 // response, if any.
 func (c *Connection) RoundTrip(req *http.Request) (*http.Response, error) {
-	stream, err := c.OpenStream()
+	stream, err := c.OpenStream(req.Context())
 	if err != nil {
 		return nil, errors.Wrap(err, ErrCantOpenSessionStream.Error())
 	}

lib/tun2/server.go

@@ -146,7 +146,10 @@ func (s *Server) GetAllBackends() []Backend {
 // ListenAndServe starts the backend TCP/KCP listeners and relays backend
 // traffic to and from them.
 func (s *Server) ListenAndServe() error {
-	ln.Log(ln.F{
+	ctx, cancel := context.WithCancel(context.Background())
+	defer cancel()
+
+	ln.Log(ctx, ln.F{
 		"action": "listen_and_serve_called",
 	})
 
@@ -157,7 +160,7 @@ func (s *Server) ListenAndServe() error {
 				panic(err)
 			}
 
-			ln.Log(ln.F{
+			ln.Log(ctx, ln.F{
 				"action": "tcp+tls_listening",
 				"addr":   l.Addr(),
 			})
@@ -165,11 +168,11 @@ func (s *Server) ListenAndServe() error {
 			for {
 				conn, err := l.Accept()
 				if err != nil {
-					ln.Error(err, ln.F{"kind": "tcp", "addr": l.Addr().String()})
+					ln.Error(ctx, err, ln.F{"kind": "tcp", "addr": l.Addr().String()})
 					continue
 				}
 
-				ln.Log(ln.F{
+				ln.Log(ctx, ln.F{
 					"action": "new_client",
 					"kcp":    false,
 					"addr":   conn.RemoteAddr(),
@@ -187,7 +190,7 @@ func (s *Server) ListenAndServe() error {
 				panic(err)
 			}
 
-			ln.Log(ln.F{
+			ln.Log(ctx, ln.F{
 				"action": "kcp+tls_listening",
 				"addr":   l.Addr(),
 			})
@@ -195,10 +198,10 @@ func (s *Server) ListenAndServe() error {
 			for {
 				conn, err := l.Accept()
 				if err != nil {
-					ln.Error(err, ln.F{"kind": "kcp", "addr": l.Addr().String()})
+					ln.Error(ctx, err, ln.F{"kind": "kcp", "addr": l.Addr().String()})
 				}
 
-				ln.Log(ln.F{
+				ln.Log(ctx, ln.F{
 					"action": "new_client",
 					"kcp":    true,
 					"addr":   conn.RemoteAddr(),
@@ -223,7 +226,7 @@ func (s *Server) ListenAndServe() error {
 				failureChance := c.detector.Phi(now)
 
 				if failureChance > 0.8 {
-					ln.Log(c.F(), ln.F{
+					ln.Log(ctx, c.F(), ln.F{
 						"action": "phi_failure_detection",
 						"value":  failureChance,
 					})
@@ -247,7 +250,7 @@ func (s *Server) HandleConn(c net.Conn, isKCP bool) {
 
 	session, err := smux.Server(c, s.cfg.SmuxConf)
 	if err != nil {
-		ln.Error(err, ln.F{
+		ln.Error(ctx, err, ln.F{
 			"action": "session_failure",
 			"local":  c.LocalAddr().String(),
 			"remote": c.RemoteAddr().String(),
@@ -261,7 +264,7 @@ func (s *Server) HandleConn(c net.Conn, isKCP bool) {
 
 	controlStream, err := session.OpenStream()
 	if err != nil {
-		ln.Error(err, ln.F{
+		ln.Error(ctx, err, ln.F{
 			"action": "control_stream_failure",
 			"local":  c.LocalAddr().String(),
 			"remote": c.RemoteAddr().String(),
@@ -275,7 +278,7 @@ func (s *Server) HandleConn(c net.Conn, isKCP bool) {
 	auth := &Auth{}
 	err = csd.Decode(auth)
 	if err != nil {
-		ln.Error(err, ln.F{
+		ln.Error(ctx, err, ln.F{
 			"action": "control_stream_auth_decoding_failure",
 			"local":  c.LocalAddr().String(),
 			"remote": c.RemoteAddr().String(),
@@ -286,7 +289,7 @@ func (s *Server) HandleConn(c net.Conn, isKCP bool) {
 
 	routeUser, err := s.cfg.Storage.HasRoute(auth.Domain)
 	if err != nil {
-		ln.Error(err, ln.F{
+		ln.Error(ctx, err, ln.F{
 			"action": "nosuch_domain",
 			"local":  c.LocalAddr().String(),
 			"remote": c.RemoteAddr().String(),
@@ -297,7 +300,7 @@ func (s *Server) HandleConn(c net.Conn, isKCP bool) {
 
 	tokenUser, scopes, err := s.cfg.Storage.HasToken(auth.Token)
 	if err != nil {
-		ln.Error(err, ln.F{
+		ln.Error(ctx, err, ln.F{
 			"action": "nosuch_token",
 			"local":  c.LocalAddr().String(),
 			"remote": c.RemoteAddr().String(),
@@ -315,7 +318,7 @@ func (s *Server) HandleConn(c net.Conn, isKCP bool) {
 	}
 
 	if !ok {
-		ln.Error(ErrAuthMismatch, ln.F{
+		ln.Error(ctx, ErrAuthMismatch, ln.F{
 			"action": "token_not_authorized",
 			"local":  c.LocalAddr().String(),
 			"remote": c.RemoteAddr().String(),
@@ -323,7 +326,7 @@ func (s *Server) HandleConn(c net.Conn, isKCP bool) {
 	}
 
 	if routeUser != tokenUser {
-		ln.Error(ErrAuthMismatch, ln.F{
+		ln.Error(ctx, ErrAuthMismatch, ln.F{
 			"action": "auth_mismatch",
 			"local":  c.LocalAddr().String(),
 			"remote": c.RemoteAddr().String(),
@@ -346,11 +349,11 @@ func (s *Server) HandleConn(c net.Conn, isKCP bool) {
 
 	defer func() {
 		if r := recover(); r != nil {
-			ln.Log(connection, ln.F{"action": "connection handler panic", "err": r})
+			ln.Log(ctx, connection, ln.F{"action": "connection handler panic", "err": r})
 		}
 	}()
 
-	ln.Log(ln.F{
+	ln.Log(ctx, ln.F{
 		"action": "backend_connected",
 	}, connection.F())
 
@@ -386,7 +389,7 @@ func (s *Server) HandleConn(c net.Conn, isKCP bool) {
 				connection.cancel()
 			}
 		case <-ctx.Done():
-			s.RemoveConn(connection)
+			s.RemoveConn(ctx, connection)
 			connection.Close()
 
 			return
@@ -395,7 +398,7 @@ func (s *Server) HandleConn(c net.Conn, isKCP bool) {
 }
 
 // RemoveConn removes a connection.
-func (s *Server) RemoveConn(connection *Connection) {
+func (s *Server) RemoveConn(ctx context.Context, connection *Connection) {
 	s.connlock.Lock()
 	delete(s.conns, connection.conn)
 	s.connlock.Unlock()
@@ -408,7 +411,7 @@ func (s *Server) RemoveConn(connection *Connection) {
 	if ok {
 		conns, ok = val.([]*Connection)
 		if !ok {
-			ln.Error(ErrCantRemoveWhatDoesntExist, connection.F(), ln.F{
+			ln.Error(ctx, ErrCantRemoveWhatDoesntExist, connection.F(), ln.F{
 				"action": "looking_up_for_disconnect_removal",
 			})
 			return
@@ -428,7 +431,7 @@ func (s *Server) RemoveConn(connection *Connection) {
 		s.domains.Remove(auth.Domain)
 	}
 
-	ln.Log(connection.F(), ln.F{
+	ln.Log(ctx, connection.F(), ln.F{
 		"action": "client_disconnecting",
 	})
 }
@@ -469,12 +472,13 @@ func gen502Page(req *http.Request) *http.Response {
 // RoundTrip sends a HTTP request to a backend and then returns its response.
 func (s *Server) RoundTrip(req *http.Request) (*http.Response, error) {
 	var conns []*Connection
+	ctx := req.Context()
 
 	val, ok := s.domains.Get(req.Host)
 	if ok {
 		conns, ok = val.([]*Connection)
 		if !ok {
-			ln.Error(ErrNoSuchBackend, ln.F{
+			ln.Error(ctx, ErrNoSuchBackend, ln.F{
 				"action": "no_backend_connected",
 				"remote": req.RemoteAddr,
 				"host":   req.Host,
@@ -493,7 +497,7 @@ func (s *Server) RoundTrip(req *http.Request) (*http.Response, error) {
 	}
 
 	if len(goodConns) == 0 {
-		ln.Error(ErrNoSuchBackend, ln.F{
+		ln.Error(ctx, ErrNoSuchBackend, ln.F{
 			"action": "no_backend_connected",
 			"remote": req.RemoteAddr,
 			"host":   req.Host,
@@ -507,7 +511,7 @@ func (s *Server) RoundTrip(req *http.Request) (*http.Response, error) {
 
 	resp, err := c.RoundTrip(req)
 	if err != nil {
-		ln.Error(err, c.F(), ln.F{
+		ln.Error(ctx, err, c, ln.F{
 			"action": "connection_roundtrip",
 		})
 
@@ -515,7 +519,7 @@ func (s *Server) RoundTrip(req *http.Request) (*http.Response, error) {
 		return nil, err
 	}
 
-	ln.Log(c.F(), ln.F{
+	ln.Log(ctx, c, ln.F{
 		"action":      "http_traffic",
 		"remote_addr": req.RemoteAddr,
 		"host":        req.Host,