From c0cc9a787e01468d05b91e6ce693dc5cddee1b80 Mon Sep 17 00:00:00 2001 From: lordwelch Date: Fri, 7 Aug 2020 14:36:27 -0700 Subject: [PATCH] Add trace logging and remove kong --- cmd/sshrimp-agent/main.go | 71 +++++++++++++++++++++------ cmd/sshrimp-agent/unix.go | 1 + internal/signer/sshrimp.go | 16 +++--- internal/sshrimpagent/sshrimpagent.go | 21 +++++++- 4 files changed, 84 insertions(+), 25 deletions(-) diff --git a/cmd/sshrimp-agent/main.go b/cmd/sshrimp-agent/main.go index ce534fb..4edd2a7 100644 --- a/cmd/sshrimp-agent/main.go +++ b/cmd/sshrimp-agent/main.go @@ -5,6 +5,7 @@ import ( "crypto/rand" "crypto/rsa" "errors" + "flag" "fmt" "io" "net" @@ -13,50 +14,80 @@ import ( "strings" "syscall" - "github.com/alecthomas/kong" - + "github.com/sirupsen/logrus" "github.com/stoggi/sshrimp/internal/config" + "github.com/stoggi/sshrimp/internal/signer" "github.com/stoggi/sshrimp/internal/sshrimpagent" "golang.org/x/crypto/ssh" "golang.org/x/crypto/ssh/agent" ) var sigs = []os.Signal{os.Kill, os.Interrupt} +var logger = logrus.New() +var log *logrus.Entry var cli struct { Config string `kong:"arg,type='string',help='sshrimp config file (default: ${config_file} or ${env_var_name} environment variable)',default='${config_file}',env='SSHRIMP_CONFIG'"` } func main() { - ctx := kong.Parse(&cli, - kong.Name("sshrimp-agent"), - kong.Description("An SSH Agent that renews SSH certificates automatically from a SSHrimp Certificate Authority."), - kong.Vars{ - "config_file": config.DefaultPath, - "env_var_name": config.EnvVarName, - }, - ) + flag.StringVar(&cli.Config, "config", config.DefaultPath, "sshrimp config file") + v := flag.Bool("v", false, "enable verbose logging") + + logger.SetFormatter(&logrus.TextFormatter{ + FullTimestamp: true, + }) + log = logger.WithFields(logrus.Fields{ + "pid": os.Getpid(), + }) + sshrimpagent.Log = log + signer.Log = log + + flag.Parse() + + if *v { + logger.SetLevel(logrus.TraceLevel) + } c := config.NewSSHrimpWithDefaults() - ctx.FatalIfErrorf(c.Read(cli.Config)) - ctx.FatalIfErrorf(launchAgent(c, ctx)) + err := c.Read(cli.Config) + if err != nil { + panic(err) + } + err = launchAgent(c) + if err != nil { + panic(err) + } } -func launchAgent(c *config.SSHrimp, ctx *kong.Context) error { +func launchAgent(c *config.SSHrimp) error { var ( err error listener net.Listener privateKey crypto.Signer signer ssh.Signer + logMessage string ) + log.Traceln("Creating socket") if _, err = os.Stat(c.Agent.Socket); err == nil { + log.Tracef("File already exists at %s", c.Agent.Socket) conn, sockErr := net.Dial("unix", c.Agent.Socket) + if conn == nil { + logMessage = "conn is nil" + } if sockErr == nil { // socket is accepting connections + logMessage += "err reports successful connection" conn.Close() + log.Errorf("Socket connected successfully %s", logMessage) return fmt.Errorf("socket %s already exists", c.Agent.Socket) } - os.Remove(c.Agent.Socket) // socket is not accepting connections, assuming safe to remove + log.Tracef("Socket is not connected %s", logMessage) + if os.Remove(c.Agent.Socket) == nil { // socket is not accepting connections, assuming safe to remove + log.Traceln("Deleting socket: success") + } else { + log.Errorf("Deleting socket: fail") + } } // This affects all files created for the process. Since this is a sensitive @@ -68,41 +99,49 @@ func launchAgent(c *config.SSHrimp, ctx *kong.Context) error { } defer listener.Close() - ctx.Printf("listening on %s", c.Agent.Socket) + fmt.Printf("listening on %s\n", c.Agent.Socket) // Generate a new SSH private/public key pair + log.Tracef("Generating RSA %d ssh keys", 2048) privateKey, err = rsa.GenerateKey(rand.Reader, 2048) if err != nil { return err } + log.Traceln("Creating new signer from key") signer, err = ssh.NewSignerFromKey(privateKey) if err != nil { return err } // Create the sshrimp agent with our configuration and the private key signer + log.Traceln("Creating new sshrimp agent from signer and config") sshrimpAgent := sshrimpagent.NewSSHrimpAgent(c, signer) // Listen for signals so that we can close the listener and exit nicely + log.Debugf("Exiting on signals: %v", sigs) osSignals := make(chan os.Signal) signal.Notify(osSignals, sigs...) go func() { - _ = <-osSignals + <-osSignals listener.Close() }() + log.Traceln("Starting main loop") // Accept connections and serve the agent for { var conn net.Conn conn, err = listener.Accept() if err != nil { + log.Errorf("Error accepting connection: %v", err) if strings.Contains(err.Error(), "use of closed network connection") { // Occurs if the user interrupts the agent with a ctrl-c signal return nil } return err } + log.Traceln("Serving agent") if err = agent.ServeAgent(sshrimpAgent, conn); err != nil && !errors.Is(err, io.EOF) { + log.Errorf("Error serving agent: %v", err) return err } } diff --git a/cmd/sshrimp-agent/unix.go b/cmd/sshrimp-agent/unix.go index 5a47e69..b349a2d 100644 --- a/cmd/sshrimp-agent/unix.go +++ b/cmd/sshrimp-agent/unix.go @@ -1,4 +1,5 @@ // +build darwin linux + package main import ( diff --git a/internal/signer/sshrimp.go b/internal/signer/sshrimp.go index 256851e..8f9ba1f 100644 --- a/internal/signer/sshrimp.go +++ b/internal/signer/sshrimp.go @@ -18,12 +18,15 @@ import ( "github.com/aws/aws-sdk-go/aws/session" "github.com/aws/aws-sdk-go/service/lambda" "github.com/pkg/errors" + "github.com/sirupsen/logrus" "github.com/stoggi/sshrimp/internal/config" "github.com/stoggi/sshrimp/internal/identity" "golang.org/x/crypto/ssh" ) +var Log *logrus.Entry + // SSHrimpResult encodes the payload format returned from the sshrimp-ca lambda type SSHrimpResult struct { Certificate string `json:"certificate"` @@ -63,7 +66,6 @@ func SignCertificateAllRegions(publicKey ssh.PublicKey, token string, forceComma // SignCertificateGCP given a public key, identity token and forceCommand, invoke the sshrimp-ca GCP function func SignCertificateGCP(publicKey ssh.PublicKey, token string, forceCommand string, region string, c *config.SSHrimp) (*ssh.Certificate, error) { - // Setup the JSON payload for the SSHrimp CA payload, err := json.Marshal(SSHrimpEvent{ PublicKey: string(ssh.MarshalAuthorizedKey(publicKey)), @@ -78,10 +80,6 @@ func SignCertificateGCP(publicKey ssh.PublicKey, token string, forceCommand stri if err != nil { return nil, errors.Wrap(err, "http post failed: "+err.Error()) } - if result.StatusCode != 200 { - return nil, fmt.Errorf("sshrimp returned status code %d", result.StatusCode) - } - resbody, err := ioutil.ReadAll(result.Body) if err != nil { return nil, errors.Wrap(err, "failed to retrieve the response from sshrimp-ca") @@ -91,7 +89,11 @@ func SignCertificateGCP(publicKey ssh.PublicKey, token string, forceCommand stri sshrimpResult := SSHrimpResult{} err = json.Unmarshal(resbody, &sshrimpResult) if err != nil { - return nil, errors.Wrap(err, "failed to parse json response from sshrimp-ca") + return nil, errors.Wrap(err, "failed to parse json response from sshrimp-ca.: "+string(resbody)) + } + Log.Traceln("SSHrimpResult:", sshrimpResult) + if result.StatusCode != 200 { + return nil, fmt.Errorf("sshrimp returned status code %d. Message: %s", result.StatusCode, string(resbody)) } // These error types and messages can also come from the aws-sdk-go lambda handler @@ -165,7 +167,7 @@ func ValidateRequest(event SSHrimpEvent, c *config.SSHrimp, requestID string, fu } // Validate the user supplied identity token with the loaded configuration - i, err := identity.NewIdentity(c) + i, _ := identity.NewIdentity(c) username, err := i.Validate(event.Token) if err != nil { return ssh.Certificate{}, err diff --git a/internal/sshrimpagent/sshrimpagent.go b/internal/sshrimpagent/sshrimpagent.go index 17c0ba5..9a8e19d 100644 --- a/internal/sshrimpagent/sshrimpagent.go +++ b/internal/sshrimpagent/sshrimpagent.go @@ -5,6 +5,7 @@ import ( "errors" "time" + "github.com/sirupsen/logrus" "github.com/stoggi/aws-oidc/provider" "github.com/stoggi/sshrimp/internal/config" "github.com/stoggi/sshrimp/internal/signer" @@ -12,6 +13,8 @@ import ( "golang.org/x/crypto/ssh/agent" ) +var Log *logrus.Entry + type sshrimpAgent struct { providerConfig provider.ProviderConfig signer ssh.Signer @@ -43,6 +46,7 @@ func NewSSHrimpAgent(c *config.SSHrimp, signer ssh.Signer) agent.Agent { // RemoveAll clears the current certificate and identity token (including refresh token) func (r *sshrimpAgent) RemoveAll() error { + Log.Debugln("Removing identity token and certificate") r.certificate = &ssh.Certificate{} r.token = &provider.OAuth2Token{} return nil @@ -65,18 +69,24 @@ func (r *sshrimpAgent) Unlock(passphrase []byte) error { // List returns the identities, but also signs the certificate using sshrimp-ca if expired. func (r *sshrimpAgent) List() ([]*agent.Key, error) { + Log.Traceln("Listing current identities") unixNow := time.Now().Unix() before := int64(r.certificate.ValidBefore) if r.certificate.ValidBefore != uint64(ssh.CertTimeInfinity) && (unixNow >= before || before < 0) { // Certificate has expired + Log.Traceln("Certificate has expired") + Log.Traceln("authenticating token") err := r.providerConfig.Authenticate(r.token) if err != nil { + Log.Errorf("authenticating the token failed: %v", err) return nil, err } + Log.Traceln("signing certificate") cert, err := signer.SignCertificateAllRegions(r.signer.PublicKey(), r.token.IDToken, "", r.config) if err != nil { + Log.Errorf("signing certificate failed: %v", err) return nil, err } r.certificate = cert @@ -109,21 +119,28 @@ func (r *sshrimpAgent) Signers() ([]ssh.Signer, error) { } func (r *sshrimpAgent) SignWithFlags(key ssh.PublicKey, data []byte, flags agent.SignatureFlags) (*ssh.Signature, error) { + Log.Traceln("requested sign with flags") sign, ok := r.signer.(ssh.AlgorithmSigner) + Log.Tracef("signer is AlgorithmSigner: %v", ok) if ok { if flags&agent.SignatureFlagRsaSha512 == agent.SignatureFlagRsaSha512 { + Log.Traceln("sha 512 requested") s, err := sign.SignWithAlgorithm(rand.Reader, data, ssh.SigAlgoRSASHA2512) if err == nil { - return s, err + Log.Debugln("sha 512 available:", err) + return s, nil } } if flags&agent.SignatureFlagRsaSha256 == agent.SignatureFlagRsaSha256 { + Log.Traceln("sha 256 requested") s, err := sign.SignWithAlgorithm(rand.Reader, data, ssh.SigAlgoRSASHA2256) if err == nil { - return s, err + Log.Debugln("sha 256 available:", err) + return s, nil } } } + Log.Traceln("signing data") return r.Sign(key, data) } func (r *sshrimpAgent) Extension(extensionType string, contents []byte) ([]byte, error) {