From 27e0906450934f7b2132326aa4e187fb7c541ab8 Mon Sep 17 00:00:00 2001 From: Simon Ser Date: Fri, 3 Apr 2020 18:59:17 +0200 Subject: [PATCH] Introduce messageLogger This centralizes formatting related to message logging in a single place. --- downstream.go | 2 +- logger.go | 108 ++++++++++++++++++++++++++++++++++++++++++++++++++ upstream.go | 81 +++++++++++-------------------------- user.go | 6 ++- 4 files changed, 137 insertions(+), 60 deletions(-) create mode 100644 logger.go diff --git a/downstream.go b/downstream.go index fc10a26..98668dd 100644 --- a/downstream.go +++ b/downstream.go @@ -1232,7 +1232,7 @@ func (dc *downstreamConn) handleMessageRegistered(msg *irc.Message) error { dc.ourMessages[echoMsg] = struct{}{} dc.lock.Unlock() - uc.appendLog(upstreamName, "<%s> %s", uc.nick, text) + uc.appendLog(upstreamName, echoMsg) uc.network.ring.Produce(echoMsg) } diff --git a/logger.go b/logger.go new file mode 100644 index 0000000..ab8f15e --- /dev/null +++ b/logger.go @@ -0,0 +1,108 @@ +package soju + +import ( + "fmt" + "os" + "path/filepath" + "strings" + "time" + + "gopkg.in/irc.v3" +) + +type messageLogger struct { + conn *upstreamConn + entity string + + filename string + file *os.File +} + +func newMessageLogger(uc *upstreamConn, entity string) *messageLogger { + return &messageLogger{ + conn: uc, + entity: entity, + } +} + +func (ml *messageLogger) Append(msg *irc.Message) error { + s := formatMessage(msg) + if s == "" { + return nil + } + + // TODO: enforce maximum open file handles (LRU cache of file handles) + // TODO: handle non-monotonic clock behaviour + now := time.Now() + year, month, day := now.Date() + filename := fmt.Sprintf("%04d-%02d-%02d.log", year, month, day) + if ml.filename != filename { + if ml.file != nil { + ml.file.Close() + } + + // TODO: handle/forbid network/entity names with illegal path characters + dir := filepath.Join(ml.conn.srv.LogPath, ml.conn.user.Username, ml.conn.network.Name, ml.entity) + if err := os.MkdirAll(dir, 0700); err != nil { + return fmt.Errorf("failed to create logs directory %q: %v", dir, err) + } + + path := filepath.Join(dir, filename) + f, err := os.OpenFile(path, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0600) + if err != nil { + return fmt.Errorf("failed to open log file %q: %v", path, err) + } + + ml.filename = filename + ml.file = f + } + + _, err := fmt.Fprintf(ml.file, "[%02d:%02d:%02d] %s\n", now.Hour(), now.Minute(), now.Second(), s) + if err != nil { + return fmt.Errorf("failed to log message to %q: %v", ml.filename, err) + } + return nil +} + +func (ml *messageLogger) Close() error { + if ml.file == nil { + return nil + } + return ml.file.Close() +} + +// formatMessage formats a message log line. It assumes a well-formed IRC +// message. +func formatMessage(msg *irc.Message) string { + switch strings.ToUpper(msg.Command) { + case "NICK": + return fmt.Sprintf("*** %s is now known as %s", msg.Prefix.Name, msg.Params[0]) + case "JOIN": + return fmt.Sprintf("*** Joins: %s (%s@%s)", msg.Prefix.Name, msg.Prefix.User, msg.Prefix.Host) + case "PART": + var reason string + if len(msg.Params) > 1 { + reason = msg.Params[1] + } + return fmt.Sprintf("*** Parts: %s (%s@%s) (%s)", msg.Prefix.Name, msg.Prefix.User, msg.Prefix.Host, reason) + case "KICK": + nick := msg.Params[1] + var reason string + if len(msg.Params) > 2 { + reason = msg.Params[2] + } + return fmt.Sprintf("*** %s was kicked by %s (%s)", nick, msg.Prefix.Name, reason) + case "QUIT": + var reason string + if len(msg.Params) > 0 { + reason = msg.Params[0] + } + return fmt.Sprintf("*** Quits: %s (%s@%s) (%s)", msg.Prefix.Name, msg.Prefix.User, msg.Prefix.Host, reason) + case "MODE": + return fmt.Sprintf("*** %s sets mode: %s", msg.Prefix.Name, strings.Join(msg.Params[1:], " ")) + case "PRIVMSG", "NOTICE": + return fmt.Sprintf("<%s> %s", msg.Prefix.Name, msg.Params[1]) + default: + return "" + } +} diff --git a/upstream.go b/upstream.go index 000902c..f21740d 100644 --- a/upstream.go +++ b/upstream.go @@ -8,7 +8,6 @@ import ( "io" "net" "os" - "path/filepath" "strconv" "strings" "time" @@ -62,7 +61,7 @@ type upstreamConn struct { // set of LIST commands in progress, per downstream pendingLISTDownstreamSet map[uint64]struct{} - logs map[string]entityLog + messageLoggers map[string]*messageLogger } type entityLog struct { @@ -97,7 +96,7 @@ func connectToUpstream(network *network) (*upstreamConn, error) { availableChannelModes: stdChannelModes, availableMemberships: stdMemberships, pendingLISTDownstreamSet: make(map[uint64]struct{}), - logs: make(map[string]entityLog), + messageLoggers: make(map[string]*messageLogger), } return uc, nil @@ -273,7 +272,7 @@ func (uc *upstreamConn) handleMessage(msg *irc.Message) error { if nick == uc.nick { target = msg.Prefix.Name } - uc.appendLog(target, "<%s> %s", msg.Prefix.Name, text) + uc.appendLog(target, msg) uc.forEachDownstream(func(dc *downstreamConn) { dc.SendMessage(&irc.Message{ @@ -578,7 +577,7 @@ func (uc *upstreamConn) handleMessage(msg *irc.Message) error { if membership, ok := ch.Members[msg.Prefix.Name]; ok { delete(ch.Members, msg.Prefix.Name) ch.Members[newNick] = membership - uc.appendLog(ch.Name, "*** %s is now known as %s", msg.Prefix.Name, newNick) + uc.appendLog(ch.Name, msg) } } @@ -622,7 +621,7 @@ func (uc *upstreamConn) handleMessage(msg *irc.Message) error { ch.Members[msg.Prefix.Name] = nil } - uc.appendLog(ch, "*** Joins: %s (%s@%s)", msg.Prefix.Name, msg.Prefix.User, msg.Prefix.Host) + uc.appendLog(ch, msg) uc.forEachDownstream(func(dc *downstreamConn) { dc.SendMessage(&irc.Message{ @@ -659,13 +658,17 @@ func (uc *upstreamConn) handleMessage(msg *irc.Message) error { delete(ch.Members, msg.Prefix.Name) } - uc.appendLog(ch, "*** Parts: %s (%s@%s) (%s)", msg.Prefix.Name, msg.Prefix.User, msg.Prefix.Host, reason) + uc.appendLog(ch, msg) uc.forEachDownstream(func(dc *downstreamConn) { + params := []string{dc.marshalChannel(uc, ch)} + if reason != "" { + params = append(params, reason) + } dc.SendMessage(&irc.Message{ Prefix: dc.marshalUserPrefix(uc, msg.Prefix), Command: "PART", - Params: []string{dc.marshalChannel(uc, ch)}, + Params: params, }) }) } @@ -681,7 +684,7 @@ func (uc *upstreamConn) handleMessage(msg *irc.Message) error { var reason string if len(msg.Params) > 2 { - reason = msg.Params[1] + reason = msg.Params[2] } if user == uc.nick { @@ -695,7 +698,7 @@ func (uc *upstreamConn) handleMessage(msg *irc.Message) error { delete(ch.Members, user) } - uc.appendLog(channel, "*** %s was kicked by %s (%s)", user, msg.Prefix.Name, reason) + uc.appendLog(channel, msg) uc.forEachDownstream(func(dc *downstreamConn) { params := []string{dc.marshalChannel(uc, channel), dc.marshalNick(uc, user)} @@ -713,11 +716,6 @@ func (uc *upstreamConn) handleMessage(msg *irc.Message) error { return fmt.Errorf("expected a prefix") } - var reason string - if len(msg.Params) > 0 { - reason = msg.Params[0] - } - if msg.Prefix.Name == uc.nick { uc.logger.Printf("quit") } @@ -726,7 +724,7 @@ func (uc *upstreamConn) handleMessage(msg *irc.Message) error { if _, ok := ch.Members[msg.Prefix.Name]; ok { delete(ch.Members, msg.Prefix.Name) - uc.appendLog(ch.Name, "*** Quits: %s (%s@%s) (%s)", msg.Prefix.Name, msg.Prefix.User, msg.Prefix.Host, reason) + uc.appendLog(ch.Name, msg) } } @@ -802,11 +800,7 @@ func (uc *upstreamConn) handleMessage(msg *irc.Message) error { } } - modeMsg := modeStr - for _, v := range msg.Params[2:] { - modeMsg += " " + v - } - uc.appendLog(ch.Name, "*** %s sets mode: %s", msg.Prefix.Name, modeMsg) + uc.appendLog(ch.Name, msg) uc.forEachDownstream(func(dc *downstreamConn) { params := []string{dc.marshalChannel(uc, name), modeStr} @@ -1163,7 +1157,7 @@ func (uc *upstreamConn) handleMessage(msg *irc.Message) error { if nick == uc.nick { target = msg.Prefix.Name } - uc.appendLog(target, "<%s> %s", msg.Prefix.Name, text) + uc.appendLog(target, msg) uc.network.ring.Produce(msg) case "INVITE": @@ -1377,46 +1371,19 @@ func (uc *upstreamConn) SendMessageLabeled(downstreamID uint64, msg *irc.Message } // TODO: handle moving logs when a network name changes, when support for this is added -func (uc *upstreamConn) appendLog(entity string, format string, a ...interface{}) { +func (uc *upstreamConn) appendLog(entity string, msg *irc.Message) { if uc.srv.LogPath == "" { return } - // TODO: enforce maximum open file handles (LRU cache of file handles) - // TODO: handle non-monotonic clock behaviour - now := time.Now() - year, month, day := now.Date() - name := fmt.Sprintf("%04d-%02d-%02d.log", year, month, day) - log, ok := uc.logs[entity] - if !ok || log.name != name { - if ok { - log.file.Close() - delete(uc.logs, entity) - } - // TODO: handle/forbid network/entity names with illegal path characters - dir := filepath.Join(uc.srv.LogPath, uc.user.Username, uc.network.Name, entity) - if err := os.MkdirAll(dir, 0700); err != nil { - uc.logger.Printf("failed to log message: could not create logs directory %q: %v", dir, err) - return - } - path := filepath.Join(dir, name) - f, err := os.OpenFile(path, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0600) - if err != nil { - uc.logger.Printf("failed to log message: could not open or create log file %q: %v", path, err) - return - } - log = entityLog{ - name: name, - file: f, - } - uc.logs[entity] = log + + ml, ok := uc.messageLoggers[entity] + if !ok { + ml = newMessageLogger(uc, entity) + uc.messageLoggers[entity] = ml } - format = "[%02d:%02d:%02d] " + format + "\n" - args := []interface{}{now.Hour(), now.Minute(), now.Second()} - args = append(args, a...) - - if _, err := fmt.Fprintf(log.file, format, args...); err != nil { - uc.logger.Printf("failed to log message to %q: %v", log.name, err) + if err := ml.Append(msg); err != nil { + uc.logger.Printf("failed to log message: %v", err) } } diff --git a/user.go b/user.go index af4d97f..04c77a9 100644 --- a/user.go +++ b/user.go @@ -207,8 +207,10 @@ func (u *user) run() { uc.network.conn = nil uc.network.lock.Unlock() - for _, log := range uc.logs { - log.file.Close() + for _, ml := range uc.messageLoggers { + if err := ml.Close(); err != nil { + uc.logger.Printf("failed to close message logger: %v", err) + } } uc.endPendingLISTs(true)