Hopefully fix xmpp server communication error handling, but fix is kinda dirty

2024-12-07 20:12:28 +03:00
parent 073138bde4
commit 21b5f59c1c
4 changed files with 101 additions and 79 deletions
--- a/Design.txt
+++ b/Design.txt
@@ -60,3 +60,12 @@ Cуществует несколько видов пинга:
 ------------------------------------------------------------------------------------------------------------------------
 Бот не читает историю, когда присоединяется к чатам, поэтому если его какое-то время не было в комнате и кто-то произнёс
 непотребную фразу, ретроспективного бана не будет.
+
+
+Проблема реконнекта
+------------------------------------------------------------------------------------------------------------------------
+На текущий момент решена не совсем чисто. Скорее всего, при реконнекте утекают ресурсы, связанные с jabber-соединением.
+Проблема в том, что приходится пересоздавать основной "объект" со всеми его полями.
+Кроме того, sig handler фактичеки не завершается, потому что в него не приходит ни одного сигнала и формально остаётся
+висеть на channel-е навечно.
+А ещё есть пингеры каналов и пингеры сервера. Их бы тоже завершать явным образом.
--- a/cmd/buny-jabber-bot/main.go
+++ b/cmd/buny-jabber-bot/main.go
@@ -16,88 +16,86 @@ import (

 // main - фактичеcки, начало и основное тело программы.
 func main() {
-	var j = jabber.Jabber{
-		SigChan:        make(chan os.Signal, 1),
-		GTomb:          tomb.Tomb{},
-		RoomsConnected: make([]string, 1),
-	}
-
-	log.SetFormatter(&log.TextFormatter{ //nolint:exhaustruct
-		DisableQuote:           true,
-		DisableLevelTruncation: false,
-		DisableColors:          true,
-		FullTimestamp:          true,
-		TimestampFormat:        "2006-01-02 15:04:05",
-	})
-
-	if err := j.ReadConfig(); err != nil {
-		log.Error(err)
-
-		os.Exit(1)
-	}
-
-	// no panic
-	switch j.C.Loglevel {
-	case "fatal":
-		log.SetLevel(log.FatalLevel)
-	case "error":
-		log.SetLevel(log.ErrorLevel)
-	case "warn":
-		log.SetLevel(log.WarnLevel)
-	case "info":
-		log.SetLevel(log.InfoLevel)
-	case "debug":
-		log.SetLevel(log.DebugLevel)
-	case "trace":
-		log.SetLevel(log.TraceLevel)
-	default:
-		log.SetLevel(log.InfoLevel)
-	}
-
-	// Откроем лог и скормим его логгеру.
-	if j.C.Log != "" {
-		logfile, err := os.OpenFile(j.C.Log, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0644)
-
-		if err != nil {
-			log.Fatalf("Unable to open log file %s: %s", j.C.Log, err)
+	for {
+		var j = jabber.Jabber{
+			SigChan:        make(chan os.Signal, 1),
+			GTomb:          tomb.Tomb{},
+			RoomsConnected: make([]string, 1),
 		}

-		log.SetOutput(logfile)
-	}
+		log.SetFormatter(&log.TextFormatter{ //nolint:exhaustruct
+			DisableQuote:           true,
+			DisableLevelTruncation: false,
+			DisableColors:          true,
+			FullTimestamp:          true,
+			TimestampFormat:        "2006-01-02 15:04:05",
+		})

-	myLogLevel := log.GetLevel()
-	log.Warnf("Loglevel set to %v", myLogLevel)
+		if err := j.ReadConfig(); err != nil {
+			log.Error(err)

-	verboseClient := false
+			os.Exit(1)
+		}

-	if myLogLevel == log.TraceLevel {
-		verboseClient = true
-	}
+		// no panic
+		switch j.C.Loglevel {
+		case "fatal":
+			log.SetLevel(log.FatalLevel)
+		case "error":
+			log.SetLevel(log.ErrorLevel)
+		case "warn":
+			log.SetLevel(log.WarnLevel)
+		case "info":
+			log.SetLevel(log.InfoLevel)
+		case "debug":
+			log.SetLevel(log.DebugLevel)
+		case "trace":
+			log.SetLevel(log.TraceLevel)
+		default:
+			log.SetLevel(log.InfoLevel)
+		}

-	// Самое время вгрузить белые и чёрные списки, если что - получим ошибку в лог.
-	if err := j.ReadWhitelist(); err != nil {
-		log.Error(err)
+		// Откроем лог и скормим его логгеру.
+		if j.C.Log != "" {
+			logfile, err := os.OpenFile(j.C.Log, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0644)

-		os.Exit(1)
-	}
+			if err != nil {
+				log.Fatalf("Unable to open log file %s: %s", j.C.Log, err)
+			}

-	if err := j.ReadBlacklist(); err != nil {
-		log.Error(err)
+			log.SetOutput(logfile)
+		}

-		os.Exit(1)
-	}
+		myLogLevel := log.GetLevel()
+		log.Warnf("Loglevel set to %v", myLogLevel)

-	// github.com/mattn/go-xmpp пишет в stdio, нам этого не надо, ловим выхлоп его в logrus с уровнем trace.
-	xmpp.DebugWriter = log.WithFields(log.Fields{"logger": "stdlib"}).WriterLevel(log.TraceLevel)
+		verboseClient := false

-	// Хэндлер сигналов не надо трогать, он нужен для завершения программы целиком.
-	go j.SigHandler()
-	signal.Notify(j.SigChan, os.Interrupt)
+		if myLogLevel == log.TraceLevel {
+			verboseClient = true
+		}
+
+		// Самое время вгрузить белые и чёрные списки, если что - получим ошибку в лог.
+		if err := j.ReadWhitelist(); err != nil {
+			log.Error(err)
+
+			os.Exit(1)
+		}
+
+		if err := j.ReadBlacklist(); err != nil {
+			log.Error(err)
+
+			os.Exit(1)
+		}
+
+		// github.com/mattn/go-xmpp пишет в stdio, нам этого не надо, ловим выхлоп его в logrus с уровнем trace.
+		xmpp.DebugWriter = log.WithFields(log.Fields{"logger": "stdlib"}).WriterLevel(log.TraceLevel)
+
+		// Хэндлер сигналов.
+		j.GTomb.Go(func() error { return j.SigHandler() })
+
+		signal.Notify(j.SigChan, os.Interrupt)

-	// Враппер основной программы. Фактически на каждой серьёзной ошибке, например, сетевой, mainLoop и некоторые
-	// вспомогательные корутины прекращает свою работу. Здесь мы это ловим и запускаем их снова. Задача в том, чтобы
-	// запустить все асинхронные процессы заново, с чистого листа, но уже с распарсенным конфигом.
-	for {
 		j.Options = &xmpp.Options{ //nolint:exhaustruct
 			Host:     fmt.Sprintf("%s:%d", j.C.Jabber.Server, j.C.Jabber.Port),
 			User:     j.C.Jabber.User,
@@ -117,17 +115,18 @@ func main() {
 			DialTimeout:                  time.Duration(j.C.Jabber.ConnectionTimeout) * time.Second,
 		}

+		// Враппер основной программы. Фактически на каждой серьёзной ошибке, например, сетевой, mainLoop и некоторые
+		// вспомогательные корутины прекращает свою работу. Здесь мы это ловим и запускаем их снова. Задача в том, чтобы
+		// запустить все асинхронные процессы заново, с чистого листа, но уже с распарсенным конфигом.
+
 		// Устанавливаем соединение и гребём события, посылаемые сервером - основной и вспомогательные циклы программы.
 		j.GTomb.Go(func() error { return j.MyLoop() })

-		// Логгируем причину завершения mainLoop и вспомогательных циклов программы.
-		log.Error(j.GTomb.Wait())
+		// Ловим первый же kill и не дождаемся остальных, хотя формально надо бы.
+		_ = <-j.GTomb.Dying()

-		// Если у нас wire error, то вызов .Close() повлечёт за собой ошибку, но мы вынуждены звать .Close(), чтоб
-		// закрыть tls контекст и почистить всё что связанно с прерванным соединением.
-		log.Infoln("Closing connection to jabber server")
-
-		_ = j.Talk.Close()
+		// Если у нас wire error, то вызов .Close() повлечёт за собой ошибку. А если у нас не wire error, то по ходу мы
+		// получим утечку сокетов.

 		time.Sleep(time.Duration(j.C.Jabber.ReconnectDelay) * time.Second)
 	}
--- a/internal/jabber/main_loop.go
+++ b/internal/jabber/main_loop.go
@@ -2,6 +2,8 @@ package jabber

 import (
 	"time"
+
+	log "github.com/sirupsen/logrus"
 )

 // MyLoop - основной цикл программы.
@@ -23,13 +25,21 @@ func (j *Jabber) MyLoop() error {

 		// Установим коннект
 		if err := j.EstablishConnection(); err != nil {
+			log.Error(err)
+
 			return err
 		}

 		j.ServerPingTimestampRx = time.Now().Unix() // Считаем, что если коннект запустился, то первый пинг успешен.

 		// Тыкаем сервер палочкой, проверяем, что коннект жив и вываливаемся из mainLoop, если он не жив.
-		j.GTomb.Go(func() error { return j.ProbeServerLiveness() })
+		j.GTomb.Go(
+			func() error {
+				err := j.ProbeServerLiveness()
+				log.Error(err)
+				return err
+			},
+		)

 		// Тыкаем muc-и палочкой, проверяем, что они живы и вываливаемся из mainLoop, если пинги пропали.
 		// Если пинги до комнаты пропали, то это фактически значит, что либо сервер потерял связь с MUC-компонентом,
@@ -56,6 +66,8 @@ func (j *Jabber) MyLoop() error {
 			chat, err := j.Talk.Recv()

 			if err != nil {
+				log.Errorf("Unable to get recieve data from socket: %s", err)
+
 				return err
 			}

--- a/internal/jabber/sig_handler.go
+++ b/internal/jabber/sig_handler.go
@@ -8,7 +8,7 @@ import (
 	log "github.com/sirupsen/logrus"
 )

-func (j *Jabber) SigHandler() {
+func (j *Jabber) SigHandler() error {
 	log.Debug("Installing signal handler")

 	for s := range j.SigChan {
@@ -55,4 +55,6 @@ func (j *Jabber) SigHandler() {

 		os.Exit(0)
 	}
+
+	return nil
 }