diff --git a/cmd/route-cli/main.go b/cmd/route-cli/main.go index a069f5f..9d1b87f 100644 --- a/cmd/route-cli/main.go +++ b/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) diff --git a/cmd/route-httpagent/main.go b/cmd/route-httpagent/main.go index f862c19..57ac67b 100644 --- a/cmd/route-httpagent/main.go +++ b/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{ - "action": "client_running", - }) - os.Exit(1) + ln.FatalErr(context.Background(), err, ln.Action("http agent is now running")) } } diff --git a/cmd/routed/main.go b/cmd/routed/main.go index 56b465e..94c789d 100644 --- a/cmd/routed/main.go +++ b/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) { }, } - hs.ListenAndServeTLS("", "") + for { + hs.ListenAndServeTLS("", "") + } } diff --git a/internal/database/boltdb.go b/internal/database/boltdb.go index eec5bfe..c51fb62 100644 --- a/internal/database/boltdb.go +++ b/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: diff --git a/internal/server/common.go b/internal/server/common.go index e55c179..9ba6c26 100644 --- a/internal/server/common.go +++ b/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 } diff --git a/internal/server/route.go b/internal/server/route.go index 080a34c..08fb2e7 100644 --- a/internal/server/route.go +++ b/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 } diff --git a/lib/tun2/connection.go b/lib/tun2/connection.go index cf9fa5d..ae2d646 100644 --- a/lib/tun2/connection.go +++ b/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()) } diff --git a/lib/tun2/server.go b/lib/tun2/server.go index d191372..3f72373 100644 --- a/lib/tun2/server.go +++ b/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,