X-Git-Url: https://git.r.bdr.sh/rbdr/mobius/blobdiff_plain/f22acf38da970aa0d865a9978c9499dad01d235f..e2de9d02db38ff188fea569a5b98071a6bd403ea:/hotline/server.go?ds=sidebyside diff --git a/hotline/server.go b/hotline/server.go index 9ffd272..1aa9b1a 100644 --- a/hotline/server.go +++ b/hotline/server.go @@ -18,7 +18,6 @@ import ( "net" "os" "path/filepath" - "runtime/debug" "strings" "sync" "time" @@ -34,36 +33,52 @@ 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 +var frogblastVersion = []byte{0, 0, 0, 0xb9} // version ID used by the Frogblast 1.2.4 client type Server struct { Port int Accounts map[string]*Account Agreement []byte Clients map[uint16]*ClientConn - ThreadedNews *ThreadedNews - FileTransfers map[uint32]*FileTransfer - Config *Config - ConfigDir string - Logger *zap.SugaredLogger - PrivateChats map[uint32]*PrivateChat + fileTransfers map[[4]byte]*FileTransfer + + 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 outbox chan Transaction mux sync.Mutex + threadedNewsMux sync.Mutex + ThreadedNews *ThreadedNews + flatNewsMux sync.Mutex FlatNews []byte + + banListMU sync.Mutex + 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 { @@ -131,7 +146,6 @@ func (s *Server) ServeFileTransfers(ctx context.Context, ln net.Listener) error } func (s *Server) sendTransaction(t Transaction) error { - requestNum := binary.BigEndian.Uint16(t.Type) clientID, err := byteToInt(*t.clientID) if err != nil { return err @@ -143,50 +157,48 @@ func (s *Server) sendTransaction(t Transaction) error { if client == nil { return fmt.Errorf("invalid client id %v", *t.clientID) } - userName := string(client.UserName) - login := client.Account.Login - - handler := TransactionHandlers[requestNum] b, err := t.MarshalBinary() if err != nil { return err } - var n int - if n, err = client.Connection.Write(b); err != nil { + + _, err = client.Connection.Write(b) + if err != nil { return err } - s.Logger.Debugw("Sent Transaction", - "name", userName, - "login", login, - "IsReply", t.IsReply, - "type", handler.Name, - "sentBytes", n, - "remoteAddr", client.RemoteAddr, - ) + 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 { + go s.processOutbox() + 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() { - 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()) + + defer conn.Close() + if err := s.handleNewConnection(connCtx, conn, conn.RemoteAddr().String()); err != nil { if err == io.EOF { s.Logger.Infow("Client disconnected", "RemoteAddr", conn.RemoteAddr()) } else { @@ -208,15 +220,16 @@ func NewServer(configDir string, netPort int, logger *zap.SugaredLogger, FS File 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, 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), } var err error @@ -235,6 +248,9 @@ func NewServer(configDir string, netPort int, logger *zap.SugaredLogger, FS File return nil, err } + // try to load the ban list, but ignore errors as this file may not be present or may be empty + _ = server.loadBanList(filepath.Join(configDir, "Banlist.yaml")) + if err := server.loadThreadedNews(filepath.Join(configDir, "ThreadedNews.yaml")); err != nil { return nil, err } @@ -271,7 +287,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) @@ -302,16 +318,16 @@ func (s *Server) keepaliveHandler() { if c.IdleTime > userIdleSeconds && !c.Idle { c.Idle = true - flagBitmap := big.NewInt(int64(binary.BigEndian.Uint16(*c.Flags))) + flagBitmap := big.NewInt(int64(binary.BigEndian.Uint16(c.Flags))) flagBitmap.SetBit(flagBitmap, userFlagAway, 1) - binary.BigEndian.PutUint16(*c.Flags, uint16(flagBitmap.Int64())) + binary.BigEndian.PutUint16(c.Flags, uint16(flagBitmap.Int64())) c.sendAll( tranNotifyChangeUser, NewField(fieldUserID, *c.ID), - NewField(fieldUserFlags, *c.Flags), + NewField(fieldUserFlags, c.Flags), NewField(fieldUserName, c.UserName), - NewField(fieldUserIconID, *c.Icon), + NewField(fieldUserIconID, c.Icon), ) } } @@ -319,15 +335,31 @@ func (s *Server) keepaliveHandler() { } } +func (s *Server) writeBanList() error { + s.banListMU.Lock() + defer s.banListMU.Unlock() + + out, err := yaml.Marshal(s.banList) + if err != nil { + return err + } + err = ioutil.WriteFile( + filepath.Join(s.ConfigDir, "Banlist.yaml"), + out, + 0666, + ) + return err +} + func (s *Server) writeThreadedNews() error { - s.mux.Lock() - defer s.mux.Unlock() + s.threadedNewsMux.Lock() + defer s.threadedNewsMux.Unlock() out, err := yaml.Marshal(s.ThreadedNews) if err != nil { return err } - err = ioutil.WriteFile( + err = s.FS.WriteFile( filepath.Join(s.ConfigDir, "ThreadedNews.yaml"), out, 0666, @@ -335,23 +367,31 @@ func (s *Server) writeThreadedNews() error { 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() clientConn := &ClientConn{ ID: &[]byte{0, 0}, - Icon: &[]byte{0, 0}, - Flags: &[]byte{0, 0}, + Icon: []byte{0, 0}, + Flags: []byte{0, 0}, UserName: []byte{}, Connection: conn, Server: s, - Version: &[]byte{}, + Version: []byte{}, AutoReply: []byte{}, - Transfers: make(map[int][]*FileTransfer), + transfers: map[int]map[[4]byte]*FileTransfer{}, Agreed: false, RemoteAddr: remoteAddr, } + clientConn.transfers = map[int]map[[4]byte]*FileTransfer{ + FileDownload: {}, + FileUpload: {}, + FolderDownload: {}, + FolderUpload: {}, + bannerDownload: {}, + } + *s.NextGuestID++ ID := *s.NextGuestID @@ -362,7 +402,7 @@ func (s *Server) NewClientConn(conn net.Conn, remoteAddr string) *ClientConn { } // NewUser creates a new user account entry in the server map and config file -func (s *Server) NewUser(login, name, password string, access []byte) error { +func (s *Server) NewUser(login, name, password string, access accessBitmap) error { s.mux.Lock() defer s.mux.Unlock() @@ -370,7 +410,7 @@ func (s *Server) NewUser(login, name, password string, access []byte) error { Login: login, Name: name, Password: hashAndSalt([]byte(password)), - Access: &access, + Access: access, } out, err := yaml.Marshal(&account) if err != nil { @@ -381,7 +421,7 @@ func (s *Server) NewUser(login, name, password string, access []byte) error { return s.FS.WriteFile(filepath.Join(s.ConfigDir, "Users", login+".yaml"), out, 0666) } -func (s *Server) UpdateUser(login, newLogin, name, password string, access []byte) error { +func (s *Server) UpdateUser(login, newLogin, name, password string, access accessBitmap) error { s.mux.Lock() defer s.mux.Unlock() @@ -396,7 +436,7 @@ func (s *Server) UpdateUser(login, newLogin, name, password string, access []byt } account := s.Accounts[newLogin] - account.Access = &access + account.Access = access account.Name = name account.Password = password @@ -433,8 +473,8 @@ func (s *Server) connectedUsers() []Field { } user := User{ ID: *c.ID, - Icon: *c.Icon, - Flags: *c.Flags, + Icon: c.Icon, + Flags: c.Flags, Name: string(c.UserName), } connectedUsers = append(connectedUsers, NewField(fieldUsernameWithInfo, user.Payload())) @@ -442,6 +482,16 @@ func (s *Server) connectedUsers() []Field { return connectedUsers } +func (s *Server) loadBanList(path string) error { + fh, err := os.Open(path) + if err != nil { + return err + } + decoder := yaml.NewDecoder(fh) + + return decoder.Decode(s.banList) +} + // loadThreadedNews loads the threaded news data from disk func (s *Server) loadThreadedNews(threadedNewsPath string) error { fh, err := os.Open(threadedNewsPath) @@ -501,48 +551,61 @@ func (s *Server) loadConfig(path string) error { return nil } -const ( - minTransactionLen = 22 // minimum length of any transaction -) - -// dontPanic recovers and logs panics instead of crashing -// TODO: remove this after known issues are fixed -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, conn net.Conn, remoteAddr string) error { +func (s *Server) handleNewConnection(ctx context.Context, rwc io.ReadWriteCloser, remoteAddr string) error { defer dontPanic(s.Logger) - if err := Handshake(conn); err != nil { + if err := Handshake(rwc); err != nil { return err } - buf := make([]byte, 1024) - // TODO: fix potential short read with io.ReadFull - readLen, err := conn.Read(buf) - if readLen < minTransactionLen { - return err - } - if err != nil { - return err - } + // Create a new scanner for parsing incoming bytes into transaction tokens + scanner := bufio.NewScanner(rwc) + scanner.Split(transactionScanner) - clientLogin, _, err := ReadTransaction(buf[:readLen]) - if err != nil { + scanner.Scan() + + // 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(conn, remoteAddr) + c := s.NewClientConn(rwc, remoteAddr) + + // check if remoteAddr is present in the ban list + if banUntil, ok := s.banList[strings.Split(remoteAddr, ":")[0]]; ok { + // permaban + if banUntil == nil { + s.outbox <- *NewTransaction( + tranServerMsg, + c.ID, + NewField(fieldData, []byte("You are permanently banned on this server")), + NewField(fieldChatOptions, []byte{0, 0}), + ) + time.Sleep(1 * time.Second) + return nil + } else if time.Now().Before(*banUntil) { + s.outbox <- *NewTransaction( + tranServerMsg, + c.ID, + NewField(fieldData, []byte("You are temporarily banned on this server")), + NewField(fieldChatOptions, []byte{0, 0}), + ) + time.Sleep(1 * time.Second) + return nil + } + + } defer c.Disconnect() encodedLogin := clientLogin.GetField(fieldUserLogin).Data encodedPassword := clientLogin.GetField(fieldUserPassword).Data - *c.Version = clientLogin.GetField(fieldVersion).Data + c.Version = clientLogin.GetField(fieldVersion).Data var login string for _, char := range encodedLogin { @@ -552,114 +615,115 @@ func (s *Server) handleNewConnection(ctx context.Context, conn net.Conn, remoteA 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.") + t := c.NewErrReply(&clientLogin, "Incorrect login.") b, err := t.MarshalBinary() if err != nil { return err } - if _, err := conn.Write(b); err != nil { + if _, err := rwc.Write(b); err != nil { return err } - return fmt.Errorf("incorrect login") - } - if clientLogin.GetField(fieldUserName).Data != nil { - c.UserName = clientLogin.GetField(fieldUserName).Data + c.logger.Infow("Login failed", "clientVersion", fmt.Sprintf("%x", c.Version)) + + return nil } if clientLogin.GetField(fieldUserIconID).Data != nil { - *c.Icon = clientLogin.GetField(fieldUserIconID).Data + c.Icon = clientLogin.GetField(fieldUserIconID).Data } c.Account = c.Server.Accounts[login] - if c.Authorize(accessDisconUser) { - *c.Flags = []byte{0, 2} + if clientLogin.GetField(fieldUserName).Data != nil { + if c.Authorize(accessAnyName) { + c.UserName = clientLogin.GetField(fieldUserName).Data + } else { + c.UserName = []byte(c.Account.Name) + } } - s.Logger.Infow("Client connection received", "login", login, "version", *c.Version, "RemoteAddr", remoteAddr) + if c.Authorize(accessDisconUser) { + c.Flags = []byte{0, 2} + } - s.outbox <- c.NewReply(clientLogin, + 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)), ) // Send user access privs so client UI knows how to behave - c.Server.outbox <- *NewTransaction(tranUserAccess, c.ID, NewField(fieldUserAccess, *c.Account.Access)) - - // Show agreement to client - c.Server.outbox <- *NewTransaction(tranShowAgreement, c.ID, NewField(fieldData, s.Agreement)) + c.Server.outbox <- *NewTransaction(tranUserAccess, c.ID, NewField(fieldUserAccess, c.Account.Access[:])) + + // Accounts with accessNoAgreement do not receive the server agreement on login. The behavior is different between + // client versions. For 1.2.3 client, we do not send tranShowAgreement. For other client versions, we send + // tranShowAgreement but with the NoServerAgreement field set to 1. + if c.Authorize(accessNoAgreement) { + // If client version is nil, then the client uses the 1.2.3 login behavior + if c.Version != nil { + c.Server.outbox <- *NewTransaction(tranShowAgreement, c.ID, NewField(fieldNoServerAgreement, []byte{1})) + } + } else { + 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) { + if c.Version == nil || bytes.Equal(c.Version, nostalgiaVersion) || bytes.Equal(c.Version, frogblastVersion) { c.Agreed = true + 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.notifyOthers( + for _, t := range c.notifyOthers( *NewTransaction( tranNotifyChangeUser, nil, NewField(fieldUserName, c.UserName), NewField(fieldUserID, *c.ID), - 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.ConnectionCounter += 1 + if len(s.Clients) > c.Server.Stats.ConnectionPeak { + c.Server.Stats.ConnectionPeak = len(s.Clients) + } - const readBuffSize = 1024000 // 1KB - TODO: what should this be? - tranBuff := make([]byte, 0) - tReadlen := 0 - // Infinite loop where take action on incoming client requests until the connection is closed - for { - buf = make([]byte, readBuffSize) - tranBuff = tranBuff[tReadlen:] + // Scan for new transactions and handle them as they come in. + for scanner.Scan() { + // 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()) - readLen, err := c.Connection.Read(buf) - if err != nil { + var t Transaction + if _, err := t.Write(buf); err != nil { return err } - tranBuff = append(tranBuff, buf[:readLen]...) - // We may have read multiple requests worth of bytes from Connection.Read. readTransactions splits them - // 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) - } - - // 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) - } + if err := c.handleTransaction(t); err != nil { + 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 + return nil } 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 @@ -685,52 +749,69 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro return err } - transferRefNum := binary.BigEndian.Uint32(t.ReferenceNumber[:]) defer func() { s.mux.Lock() - delete(s.FileTransfers, transferRefNum) + 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() - fileTransfer, ok := s.FileTransfers[transferRefNum] + fileTransfer, ok := s.fileTransfers[t.ReferenceNumber] 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, - "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 { 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 { 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 } - 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 _, err := wr.Write(fw.ffo.BinaryMarshal()); err != nil { + if _, err := rwc.Write(fw.ffo.BinaryMarshal()); err != nil { return err } } @@ -740,23 +821,21 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro 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 } - if err := wr.Flush(); err != nil { + if _, err = io.Copy(rwc, io.TeeReader(br, fileTransfer.bytesSentCounter)); err != nil { 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 { - err = binary.Write(wr, binary.BigEndian, fw.rsrcForkHeader()) + err = binary.Write(rwc, binary.BigEndian, fw.rsrcForkHeader()) if err != nil { return err } - if err := wr.Flush(); err != nil { - return err - } } rFile, err := fw.rsrcForkFile() @@ -764,19 +843,14 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro 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 - - destinationFile, err := readPath(s.Config.FileRoot, fileTransfer.FilePath, fileTransfer.FileName) - if err != nil { - return err - } + s.Stats.UploadsInProgress += 1 + defer func() { s.Stats.UploadsInProgress -= 1 }() var file *os.File @@ -787,30 +861,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: - _, err = os.Stat(destinationFile) + _, err = os.Stat(fullPath) 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 - 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 } } - f, err := newFileWrapper(s.FS, destinationFile, 0) + f, err := newFileWrapper(s.FS, fullPath, 0) if err != nil { return err } - defer func() { _ = file.Close() }() - - s.Logger.Infow("File upload started", "transactionRef", fileTransfer.ReferenceNumber, "dstFile", destinationFile) + rLogger.Infow("File upload started", "dstFile", fullPath) rForkWriter := io.Discard iForkWriter := io.Discard @@ -826,16 +894,25 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro } } - if err := receiveFile(rwc, file, rForkWriter, iForkWriter); err != nil { + 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 := s.FS.Rename(destinationFile+".incomplete", destinationFile); err != nil { + if err := s.FS.Rename(fullPath+".incomplete", fullPath); err != nil { return err } - s.Logger.Infow("File upload complete", "transactionRef", fileTransfer.ReferenceNumber, "dstFile", destinationFile) + 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 @@ -863,14 +940,9 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro // // 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 { @@ -878,7 +950,7 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro } 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 @@ -897,7 +969,7 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro } 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 @@ -916,7 +988,7 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro 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 @@ -948,9 +1020,8 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro return nil } - s.Logger.Infow("File download started", + rLogger.Infow("File download started", "fileName", info.Name(), - "transactionRef", fileTransfer.ReferenceNumber, "TransferSize", fmt.Sprintf("%x", hlFile.ffo.TransferSize(dataOffset)), ) @@ -972,8 +1043,7 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro } // 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 } @@ -988,8 +1058,7 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro 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 } } @@ -1002,23 +1071,24 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro return nil }) - case FolderUpload: - dstPath, err := readPath(s.Config.FileRoot, fileTransfer.FilePath, fileTransfer.FileName) if err != nil { return err } - s.Logger.Infow( + case FolderUpload: + s.Stats.UploadCounter += 1 + s.Stats.UploadsInProgress += 1 + defer func() { s.Stats.UploadsInProgress -= 1 }() + rLogger.Infow( "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. - 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 } } @@ -1050,17 +1120,16 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro return err } - s.Logger.Infow( + rLogger.Infow( "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} { - 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 } } @@ -1073,7 +1142,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. - _, 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 } @@ -1082,7 +1151,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. - 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 } @@ -1101,7 +1170,7 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro 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 } @@ -1121,11 +1190,11 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro 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) } - 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 } @@ -1135,14 +1204,14 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro 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 } - 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 { @@ -1162,10 +1231,10 @@ func (s *Server) handleFileTransfer(ctx context.Context, rwc io.ReadWriter) erro return err } } - if err := receiveFile(rwc, incWriter, rForkWriter, iForkWriter); err != nil { + if err := receiveFile(rwc, incWriter, rForkWriter, iForkWriter, fileTransfer.bytesSentCounter); err != nil { return err } - // _ = newFile.Close() + if err := os.Rename(filePath+".incomplete", filePath); err != nil { return err } @@ -1177,7 +1246,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