2019-07-20 10:26:52 +00:00
|
|
|
package sftpd
|
|
|
|
|
|
|
|
import (
|
2020-01-10 18:20:22 +00:00
|
|
|
"errors"
|
2019-10-09 15:33:30 +00:00
|
|
|
"fmt"
|
2019-11-26 21:26:42 +00:00
|
|
|
"io"
|
2019-07-20 10:26:52 +00:00
|
|
|
"os"
|
2020-01-10 18:20:22 +00:00
|
|
|
"sync"
|
2019-07-20 10:26:52 +00:00
|
|
|
"time"
|
|
|
|
|
|
|
|
"github.com/drakkan/sftpgo/dataprovider"
|
|
|
|
"github.com/drakkan/sftpgo/logger"
|
2019-09-13 16:45:36 +00:00
|
|
|
"github.com/drakkan/sftpgo/metrics"
|
2020-01-19 06:41:05 +00:00
|
|
|
"github.com/eikenb/pipeat"
|
2019-07-20 10:26:52 +00:00
|
|
|
)
|
|
|
|
|
|
|
|
const (
|
|
|
|
transferUpload = iota
|
|
|
|
transferDownload
|
|
|
|
)
|
|
|
|
|
2020-01-12 07:25:08 +00:00
|
|
|
var (
|
|
|
|
errTransferClosed = errors.New("transfer already closed")
|
|
|
|
)
|
|
|
|
|
2019-07-30 18:51:29 +00:00
|
|
|
// Transfer contains the transfer details for an upload or a download.
|
|
|
|
// It implements the io Reader and Writer interface to handle files downloads and uploads
|
2019-07-20 10:26:52 +00:00
|
|
|
type Transfer struct {
|
2019-10-09 15:33:30 +00:00
|
|
|
file *os.File
|
2020-01-19 06:41:05 +00:00
|
|
|
writerAt *pipeat.PipeWriterAt
|
|
|
|
readerAt *pipeat.PipeReaderAt
|
|
|
|
cancelFn func()
|
2019-10-09 15:33:30 +00:00
|
|
|
path string
|
|
|
|
start time.Time
|
|
|
|
bytesSent int64
|
|
|
|
bytesReceived int64
|
|
|
|
user dataprovider.User
|
|
|
|
connectionID string
|
|
|
|
transferType int
|
|
|
|
lastActivity time.Time
|
|
|
|
isNewFile bool
|
|
|
|
protocol string
|
|
|
|
transferError error
|
|
|
|
isFinished bool
|
|
|
|
minWriteOffset int64
|
2020-01-10 18:20:22 +00:00
|
|
|
expectedSize int64
|
2020-01-23 09:19:56 +00:00
|
|
|
initialSize int64
|
2020-01-10 18:20:22 +00:00
|
|
|
lock *sync.Mutex
|
2019-09-07 21:10:20 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
// TransferError is called if there is an unexpected error.
|
|
|
|
// For example network or client issues
|
|
|
|
func (t *Transfer) TransferError(err error) {
|
2020-01-10 18:20:22 +00:00
|
|
|
t.lock.Lock()
|
|
|
|
defer t.lock.Unlock()
|
|
|
|
if t.transferError != nil {
|
|
|
|
return
|
|
|
|
}
|
2019-09-07 21:10:20 +00:00
|
|
|
t.transferError = err
|
2020-01-19 06:41:05 +00:00
|
|
|
if t.cancelFn != nil {
|
|
|
|
t.cancelFn()
|
|
|
|
}
|
2019-09-10 16:47:21 +00:00
|
|
|
elapsed := time.Since(t.start).Nanoseconds() / 1000000
|
2019-09-09 06:57:11 +00:00
|
|
|
logger.Warn(logSender, t.connectionID, "Unexpected error for transfer, path: %#v, error: \"%v\" bytes sent: %v, "+
|
2019-09-10 16:47:21 +00:00
|
|
|
"bytes received: %v transfer running since %v ms", t.path, t.transferError, t.bytesSent, t.bytesReceived, elapsed)
|
2019-07-20 10:26:52 +00:00
|
|
|
}
|
|
|
|
|
2019-07-30 18:51:29 +00:00
|
|
|
// ReadAt reads len(p) bytes from the File to download starting at byte offset off and updates the bytes sent.
|
|
|
|
// It handles download bandwidth throttling too
|
2019-07-20 10:26:52 +00:00
|
|
|
func (t *Transfer) ReadAt(p []byte, off int64) (n int, err error) {
|
2019-07-27 07:38:09 +00:00
|
|
|
t.lastActivity = time.Now()
|
2020-01-19 06:41:05 +00:00
|
|
|
var readed int
|
|
|
|
var e error
|
|
|
|
if t.readerAt != nil {
|
|
|
|
readed, e = t.readerAt.ReadAt(p, off)
|
|
|
|
} else {
|
|
|
|
readed, e = t.file.ReadAt(p, off)
|
|
|
|
}
|
2020-01-10 18:20:22 +00:00
|
|
|
t.lock.Lock()
|
2019-07-20 10:26:52 +00:00
|
|
|
t.bytesSent += int64(readed)
|
2020-01-10 18:20:22 +00:00
|
|
|
t.lock.Unlock()
|
|
|
|
if e != nil && e != io.EOF {
|
|
|
|
t.TransferError(e)
|
|
|
|
return readed, e
|
|
|
|
}
|
2019-07-20 10:26:52 +00:00
|
|
|
t.handleThrottle()
|
|
|
|
return readed, e
|
|
|
|
}
|
|
|
|
|
2019-07-30 18:51:29 +00:00
|
|
|
// WriteAt writes len(p) bytes to the uploaded file starting at byte offset off and updates the bytes received.
|
|
|
|
// It handles upload bandwidth throttling too
|
2019-07-20 10:26:52 +00:00
|
|
|
func (t *Transfer) WriteAt(p []byte, off int64) (n int, err error) {
|
2019-07-27 07:38:09 +00:00
|
|
|
t.lastActivity = time.Now()
|
2019-10-09 15:33:30 +00:00
|
|
|
if off < t.minWriteOffset {
|
2020-01-10 18:20:22 +00:00
|
|
|
err := fmt.Errorf("Invalid write offset: %v minimum valid value: %v", off, t.minWriteOffset)
|
|
|
|
t.TransferError(err)
|
|
|
|
return 0, err
|
2019-10-09 15:33:30 +00:00
|
|
|
}
|
2020-01-19 06:41:05 +00:00
|
|
|
var written int
|
|
|
|
var e error
|
|
|
|
if t.writerAt != nil {
|
|
|
|
written, e = t.writerAt.WriteAt(p, off)
|
|
|
|
} else {
|
|
|
|
written, e = t.file.WriteAt(p, off)
|
|
|
|
}
|
2020-01-10 18:20:22 +00:00
|
|
|
t.lock.Lock()
|
2019-07-20 10:26:52 +00:00
|
|
|
t.bytesReceived += int64(written)
|
2020-01-10 18:20:22 +00:00
|
|
|
t.lock.Unlock()
|
|
|
|
if e != nil {
|
|
|
|
t.TransferError(e)
|
|
|
|
return written, e
|
|
|
|
}
|
2019-07-20 10:26:52 +00:00
|
|
|
t.handleThrottle()
|
|
|
|
return written, e
|
|
|
|
}
|
|
|
|
|
2019-07-30 18:51:29 +00:00
|
|
|
// Close it is called when the transfer is completed.
|
2020-01-09 11:00:37 +00:00
|
|
|
// It closes the underlying file, logs the transfer info, updates the user quota (for uploads)
|
|
|
|
// and executes any defined action.
|
2019-09-10 16:47:21 +00:00
|
|
|
// If there is an error no action will be executed and, in atomic mode, we try to delete
|
|
|
|
// the temporary file
|
2019-07-20 10:26:52 +00:00
|
|
|
func (t *Transfer) Close() error {
|
2020-01-10 18:20:22 +00:00
|
|
|
t.lock.Lock()
|
|
|
|
defer t.lock.Unlock()
|
2019-09-07 21:10:20 +00:00
|
|
|
if t.isFinished {
|
2020-01-12 07:25:08 +00:00
|
|
|
return errTransferClosed
|
2019-09-07 21:10:20 +00:00
|
|
|
}
|
2020-01-19 06:41:05 +00:00
|
|
|
err := t.closeIO()
|
2019-09-10 16:47:21 +00:00
|
|
|
t.isFinished = true
|
|
|
|
numFiles := 0
|
|
|
|
if t.isNewFile {
|
|
|
|
numFiles = 1
|
|
|
|
}
|
2020-01-10 18:20:22 +00:00
|
|
|
t.checkDownloadSize()
|
2020-01-19 06:41:05 +00:00
|
|
|
if t.transferType == transferUpload && t.file != nil && t.file.Name() != t.path {
|
2019-10-09 15:33:30 +00:00
|
|
|
if t.transferError == nil || uploadMode == uploadModeAtomicWithResume {
|
2019-09-10 16:47:21 +00:00
|
|
|
err = os.Rename(t.file.Name(), t.path)
|
|
|
|
logger.Debug(logSender, t.connectionID, "atomic upload completed, rename: %#v -> %#v, error: %v",
|
|
|
|
t.file.Name(), t.path, err)
|
|
|
|
} else {
|
|
|
|
err = os.Remove(t.file.Name())
|
|
|
|
logger.Warn(logSender, t.connectionID, "atomic upload completed with error: \"%v\", delete temporary file: %#v, "+
|
|
|
|
"deletion error: %v", t.transferError, t.file.Name(), err)
|
|
|
|
if err == nil {
|
|
|
|
numFiles--
|
|
|
|
t.bytesReceived = 0
|
|
|
|
}
|
|
|
|
}
|
2019-08-04 07:37:58 +00:00
|
|
|
}
|
2019-09-07 21:10:20 +00:00
|
|
|
if t.transferError == nil {
|
2019-09-10 16:47:21 +00:00
|
|
|
elapsed := time.Since(t.start).Nanoseconds() / 1000000
|
2019-09-07 21:10:20 +00:00
|
|
|
if t.transferType == transferDownload {
|
|
|
|
logger.TransferLog(downloadLogSender, t.path, elapsed, t.bytesSent, t.user.Username, t.connectionID, t.protocol)
|
2020-01-09 11:00:37 +00:00
|
|
|
go executeAction(operationDownload, t.user.Username, t.path, "", "", t.bytesSent)
|
2019-09-07 21:10:20 +00:00
|
|
|
} else {
|
|
|
|
logger.TransferLog(uploadLogSender, t.path, elapsed, t.bytesReceived, t.user.Username, t.connectionID, t.protocol)
|
2020-01-09 11:00:37 +00:00
|
|
|
go executeAction(operationUpload, t.user.Username, t.path, "", "", t.bytesReceived+t.minWriteOffset)
|
2019-09-07 21:10:20 +00:00
|
|
|
}
|
2020-01-10 18:20:22 +00:00
|
|
|
} else {
|
|
|
|
logger.Warn(logSender, t.connectionID, "transfer error: %v, path: %#v", t.transferError, t.path)
|
|
|
|
if err == nil {
|
|
|
|
err = t.transferError
|
|
|
|
}
|
2019-07-20 10:26:52 +00:00
|
|
|
}
|
2019-09-13 16:45:36 +00:00
|
|
|
metrics.TransferCompleted(t.bytesSent, t.bytesReceived, t.transferType, t.transferError)
|
2019-07-20 10:26:52 +00:00
|
|
|
removeTransfer(t)
|
2020-01-23 09:19:56 +00:00
|
|
|
t.updateQuota(numFiles)
|
2019-07-27 09:17:32 +00:00
|
|
|
return err
|
2019-07-20 10:26:52 +00:00
|
|
|
}
|
|
|
|
|
2020-01-19 06:41:05 +00:00
|
|
|
func (t *Transfer) closeIO() error {
|
|
|
|
var err error
|
|
|
|
if t.writerAt != nil {
|
|
|
|
err = t.writerAt.Close()
|
|
|
|
} else if t.readerAt != nil {
|
|
|
|
err = t.readerAt.Close()
|
|
|
|
} else {
|
|
|
|
err = t.file.Close()
|
|
|
|
}
|
|
|
|
return err
|
|
|
|
}
|
|
|
|
|
2020-01-23 09:19:56 +00:00
|
|
|
func (t *Transfer) updateQuota(numFiles int) bool {
|
|
|
|
// S3 uploads are atomic, if there is an error nothing is uploaded
|
|
|
|
if t.file == nil && t.transferError != nil {
|
|
|
|
return false
|
|
|
|
}
|
|
|
|
if t.transferType == transferUpload && (numFiles != 0 || t.bytesReceived > 0) {
|
|
|
|
dataprovider.UpdateUserQuota(dataProvider, t.user, numFiles, t.bytesReceived-t.initialSize, false)
|
|
|
|
return true
|
|
|
|
}
|
|
|
|
return false
|
|
|
|
}
|
|
|
|
|
2020-01-10 18:20:22 +00:00
|
|
|
func (t *Transfer) checkDownloadSize() {
|
|
|
|
if t.transferType == transferDownload && t.transferError == nil && t.bytesSent < t.expectedSize {
|
|
|
|
t.transferError = fmt.Errorf("incomplete download: %v/%v bytes transferred", t.bytesSent, t.expectedSize)
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2019-07-20 10:26:52 +00:00
|
|
|
func (t *Transfer) handleThrottle() {
|
|
|
|
var wantedBandwidth int64
|
|
|
|
var trasferredBytes int64
|
|
|
|
if t.transferType == transferDownload {
|
|
|
|
wantedBandwidth = t.user.DownloadBandwidth
|
|
|
|
trasferredBytes = t.bytesSent
|
|
|
|
} else {
|
|
|
|
wantedBandwidth = t.user.UploadBandwidth
|
|
|
|
trasferredBytes = t.bytesReceived
|
|
|
|
}
|
|
|
|
if wantedBandwidth > 0 {
|
|
|
|
// real and wanted elapsed as milliseconds, bytes as kilobytes
|
|
|
|
realElapsed := time.Since(t.start).Nanoseconds() / 1000000
|
2019-07-27 07:38:09 +00:00
|
|
|
// trasferredBytes / 1000 = KB/s, we multiply for 1000 to get milliseconds
|
2019-07-20 10:26:52 +00:00
|
|
|
wantedElapsed := 1000 * (trasferredBytes / 1000) / wantedBandwidth
|
|
|
|
if wantedElapsed > realElapsed {
|
|
|
|
toSleep := time.Duration(wantedElapsed - realElapsed)
|
|
|
|
time.Sleep(toSleep * time.Millisecond)
|
|
|
|
}
|
|
|
|
}
|
|
|
|
}
|
2019-11-26 21:26:42 +00:00
|
|
|
|
|
|
|
// used for ssh commands.
|
|
|
|
// It reads from src until EOF so it does not treat an EOF from Read as an error to be reported.
|
|
|
|
// EOF from Write is reported as error
|
|
|
|
func (t *Transfer) copyFromReaderToWriter(dst io.Writer, src io.Reader, maxWriteSize int64) (int64, error) {
|
|
|
|
var written int64
|
|
|
|
var err error
|
|
|
|
if maxWriteSize < 0 {
|
|
|
|
return 0, errQuotaExceeded
|
|
|
|
}
|
|
|
|
buf := make([]byte, 32768)
|
|
|
|
for {
|
|
|
|
t.lastActivity = time.Now()
|
|
|
|
nr, er := src.Read(buf)
|
|
|
|
if nr > 0 {
|
|
|
|
nw, ew := dst.Write(buf[0:nr])
|
|
|
|
if nw > 0 {
|
|
|
|
written += int64(nw)
|
|
|
|
if t.transferType == transferDownload {
|
|
|
|
t.bytesSent = written
|
|
|
|
} else {
|
|
|
|
t.bytesReceived = written
|
|
|
|
}
|
|
|
|
if maxWriteSize > 0 && written > maxWriteSize {
|
|
|
|
err = errQuotaExceeded
|
|
|
|
break
|
|
|
|
}
|
|
|
|
}
|
|
|
|
if ew != nil {
|
|
|
|
err = ew
|
|
|
|
break
|
|
|
|
}
|
|
|
|
if nr != nw {
|
|
|
|
err = io.ErrShortWrite
|
|
|
|
break
|
|
|
|
}
|
|
|
|
}
|
|
|
|
if er != nil {
|
|
|
|
if er != io.EOF {
|
|
|
|
err = er
|
|
|
|
}
|
|
|
|
break
|
|
|
|
}
|
|
|
|
t.handleThrottle()
|
|
|
|
}
|
|
|
|
t.transferError = err
|
|
|
|
if t.bytesSent > 0 || t.bytesReceived > 0 || err != nil {
|
|
|
|
metrics.TransferCompleted(t.bytesSent, t.bytesReceived, t.transferType, t.transferError)
|
|
|
|
}
|
|
|
|
return written, err
|
|
|
|
}
|