From da2c37bb955bbdfceb95bbcc48e1267716152804 Mon Sep 17 00:00:00 2001 From: Alex Auvolat Date: Sat, 1 Feb 2020 15:05:44 +0100 Subject: Better logging --- ldapserver/client.go | 37 ++++++++++++++++--------------------- ldapserver/logger.go | 32 +++++++------------------------- ldapserver/packet.go | 2 +- ldapserver/route.go | 8 +++----- ldapserver/server.go | 2 +- 5 files changed, 28 insertions(+), 53 deletions(-) (limited to 'ldapserver') diff --git a/ldapserver/client.go b/ldapserver/client.go index 681aa76..7ab043d 100644 --- a/ldapserver/client.go +++ b/ldapserver/client.go @@ -134,9 +134,12 @@ func (c *client) serve() { Logger.Printf("Error reading Message : %s\n\t%x", err.Error(), messagePacket.bytes) continue } - if TRACE { - //Logger.Printf("<<< %d - %s - hex=%x", c.Numero, message.ProtocolOpName(), messagePacket) - Logger.Printf("<<< %d - %#v", c.Numero, message) + + //Logger.Printf("<<< %d - %s - hex=%x", c.Numero, message.ProtocolOpName(), messagePacket) + if br, ok := message.ProtocolOp().(ldap.BindRequest); ok { + Logger.Debugf("<<< [%d] (bind request for %s)", c.Numero, br.Name()) + } else { + Logger.Debugf("<<< [%d] %#v", c.Numero, message) } // TODO: Use a implementation to limit runnuning request by client @@ -175,47 +178,39 @@ func (c *client) serve() { // * close client connection // * signal to server that client shutdown is ok func (c *client) close() { - if DEBUG { - Logger.Printf("client %d close()", c.Numero) - } + Logger.Tracef("client %d close()", c.Numero) close(c.closing) // stop reading from client c.rwc.SetReadDeadline(time.Now().Add(time.Millisecond)) - if DEBUG { - Logger.Printf("client %d close() - stop reading from client", c.Numero) - } + Logger.Tracef("client %d close() - stop reading from client", c.Numero) // signals to all currently running request processor to stop c.mutex.Lock() for messageID, request := range c.requestList { - Logger.Printf("Client %d close() - sent abandon signal to request[messageID = %d]", c.Numero, messageID) + Logger.Debugf("Client %d close() - sent abandon signal to request[messageID = %d]", c.Numero, messageID) go request.Abandon() } c.mutex.Unlock() - if DEBUG { - Logger.Printf("client %d close() - Abandon signal sent to processors", c.Numero) - } + Logger.Tracef("client %d close() - Abandon signal sent to processors", c.Numero) c.wg.Wait() // wait for all current running request processor to end close(c.chanOut) // No more message will be sent to client, close chanOUT - if DEBUG { - Logger.Printf("client [%d] request processors ended", c.Numero) - } + Logger.Tracef("client [%d] request processors ended", c.Numero) <-c.writeDone // Wait for the last message sent to be written c.rwc.Close() // close client connection - Logger.Printf("client [%d] connection closed", c.Numero) + Logger.Debugf("client [%d] connection closed", c.Numero) c.srv.wg.Done() // signal to server that client shutdown is ok } func (c *client) writeMessage(m *ldap.LDAPMessage) { data, _ := m.Write() - if TRACE { - //Logger.Printf(">>> %d - %s - hex=%x", c.Numero, m.ProtocolOpName(), data.Bytes()) - Logger.Printf(">>> %d - %#v", c.Numero, m) - } + + //Logger.Printf(">>> %d - %s - hex=%x", c.Numero, m.ProtocolOpName(), data.Bytes()) + Logger.Tracef(">>> [%d] %#v", c.Numero, m) + c.bw.Write(data.Bytes()) c.bw.Flush() } diff --git a/ldapserver/logger.go b/ldapserver/logger.go index 9f145cf..9286956 100644 --- a/ldapserver/logger.go +++ b/ldapserver/logger.go @@ -1,36 +1,18 @@ package ldapserver import ( - "io/ioutil" - "log" "os" -) - -var Logger logger - -const DEBUG = false -const TRACE = false -// Logger represents log.Logger functions from the standard library -type logger interface { - Fatal(v ...interface{}) - Fatalf(format string, v ...interface{}) - Fatalln(v ...interface{}) + log "github.com/sirupsen/logrus" +) - Panic(v ...interface{}) - Panicf(format string, v ...interface{}) - Panicln(v ...interface{}) +var Logger *log.Logger - Print(v ...interface{}) - Printf(format string, v ...interface{}) - Println(v ...interface{}) -} func init() { - Logger = log.New(os.Stdout, "", log.LstdFlags) + Logger = log.New() + Logger.SetOutput(os.Stdout) + Logger.SetFormatter(&log.TextFormatter{}) + Logger.SetLevel(log.InfoLevel) } -var ( - // DiscardingLogger can be used to disable logging output - DiscardingLogger = log.New(ioutil.Discard, "", 0) -) diff --git a/ldapserver/packet.go b/ldapserver/packet.go index 24d01ed..bd0f6e5 100644 --- a/ldapserver/packet.go +++ b/ldapserver/packet.go @@ -86,7 +86,7 @@ func readTagAndLength(conn *bufio.Reader, bytes *[]byte) (ret ldap.TagAndLength, // } // We are expecting the LDAP sequence tag 0x30 as first byte if b != 0x30 { - panic(fmt.Sprintf("Expecting 0x30 as first byte, but got %#x instead", b)) + return nil, fmt.Errorf("Expecting 0x30 as first byte, but got %#x instead", b) } b, err = readBytes(conn, bytes, 1) diff --git a/ldapserver/route.go b/ldapserver/route.go index ec09f7d..6ced938 100644 --- a/ldapserver/route.go +++ b/ldapserver/route.go @@ -148,11 +148,9 @@ func (h *RouteMux) ServeLDAP(s UserState, w ResponseWriter, r *Message) { } if route.label != "" { - if DEBUG { - Logger.Printf("") - Logger.Printf(" ROUTE MATCH ; %s", route.label) - Logger.Printf("") - } + Logger.Tracef("") + Logger.Tracef(" ROUTE MATCH ; %s", route.label) + Logger.Tracef("") } route.handler(s, w, r) diff --git a/ldapserver/server.go b/ldapserver/server.go index 3640d0a..d4f2128 100644 --- a/ldapserver/server.go +++ b/ldapserver/server.go @@ -36,7 +36,7 @@ func NewServer() *Server { // If a handler already exists for pattern, Handle panics func (s *Server) Handle(h Handler) { if s.Handler != nil { - panic("LDAP: multiple Handler registrations") + Logger.Fatal("LDAP: multiple Handler registrations") } s.Handler = h } -- cgit v1.2.3