fix(xray): implement graceful shutdown for xray process and add tests (#4259)

sub/sub.go

@@ -12,6 +12,7 @@ import (
 	"os"
 	"strconv"
 	"strings"
+	"time"
 
 	"github.com/mhsanaei/3x-ui/v3/logger"
 	"github.com/mhsanaei/3x-ui/v3/util/common"
@@ -313,7 +314,9 @@ func (s *Server) Stop() error {
 	var err1 error
 	var err2 error
 	if s.httpServer != nil {
-		err1 = s.httpServer.Shutdown(s.ctx)
+		shutdownCtx, shutdownCancel := context.WithTimeout(context.Background(), 10*time.Second)
+		defer shutdownCancel()
+		err1 = s.httpServer.Shutdown(shutdownCtx)
 	}
 	if s.listener != nil {
 		err2 = s.listener.Close()

web/web.go

@@ -456,7 +456,9 @@ func (s *Server) Stop() error {
 	var err1 error
 	var err2 error
 	if s.httpServer != nil {
-		err1 = s.httpServer.Shutdown(s.ctx)
+		shutdownCtx, shutdownCancel := context.WithTimeout(context.Background(), 10*time.Second)
+		defer shutdownCancel()
+		err1 = s.httpServer.Shutdown(shutdownCtx)
 	}
 	if s.listener != nil {
 		err2 = s.listener.Close()

xray/process.go

@@ -10,6 +10,7 @@ import (
 	"runtime"
 	"strings"
 	"sync"
+	"sync/atomic"
 	"syscall"
 	"time"
 
@@ -120,7 +121,8 @@ func NewTestProcess(xrayConfig *Config, configPath string) *Process {
 }
 
 type process struct {
-	cmd *exec.Cmd
+	cmd  *exec.Cmd
+	done chan struct{}
 
 	version string
 	apiPort int
@@ -139,8 +141,15 @@ type process struct {
 	logWriter  *LogWriter
 	exitErr    error
 	startTime  time.Time
+
+	intentionalStop atomic.Bool
 }
 
+var (
+	xrayGracefulStopTimeout = 5 * time.Second
+	xrayForceStopTimeout    = 2 * time.Second
+)
+
 // newProcess creates a new internal process struct for Xray.
 func newProcess(config *Config) *process {
 	return &process{
@@ -163,6 +172,13 @@ func (p *process) IsRunning() bool {
 	if p.cmd == nil || p.cmd.Process == nil {
 		return false
 	}
+	if p.done != nil {
+		select {
+		case <-p.done:
+			return false
+		default:
+		}
+	}
 	if p.cmd.ProcessState == nil {
 		return true
 	}
@@ -326,27 +342,13 @@ func (p *process) Start() (err error) {
 	}
 
 	cmd := exec.Command(GetBinaryPath(), "-c", configPath)
-	p.cmd = cmd
-
 	cmd.Stdout = p.logWriter
 	cmd.Stderr = p.logWriter
 
-	go func() {
-		err := cmd.Run()
-		if err != nil {
-			// On Windows, killing the process results in "exit status 1" which isn't an error for us
-			if runtime.GOOS == "windows" {
-				errStr := strings.ToLower(err.Error())
-				if strings.Contains(errStr, "exit status 1") {
-					// Suppress noisy log on graceful stop
-					p.exitErr = err
-					return
-				}
-			}
-			logger.Error("Failure in running xray-core:", err)
-			p.exitErr = err
-		}
-	}()
+	err = p.startCommand(cmd)
+	if err != nil {
+		return err
+	}
 
 	p.refreshVersion()
 	p.refreshAPIPort()
@@ -354,11 +356,49 @@ func (p *process) Start() (err error) {
 	return nil
 }
 
+func (p *process) startCommand(cmd *exec.Cmd) error {
+	p.cmd = cmd
+	p.done = make(chan struct{})
+	p.exitErr = nil
+	p.intentionalStop.Store(false)
+
+	if err := cmd.Start(); err != nil {
+		close(p.done)
+		p.cmd = nil
+		return err
+	}
+
+	go p.waitForCommand(cmd)
+	return nil
+}
+
+func (p *process) waitForCommand(cmd *exec.Cmd) {
+	defer close(p.done)
+
+	err := cmd.Wait()
+	if err == nil || p.intentionalStop.Load() {
+		return
+	}
+
+	// On Windows, killing the process results in "exit status 1" which isn't an error for us.
+	if runtime.GOOS == "windows" {
+		errStr := strings.ToLower(err.Error())
+		if strings.Contains(errStr, "exit status 1") {
+			p.exitErr = err
+			return
+		}
+	}
+
+	logger.Error("Failure in running xray-core:", err)
+	p.exitErr = err
+}
+
 // Stop terminates the running Xray process.
 func (p *process) Stop() error {
 	if !p.IsRunning() {
 		return errors.New("xray is not running")
 	}
+	p.intentionalStop.Store(true)
 
 	// Remove temporary config file used for test runs so main config is never touched
 	if p.configPath != "" {
@@ -371,9 +411,43 @@ func (p *process) Stop() error {
 	}
 
 	if runtime.GOOS == "windows" {
-		return p.cmd.Process.Kill()
-	} else {
-		return p.cmd.Process.Signal(syscall.SIGTERM)
+		if err := p.cmd.Process.Kill(); err != nil && !errors.Is(err, os.ErrProcessDone) {
+			return err
+		}
+		return p.waitForExit(xrayForceStopTimeout)
+	}
+
+	if err := p.cmd.Process.Signal(syscall.SIGTERM); err != nil {
+		if errors.Is(err, os.ErrProcessDone) {
+			return p.waitForExit(xrayForceStopTimeout)
+		}
+		return err
+	}
+
+	if err := p.waitForExit(xrayGracefulStopTimeout); err == nil {
+		return nil
+	}
+
+	logger.Warning("xray-core did not stop after SIGTERM, killing process")
+	if err := p.cmd.Process.Kill(); err != nil && !errors.Is(err, os.ErrProcessDone) {
+		return err
+	}
+	return p.waitForExit(xrayForceStopTimeout)
+}
+
+func (p *process) waitForExit(timeout time.Duration) error {
+	if p.done == nil {
+		return nil
+	}
+
+	timer := time.NewTimer(timeout)
+	defer timer.Stop()
+
+	select {
+	case <-p.done:
+		return nil
+	case <-timer.C:
+		return common.NewErrorf("timed out waiting for xray-core process to stop after %s", timeout)
 	}
 }
 

xray/process_test.go

@@ -0,0 +1,162 @@
+//go:build !windows
+
+package xray
+
+import (
+	"os"
+	"os/exec"
+	"os/signal"
+	"path/filepath"
+	"syscall"
+	"testing"
+	"time"
+
+	xuilogger "github.com/mhsanaei/3x-ui/v3/logger"
+	"github.com/op/go-logging"
+)
+
+func TestStopWaitsForGracefulExit(t *testing.T) {
+	initProcessTestLogger(t)
+
+	p := startProcessHelper(t, "delayed-term")
+
+	start := time.Now()
+	if err := p.Stop(); err != nil {
+		t.Fatalf("Stop: %v", err)
+	}
+	if elapsed := time.Since(start); elapsed < 150*time.Millisecond {
+		t.Fatalf("Stop returned before child exited; elapsed=%s", elapsed)
+	}
+	if p.IsRunning() {
+		t.Fatal("process still reports running after Stop")
+	}
+}
+
+func TestIntentionalStopDoesNotRecordExitError(t *testing.T) {
+	initProcessTestLogger(t)
+
+	p := startProcessHelper(t, "default-term")
+
+	if err := p.Stop(); err != nil {
+		t.Fatalf("Stop: %v", err)
+	}
+	if err := p.GetErr(); err != nil {
+		t.Fatalf("GetErr after intentional stop = %v, want nil", err)
+	}
+	if result := p.GetResult(); result != "" {
+		t.Fatalf("GetResult after intentional stop = %q, want empty", result)
+	}
+}
+
+func TestStopKillsProcessThatIgnoresSIGTERM(t *testing.T) {
+	initProcessTestLogger(t)
+
+	oldGraceful := xrayGracefulStopTimeout
+	oldForce := xrayForceStopTimeout
+	xrayGracefulStopTimeout = 100 * time.Millisecond
+	xrayForceStopTimeout = 2 * time.Second
+	t.Cleanup(func() {
+		xrayGracefulStopTimeout = oldGraceful
+		xrayForceStopTimeout = oldForce
+	})
+
+	p := startProcessHelper(t, "ignore-term")
+
+	if err := p.Stop(); err != nil {
+		t.Fatalf("Stop: %v", err)
+	}
+	if p.IsRunning() {
+		t.Fatal("process still reports running after forced stop")
+	}
+}
+
+func initProcessTestLogger(t *testing.T) {
+	t.Helper()
+	t.Setenv("XUI_LOG_FOLDER", t.TempDir())
+	xuilogger.InitLogger(logging.ERROR)
+}
+
+func startProcessHelper(t *testing.T, mode string) *process {
+	t.Helper()
+
+	readyPath := filepath.Join(t.TempDir(), "ready")
+	cmd := exec.Command(os.Args[0], "-test.run=TestXrayProcessHelper", "--", mode)
+	cmd.Env = append(os.Environ(),
+		"XRAY_PROCESS_HELPER=1",
+		"XRAY_PROCESS_READY="+readyPath,
+	)
+
+	p := newProcess(nil)
+	if err := p.startCommand(cmd); err != nil {
+		t.Fatalf("start helper process: %v", err)
+	}
+	waitForProcessHelperReady(t, readyPath)
+
+	t.Cleanup(func() {
+		if p.IsRunning() {
+			p.intentionalStop.Store(true)
+			_ = p.cmd.Process.Kill()
+			_ = p.waitForExit(2 * time.Second)
+		}
+	})
+
+	return p
+}
+
+func waitForProcessHelperReady(t *testing.T, readyPath string) {
+	t.Helper()
+
+	deadline := time.Now().Add(2 * time.Second)
+	for time.Now().Before(deadline) {
+		if _, err := os.Stat(readyPath); err == nil {
+			return
+		}
+		time.Sleep(10 * time.Millisecond)
+	}
+	t.Fatalf("helper process did not become ready")
+}
+
+func TestXrayProcessHelper(t *testing.T) {
+	if os.Getenv("XRAY_PROCESS_HELPER") != "1" {
+		return
+	}
+
+	mode := ""
+	for i, arg := range os.Args {
+		if arg == "--" && i+1 < len(os.Args) {
+			mode = os.Args[i+1]
+			break
+		}
+	}
+
+	switch mode {
+	case "delayed-term":
+		sigCh := make(chan os.Signal, 1)
+		signal.Notify(sigCh, syscall.SIGTERM)
+		markProcessHelperReady(t)
+		<-sigCh
+		time.Sleep(200 * time.Millisecond)
+		os.Exit(0)
+	case "default-term":
+		markProcessHelperReady(t)
+		select {}
+	case "ignore-term":
+		signal.Ignore(syscall.SIGTERM)
+		markProcessHelperReady(t)
+		select {}
+	default:
+		t.Fatalf("unknown helper mode %q", mode)
+	}
+}
+
+func markProcessHelperReady(t *testing.T) {
+	t.Helper()
+
+	readyPath := os.Getenv("XRAY_PROCESS_READY")
+	if readyPath == "" {
+		t.Fatal("XRAY_PROCESS_READY is not set")
+	}
+	if err := os.WriteFile(readyPath, []byte("ready"), 0644); err != nil {
+		t.Fatalf("write helper ready file: %v", err)
+	}
+}