logging now uses syslog

This commit is contained in:
Russ Magee 2018-10-25 22:14:18 -07:00
parent 90deb5b1ff
commit 752dbf6080
3 changed files with 74 additions and 33 deletions

View file

@ -37,7 +37,9 @@ import (
"fmt" "fmt"
"hash" "hash"
"io" "io"
"io/ioutil"
"log" "log"
"log/syslog"
"math/big" "math/big"
"math/rand" "math/rand"
"net" "net"
@ -95,6 +97,26 @@ type (
} }
) )
var (
Log *syslog.Writer // reg. syslog output (no -d)
)
func _initLogging(d bool, c string, f syslog.Priority) {
if Log == nil {
Log, _ = syslog.New(f, fmt.Sprintf("%s:hkexnet", c))
}
if d {
log.SetFlags(0) // syslog will have date,time
log.SetOutput(Log)
} else {
log.SetOutput(ioutil.Discard)
}
}
func Init(d bool, c string, f syslog.Priority) {
_initLogging(d, c, f)
}
func (hc Conn) GetStatus() CSOType { func (hc Conn) GetStatus() CSOType {
return *hc.closeStat return *hc.closeStat
} }
@ -454,6 +476,10 @@ func HKExAcceptSetup(c *net.Conn, hc *Conn) (err error) {
// //
// "H_SHA256" // "H_SHA256"
func Dial(protocol string, ipport string, extensions ...string) (hc Conn, err error) { func Dial(protocol string, ipport string, extensions ...string) (hc Conn, err error) {
if Log == nil {
Init(false, "client", syslog.LOG_DAEMON|syslog.LOG_DEBUG)
}
// Open raw Conn c // Open raw Conn c
c, err := net.Dial(protocol, ipport) c, err := net.Dial(protocol, ipport)
if err != nil { if err != nil {
@ -508,7 +534,7 @@ func (hc *Conn) Close() (err error) {
log.Printf("** Writing closeStat %d at Close()\n", *hc.closeStat) log.Printf("** Writing closeStat %d at Close()\n", *hc.closeStat)
hc.WritePacket(s, CSOExitStatus) hc.WritePacket(s, CSOExitStatus)
err = (*hc.c).Close() err = (*hc.c).Close()
log.Println("[Conn Closing]") Log.Notice(fmt.Sprintln("[Conn Closing]"))
return return
} }
@ -570,11 +596,15 @@ type HKExListener struct {
// //
// See go doc net.Listen // See go doc net.Listen
func Listen(protocol string, ipport string) (hl HKExListener, e error) { func Listen(protocol string, ipport string) (hl HKExListener, e error) {
if Log == nil {
Init(false, "server", syslog.LOG_DAEMON|syslog.LOG_DEBUG)
}
l, err := net.Listen(protocol, ipport) l, err := net.Listen(protocol, ipport)
if err != nil { if err != nil {
return HKExListener{nil}, err return HKExListener{nil}, err
} }
log.Println("[Listening]") Log.Notice(fmt.Sprintf("[Listening on %s]\n", ipport))
hl.l = l hl.l = l
return return
} }
@ -584,7 +614,7 @@ func Listen(protocol string, ipport string) (hl HKExListener, e error) {
// //
// See go doc net.Listener.Close // See go doc net.Listener.Close
func (hl HKExListener) Close() error { func (hl HKExListener) Close() error {
log.Println("[Listener Closed]") Log.Notice(fmt.Sprintln("[Listener Closed]"))
return hl.l.Close() return hl.l.Close()
} }
@ -604,7 +634,7 @@ func (hl *HKExListener) Accept() (hc Conn, err error) {
if err != nil { if err != nil {
return Conn{}, err return Conn{}, err
} }
log.Println("[net.Listener Accepted]") Log.Notice(fmt.Sprintln("[net.Listener Accepted]"))
// Read KEx alg proposed by client // Read KEx alg proposed by client
var kexAlg KEXAlg var kexAlg KEXAlg
@ -683,7 +713,7 @@ func (hc Conn) Read(b []byte) (n int, err error) {
// (on server side) err.Error() == "<iface/addr info ...>: use of closed network connection" // (on server side) err.Error() == "<iface/addr info ...>: use of closed network connection"
if err != nil { if err != nil {
if err == io.EOF || strings.HasSuffix(err.Error(), "use of closed network connection") { if err == io.EOF || strings.HasSuffix(err.Error(), "use of closed network connection") {
log.Println("[Client hung up]") Log.Notice(fmt.Sprintln("[Client hung up]"))
} else { } else {
log.Println(err) log.Println(err)
} }
@ -693,12 +723,12 @@ func (hc Conn) Read(b []byte) (n int, err error) {
err = binary.Read(*hc.c, binary.BigEndian, &payloadLen) err = binary.Read(*hc.c, binary.BigEndian, &payloadLen)
if err != nil { if err != nil {
if err.Error() != "EOF" { if err.Error() != "EOF" {
log.Println("[2]unexpected Read() err:", err) Log.Err(fmt.Sprintln("[2]unexpected Read() err:", err))
} }
} }
if payloadLen > MAX_PAYLOAD_LEN { if payloadLen > MAX_PAYLOAD_LEN {
log.Printf("[Insane payloadLen:%v]\n", payloadLen) Log.Err(fmt.Sprintf("[Insane payloadLen:%v]\n", payloadLen))
hc.Close() hc.Close()
return 1, errors.New("Insane payloadLen") return 1, errors.New("Insane payloadLen")
} }
@ -710,9 +740,9 @@ func (hc Conn) Read(b []byte) (n int, err error) {
// (on server side) err.Error() == "<iface/addr info ...>: use of closed network connection" // (on server side) err.Error() == "<iface/addr info ...>: use of closed network connection"
if err != nil && err.Error() != "EOF" { if err != nil && err.Error() != "EOF" {
if !strings.HasSuffix(err.Error(), "use of closed network connection") { if !strings.HasSuffix(err.Error(), "use of closed network connection") {
log.Println("[3]unexpected Read() err:", err) Log.Err(fmt.Sprintln("[3]unexpected Read() err:", err))
} else { } else {
log.Println("[Client hung up]") Log.Notice(fmt.Sprintln("[Client hung up]"))
} }
} }
@ -757,7 +787,7 @@ func (hc Conn) Read(b []byte) (n int, err error) {
if len(payloadBytes) > 0 { if len(payloadBytes) > 0 {
hc.SetStatus(CSOType(binary.BigEndian.Uint32(payloadBytes))) hc.SetStatus(CSOType(binary.BigEndian.Uint32(payloadBytes)))
} else { } else {
log.Println("[truncated payload, cannot determine CSOExitStatus]") Log.Err(fmt.Sprintln("[truncated payload, cannot determine CSOExitStatus]"))
hc.SetStatus(CSETruncCSO) hc.SetStatus(CSETruncCSO)
} }
hc.Close() hc.Close()
@ -770,11 +800,11 @@ func (hc Conn) Read(b []byte) (n int, err error) {
log.Printf("<%04x) HMAC:(i)%s (c)%02x\r\n", decryptN, hex.EncodeToString([]byte(hmacIn[0:])), hTmp) log.Printf("<%04x) HMAC:(i)%s (c)%02x\r\n", decryptN, hex.EncodeToString([]byte(hmacIn[0:])), hTmp)
if *hc.closeStat == CSETruncCSO { if *hc.closeStat == CSETruncCSO {
log.Println("[cannot verify HMAC]") Log.Err(fmt.Sprintln("[cannot verify HMAC]"))
} else { } else {
// Log alert if hmac didn't match, corrupted channel // Log alert if hmac didn't match, corrupted channel
if !bytes.Equal(hTmp, []byte(hmacIn[0:])) /*|| hmacIn[0] > 0xf8*/ { if !bytes.Equal(hTmp, []byte(hmacIn[0:])) /*|| hmacIn[0] > 0xf8*/ {
fmt.Println("** ALERT - detected HMAC mismatch, possible channel tampering **") Log.Err(fmt.Sprintln("** ALERT - detected HMAC mismatch, possible channel tampering **"))
_, _ = (*hc.c).Write([]byte{CSOHmacInvalid}) _, _ = (*hc.c).Write([]byte{CSOHmacInvalid})
} }
} }

View file

@ -16,6 +16,7 @@ import (
"io" "io"
"io/ioutil" "io/ioutil"
"log" "log"
"log/syslog"
"os" "os"
"os/exec" "os/exec"
"os/user" "os/user"
@ -33,7 +34,8 @@ import (
) )
var ( var (
wg sync.WaitGroup wg sync.WaitGroup
Log *syslog.Writer // reg. syslog output (no -d)
) )
// Get terminal size using 'stty' command // Get terminal size using 'stty' command
@ -469,12 +471,14 @@ func main() {
// either the shell session or copy operation. // either the shell session or copy operation.
_ = shellMode _ = shellMode
Log, _ = syslog.New(syslog.LOG_USER|syslog.LOG_DEBUG, "hkexsh")
hkexnet.Init(dbg, "hkexsh", syslog.LOG_USER|syslog.LOG_DEBUG)
if dbg { if dbg {
log.SetOutput(os.Stdout) log.SetOutput(Log)
} else { } else {
log.SetOutput(ioutil.Discard) log.SetOutput(ioutil.Discard)
} }
if !gopt { if !gopt {
// See if we can log in via an auth token // See if we can log in via an auth token
u, _ := user.Current() u, _ := user.Current()

View file

@ -18,6 +18,7 @@ import (
"io" "io"
"io/ioutil" "io/ioutil"
"log" "log"
"log/syslog"
"os" "os"
"os/exec" "os/exec"
"os/user" "os/user"
@ -31,6 +32,10 @@ import (
"github.com/kr/pty" "github.com/kr/pty"
) )
var (
Log *syslog.Writer // reg. syslog output (no -d)
)
/* -------------------------------------------------------------- */ /* -------------------------------------------------------------- */
// Perform a client->server copy // Perform a client->server copy
func runClientToServerCopyAs(who, ttype string, conn *hkexnet.Conn, fpath string, chaffing bool) (err error, exitStatus uint32) { func runClientToServerCopyAs(who, ttype string, conn *hkexnet.Conn, fpath string, chaffing bool) (err error, exitStatus uint32) {
@ -382,8 +387,10 @@ func main() {
} }
} }
Log, _ = syslog.New(syslog.LOG_DAEMON|syslog.LOG_DEBUG, "hkexshd")
hkexnet.Init(dbg, "hkexshd", syslog.LOG_DAEMON|syslog.LOG_DEBUG)
if dbg { if dbg {
log.SetOutput(os.Stdout) log.SetOutput(Log)
} else { } else {
log.SetOutput(ioutil.Discard) log.SetOutput(ioutil.Discard)
} }
@ -499,7 +506,7 @@ func main() {
if valid { if valid {
hc.Write([]byte{1}) hc.Write([]byte{1})
} else { } else {
log.Println("Invalid user", string(rec.Who())) Log.Notice(fmt.Sprintln("Invalid user", string(rec.Who())))
hc.Write([]byte{0}) // ? required? hc.Write([]byte{0}) // ? required?
return return
} }
@ -510,7 +517,7 @@ func main() {
// Generate automated login token // Generate automated login token
addr := hc.RemoteAddr() addr := hc.RemoteAddr()
hname := goutmp.GetHost(addr.String()) hname := goutmp.GetHost(addr.String())
log.Printf("[Generating autologin token for [%s@%s]]\n", rec.Who(), hname) Log.Notice(fmt.Sprintf("[Generating autologin token for [%s@%s]]\n", rec.Who(), hname))
token := GenAuthToken(string(rec.Who()), string(rec.ConnHost())) token := GenAuthToken(string(rec.Who()), string(rec.ConnHost()))
tokenCmd := fmt.Sprintf("echo \"%s\" | tee -a ~/.hkexsh_id", token) tokenCmd := fmt.Sprintf("echo \"%s\" | tee -a ~/.hkexsh_id", token)
runErr, cmdStatus := runShellAs(string(rec.Who()), string(rec.TermType()), tokenCmd, false, hc, chaffEnabled) runErr, cmdStatus := runShellAs(string(rec.Who()), string(rec.TermType()), tokenCmd, false, hc, chaffEnabled)
@ -518,7 +525,7 @@ func main() {
// Clear current op so user can enter next, or EOF // Clear current op so user can enter next, or EOF
rec.SetOp([]byte{0}) rec.SetOp([]byte{0})
if runErr != nil { if runErr != nil {
log.Printf("[Error generating autologin token for %s@%s]\n", rec.Who(), hname) Log.Err(fmt.Sprintf("[Error generating autologin token for %s@%s]\n", rec.Who(), hname))
} else { } else {
log.Printf("[Autologin token generation completed for %s@%s, status %d]\n", rec.Who(), hname, cmdStatus) log.Printf("[Autologin token generation completed for %s@%s, status %d]\n", rec.Who(), hname, cmdStatus)
hc.SetStatus(hkexnet.CSOType(cmdStatus)) hc.SetStatus(hkexnet.CSOType(cmdStatus))
@ -527,22 +534,22 @@ func main() {
// Non-interactive command // Non-interactive command
addr := hc.RemoteAddr() addr := hc.RemoteAddr()
hname := goutmp.GetHost(addr.String()) hname := goutmp.GetHost(addr.String())
log.Printf("[Running command for [%s@%s]]\n", rec.Who(), hname) Log.Notice(fmt.Sprintf("[Running command for [%s@%s]]\n", rec.Who(), hname))
runErr, cmdStatus := runShellAs(string(rec.Who()), string(rec.TermType()), string(rec.Cmd()), false, hc, chaffEnabled) runErr, cmdStatus := runShellAs(string(rec.Who()), string(rec.TermType()), string(rec.Cmd()), false, hc, chaffEnabled)
// Returned hopefully via an EOF or exit/logout; // Returned hopefully via an EOF or exit/logout;
// Clear current op so user can enter next, or EOF // Clear current op so user can enter next, or EOF
rec.SetOp([]byte{0}) rec.SetOp([]byte{0})
if runErr != nil { if runErr != nil {
log.Printf("[Error spawning cmd for %s@%s]\n", rec.Who(), hname) Log.Err(fmt.Sprintf("[Error spawning cmd for %s@%s]\n", rec.Who(), hname))
} else { } else {
log.Printf("[Command completed for %s@%s, status %d]\n", rec.Who(), hname, cmdStatus) Log.Notice(fmt.Sprintf("[Command completed for %s@%s, status %d]\n", rec.Who(), hname, cmdStatus))
hc.SetStatus(hkexnet.CSOType(cmdStatus)) hc.SetStatus(hkexnet.CSOType(cmdStatus))
} }
} else if rec.Op()[0] == 's' { } else if rec.Op()[0] == 's' {
// Interactive session // Interactive session
addr := hc.RemoteAddr() addr := hc.RemoteAddr()
hname := goutmp.GetHost(addr.String()) hname := goutmp.GetHost(addr.String())
log.Printf("[Running shell for [%s@%s]]\n", rec.Who(), hname) Log.Notice(fmt.Sprintf("[Running shell for [%s@%s]]\n", rec.Who(), hname))
utmpx := goutmp.Put_utmp(string(rec.Who()), hname) utmpx := goutmp.Put_utmp(string(rec.Who()), hname)
defer func() { goutmp.Unput_utmp(utmpx) }() defer func() { goutmp.Unput_utmp(utmpx) }()
@ -552,9 +559,9 @@ func main() {
// Clear current op so user can enter next, or EOF // Clear current op so user can enter next, or EOF
rec.SetOp([]byte{0}) rec.SetOp([]byte{0})
if runErr != nil { if runErr != nil {
log.Printf("[Error spawning shell for %s@%s]\n", rec.Who(), hname) Log.Err(fmt.Sprintf("[Error spawning shell for %s@%s]\n", rec.Who(), hname))
} else { } else {
log.Printf("[Shell completed for %s@%s, status %d]\n", rec.Who(), hname, cmdStatus) Log.Notice(fmt.Sprintf("[Shell completed for %s@%s, status %d]\n", rec.Who(), hname, cmdStatus))
hc.SetStatus(hkexnet.CSOType(cmdStatus)) hc.SetStatus(hkexnet.CSOType(cmdStatus))
} }
} else if rec.Op()[0] == 'D' { } else if rec.Op()[0] == 'D' {
@ -562,15 +569,15 @@ func main() {
log.Printf("[Client->Server copy]\n") log.Printf("[Client->Server copy]\n")
addr := hc.RemoteAddr() addr := hc.RemoteAddr()
hname := goutmp.GetHost(addr.String()) hname := goutmp.GetHost(addr.String())
log.Printf("[Running copy for [%s@%s]]\n", rec.Who(), hname) Log.Notice(fmt.Sprintf("[Running copy for [%s@%s]]\n", rec.Who(), hname))
runErr, cmdStatus := runClientToServerCopyAs(string(rec.Who()), string(rec.TermType()), hc, string(rec.Cmd()), chaffEnabled) runErr, cmdStatus := runClientToServerCopyAs(string(rec.Who()), string(rec.TermType()), hc, string(rec.Cmd()), chaffEnabled)
// Returned hopefully via an EOF or exit/logout; // Returned hopefully via an EOF or exit/logout;
// Clear current op so user can enter next, or EOF // Clear current op so user can enter next, or EOF
rec.SetOp([]byte{0}) rec.SetOp([]byte{0})
if runErr != nil { if runErr != nil {
log.Printf("[Error running cp for %s@%s]\n", rec.Who(), hname) Log.Err(fmt.Sprintf("[Error running cp for %s@%s]\n", rec.Who(), hname))
} else { } else {
log.Printf("[Command completed for %s@%s, status %d]\n", rec.Who(), hname, cmdStatus) Log.Notice(fmt.Sprintf("[Command completed for %s@%s, status %d]\n", rec.Who(), hname, cmdStatus))
} }
hc.SetStatus(hkexnet.CSOType(cmdStatus)) hc.SetStatus(hkexnet.CSOType(cmdStatus))
@ -584,26 +591,26 @@ func main() {
log.Printf("[Server->Client copy]\n") log.Printf("[Server->Client copy]\n")
addr := hc.RemoteAddr() addr := hc.RemoteAddr()
hname := goutmp.GetHost(addr.String()) hname := goutmp.GetHost(addr.String())
log.Printf("[Running copy for [%s@%s]]\n", rec.Who(), hname) Log.Notice(fmt.Sprintf("[Running copy for [%s@%s]]\n", rec.Who(), hname))
runErr, cmdStatus := runServerToClientCopyAs(string(rec.Who()), string(rec.TermType()), hc, string(rec.Cmd()), chaffEnabled) runErr, cmdStatus := runServerToClientCopyAs(string(rec.Who()), string(rec.TermType()), hc, string(rec.Cmd()), chaffEnabled)
// Returned hopefully via an EOF or exit/logout; // Returned hopefully via an EOF or exit/logout;
// Clear current op so user can enter next, or EOF // Clear current op so user can enter next, or EOF
rec.SetOp([]byte{0}) rec.SetOp([]byte{0})
if runErr != nil { if runErr != nil {
log.Printf("[Error spawning cp for %s@%s]\n", rec.Who(), hname) Log.Err(fmt.Sprintf("[Error spawning cp for %s@%s]\n", rec.Who(), hname))
} else { } else {
log.Printf("[Command completed for %s@%s, status %d]\n", rec.Who(), hname, cmdStatus) Log.Notice(fmt.Sprintf("[Command completed for %s@%s, status %d]\n", rec.Who(), hname, cmdStatus))
} }
hc.SetStatus(hkexnet.CSOType(cmdStatus)) hc.SetStatus(hkexnet.CSOType(cmdStatus))
//fmt.Println("Waiting for EOF from other end.") //fmt.Println("Waiting for EOF from other end.")
//_, _ = hc.Read(nil /*ackByte*/) //_, _ = hc.Read(nil /*ackByte*/)
//fmt.Println("Got remote end ack.") //fmt.Println("Got remote end ack.")
} else { } else {
log.Println("[Bad hkexsh.Session]") Log.Err(fmt.Sprintln("[Bad hkexsh.Session]"))
} }
return return
}(&conn) }(&conn)
} // Accept() success } // Accept() success
} //endfor } //endfor
log.Println("[Exiting]") Log.Notice(fmt.Sprintln("[Exiting]"))
} }