From e5a3c50f83edcd85a790ec256bce5f0ed196a3d9 Mon Sep 17 00:00:00 2001
From: tgic <farmer1992@gmail.com>
Date: Tue, 9 Dec 2014 15:50:28 +0800
Subject: [PATCH] add logger to sshpiperd

---
 sshpiperd/sshpiperd.go | 61 ++++++++++++++++++++++++++++++------------
 1 file changed, 44 insertions(+), 17 deletions(-)

diff --git a/sshpiperd/sshpiperd.go b/sshpiperd/sshpiperd.go
index 857fa8c5..16a8b926 100644
--- a/sshpiperd/sshpiperd.go
+++ b/sshpiperd/sshpiperd.go
@@ -6,7 +6,9 @@ import (
 	"fmt"
 	"github.com/tg123/sshpiper/ssh"
 	"io/ioutil"
+	"log"
 	"net"
+	"os"
 	"strings"
 )
 
@@ -24,6 +26,8 @@ var (
 	WorkingDir   string
 	PiperKeyFile string
 	ShowHelp     bool
+
+	logger = log.New(os.Stdout, "", log.Ldate|log.Ltime)
 )
 
 func init() {
@@ -57,6 +61,10 @@ func (file userFile) read(user string) ([]byte, error) {
 	return ioutil.ReadFile(userSpecFile(user, string(file)))
 }
 
+func (file userFile) realPath(user string) string {
+	return userSpecFile(user, string(file))
+}
+
 // TODO log
 func main() {
 
@@ -65,12 +73,6 @@ func main() {
 		return
 	}
 
-	listener, err := net.Listen("tcp", fmt.Sprintf("%s:%d", ListenAddr, Port))
-	if err != nil {
-		panic("failed to listen for connection")
-	}
-	defer listener.Close()
-
 	piper := &ssh.SSHPiper{
 		FindUpstream: func(conn ssh.ConnMetadata) (net.Conn, *ssh.ClientConfig, error) {
 
@@ -82,7 +84,7 @@ func main() {
 
 			saddr := strings.TrimSpace(string(addr))
 
-			fmt.Printf("map %s addr to %s \n", conn.User(), saddr)
+			logger.Printf("mapping user [%s] to [%s]", conn.User(), saddr)
 
 			c, err := net.Dial("tcp", saddr)
 			if err != nil {
@@ -94,18 +96,27 @@ func main() {
 
 		MapPublicKey: func(conn ssh.ConnMetadata, key ssh.PublicKey) (ssh.Signer, error) {
 
+			user := conn.User()
+
+			var err error
+			defer func() { // print error when func exit
+				if err != nil {
+					logger.Printf("mapping private key error: %v, public key auth denied for [%v] from [%v]", err, user, conn.RemoteAddr())
+				}
+			}()
+
 			keydata := key.Marshal()
 
-			rest, err := UserAuthorizedKeysFile.read(conn.User())
+			var rest []byte
+			rest, err = UserAuthorizedKeysFile.read(user)
 			if err != nil {
 				return nil, err
 			}
 
-			for len(rest) > 0 {
-				authedPubkey, _, _, _rest, err := ssh.ParseAuthorizedKey(rest)
+			var authedPubkey ssh.PublicKey
 
-				// TODO fix this name
-				rest = _rest
+			for len(rest) > 0 {
+				authedPubkey, _, _, rest, err = ssh.ParseAuthorizedKey(rest)
 
 				if err != nil {
 					return nil, err
@@ -113,45 +124,61 @@ func main() {
 
 				if bytes.Equal(authedPubkey.Marshal(), keydata) {
 
-					privateBytes, err := UserKeyFile.read(conn.User())
+					var privateBytes []byte
+					privateBytes, err = UserKeyFile.read(user)
 					if err != nil {
 						return nil, err
 					}
 
-					private, err := ssh.ParsePrivateKey(privateBytes)
+					var private ssh.Signer
+					private, err = ssh.ParsePrivateKey(privateBytes)
 					if err != nil {
 						return nil, err
 					}
 
+					// in log may see this twice, one is for query the other is real sign again
+					logger.Printf("auth succ, using mapped private key [%v] for user [%v] from [%v]", UserKeyFile.realPath(user), user, conn.RemoteAddr())
 					return private, nil
 				}
 			}
 
+			logger.Printf("public key auth failed user [%v] from [%v]", conn.User(), conn.RemoteAddr())
+
 			return nil, nil
 		},
 	}
 
 	privateBytes, err := ioutil.ReadFile(PiperKeyFile)
 	if err != nil {
-		panic(err)
+		logger.Fatalln(err)
 	}
 
 	private, err := ssh.ParsePrivateKey(privateBytes)
 	if err != nil {
-		panic(err)
+		logger.Fatalln(err)
 	}
 
 	piper.DownstreamConfig.AddHostKey(private)
 
+	listener, err := net.Listen("tcp", fmt.Sprintf("%s:%d", ListenAddr, Port))
+	if err != nil {
+		logger.Fatalln("failed to listen for connection")
+	}
+	defer listener.Close()
+
+	logger.Printf("listening at %s:%d, server key file %s, working dir %s", ListenAddr, Port, PiperKeyFile, WorkingDir)
+
 	for {
 		c, err := listener.Accept()
 		if err != nil {
+			logger.Printf("failed to accept connection: %v", err)
 			continue
 		}
 
+		logger.Printf("connection accepted: %v", c.RemoteAddr())
 		go func() {
 			err := piper.Serve(c)
-			fmt.Println(err)
+			logger.Printf("connection %v closed reason: %v", c.RemoteAddr(), err)
 		}()
 	}
 }