]> git.r.bdr.sh - rbdr/mobius/blobdiff - hotline/server.go
Fix regression in 1.5 login behavior
[rbdr/mobius] / hotline / server.go
index 392c8f31ac47364f356f77614585753d260d048d..3e4ba2f08f90d1f9db317085c0873f82930292ac 100644 (file)
@@ -2,7 +2,6 @@ package hotline
 
 import (
        "bufio"
-       "bytes"
        "context"
        "encoding/binary"
        "errors"
@@ -18,7 +17,6 @@ import (
        "net"
        "os"
        "path/filepath"
-       "runtime/debug"
        "strings"
        "sync"
        "time"
@@ -34,14 +32,6 @@ type requestCtx struct {
        name       string
 }
 
-const (
-       userIdleSeconds        = 300 // time in seconds before an inactive user is marked idle
-       idleCheckInterval      = 10  // time in seconds to check for idle users
-       trackerUpdateFrequency = 300 // time in seconds between tracker re-registration
-)
-
-var nostalgiaVersion = []byte{0, 0, 2, 0x2c} // version ID used by the Nostalgia client
-
 type Server struct {
        Port          int
        Accounts      map[string]*Account
@@ -49,13 +39,18 @@ type Server struct {
        Clients       map[uint16]*ClientConn
        fileTransfers map[[4]byte]*FileTransfer
 
-       Config        *Config
-       ConfigDir     string
-       Logger        *zap.SugaredLogger
-       PrivateChats  map[uint32]*PrivateChat
+       Config    *Config
+       ConfigDir string
+       Logger    *zap.SugaredLogger
+
+       PrivateChatsMu sync.Mutex
+       PrivateChats   map[uint32]*PrivateChat
+
        NextGuestID   *uint16
        TrackerPassID [4]byte
-       Stats         *Stats
+
+       StatsMu sync.Mutex
+       Stats   *Stats
 
        FS FileStore // Storage backend to use for File storage
 
@@ -72,6 +67,16 @@ type Server struct {
        banList   map[string]*time.Time
 }
 
+func (s *Server) CurrentStats() Stats {
+       s.StatsMu.Lock()
+       defer s.StatsMu.Unlock()
+
+       stats := s.Stats
+       stats.CurrentlyConnected = len(s.Clients)
+
+       return *stats
+}
+
 type PrivateChat struct {
        Subject    string
        ClientConn map[uint16]*ClientConn
@@ -144,18 +149,18 @@ func (s *Server) sendTransaction(t Transaction) error {
 
        s.mux.Lock()
        client := s.Clients[uint16(clientID)]
+       s.mux.Unlock()
        if client == nil {
                return fmt.Errorf("invalid client id %v", *t.clientID)
        }
 
-       s.mux.Unlock()
-
        b, err := t.MarshalBinary()
        if err != nil {
                return err
        }
 
-       if _, err := client.Connection.Write(b); err != nil {
+       _, err = client.Connection.Write(b)
+       if err != nil {
                return err
        }
 
@@ -217,7 +222,7 @@ func NewServer(configDir string, netPort int, logger *zap.SugaredLogger, FS File
                Logger:        logger,
                NextGuestID:   new(uint16),
                outbox:        make(chan Transaction),
-               Stats:         &Stats{StartTime: time.Now()},
+               Stats:         &Stats{Since: time.Now()},
                ThreadedNews:  &ThreadedNews{},
                FS:            FS,
                banList:       make(map[string]*time.Time),
@@ -278,7 +283,7 @@ func NewServer(configDir string, netPort int, logger *zap.SugaredLogger, FS File
                                        if err := register(t, tr); err != nil {
                                                server.Logger.Errorw("unable to register with tracker %v", "error", err)
                                        }
-                                       server.Logger.Infow("Sent Tracker registration", "data", tr)
+                                       server.Logger.Debugw("Sent Tracker registration", "addr", t)
                                }
 
                                time.Sleep(trackerUpdateFrequency * time.Second)
@@ -372,7 +377,6 @@ func (s *Server) NewClientConn(conn io.ReadWriteCloser, remoteAddr string) *Clie
                Version:    []byte{},
                AutoReply:  []byte{},
                transfers:  map[int]map[[4]byte]*FileTransfer{},
-               Agreed:     false,
                RemoteAddr: remoteAddr,
        }
        clientConn.transfers = map[int]map[[4]byte]*FileTransfer{
@@ -459,9 +463,6 @@ func (s *Server) connectedUsers() []Field {
 
        var connectedUsers []Field
        for _, c := range sortedClients(s.Clients) {
-               if !c.Agreed {
-                       continue
-               }
                user := User{
                        ID:    *c.ID,
                        Icon:  c.Icon,
@@ -542,14 +543,6 @@ func (s *Server) loadConfig(path string) error {
        return nil
 }
 
-// dontPanic logs panics instead of crashing
-func dontPanic(logger *zap.SugaredLogger) {
-       if r := recover(); r != nil {
-               fmt.Println("stacktrace from panic: \n" + string(debug.Stack()))
-               logger.Errorw("PANIC", "err", r, "trace", string(debug.Stack()))
-       }
-}
-
 // handleNewConnection takes a new net.Conn and performs the initial login sequence
 func (s *Server) handleNewConnection(ctx context.Context, rwc io.ReadWriteCloser, remoteAddr string) error {
        defer dontPanic(s.Logger)
@@ -564,9 +557,14 @@ func (s *Server) handleNewConnection(ctx context.Context, rwc io.ReadWriteCloser
 
        scanner.Scan()
 
-       clientLogin, _, err := ReadTransaction(scanner.Bytes())
-       if err != nil {
-               panic(err)
+       // Make a new []byte slice and copy the scanner bytes to it.  This is critical to avoid a data race as the
+       // scanner re-uses the buffer for subsequent scans.
+       buf := make([]byte, len(scanner.Bytes()))
+       copy(buf, scanner.Bytes())
+
+       var clientLogin Transaction
+       if _, err := clientLogin.Write(buf); err != nil {
+               return err
        }
 
        c := s.NewClientConn(rwc, remoteAddr)
@@ -613,7 +611,7 @@ func (s *Server) handleNewConnection(ctx context.Context, rwc io.ReadWriteCloser
 
        // If authentication fails, send error reply and close connection
        if !c.Authenticate(login, encodedPassword) {
-               t := c.NewErrReply(clientLogin, "Incorrect login.")
+               t := c.NewErrReply(&clientLogin, "Incorrect login.")
                b, err := t.MarshalBinary()
                if err != nil {
                        return err
@@ -645,7 +643,7 @@ func (s *Server) handleNewConnection(ctx context.Context, rwc io.ReadWriteCloser
                c.Flags = []byte{0, 2}
        }
 
-       s.outbox <- c.NewReply(clientLogin,
+       s.outbox <- c.NewReply(&clientLogin,
                NewField(fieldVersion, []byte{0x00, 0xbe}),
                NewField(fieldCommunityBannerID, []byte{0, 0}),
                NewField(fieldServerName, []byte(s.Config.Name)),
@@ -666,12 +664,17 @@ func (s *Server) handleNewConnection(ctx context.Context, rwc io.ReadWriteCloser
                c.Server.outbox <- *NewTransaction(tranShowAgreement, c.ID, NewField(fieldData, s.Agreement))
        }
 
-       // Used simplified hotline v1.2.3 login flow for clients that do not send login info in tranAgreed
-       if c.Version == nil || bytes.Equal(c.Version, nostalgiaVersion) {
-               c.Agreed = true
+       // If the client has provided a username as part of the login, we can infer that it is using the 1.2.3 login
+       // flow and not the 1.5+ flow.
+       if len(c.UserName) != 0 {
+               // Add the client username to the logger.  For 1.5+ clients, we don't have this information yet as it comes as
+               // part of tranAgreed
                c.logger = c.logger.With("name", string(c.UserName))
-               c.logger.Infow("Login successful", "clientVersion", fmt.Sprintf("%v", func() int { i, _ := byteToInt(c.Version); return i }()))
 
+               c.logger.Infow("Login successful", "clientVersion", "Not sent (probably 1.2.3)")
+
+               // Notify other clients on the server that the new user has logged in.  For 1.5+ clients we don't have this
+               // information yet, so we do it in tranAgreed instead
                for _, t := range c.notifyOthers(
                        *NewTransaction(
                                tranNotifyChangeUser, nil,
@@ -685,7 +688,10 @@ func (s *Server) handleNewConnection(ctx context.Context, rwc io.ReadWriteCloser
                }
        }
 
-       c.Server.Stats.LoginCount += 1
+       c.Server.Stats.ConnectionCounter += 1
+       if len(s.Clients) > c.Server.Stats.ConnectionPeak {
+               c.Server.Stats.ConnectionPeak = len(s.Clients)
+       }
 
        // Scan for new transactions and handle them as they come in.
        for scanner.Scan() {
@@ -694,11 +700,12 @@ func (s *Server) handleNewConnection(ctx context.Context, rwc io.ReadWriteCloser
                buf := make([]byte, len(scanner.Bytes()))
                copy(buf, scanner.Bytes())
 
-               t, _, err := ReadTransaction(buf)
-               if err != nil {
-                       panic(err)
+               var t Transaction
+               if _, err := t.Write(buf); err != nil {
+                       return err
                }
-               if err := c.handleTransaction(*t); err != nil {
+
+               if err := c.handleTransaction(t); err != nil {
                        c.logger.Errorw("Error handling transaction", "err", err)
                }
        }
@@ -706,15 +713,14 @@ func (s *Server) handleNewConnection(ctx context.Context, rwc io.ReadWriteCloser
 }
 
 func (s *Server) NewPrivateChat(cc *ClientConn) []byte {
-       s.mux.Lock()
-       defer s.mux.Unlock()
+       s.PrivateChatsMu.Lock()
+       defer s.PrivateChatsMu.Unlock()
 
        randID := make([]byte, 4)
        rand.Read(randID)
        data := binary.BigEndian.Uint32(randID[:])
 
        s.PrivateChats[data] = &PrivateChat{
-               Subject:    "",
                ClientConn: make(map[uint16]*ClientConn),
        }
        s.PrivateChats[data].ClientConn[cc.uint16ID()] = cc
@@ -745,6 +751,10 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                delete(s.fileTransfers, t.ReferenceNumber)
                s.mux.Unlock()
 
+               // Wait a few seconds before closing the connection: this is a workaround for problems
+               // observed with Windows clients where the client must initiate close of the TCP connection before
+               // the server does.  This is gross and seems unnecessary.  TODO: Revisit?
+               time.Sleep(3 * time.Second)
        }()
 
        s.mux.Lock()
@@ -774,11 +784,14 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
        switch fileTransfer.Type {
        case bannerDownload:
                if err := s.bannerDownload(rwc); err != nil {
-                       panic(err)
                        return err
                }
        case FileDownload:
                s.Stats.DownloadCounter += 1
+               s.Stats.DownloadsInProgress += 1
+               defer func() {
+                       s.Stats.DownloadsInProgress -= 1
+               }()
 
                var dataOffset int64
                if fileTransfer.fileResumeData != nil {
@@ -833,6 +846,8 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
 
        case FileUpload:
                s.Stats.UploadCounter += 1
+               s.Stats.UploadsInProgress += 1
+               defer func() { s.Stats.UploadsInProgress -= 1 }()
 
                var file *os.File
 
@@ -889,7 +904,12 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                }
 
                rLogger.Infow("File upload complete", "dstFile", fullPath)
+
        case FolderDownload:
+               s.Stats.DownloadCounter += 1
+               s.Stats.DownloadsInProgress += 1
+               defer func() { s.Stats.DownloadsInProgress -= 1 }()
+
                // Folder Download flow:
                // 1. Get filePath from the transfer
                // 2. Iterate over files
@@ -1053,6 +1073,9 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                }
 
        case FolderUpload:
+               s.Stats.UploadCounter += 1
+               s.Stats.UploadsInProgress += 1
+               defer func() { s.Stats.UploadsInProgress -= 1 }()
                rLogger.Infow(
                        "Folder upload started",
                        "dstPath", fullPath,