]> git.r.bdr.sh - rbdr/mobius/blobdiff - hotline/server.go
Improve logging readability
[rbdr/mobius] / hotline / server.go
index ba0a6689c619251620e28a4dab4c195ea024fb04..0677a813a6d48da4a2aaf99fca228d0c1a28c366 100644 (file)
@@ -43,12 +43,14 @@ const (
 var nostalgiaVersion = []byte{0, 0, 2, 0x2c} // version ID used by the Nostalgia client
 
 type Server struct {
 var nostalgiaVersion = []byte{0, 0, 2, 0x2c} // version ID used by the Nostalgia client
 
 type Server struct {
-       Port          int
-       Accounts      map[string]*Account
-       Agreement     []byte
-       Clients       map[uint16]*ClientConn
-       ThreadedNews  *ThreadedNews
-       FileTransfers map[uint32]*FileTransfer
+       Port         int
+       Accounts     map[string]*Account
+       Agreement    []byte
+       Clients      map[uint16]*ClientConn
+       ThreadedNews *ThreadedNews
+
+       fileTransfers map[[4]byte]*FileTransfer
+
        Config        *Config
        ConfigDir     string
        Logger        *zap.SugaredLogger
        Config        *Config
        ConfigDir     string
        Logger        *zap.SugaredLogger
@@ -167,26 +169,33 @@ func (s *Server) sendTransaction(t Transaction) error {
        return nil
 }
 
        return nil
 }
 
+func (s *Server) processOutbox() {
+       for {
+               t := <-s.outbox
+               go func() {
+                       if err := s.sendTransaction(t); err != nil {
+                               s.Logger.Errorw("error sending transaction", "err", err)
+                       }
+               }()
+       }
+}
+
 func (s *Server) Serve(ctx context.Context, ln net.Listener) error {
 func (s *Server) Serve(ctx context.Context, ln net.Listener) error {
+       go s.processOutbox()
+
        for {
                conn, err := ln.Accept()
                if err != nil {
                        s.Logger.Errorw("error accepting connection", "err", err)
                }
        for {
                conn, err := ln.Accept()
                if err != nil {
                        s.Logger.Errorw("error accepting connection", "err", err)
                }
+               connCtx := context.WithValue(ctx, contextKeyReq, requestCtx{
+                       remoteAddr: conn.RemoteAddr().String(),
+               })
 
                go func() {
 
                go func() {
-                       for {
-                               t := <-s.outbox
-                               go func() {
-                                       if err := s.sendTransaction(t); err != nil {
-                                               s.Logger.Errorw("error sending transaction", "err", err)
-                                       }
-                               }()
-                       }
-               }()
-               go func() {
-                       if err := s.handleNewConnection(ctx, conn, conn.RemoteAddr().String()); err != nil {
-                               s.Logger.Infow("New client connection established", "RemoteAddr", conn.RemoteAddr())
+                       s.Logger.Infow("Connection established", "RemoteAddr", conn.RemoteAddr())
+
+                       if err := s.handleNewConnection(connCtx, conn, conn.RemoteAddr().String()); err != nil {
                                if err == io.EOF {
                                        s.Logger.Infow("Client disconnected", "RemoteAddr", conn.RemoteAddr())
                                } else {
                                if err == io.EOF {
                                        s.Logger.Infow("Client disconnected", "RemoteAddr", conn.RemoteAddr())
                                } else {
@@ -208,7 +217,7 @@ func NewServer(configDir string, netPort int, logger *zap.SugaredLogger, FS File
                Accounts:      make(map[string]*Account),
                Config:        new(Config),
                Clients:       make(map[uint16]*ClientConn),
                Accounts:      make(map[string]*Account),
                Config:        new(Config),
                Clients:       make(map[uint16]*ClientConn),
-               FileTransfers: make(map[uint32]*FileTransfer),
+               fileTransfers: make(map[[4]byte]*FileTransfer),
                PrivateChats:  make(map[uint32]*PrivateChat),
                ConfigDir:     configDir,
                Logger:        logger,
                PrivateChats:  make(map[uint32]*PrivateChat),
                ConfigDir:     configDir,
                Logger:        logger,
@@ -335,7 +344,7 @@ func (s *Server) writeThreadedNews() error {
        return err
 }
 
        return err
 }
 
-func (s *Server) NewClientConn(conn net.Conn, remoteAddr string) *ClientConn {
+func (s *Server) NewClientConn(conn io.ReadWriteCloser, remoteAddr string) *ClientConn {
        s.mux.Lock()
        defer s.mux.Unlock()
 
        s.mux.Lock()
        defer s.mux.Unlock()
 
@@ -348,10 +357,18 @@ func (s *Server) NewClientConn(conn net.Conn, remoteAddr string) *ClientConn {
                Server:     s,
                Version:    &[]byte{},
                AutoReply:  []byte{},
                Server:     s,
                Version:    &[]byte{},
                AutoReply:  []byte{},
-               Transfers:  make(map[int][]*FileTransfer),
+               transfers:  map[int]map[[4]byte]*FileTransfer{},
                Agreed:     false,
                RemoteAddr: remoteAddr,
        }
                Agreed:     false,
                RemoteAddr: remoteAddr,
        }
+       clientConn.transfers = map[int]map[[4]byte]*FileTransfer{
+               FileDownload:   {},
+               FileUpload:     {},
+               FolderDownload: {},
+               FolderUpload:   {},
+               bannerDownload: {},
+       }
+
        *s.NextGuestID++
        ID := *s.NextGuestID
 
        *s.NextGuestID++
        ID := *s.NextGuestID
 
@@ -515,7 +532,7 @@ func dontPanic(logger *zap.SugaredLogger) {
 }
 
 // handleNewConnection takes a new net.Conn and performs the initial login sequence
 }
 
 // handleNewConnection takes a new net.Conn and performs the initial login sequence
-func (s *Server) handleNewConnection(ctx context.Context, conn net.Conn, remoteAddr string) error {
+func (s *Server) handleNewConnection(ctx context.Context, conn io.ReadWriteCloser, remoteAddr string) error {
        defer dontPanic(s.Logger)
 
        if err := Handshake(conn); err != nil {
        defer dontPanic(s.Logger)
 
        if err := Handshake(conn); err != nil {
@@ -552,6 +569,8 @@ func (s *Server) handleNewConnection(ctx context.Context, conn net.Conn, remoteA
                login = GuestAccount
        }
 
                login = GuestAccount
        }
 
+       c.logger = s.Logger.With("remoteAddr", remoteAddr, "login", login)
+
        // If authentication fails, send error reply and close connection
        if !c.Authenticate(login, encodedPassword) {
                t := c.NewErrReply(clientLogin, "Incorrect login.")
        // If authentication fails, send error reply and close connection
        if !c.Authenticate(login, encodedPassword) {
                t := c.NewErrReply(clientLogin, "Incorrect login.")
@@ -562,7 +581,10 @@ func (s *Server) handleNewConnection(ctx context.Context, conn net.Conn, remoteA
                if _, err := conn.Write(b); err != nil {
                        return err
                }
                if _, err := conn.Write(b); err != nil {
                        return err
                }
-               return fmt.Errorf("incorrect login")
+
+               c.logger.Infow("Login failed", "clientVersion", fmt.Sprintf("%x", *c.Version))
+
+               return nil
        }
 
        if clientLogin.GetField(fieldUserName).Data != nil {
        }
 
        if clientLogin.GetField(fieldUserName).Data != nil {
@@ -579,11 +601,9 @@ func (s *Server) handleNewConnection(ctx context.Context, conn net.Conn, remoteA
                *c.Flags = []byte{0, 2}
        }
 
                *c.Flags = []byte{0, 2}
        }
 
-       s.Logger.Infow("Client connection received", "login", login, "version", *c.Version, "RemoteAddr", remoteAddr)
-
        s.outbox <- c.NewReply(clientLogin,
                NewField(fieldVersion, []byte{0x00, 0xbe}),
        s.outbox <- c.NewReply(clientLogin,
                NewField(fieldVersion, []byte{0x00, 0xbe}),
-               NewField(fieldCommunityBannerID, []byte{0x00, 0x01}),
+               NewField(fieldCommunityBannerID, []byte{0, 0}),
                NewField(fieldServerName, []byte(s.Config.Name)),
        )
 
                NewField(fieldServerName, []byte(s.Config.Name)),
        )
 
@@ -596,8 +616,10 @@ func (s *Server) handleNewConnection(ctx context.Context, conn net.Conn, remoteA
        // 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
        // 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
+               c.logger = c.logger.With("name", string(c.UserName))
+               c.logger.Infow("Login successful", "clientVersion", fmt.Sprintf("%x", *c.Version))
 
 
-               c.notifyOthers(
+               for _, t := range c.notifyOthers(
                        *NewTransaction(
                                tranNotifyChangeUser, nil,
                                NewField(fieldUserName, c.UserName),
                        *NewTransaction(
                                tranNotifyChangeUser, nil,
                                NewField(fieldUserName, c.UserName),
@@ -605,7 +627,9 @@ func (s *Server) handleNewConnection(ctx context.Context, conn net.Conn, remoteA
                                NewField(fieldUserIconID, *c.Icon),
                                NewField(fieldUserFlags, *c.Flags),
                        ),
                                NewField(fieldUserIconID, *c.Icon),
                                NewField(fieldUserFlags, *c.Flags),
                        ),
-               )
+               ) {
+                       c.Server.outbox <- t
+               }
        }
 
        c.Server.Stats.LoginCount += 1
        }
 
        c.Server.Stats.LoginCount += 1
@@ -628,28 +652,18 @@ func (s *Server) handleNewConnection(ctx context.Context, conn net.Conn, remoteA
                // into a slice of transactions
                var transactions []Transaction
                if transactions, tReadlen, err = readTransactions(tranBuff); err != nil {
                // into a slice of transactions
                var transactions []Transaction
                if transactions, tReadlen, err = readTransactions(tranBuff); err != nil {
-                       c.Server.Logger.Errorw("Error handling transaction", "err", err)
+                       c.logger.Errorw("Error handling transaction", "err", err)
                }
 
                // iterate over all the transactions that were parsed from the byte slice and handle them
                for _, t := range transactions {
                        if err := c.handleTransaction(&t); err != nil {
                }
 
                // iterate over all the transactions that were parsed from the byte slice and handle them
                for _, t := range transactions {
                        if err := c.handleTransaction(&t); err != nil {
-                               c.Server.Logger.Errorw("Error handling transaction", "err", err)
+                               c.logger.Errorw("Error handling transaction", "err", err)
                        }
                }
        }
 }
 
                        }
                }
        }
 }
 
-// NewTransactionRef generates a random ID for the file transfer.  The Hotline client includes this ID
-// in the transfer request payload, and the file transfer server will use it to map the request
-// to a transfer
-func (s *Server) NewTransactionRef() []byte {
-       transactionRef := make([]byte, 4)
-       rand.Read(transactionRef)
-
-       return transactionRef
-}
-
 func (s *Server) NewPrivateChat(cc *ClientConn) []byte {
        s.mux.Lock()
        defer s.mux.Unlock()
 func (s *Server) NewPrivateChat(cc *ClientConn) []byte {
        s.mux.Lock()
        defer s.mux.Unlock()
@@ -685,52 +699,62 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                return err
        }
 
                return err
        }
 
-       transferRefNum := binary.BigEndian.Uint32(t.ReferenceNumber[:])
        defer func() {
                s.mux.Lock()
        defer func() {
                s.mux.Lock()
-               delete(s.FileTransfers, transferRefNum)
+               delete(s.fileTransfers, t.ReferenceNumber)
                s.mux.Unlock()
                s.mux.Unlock()
+
        }()
 
        s.mux.Lock()
        }()
 
        s.mux.Lock()
-       fileTransfer, ok := s.FileTransfers[transferRefNum]
+       fileTransfer, ok := s.fileTransfers[t.ReferenceNumber]
        s.mux.Unlock()
        if !ok {
                return errors.New("invalid transaction ID")
        }
 
        s.mux.Unlock()
        if !ok {
                return errors.New("invalid transaction ID")
        }
 
+       defer func() {
+               fileTransfer.ClientConn.transfersMU.Lock()
+               delete(fileTransfer.ClientConn.transfers[fileTransfer.Type], t.ReferenceNumber)
+               fileTransfer.ClientConn.transfersMU.Unlock()
+       }()
+
        rLogger := s.Logger.With(
                "remoteAddr", ctx.Value(contextKeyReq).(requestCtx).remoteAddr,
        rLogger := s.Logger.With(
                "remoteAddr", ctx.Value(contextKeyReq).(requestCtx).remoteAddr,
-               "xferID", transferRefNum,
+               "login", fileTransfer.ClientConn.Account.Login,
+               "name", string(fileTransfer.ClientConn.UserName),
        )
 
        )
 
-       switch fileTransfer.Type {
-       case FileDownload:
-               s.Stats.DownloadCounter += 1
+       fullPath, err := readPath(s.Config.FileRoot, fileTransfer.FilePath, fileTransfer.FileName)
+       if err != nil {
+               return err
+       }
 
 
-               fullFilePath, err := readPath(s.Config.FileRoot, fileTransfer.FilePath, fileTransfer.FileName)
-               if err != nil {
+       switch fileTransfer.Type {
+       case bannerDownload:
+               if err := s.bannerDownload(rwc); err != nil {
+                       panic(err)
                        return err
                }
                        return err
                }
+       case FileDownload:
+               s.Stats.DownloadCounter += 1
 
                var dataOffset int64
                if fileTransfer.fileResumeData != nil {
                        dataOffset = int64(binary.BigEndian.Uint32(fileTransfer.fileResumeData.ForkInfoList[0].DataSize[:]))
                }
 
 
                var dataOffset int64
                if fileTransfer.fileResumeData != nil {
                        dataOffset = int64(binary.BigEndian.Uint32(fileTransfer.fileResumeData.ForkInfoList[0].DataSize[:]))
                }
 
-               fw, err := newFileWrapper(s.FS, fullFilePath, 0)
+               fw, err := newFileWrapper(s.FS, fullPath, 0)
                if err != nil {
                        return err
                }
 
                if err != nil {
                        return err
                }
 
-               rLogger.Infow("File download started", "filePath", fullFilePath, "transactionRef", fileTransfer.ReferenceNumber)
-
-               wr := bufio.NewWriterSize(rwc, 1460)
+               rLogger.Infow("File download started", "filePath", fullPath)
 
                // if file transfer options are included, that means this is a "quick preview" request from a 1.5+ client
                if fileTransfer.options == nil {
                        // Start by sending flat file object to client
 
                // if file transfer options are included, that means this is a "quick preview" request from a 1.5+ client
                if fileTransfer.options == nil {
                        // Start by sending flat file object to client
-                       if _, err := wr.Write(fw.ffo.BinaryMarshal()); err != nil {
+                       if _, err := rwc.Write(fw.ffo.BinaryMarshal()); err != nil {
                                return err
                        }
                }
                                return err
                        }
                }
@@ -740,23 +764,21 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                        return err
                }
 
                        return err
                }
 
-               if err := sendFile(wr, file, int(dataOffset)); err != nil {
+               br := bufio.NewReader(file)
+               if _, err := br.Discard(int(dataOffset)); err != nil {
                        return err
                }
 
                        return err
                }
 
-               if err := wr.Flush(); err != nil {
+               if _, err = io.Copy(rwc, io.TeeReader(br, fileTransfer.bytesSentCounter)); err != nil {
                        return err
                }
 
                        return err
                }
 
-               // if the client requested to resume transfer, do not send the resource fork, or it will be appended into the fileWrapper data
+               // if the client requested to resume transfer, do not send the resource fork header, or it will be appended into the fileWrapper data
                if fileTransfer.fileResumeData == nil {
                if fileTransfer.fileResumeData == nil {
-                       err = binary.Write(wr, binary.BigEndian, fw.rsrcForkHeader())
+                       err = binary.Write(rwc, binary.BigEndian, fw.rsrcForkHeader())
                        if err != nil {
                                return err
                        }
                        if err != nil {
                                return err
                        }
-                       if err := wr.Flush(); err != nil {
-                               return err
-                       }
                }
 
                rFile, err := fw.rsrcForkFile()
                }
 
                rFile, err := fw.rsrcForkFile()
@@ -764,20 +786,13 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                        return nil
                }
 
                        return nil
                }
 
-               err = sendFile(wr, rFile, int(dataOffset))
-
-               if err := wr.Flush(); err != nil {
+               if _, err = io.Copy(rwc, io.TeeReader(rFile, fileTransfer.bytesSentCounter)); err != nil {
                        return err
                }
 
        case FileUpload:
                s.Stats.UploadCounter += 1
 
                        return err
                }
 
        case FileUpload:
                s.Stats.UploadCounter += 1
 
-               destinationFile, err := readPath(s.Config.FileRoot, fileTransfer.FilePath, fileTransfer.FileName)
-               if err != nil {
-                       return err
-               }
-
                var file *os.File
 
                // A file upload has three possible cases:
                var file *os.File
 
                // A file upload has three possible cases:
@@ -787,28 +802,24 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                //  We have to infer which case applies by inspecting what is already on the filesystem
 
                // 1) Check for existing file:
                //  We have to infer which case applies by inspecting what is already on the filesystem
 
                // 1) Check for existing file:
-               _, err = os.Stat(destinationFile)
+               _, err = os.Stat(fullPath)
                if err == nil {
                if err == nil {
-                       // If found, that means this upload is intended to replace the file
-                       if err = os.Remove(destinationFile); err != nil {
-                               return err
-                       }
-                       file, err = os.Create(destinationFile + incompleteFileSuffix)
+                       return errors.New("existing file found at " + fullPath)
                }
                if errors.Is(err, fs.ErrNotExist) {
                        // If not found, open or create a new .incomplete file
                }
                if errors.Is(err, fs.ErrNotExist) {
                        // If not found, open or create a new .incomplete file
-                       file, err = os.OpenFile(destinationFile+incompleteFileSuffix, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0644)
+                       file, err = os.OpenFile(fullPath+incompleteFileSuffix, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0644)
                        if err != nil {
                                return err
                        }
                }
 
                        if err != nil {
                                return err
                        }
                }
 
-               f, err := newFileWrapper(s.FS, destinationFile, 0)
+               f, err := newFileWrapper(s.FS, fullPath, 0)
                if err != nil {
                        return err
                }
 
                if err != nil {
                        return err
                }
 
-               s.Logger.Infow("File upload started", "transactionRef", fileTransfer.ReferenceNumber, "dstFile", destinationFile)
+               rLogger.Infow("File upload started", "dstFile", fullPath)
 
                rForkWriter := io.Discard
                iForkWriter := io.Discard
 
                rForkWriter := io.Discard
                iForkWriter := io.Discard
@@ -824,19 +835,19 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                        }
                }
 
                        }
                }
 
-               if err := receiveFile(rwc, file, rForkWriter, iForkWriter); err != nil {
-                       return err
+               if err := receiveFile(rwc, file, rForkWriter, iForkWriter, fileTransfer.bytesSentCounter); err != nil {
+                       s.Logger.Error(err)
                }
 
                if err := file.Close(); err != nil {
                        return err
                }
                }
 
                if err := file.Close(); err != nil {
                        return err
                }
-               
-               if err := s.FS.Rename(destinationFile+".incomplete", destinationFile); err != nil {
+
+               if err := s.FS.Rename(fullPath+".incomplete", fullPath); err != nil {
                        return err
                }
 
                        return err
                }
 
-               s.Logger.Infow("File upload complete", "transactionRef", fileTransfer.ReferenceNumber, "dstFile", destinationFile)
+               rLogger.Infow("File upload complete", "dstFile", fullPath)
        case FolderDownload:
                // Folder Download flow:
                // 1. Get filePath from the transfer
        case FolderDownload:
                // Folder Download flow:
                // 1. Get filePath from the transfer
@@ -865,14 +876,9 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                //
                // This notifies the server to send the next item header
 
                //
                // This notifies the server to send the next item header
 
-               fullFilePath, err := readPath(s.Config.FileRoot, fileTransfer.FilePath, fileTransfer.FileName)
-               if err != nil {
-                       return err
-               }
-
-               basePathLen := len(fullFilePath)
+               basePathLen := len(fullPath)
 
 
-               s.Logger.Infow("Start folder download", "path", fullFilePath, "ReferenceNumber", fileTransfer.ReferenceNumber)
+               rLogger.Infow("Start folder download", "path", fullPath)
 
                nextAction := make([]byte, 2)
                if _, err := io.ReadFull(rwc, nextAction); err != nil {
 
                nextAction := make([]byte, 2)
                if _, err := io.ReadFull(rwc, nextAction); err != nil {
@@ -880,7 +886,7 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                }
 
                i := 0
                }
 
                i := 0
-               err = filepath.Walk(fullFilePath+"/", func(path string, info os.FileInfo, err error) error {
+               err = filepath.Walk(fullPath+"/", func(path string, info os.FileInfo, err error) error {
                        s.Stats.DownloadCounter += 1
                        i += 1
 
                        s.Stats.DownloadCounter += 1
                        i += 1
 
@@ -899,7 +905,7 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                        }
 
                        subPath := path[basePathLen+1:]
                        }
 
                        subPath := path[basePathLen+1:]
-                       s.Logger.Infow("Sending fileheader", "i", i, "path", path, "fullFilePath", fullFilePath, "subPath", subPath, "IsDir", info.IsDir())
+                       rLogger.Debugw("Sending fileheader", "i", i, "path", path, "fullFilePath", fullPath, "subPath", subPath, "IsDir", info.IsDir())
 
                        if i == 1 {
                                return nil
 
                        if i == 1 {
                                return nil
@@ -918,7 +924,7 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                                return err
                        }
 
                                return err
                        }
 
-                       s.Logger.Infow("Client folder download action", "action", fmt.Sprintf("%X", nextAction[0:2]))
+                       rLogger.Debugw("Client folder download action", "action", fmt.Sprintf("%X", nextAction[0:2]))
 
                        var dataOffset int64
 
 
                        var dataOffset int64
 
@@ -950,9 +956,8 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                                return nil
                        }
 
                                return nil
                        }
 
-                       s.Logger.Infow("File download started",
+                       rLogger.Infow("File download started",
                                "fileName", info.Name(),
                                "fileName", info.Name(),
-                               "transactionRef", fileTransfer.ReferenceNumber,
                                "TransferSize", fmt.Sprintf("%x", hlFile.ffo.TransferSize(dataOffset)),
                        )
 
                                "TransferSize", fmt.Sprintf("%x", hlFile.ffo.TransferSize(dataOffset)),
                        )
 
@@ -974,8 +979,7 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                        }
 
                        // wr := bufio.NewWriterSize(rwc, 1460)
                        }
 
                        // wr := bufio.NewWriterSize(rwc, 1460)
-                       err = sendFile(rwc, file, int(dataOffset))
-                       if err != nil {
+                       if _, err = io.Copy(rwc, io.TeeReader(file, fileTransfer.bytesSentCounter)); err != nil {
                                return err
                        }
 
                                return err
                        }
 
@@ -990,8 +994,7 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                                        return err
                                }
 
                                        return err
                                }
 
-                               err = sendFile(rwc, rFile, int(dataOffset))
-                               if err != nil {
+                               if _, err = io.Copy(rwc, io.TeeReader(rFile, fileTransfer.bytesSentCounter)); err != nil {
                                        return err
                                }
                        }
                                        return err
                                }
                        }
@@ -1004,23 +1007,21 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                        return nil
                })
 
                        return nil
                })
 
-       case FolderUpload:
-               dstPath, err := readPath(s.Config.FileRoot, fileTransfer.FilePath, fileTransfer.FileName)
                if err != nil {
                        return err
                }
 
                if err != nil {
                        return err
                }
 
-               s.Logger.Infow(
+       case FolderUpload:
+               rLogger.Infow(
                        "Folder upload started",
                        "Folder upload started",
-                       "transactionRef", fileTransfer.ReferenceNumber,
-                       "dstPath", dstPath,
-                       "TransferSize", fmt.Sprintf("%x", fileTransfer.TransferSize),
+                       "dstPath", fullPath,
+                       "TransferSize", binary.BigEndian.Uint32(fileTransfer.TransferSize),
                        "FolderItemCount", fileTransfer.FolderItemCount,
                )
 
                // Check if the target folder exists.  If not, create it.
                        "FolderItemCount", fileTransfer.FolderItemCount,
                )
 
                // Check if the target folder exists.  If not, create it.
-               if _, err := s.FS.Stat(dstPath); os.IsNotExist(err) {
-                       if err := s.FS.Mkdir(dstPath, 0777); err != nil {
+               if _, err := s.FS.Stat(fullPath); os.IsNotExist(err) {
+                       if err := s.FS.Mkdir(fullPath, 0777); err != nil {
                                return err
                        }
                }
                                return err
                        }
                }
@@ -1052,17 +1053,16 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                                return err
                        }
 
                                return err
                        }
 
-                       s.Logger.Infow(
+                       rLogger.Infow(
                                "Folder upload continued",
                                "Folder upload continued",
-                               "transactionRef", fmt.Sprintf("%x", fileTransfer.ReferenceNumber),
                                "FormattedPath", fu.FormattedPath(),
                                "IsFolder", fmt.Sprintf("%x", fu.IsFolder),
                                "PathItemCount", binary.BigEndian.Uint16(fu.PathItemCount[:]),
                        )
 
                        if fu.IsFolder == [2]byte{0, 1} {
                                "FormattedPath", fu.FormattedPath(),
                                "IsFolder", fmt.Sprintf("%x", fu.IsFolder),
                                "PathItemCount", binary.BigEndian.Uint16(fu.PathItemCount[:]),
                        )
 
                        if fu.IsFolder == [2]byte{0, 1} {
-                               if _, err := os.Stat(filepath.Join(dstPath, fu.FormattedPath())); os.IsNotExist(err) {
-                                       if err := os.Mkdir(filepath.Join(dstPath, fu.FormattedPath()), 0777); err != nil {
+                               if _, err := os.Stat(filepath.Join(fullPath, fu.FormattedPath())); os.IsNotExist(err) {
+                                       if err := os.Mkdir(filepath.Join(fullPath, fu.FormattedPath()), 0777); err != nil {
                                                return err
                                        }
                                }
                                                return err
                                        }
                                }
@@ -1075,7 +1075,7 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                                nextAction := dlFldrActionSendFile
 
                                // Check if we have the full file already.  If so, send dlFldrAction_NextFile to client to skip.
                                nextAction := dlFldrActionSendFile
 
                                // Check if we have the full file already.  If so, send dlFldrAction_NextFile to client to skip.
-                               _, err = os.Stat(filepath.Join(dstPath, fu.FormattedPath()))
+                               _, err = os.Stat(filepath.Join(fullPath, fu.FormattedPath()))
                                if err != nil && !errors.Is(err, fs.ErrNotExist) {
                                        return err
                                }
                                if err != nil && !errors.Is(err, fs.ErrNotExist) {
                                        return err
                                }
@@ -1084,7 +1084,7 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                                }
 
                                //  Check if we have a partial file already.  If so, send dlFldrAction_ResumeFile to client to resume upload.
                                }
 
                                //  Check if we have a partial file already.  If so, send dlFldrAction_ResumeFile to client to resume upload.
-                               incompleteFile, err := os.Stat(filepath.Join(dstPath, fu.FormattedPath()+incompleteFileSuffix))
+                               incompleteFile, err := os.Stat(filepath.Join(fullPath, fu.FormattedPath()+incompleteFileSuffix))
                                if err != nil && !errors.Is(err, fs.ErrNotExist) {
                                        return err
                                }
                                if err != nil && !errors.Is(err, fs.ErrNotExist) {
                                        return err
                                }
@@ -1103,7 +1103,7 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                                        offset := make([]byte, 4)
                                        binary.BigEndian.PutUint32(offset, uint32(incompleteFile.Size()))
 
                                        offset := make([]byte, 4)
                                        binary.BigEndian.PutUint32(offset, uint32(incompleteFile.Size()))
 
-                                       file, err := os.OpenFile(dstPath+"/"+fu.FormattedPath()+incompleteFileSuffix, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
+                                       file, err := os.OpenFile(fullPath+"/"+fu.FormattedPath()+incompleteFileSuffix, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
                                        if err != nil {
                                                return err
                                        }
                                        if err != nil {
                                                return err
                                        }
@@ -1123,11 +1123,11 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                                                return err
                                        }
 
                                                return err
                                        }
 
-                                       if err := receiveFile(rwc, file, ioutil.Discard, ioutil.Discard); err != nil {
+                                       if err := receiveFile(rwc, file, ioutil.Discard, ioutil.Discard, fileTransfer.bytesSentCounter); err != nil {
                                                s.Logger.Error(err)
                                        }
 
                                                s.Logger.Error(err)
                                        }
 
-                                       err = os.Rename(dstPath+"/"+fu.FormattedPath()+".incomplete", dstPath+"/"+fu.FormattedPath())
+                                       err = os.Rename(fullPath+"/"+fu.FormattedPath()+".incomplete", fullPath+"/"+fu.FormattedPath())
                                        if err != nil {
                                                return err
                                        }
                                        if err != nil {
                                                return err
                                        }
@@ -1137,14 +1137,14 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                                                return err
                                        }
 
                                                return err
                                        }
 
-                                       filePath := filepath.Join(dstPath, fu.FormattedPath())
+                                       filePath := filepath.Join(fullPath, fu.FormattedPath())
 
                                        hlFile, err := newFileWrapper(s.FS, filePath, 0)
                                        if err != nil {
                                                return err
                                        }
 
 
                                        hlFile, err := newFileWrapper(s.FS, filePath, 0)
                                        if err != nil {
                                                return err
                                        }
 
-                                       s.Logger.Infow("Starting file transfer", "path", filePath, "fileNum", i+1, "fileSize", binary.BigEndian.Uint32(fileSize))
+                                       rLogger.Infow("Starting file transfer", "path", filePath, "fileNum", i+1, "fileSize", binary.BigEndian.Uint32(fileSize))
 
                                        incWriter, err := hlFile.incFileWriter()
                                        if err != nil {
 
                                        incWriter, err := hlFile.incFileWriter()
                                        if err != nil {
@@ -1164,10 +1164,10 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                                                        return err
                                                }
                                        }
                                                        return err
                                                }
                                        }
-                                       if err := receiveFile(rwc, incWriter, rForkWriter, iForkWriter); err != nil {
+                                       if err := receiveFile(rwc, incWriter, rForkWriter, iForkWriter, fileTransfer.bytesSentCounter); err != nil {
                                                return err
                                        }
                                                return err
                                        }
-                                       // _ = newFile.Close()
+
                                        if err := os.Rename(filePath+".incomplete", filePath); err != nil {
                                                return err
                                        }
                                        if err := os.Rename(filePath+".incomplete", filePath); err != nil {
                                                return err
                                        }
@@ -1179,7 +1179,7 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro
                                }
                        }
                }
                                }
                        }
                }
-               s.Logger.Infof("Folder upload complete")
+               rLogger.Infof("Folder upload complete")
        }
 
        return nil
        }
 
        return nil