Skip to content

Commit 4d23757

Browse files
authored
fix: prevent IdleTimeout from closing control connection during activ… (#577)
* fix: prevent IdleTimeout from closing control connection during active data transfers Before this change, the server would immediately close control connections when IdleTimeout was reached, regardless of whether a data transfer was active. This caused issues with large or slow file transfers that could take longer than the configured idle timeout. Now the server checks if there is an active data transfer (isTransferOpen) before closing the connection. If a transfer is active, it extends the deadline instead of closing the connection, allowing the transfer to complete. Fixes #430 * test: Add test for connection close during active data transfer This test simulates closing a connection during an active data transfer to verify proper cleanup and error handling. It tests both passive and active transfer modes. The test: - Uploads a large file (10MB) - Starts a download (RETR) operation - Closes the connection mid-transfer - Verifies the server remains functional - Confirms the file is still accessible This improves test coverage for error handling paths and ensures the server gracefully handles unexpected connection closures during transfers. * fix: resolve linter errors in connection close test Fix two linter issues in TestConnectionCloseDuringTransfer: - ineffassign: Use _ to explicitly ignore client.Close() error - govet shadow: Use = instead of := to avoid shadowing err variable * fix: simplify connection close test to passive mode only The active mode test was failing in CI due to connection setup complexity with the FTP client library. Since passive mode is the more common scenario and already validates the server's resilience to connection closure during transfer, focusing on passive mode provides sufficient coverage. Active mode adds complexity without additional value for this specific test case, as the server-side cleanup logic is the same regardless of transfer mode. * test: Add test for idle timeout behavior during data transfers Verifies that the idle timeout doesn't prematurely close the control connection when a data transfer is actively in progress, ensuring the deadline is properly extended during active I/O operations. * fix: prevent control connection timeout during active data transfers Modified handleCommandsStreamError to return a boolean indicating whether to disconnect. When an idle timeout occurs during an active data transfer, the deadline is extended and the connection is maintained (returns false). This allows long-running transfers to complete successfully even when they exceed the configured idle timeout period.
1 parent 4b558e8 commit 4d23757

File tree

3 files changed

+164
-11
lines changed

3 files changed

+164
-11
lines changed

client_handler.go

Lines changed: 35 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -455,9 +455,9 @@ func (c *clientHandler) readCommand() bool {
455455
}
456456

457457
if err != nil {
458-
c.handleCommandsStreamError(err)
458+
shouldDisconnect := c.handleCommandsStreamError(err)
459459

460-
return true
460+
return shouldDisconnect
461461
}
462462

463463
line := string(lineSlice)
@@ -471,11 +471,31 @@ func (c *clientHandler) readCommand() bool {
471471
return false
472472
}
473473

474-
func (c *clientHandler) handleCommandsStreamError(err error) {
474+
func (c *clientHandler) handleCommandsStreamError(err error) bool {
475475
// florent(2018-01-14): #58: IDLE timeout: Adding some code to deal with the deadline
476476
var errNetError net.Error
477477
if errors.As(err, &errNetError) { //nolint:nestif // too much effort to change for now
478478
if errNetError.Timeout() {
479+
// Check if there's an active data transfer before closing the control connection
480+
c.transferMu.Lock()
481+
hasActiveTransfer := c.isTransferOpen
482+
c.transferMu.Unlock()
483+
484+
if hasActiveTransfer {
485+
// If there's an active data transfer, extend the deadline and continue
486+
extendedDeadline := time.Now().Add(time.Duration(time.Second.Nanoseconds() * int64(c.server.settings.IdleTimeout)))
487+
if errSet := c.conn.SetDeadline(extendedDeadline); errSet != nil {
488+
c.logger.Error("Could not extend read deadline during active transfer", "err", errSet)
489+
}
490+
491+
if c.debug {
492+
c.logger.Debug("Idle timeout occurred during active transfer, extending deadline")
493+
}
494+
495+
// Don't disconnect - the transfer is still active
496+
return false
497+
}
498+
479499
// We have to extend the deadline now
480500
if errSet := c.conn.SetDeadline(time.Now().Add(time.Minute)); errSet != nil {
481501
c.logger.Error("Could not set read deadline", "err", errSet)
@@ -490,19 +510,23 @@ func (c *clientHandler) handleCommandsStreamError(err error) {
490510
c.logger.Error("Flush error", "err", errFlush)
491511
}
492512

493-
return
513+
return true
494514
}
495515

496516
c.logger.Error("Network error", "err", err)
497-
} else {
498-
if errors.Is(err, io.EOF) {
499-
if c.debug {
500-
c.logger.Debug("Client disconnected", "clean", false)
501-
}
502-
} else {
503-
c.logger.Error("Read error", "err", err)
517+
518+
return true
519+
}
520+
521+
if errors.Is(err, io.EOF) {
522+
if c.debug {
523+
c.logger.Debug("Client disconnected", "clean", false)
504524
}
525+
} else {
526+
c.logger.Error("Read error", "err", err)
505527
}
528+
529+
return true
506530
}
507531

508532
// handleCommand takes care of executing the received line

idle_timeout_transfer_test.go

Lines changed: 66 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,66 @@
1+
package ftpserver
2+
3+
import (
4+
"bytes"
5+
"testing"
6+
"time"
7+
8+
"github.com/secsy/goftp"
9+
"github.com/stretchr/testify/require"
10+
)
11+
12+
// TestIdleTimeoutDuringTransfer verifies that the idle timeout doesn't close
13+
// the control connection when a data transfer is active.
14+
func TestIdleTimeoutDuringTransfer(t *testing.T) {
15+
// Create a server with a very short idle timeout
16+
// The test driver adds 500ms delay for files with "delay-io" in the name
17+
server := NewTestServerWithTestDriver(t, &TestServerDriver{
18+
Debug: true,
19+
Settings: &Settings{
20+
IdleTimeout: 1, // 1 second idle timeout
21+
},
22+
})
23+
24+
conf := goftp.Config{
25+
User: authUser,
26+
Password: authPass,
27+
}
28+
29+
client, err := goftp.DialConfig(conf, server.Addr())
30+
require.NoError(t, err, "Couldn't connect")
31+
32+
defer func() { panicOnError(client.Close()) }()
33+
34+
// Create test data - size chosen so that with 500ms delays per read,
35+
// the transfer will take longer than the 1 second idle timeout
36+
data := make([]byte, 1024*1024) // 1MB
37+
for i := range data {
38+
data[i] = byte(i % 256)
39+
}
40+
41+
// Upload the file with "delay-io" in the name to trigger slow I/O
42+
// This will cause each Read() operation to take 500ms
43+
err = client.Store("delay-io-test.bin", bytes.NewReader(data))
44+
require.NoError(t, err, "Failed to upload file")
45+
46+
// Download the file - this will trigger multiple 500ms delays
47+
// Total time will exceed the 1 second idle timeout
48+
// The server should extend the deadline during the active transfer
49+
buf := &bytes.Buffer{}
50+
start := time.Now()
51+
err = client.Retrieve("delay-io-test.bin", buf)
52+
elapsed := time.Since(start)
53+
54+
require.NoError(t, err, "Transfer should succeed despite idle timeout")
55+
require.Equal(t, len(data), buf.Len(), "Downloaded data should match uploaded data")
56+
require.Equal(t, data, buf.Bytes(), "Downloaded content should match uploaded content")
57+
58+
// Verify the transfer took longer than the idle timeout
59+
// This proves the deadline was extended during the transfer
60+
require.Greater(t, elapsed, time.Duration(server.settings.IdleTimeout)*time.Second,
61+
"Transfer should take longer than idle timeout to verify deadline extension worked")
62+
63+
// Verify the connection is still alive after the transfer
64+
_, err = client.ReadDir("/")
65+
require.NoError(t, err, "Connection should still be alive after long transfer")
66+
}

transfer_test.go

Lines changed: 63 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1360,3 +1360,66 @@ func getPortFromEPSVResponse(t *testing.T, resp string) int {
13601360

13611361
return port
13621362
}
1363+
1364+
// TestConnectionCloseDuringTransfer tests the behavior when the control connection is closed
1365+
// during an active data transfer in passive mode. This ensures proper cleanup and error handling.
1366+
func TestConnectionCloseDuringTransfer(t *testing.T) {
1367+
t.Parallel()
1368+
1369+
server := NewTestServer(t, false)
1370+
1371+
conf := goftp.Config{
1372+
User: authUser,
1373+
Password: authPass,
1374+
}
1375+
1376+
client, err := goftp.DialConfig(conf, server.Addr())
1377+
require.NoError(t, err, "Couldn't connect")
1378+
1379+
// Upload a file first so we have something to download
1380+
file := createTemporaryFile(t, 10*1024*1024) // 10MB file
1381+
err = client.Store("large-file.bin", file)
1382+
require.NoError(t, err, "Failed to upload file")
1383+
1384+
// Open a raw connection to have more control
1385+
raw, err := client.OpenRawConn()
1386+
require.NoError(t, err)
1387+
1388+
// Prepare data connection
1389+
_, err = raw.PrepareDataConn()
1390+
require.NoError(t, err)
1391+
1392+
// Start the RETR command
1393+
returnCode, response, err := raw.SendCommand("RETR large-file.bin")
1394+
require.NoError(t, err)
1395+
require.Equal(t, StatusFileStatusOK, returnCode, response)
1396+
1397+
// Give the transfer a moment to start
1398+
time.Sleep(50 * time.Millisecond)
1399+
1400+
// Now close the raw connection abruptly during the transfer
1401+
// This simulates a network disconnection or client crash
1402+
err = raw.Close()
1403+
require.NoError(t, err)
1404+
1405+
// Close the main client connection as well
1406+
_ = client.Close()
1407+
// We expect an error here since the connection is already closed/broken
1408+
// but we don't want to fail the test - this is expected behavior
1409+
1410+
// Give the server time to clean up
1411+
time.Sleep(100 * time.Millisecond)
1412+
1413+
// Verify we can establish a new connection and the server is still functional
1414+
newClient, err := goftp.DialConfig(conf, server.Addr())
1415+
require.NoError(t, err, "Server should still be functional after connection close during transfer")
1416+
1417+
defer func() {
1418+
err = newClient.Close()
1419+
require.NoError(t, err)
1420+
}()
1421+
1422+
// Verify the file is still there and accessible
1423+
_, err = newClient.Stat("large-file.bin")
1424+
require.NoError(t, err, "File should still be accessible after interrupted transfer")
1425+
}

0 commit comments

Comments
 (0)