Smarter logging (anon5)

master
HimbeerserverDE 2021-09-13 12:14:11 +02:00
parent 9f5a9f8077
commit 2004b786dd
No known key found for this signature in database
GPG Key ID: 1A651504791E6A8B
12 changed files with 137 additions and 149 deletions

View File

@ -43,10 +43,10 @@ func onChatMsg(cc *ClientConn, cmd *mt.ToSrvChatMsg) (string, bool) {
v[i+2] = arg
}
cc.Log("-->", v...)
cc.Log("->", v...)
if !ChatCmdExists(cmdName) {
cc.Log("<--", "unknown command", cmdName)
cc.Log("<-", "unknown command", cmdName)
return "Command not found.", true
}
@ -56,7 +56,7 @@ func onChatMsg(cc *ClientConn, cmd *mt.ToSrvChatMsg) (string, bool) {
cmd := chatCmds[cmdName]
if !cc.HasPerms(cmd.Perm) {
cc.Log("<--", "deny command", cmdName)
cc.Log("<-", "deny command", cmdName)
return fmt.Sprintf("Missing permission %s.", cmd.Perm), true
}
@ -78,7 +78,7 @@ func onTelnetMsg(tlog func(dir string, v ...interface{}), w io.Writer, msg strin
}
if !ChatCmdExists(cmdName) {
tlog("<--", "unknown command", cmdName)
tlog("<-", "unknown command", cmdName)
return "Command not found.\n"
}

View File

@ -3,10 +3,10 @@ package proxy
import (
"crypto/subtle"
"errors"
"fmt"
"log"
"net"
"regexp"
"strings"
"sync"
"github.com/HimbeerserverDE/srp"
@ -29,6 +29,8 @@ type ClientConn struct {
srv *ServerConn
mu sync.RWMutex
logger *log.Logger
cstate clientState
cstateMu sync.RWMutex
name string
@ -103,21 +105,7 @@ func (cc *ClientConn) Init() <-chan struct{} { return cc.initCh }
// Log logs an interaction with the ClientConn.
// dir indicates the direction of the interaction.
func (cc *ClientConn) Log(dir string, v ...interface{}) {
if cc.Name() != "" {
format := "{%s, %s} %s {←|⇶}"
format += strings.Repeat(" %v", len(v))
log.Printf(format, append([]interface{}{
cc.Name(),
cc.RemoteAddr(),
dir,
}, v...)...)
} else {
format := "{%s} %s {←|⇶}"
format += strings.Repeat(" %v", len(v))
log.Printf(format, append([]interface{}{cc.RemoteAddr(), dir}, v...)...)
}
cc.logger.Println(append([]interface{}{dir}, v...)...)
}
func handleClt(cc *ClientConn) {
@ -152,20 +140,20 @@ func handleClt(cc *ClientConn) {
break
}
cc.Log("-->", err)
cc.Log("->", err)
continue
}
switch cmd := pkt.Cmd.(type) {
case *mt.ToSrvInit:
if cc.state() > csCreated {
cc.Log("-->", "duplicate init")
cc.Log("->", "duplicate init")
break
}
cc.setState(csInit)
if cmd.SerializeVer != latestSerializeVer {
cc.Log("<--", "invalid serializeVer")
cc.Log("<-", "invalid serializeVer")
ack, _ := cc.SendCmd(&mt.ToCltDisco{Reason: mt.UnsupportedVer})
select {
@ -178,7 +166,7 @@ func handleClt(cc *ClientConn) {
}
if cmd.MaxProtoVer < latestProtoVer {
cc.Log("<--", "invalid protoVer")
cc.Log("<-", "invalid protoVer")
ack, _ := cc.SendCmd(&mt.ToCltDisco{Reason: mt.UnsupportedVer})
select {
@ -191,7 +179,7 @@ func handleClt(cc *ClientConn) {
}
if len(cmd.PlayerName) == 0 || len(cmd.PlayerName) > maxPlayerNameLen {
cc.Log("<--", "invalid player name length")
cc.Log("<-", "invalid player name length")
ack, _ := cc.SendCmd(&mt.ToCltDisco{Reason: mt.BadName})
select {
@ -204,7 +192,7 @@ func handleClt(cc *ClientConn) {
}
if ok, _ := regexp.MatchString(playerNameChars, cmd.PlayerName); !ok {
cc.Log("<--", "invalid player name")
cc.Log("<-", "invalid player name")
ack, _ := cc.SendCmd(&mt.ToCltDisco{Reason: mt.BadNameChars})
select {
@ -217,9 +205,10 @@ func handleClt(cc *ClientConn) {
}
cc.name = cmd.PlayerName
cc.logger.SetPrefix(fmt.Sprintf("[%s %s] ", cc.RemoteAddr(), cc.Name()))
if authIface.Banned(cc.RemoteAddr().(*net.UDPAddr)) {
cc.Log("<--", "banned")
cc.Log("<-", "banned")
cc.Kick("Banned by proxy.")
break
}
@ -227,7 +216,7 @@ func handleClt(cc *ClientConn) {
playersMu.Lock()
_, ok := players[cc.Name()]
if ok {
cc.Log("<--", "already connected")
cc.Log("<-", "already connected")
ack, _ := cc.SendCmd(&mt.ToCltDisco{Reason: mt.AlreadyConnected})
select {
@ -244,7 +233,7 @@ func handleClt(cc *ClientConn) {
playersMu.Unlock()
if cc.Name() == "singleplayer" {
cc.Log("<--", "name is singleplayer")
cc.Log("<-", "name is singleplayer")
ack, _ := cc.SendCmd(&mt.ToCltDisco{Reason: mt.BadName})
select {
@ -258,7 +247,7 @@ func handleClt(cc *ClientConn) {
// user limit
if len(players) >= Conf().UserLimit {
cc.Log("<--", "player limit reached")
cc.Log("<-", "player limit reached")
ack, _ := cc.SendCmd(&mt.ToCltDisco{Reason: mt.TooManyClts})
select {
@ -286,7 +275,7 @@ func handleClt(cc *ClientConn) {
case *mt.ToSrvFirstSRP:
if cc.state() == csInit {
if cc.auth.method != mt.FirstSRP {
cc.Log("-->", "unauthorized password change")
cc.Log("->", "unauthorized password change")
ack, _ := cc.SendCmd(&mt.ToCltDisco{Reason: mt.UnexpectedData})
select {
@ -304,7 +293,7 @@ func handleClt(cc *ClientConn) {
}{}
if cmd.EmptyPasswd && Conf().RequirePasswd {
cc.Log("<--", "empty password disallowed")
cc.Log("<-", "empty password disallowed")
ack, _ := cc.SendCmd(&mt.ToCltDisco{Reason: mt.EmptyPasswd})
select {
@ -317,7 +306,7 @@ func handleClt(cc *ClientConn) {
}
if err := authIface.SetPasswd(cc.Name(), cmd.Salt, cmd.Verifier); err != nil {
cc.Log("<--", "set password fail")
cc.Log("<-", "set password fail")
ack, _ := cc.SendCmd(&mt.ToCltDisco{Reason: mt.SrvErr})
select {
@ -329,7 +318,7 @@ func handleClt(cc *ClientConn) {
break
}
cc.Log("-->", "set password")
cc.Log("->", "set password")
cc.SendCmd(&mt.ToCltAcceptAuth{
PlayerPos: mt.Pos{0, 5, 0},
MapSeed: 0,
@ -338,30 +327,30 @@ func handleClt(cc *ClientConn) {
})
} else {
if cc.state() < csSudo {
cc.Log("-->", "unauthorized sudo action")
cc.Log("->", "unauthorized sudo action")
break
}
cc.setState(cc.state() - 1)
if err := authIface.SetPasswd(cc.Name(), cmd.Salt, cmd.Verifier); err != nil {
cc.Log("<--", "change password fail")
cc.Log("<-", "change password fail")
cc.SendChatMsg("Password change failed or unavailable.")
break
}
cc.Log("-->", "change password")
cc.Log("->", "change password")
cc.SendChatMsg("Password change successful.")
}
case *mt.ToSrvSRPBytesA:
wantSudo := cc.state() == csActive
if cc.state() != csInit && cc.state() != csActive {
cc.Log("-->", "unexpected authentication")
cc.Log("->", "unexpected authentication")
break
}
if !wantSudo && cc.auth.method != mt.SRP {
cc.Log("<--", "multiple authentication attempts")
cc.Log("<-", "multiple authentication attempts")
if wantSudo {
cc.SendCmd(&mt.ToCltDenySudoMode{})
break
@ -378,7 +367,7 @@ func handleClt(cc *ClientConn) {
}
if !cmd.NoSHA1 {
cc.Log("<--", "unsupported SHA1 auth")
cc.Log("<-", "unsupported SHA1 auth")
break
}
@ -386,7 +375,7 @@ func handleClt(cc *ClientConn) {
salt, verifier, err := authIface.Passwd(cc.Name())
if err != nil {
cc.Log("<--", "SRP data retrieval fail")
cc.Log("<-", "SRP data retrieval fail")
ack, _ := cc.SendCmd(&mt.ToCltDisco{Reason: mt.SrvErr})
select {
@ -402,7 +391,7 @@ func handleClt(cc *ClientConn) {
cc.auth.srpA = cmd.A
cc.auth.srpB, _, cc.auth.srpK, err = srp.Handshake(cc.auth.srpA, verifier)
if err != nil || cc.auth.srpB == nil {
cc.Log("<--", "SRP safety check fail")
cc.Log("<-", "SRP safety check fail")
ack, _ := cc.SendCmd(&mt.ToCltDisco{Reason: mt.UnexpectedData})
select {
@ -422,12 +411,12 @@ func handleClt(cc *ClientConn) {
wantSudo := cc.state() == csActive
if cc.state() != csInit && cc.state() != csActive {
cc.Log("-->", "unexpected authentication")
cc.Log("->", "unexpected authentication")
break
}
if cc.auth.method != mt.SRP {
cc.Log("<--", "multiple authentication attempts")
cc.Log("<-", "multiple authentication attempts")
if wantSudo {
cc.SendCmd(&mt.ToCltDenySudoMode{})
break
@ -464,12 +453,12 @@ func handleClt(cc *ClientConn) {
}
} else {
if wantSudo {
cc.Log("<--", "invalid password (sudo)")
cc.Log("<-", "invalid password (sudo)")
cc.SendCmd(&mt.ToCltDenySudoMode{})
break
}
cc.Log("<--", "invalid password")
cc.Log("<-", "invalid password")
ack, _ := cc.SendCmd(&mt.ToCltDisco{Reason: mt.WrongPasswd})
select {
@ -483,7 +472,7 @@ func handleClt(cc *ClientConn) {
case *mt.ToSrvInit2:
cc.itemDefs, cc.aliases, cc.nodeDefs, cc.p0Map, cc.p0SrvMap, cc.media, err = muxContent(cc.Name())
if err != nil {
cc.Log("<--", err.Error())
cc.Log("<-", err.Error())
cc.Kick("Content multiplexing failed.")
break
}
@ -546,7 +535,7 @@ func handleClt(cc *ClientConn) {
close(cc.initCh)
case *mt.ToSrvInteract:
if cc.server() == nil {
cc.Log("-->", "no server")
cc.Log("->", "no server")
break
}
@ -557,7 +546,7 @@ func handleClt(cc *ClientConn) {
cc.server().SendCmd(cmd)
case *mt.ToSrvChatMsg:
if cc.server() == nil {
cc.Log("-->", "no server")
cc.Log("->", "no server")
break
}
@ -569,73 +558,73 @@ func handleClt(cc *ClientConn) {
}
case *mt.ToSrvDeletedBlks:
if cc.server() == nil {
cc.Log("-->", "no server")
cc.Log("->", "no server")
break
}
cc.server().SendCmd(cmd)
case *mt.ToSrvFallDmg:
if cc.server() == nil {
cc.Log("-->", "no server")
cc.Log("->", "no server")
break
}
cc.server().SendCmd(cmd)
case *mt.ToSrvGotBlks:
if cc.server() == nil {
cc.Log("-->", "no server")
cc.Log("->", "no server")
break
}
cc.server().SendCmd(cmd)
case *mt.ToSrvJoinModChan:
if cc.server() == nil {
cc.Log("-->", "no server")
cc.Log("->", "no server")
break
}
cc.server().SendCmd(cmd)
case *mt.ToSrvLeaveModChan:
if cc.server() == nil {
cc.Log("-->", "no server")
cc.Log("->", "no server")
break
}
cc.server().SendCmd(cmd)
case *mt.ToSrvMsgModChan:
if cc.server() == nil {
cc.Log("-->", "no server")
cc.Log("->", "no server")
break
}
cc.server().SendCmd(cmd)
case *mt.ToSrvNodeMetaFields:
if cc.server() == nil {
cc.Log("-->", "no server")
cc.Log("->", "no server")
break
}
cc.server().SendCmd(cmd)
case *mt.ToSrvPlayerPos:
if cc.server() == nil {
cc.Log("-->", "no server")
cc.Log("->", "no server")
break
}
cc.server().SendCmd(cmd)
case *mt.ToSrvRespawn:
if cc.server() == nil {
cc.Log("-->", "no server")
cc.Log("->", "no server")
break
}
cc.server().SendCmd(cmd)
case *mt.ToSrvInvAction:
if cc.server() == nil {
cc.Log("-->", "no server")
cc.Log("->", "no server")
break
}
cc.server().SendCmd(cmd)
case *mt.ToSrvInvFields:
if cc.server() == nil {
cc.Log("-->", "no server")
cc.Log("->", "no server")
break
}
cc.server().SendCmd(cmd)
case *mt.ToSrvSelectItem:
if cc.server() == nil {
cc.Log("-->", "no server")
cc.Log("->", "no server")
break
}
cc.server().SendCmd(cmd)

View File

@ -8,13 +8,15 @@ import (
"sync"
)
const defaultCmdPrefix = ">"
const defaultSendInterval = 0.09
const defaultUserLimit = 10
const defaultAuthBackend = "sqlite3"
const defaultTelnetAddr = "[::1]:40010"
const defaultBindAddr = ":40000"
const defaultListInterval = 300
const (
defaultCmdPrefix = ">"
defaultSendInterval = 0.09
defaultUserLimit = 10
defaultAuthBackend = "sqlite3"
defaultTelnetAddr = "[::1]:40010"
defaultBindAddr = ":40000"
defaultListInterval = 300
)
var config Config
var configMu sync.RWMutex
@ -115,6 +117,6 @@ func LoadConfig() error {
return err
}
log.Print("{←|⇶} load config")
log.Print("load config")
return nil
}

View File

@ -1,6 +1,8 @@
package proxy
import (
"fmt"
"log"
"net"
"github.com/anon55555/mt"
@ -15,8 +17,10 @@ func connect(conn net.Conn, name string, cc *ClientConn) *ServerConn {
}
cc.mu.RUnlock()
prefix := fmt.Sprintf("[server %s] ", name)
sc := &ServerConn{
Peer: mt.Connect(conn),
logger: log.New(logWriter, prefix, log.LstdFlags|log.Lmsgprefix),
initCh: make(chan struct{}),
clt: cc,
name: name,
@ -26,7 +30,7 @@ func connect(conn net.Conn, name string, cc *ClientConn) *ServerConn {
huds: make(map[mt.HUDID]mt.HUDType),
playerList: make(map[string]struct{}),
}
sc.Log("-->", "connect")
sc.Log("->", "connect")
cc.mu.Lock()
cc.srv = sc
@ -37,8 +41,10 @@ func connect(conn net.Conn, name string, cc *ClientConn) *ServerConn {
}
func connectContent(conn net.Conn, name, userName string) (*contentConn, error) {
prefix := fmt.Sprintf("[content %s] ", name)
cc := &contentConn{
Peer: mt.Connect(conn),
logger: log.New(logWriter, prefix, log.LstdFlags|log.Lmsgprefix),
doneCh: make(chan struct{}),
name: name,
userName: userName,

View File

@ -30,6 +30,8 @@ type mediaFile struct {
type contentConn struct {
mt.Peer
logger *log.Logger
cstate clientState
cstateMu sync.RWMutex
name, userName string
@ -69,10 +71,7 @@ func (cc *contentConn) addDefaultTextures() {
}
func (cc *contentConn) log(dir string, v ...interface{}) {
format := "{←|⇶} %s {%s}"
format += strings.Repeat(" %v", len(v))
log.Printf(format, append([]interface{}{dir, cc.name}, v...)...)
cc.logger.Println(append([]interface{}{dir}, v...)...)
}
func handleContent(cc *contentConn) {
@ -86,7 +85,7 @@ func handleContent(cc *contentConn) {
select {
case <-init:
case <-time.After(10 * time.Second):
cc.log("-->", "timeout")
cc.log("->", "timeout")
cc.Close()
}
}(init)
@ -112,14 +111,14 @@ func handleContent(cc *contentConn) {
break
}
cc.log("-->", err)
cc.log("->", err)
continue
}
switch cmd := pkt.Cmd.(type) {
case *mt.ToCltHello:
if cc.auth.method != 0 {
cc.log("<--", "unexpected authentication")
cc.log("<-", "unexpected authentication")
cc.Close()
break
}
@ -132,7 +131,7 @@ func handleContent(cc *contentConn) {
}
if cmd.SerializeVer != latestSerializeVer {
cc.log("<--", "invalid serializeVer")
cc.log("<-", "invalid serializeVer")
break
}
@ -140,7 +139,7 @@ func handleContent(cc *contentConn) {
case mt.SRP:
cc.auth.srpA, cc.auth.a, err = srp.InitiateHandshake()
if err != nil {
cc.log("-->", err)
cc.log("->", err)
break
}
@ -151,7 +150,7 @@ func handleContent(cc *contentConn) {
case mt.FirstSRP:
salt, verifier, err := srp.NewClient([]byte(cc.userName), []byte{})
if err != nil {
cc.log("-->", err)
cc.log("->", err)
break
}
@ -166,19 +165,19 @@ func handleContent(cc *contentConn) {
}
case *mt.ToCltSRPBytesSaltB:
if cc.auth.method != mt.SRP {
cc.log("<--", "multiple authentication attempts")
cc.log("<-", "multiple authentication attempts")
break
}
cc.auth.srpK, err = srp.CompleteHandshake(cc.auth.srpA, cc.auth.a, []byte(cc.userName), []byte{}, cmd.Salt, cmd.B)
if err != nil {
cc.log("-->", err)
cc.log("->", err)
break
}
M := srp.ClientProof([]byte(cc.userName), cmd.Salt, cc.auth.srpA, cmd.B, cc.auth.srpK)
if M == nil {
cc.log("<--", "SRP safety check fail")
cc.log("<-", "SRP safety check fail")
break
}
@ -186,7 +185,7 @@ func handleContent(cc *contentConn) {
M: M,
})
case *mt.ToCltDisco:
cc.log("<--", "deny access", cmd)
cc.log("<-", "deny access", cmd)
case *mt.ToCltAcceptAuth:
cc.auth.method = 0
cc.SendCmd(&mt.ToSrvInit2{})
@ -276,7 +275,7 @@ func (cc *ClientConn) sendMedia(filenames []string) {
}
if !known {
cc.Log("-->", "request unknown media file")
cc.Log("->", "request unknown media file")
continue
}
}

View File

@ -88,7 +88,7 @@ func announce(action string) error {
return err
}
log.Print("{←|⇶} announce ", action)
log.Println("announce", action)
return nil
}
@ -101,7 +101,7 @@ func init() {
<-t.C
if !added {
if err := announce(listAdd); err != nil {
log.Print("{←|⇶} ", err)
log.Print(err)
}
added = true
@ -109,7 +109,7 @@ func init() {
}
if err := announce(listUpdate); err != nil {
log.Print("{←|⇶} ", err)
log.Print(err)
}
}
}()

View File

@ -2,6 +2,7 @@ package proxy
import (
"fmt"
"log"
"net"
"sync"
@ -68,8 +69,10 @@ func (l *listener) accept() (*ClientConn, error) {
return nil, err
}
prefix := fmt.Sprintf("[%s] ", p.RemoteAddr())
cc := &ClientConn{
Peer: p,
logger: log.New(logWriter, prefix, log.LstdFlags|log.Lmsgprefix),
initCh: make(chan struct{}),
modChs: make(map[string]struct{}),
}
@ -86,7 +89,7 @@ func (l *listener) accept() (*ClientConn, error) {
delete(l.clts, cc)
}()
cc.Log("-->", "connect")
cc.Log("->", "connect")
go handleClt(cc)
select {

13
log.go
View File

@ -6,6 +6,8 @@ import (
"path/filepath"
)
var logWriter *LogWriter
type LogWriter struct {
f *os.File
}
@ -22,15 +24,18 @@ func (lw *LogWriter) Write(p []byte) (n int, err error) {
}
func init() {
log.SetPrefix("[proxy] ")
log.SetFlags(log.Flags() | log.Lmsgprefix)
executable, err := os.Executable()
if err != nil {
log.Fatal("{←|⇶} ", err)
log.Fatal(err)
}
path := filepath.Dir(executable) + "/latest.log"
f, err := os.OpenFile(path, os.O_WRONLY|os.O_CREATE|os.O_TRUNC, 0666)
if err != nil {
log.Fatal("{←|⇶} ", err)
log.Fatal(err)
}
go func() {
@ -38,6 +43,6 @@ func init() {
select {}
}()
lw := &LogWriter{f}
log.SetOutput(lw)
logWriter = &LogWriter{f}
log.SetOutput(logWriter)
}

View File

@ -17,7 +17,7 @@ func loadPlugins() {
func openPlugins() {
executable, err := os.Executable()
if err != nil {
log.Fatal("{←|⇶} ", err)
log.Fatal(err)
}
path := filepath.Dir(executable) + "/plugins"
@ -25,16 +25,16 @@ func openPlugins() {
dir, err := os.ReadDir(path)
if err != nil {
log.Fatal("{←|⇶} ", err)
log.Fatal(err)
}
for _, file := range dir {
_, err := plugin.Open(path + "/" + file.Name())
if err != nil {
log.Print("{←|⇶} ", err)
log.Print(err)
continue
}
}
log.Print("{←|⇶} load plugins")
log.Print("load plugins")
}

24
run.go
View File

@ -14,7 +14,7 @@ import (
// It blocks forever.
func Run() {
if err := LoadConfig(); err != nil {
log.Fatal("{←|⇶} ", err)
log.Fatal(err)
}
if !Conf().NoPlugins {
@ -26,29 +26,29 @@ func Run() {
case "sqlite3":
setAuthBackend(authSQLite3{})
default:
log.Fatal("{←|⇶} invalid auth backend")
log.Fatal("invalid auth backend")
}
go func() {
if err := telnetServer(); err != nil {
log.Fatal("{←|⇶} ", err)
log.Fatal(err)
}
}()
addr, err := net.ResolveUDPAddr("udp", Conf().BindAddr)
if err != nil {
log.Fatal("{←|⇶} ", err)
log.Fatal(err)
}
pc, err := net.ListenUDP("udp", addr)
if err != nil {
log.Fatal("{←|⇶} ", err)
log.Fatal(err)
}
l := listen(pc)
defer l.Close()
log.Print("{←|⇶} listen ", l.Addr())
log.Println("listen", l.Addr())
go func() {
sig := make(chan os.Signal, 1)
@ -59,7 +59,7 @@ func Run() {
if Conf().List.Enable {
if err := announce(listRm); err != nil {
log.Print("{←|⇶} ", err)
log.Print(err)
}
}
@ -83,11 +83,11 @@ func Run() {
cc, err := l.accept()
if err != nil {
if errors.Is(err, net.ErrClosed) {
log.Print("{←|⇶} stop listening")
log.Print("stop listening")
break
}
log.Print("{←|⇶} ", err)
log.Print(err)
continue
}
@ -96,21 +96,21 @@ func Run() {
cc.Log("<->", "handshake completed")
if len(Conf().Servers) == 0 {
cc.Log("<--", "no servers")
cc.Log("<-", "no servers")
cc.Kick("No servers are configured.")
return
}
addr, err := net.ResolveUDPAddr("udp", Conf().Servers[0].Addr)
if err != nil {
cc.Log("<--", "address resolution fail")
cc.Log("<-", "address resolution fail")
cc.Kick("Server address resolution failed.")
return
}
conn, err := net.DialUDP("udp", nil, addr)
if err != nil {
cc.Log("<--", "connection fail")
cc.Log("<-", "connection fail")
cc.Kick("Server connection failed.")
return
}

View File

@ -2,7 +2,6 @@ package proxy
import (
"errors"
"fmt"
"log"
"net"
"strings"
@ -20,6 +19,8 @@ type ServerConn struct {
clt *ClientConn
mu sync.RWMutex
logger *log.Logger
cstate clientState
cstateMu sync.RWMutex
name string
@ -71,20 +72,7 @@ func (sc *ServerConn) Init() <-chan struct{} { return sc.initCh }
// Log logs an interaction with the ServerConn.
// dir indicates the direction of the interaction.
func (sc *ServerConn) Log(dir string, v ...interface{}) {
if sc.client() != nil {
format := "%s {%s}"
format += strings.Repeat(" %v", len(v))
sc.client().Log("", fmt.Sprintf(format, append([]interface{}{
dir,
sc.name,
}, v...)...))
} else {
format := "{←|⇶} %s {%s}"
format += strings.Repeat(" %v", len(v))
log.Printf(format, append([]interface{}{dir, sc.name}, v...)...)
}
sc.logger.Println(append([]interface{}{dir}, v...)...)
}
func handleSrv(sc *ServerConn) {
@ -96,7 +84,7 @@ func handleSrv(sc *ServerConn) {
select {
case <-init:
case <-time.After(10 * time.Second):
sc.Log("-->", "timeout")
sc.Log("->", "timeout")
sc.Close()
}
}(init)
@ -146,20 +134,20 @@ func handleSrv(sc *ServerConn) {
break
}
sc.Log("<--", err)
sc.Log("<-", err)
continue
}
clt := sc.client()
if clt == nil {
sc.Log("<--", "no client")
sc.Log("<-", "no client")
continue
}
switch cmd := pkt.Cmd.(type) {
case *mt.ToCltHello:
if sc.auth.method != 0 {
sc.Log("<--", "unexpected authentication")
sc.Log("<-", "unexpected authentication")
sc.Close()
break
}
@ -172,7 +160,7 @@ func handleSrv(sc *ServerConn) {
}
if cmd.SerializeVer != latestSerializeVer {
sc.Log("<--", "invalid serializeVer")
sc.Log("<-", "invalid serializeVer")
break
}
@ -180,7 +168,7 @@ func handleSrv(sc *ServerConn) {
case mt.SRP:
sc.auth.srpA, sc.auth.a, err = srp.InitiateHandshake()
if err != nil {
sc.Log("-->", err)
sc.Log("->", err)
break
}
@ -191,7 +179,7 @@ func handleSrv(sc *ServerConn) {
case mt.FirstSRP:
salt, verifier, err := srp.NewClient([]byte(clt.name), []byte{})
if err != nil {
sc.Log("-->", err)
sc.Log("->", err)
break
}
@ -206,19 +194,19 @@ func handleSrv(sc *ServerConn) {
}
case *mt.ToCltSRPBytesSaltB:
if sc.auth.method != mt.SRP {
sc.Log("<--", "multiple authentication attempts")
sc.Log("<-", "multiple authentication attempts")
break
}
sc.auth.srpK, err = srp.CompleteHandshake(sc.auth.srpA, sc.auth.a, []byte(clt.name), []byte{}, cmd.Salt, cmd.B)
if err != nil {
sc.Log("-->", err)
sc.Log("->", err)
break
}
M := srp.ClientProof([]byte(clt.name), cmd.Salt, sc.auth.srpA, cmd.B, sc.auth.srpK)
if M == nil {
sc.Log("<--", "SRP safety check fail")
sc.Log("<-", "SRP safety check fail")
break
}
@ -226,7 +214,7 @@ func handleSrv(sc *ServerConn) {
M: M,
})
case *mt.ToCltDisco:
sc.Log("<--", "deny access", cmd)
sc.Log("<-", "deny access", cmd)
ack, _ := clt.SendCmd(cmd)
select {
@ -245,9 +233,9 @@ func handleSrv(sc *ServerConn) {
}{}
sc.SendCmd(&mt.ToSrvInit2{Lang: clt.lang})
case *mt.ToCltDenySudoMode:
sc.Log("<--", "deny sudo")
sc.Log("<-", "deny sudo")
case *mt.ToCltAcceptSudoMode:
sc.Log("<--", "accept sudo")
sc.Log("<-", "accept sudo")
sc.setState(sc.state() + 1)
case *mt.ToCltAnnounceMedia:
sc.SendCmd(&mt.ToSrvReqMedia{})

View File

@ -3,11 +3,11 @@ package proxy
import (
"bufio"
"errors"
"fmt"
"io"
"log"
"math"
"net"
"strings"
)
// A TelnetWriter can be used to print something at the other end
@ -32,7 +32,7 @@ func telnetServer() error {
}
defer ln.Close()
log.Print("{←|⇶} listen telnet ", ln.Addr())
log.Println("listen telnet", ln.Addr())
for {
select {
@ -41,7 +41,7 @@ func telnetServer() error {
default:
conn, err := ln.Accept()
if err != nil {
log.Print("{←|⇶} ", err)
log.Print(err)
continue
}
@ -52,13 +52,9 @@ func telnetServer() error {
func handleTelnet(conn net.Conn) {
tlog := func(dir string, v ...interface{}) {
format := "{%s} %s {←|⇶}"
format += strings.Repeat(" %v", len(v))
log.Printf(format, append([]interface{}{
conn.RemoteAddr(),
dir,
}, v...)...)
prefix := fmt.Sprintf("[telnet %s] ", conn.RemoteAddr())
l := log.New(logWriter, prefix, log.LstdFlags|log.Lmsgprefix)
l.Println(append([]interface{}{dir}, v...)...)
}
tlog("<->", "telnet connect")
@ -89,11 +85,11 @@ func handleTelnet(conn net.Conn) {
return
}
log.Print("{←|⇶} ", err)
log.Print(err)
continue
}
tlog("-->", "telnet command", s)
tlog("->", "telnet command", s)
if s == "\\quit" || s == "\\q" {
return