fix(webhooks): increase timeout (#902)

* fix(webhooks): increase timeout

* feat: mockindexer add dummy webhook endpoint

internal/action/run.go

@@ -189,11 +189,11 @@ func (s *service) watchFolder(ctx context.Context, action *domain.Action, releas
 }
 
 func (s *service) webhook(ctx context.Context, action *domain.Action, release domain.Release) error {
-	s.log.Trace().Msgf("action WEBHOOK: '%v' file: %v", action.Name, release.TorrentName)
+	s.log.Trace().Msgf("action WEBHOOK: '%s' file: %s", action.Name, release.TorrentName)
 	if len(action.WebhookData) > 1024 {
-		s.log.Trace().Msgf("webhook action '%v' - host: %v data: %v", action.Name, action.WebhookHost, action.WebhookData[:1024])
+		s.log.Trace().Msgf("webhook action '%s' - host: %s data: %s", action.Name, action.WebhookHost, action.WebhookData[:1024])
 	} else {
-		s.log.Trace().Msgf("webhook action '%v' - host: %v data: %v", action.Name, action.WebhookHost, action.WebhookData)
+		s.log.Trace().Msgf("webhook action '%s' - host: %s data: %s", action.Name, action.WebhookHost, action.WebhookData)
 	}
 
 	t := &http.Transport{
@@ -202,7 +202,7 @@ func (s *service) webhook(ctx context.Context, action *domain.Action, release do
 		},
 	}
 
-	client := http.Client{Transport: t, Timeout: 15 * time.Second}
+	client := http.Client{Transport: t, Timeout: 120 * time.Second}
 
 	req, err := http.NewRequestWithContext(ctx, http.MethodPost, action.WebhookHost, bytes.NewBufferString(action.WebhookData))
 	if err != nil {
@@ -212,6 +212,8 @@ func (s *service) webhook(ctx context.Context, action *domain.Action, release do
 	req.Header.Set("Content-Type", "application/json")
 	req.Header.Set("User-Agent", "autobrr")
 
+	start := time.Now()
+
 	res, err := client.Do(req)
 	if err != nil {
 		return errors.Wrap(err, "could not make request for webhook")
@@ -220,9 +222,9 @@ func (s *service) webhook(ctx context.Context, action *domain.Action, release do
 	defer res.Body.Close()
 
 	if len(action.WebhookData) > 256 {
-		s.log.Info().Msgf("successfully ran webhook action: '%v' to: %v payload: %v", action.Name, action.WebhookHost, action.WebhookData[:256])
+		s.log.Info().Msgf("successfully ran webhook action: '%s' to: %s payload: %s finished in %s", action.Name, action.WebhookHost, action.WebhookData[:256], time.Since(start))
 	} else {
-		s.log.Info().Msgf("successfully ran webhook action: '%v' to: %v payload: %v", action.Name, action.WebhookHost, action.WebhookData)
+		s.log.Info().Msgf("successfully ran webhook action: '%s' to: %s payload: %s finished in %s", action.Name, action.WebhookHost, action.WebhookData, time.Since(start))
 	}
 
 	return nil

internal/filter/service.go

@@ -570,10 +570,12 @@ func (s *service) execCmd(ctx context.Context, release *domain.Release, cmd stri
 }
 
 func (s *service) webhook(ctx context.Context, release *domain.Release, url string, data string) (int, error) {
+	s.log.Debug().Msgf("preparing to run external webhook filter to: (%s) payload: (%s)", url, data)
+
 	// if webhook data contains TorrentPathName or TorrentDataRawBytes, lets download the torrent file
 	if release.TorrentTmpFile == "" && (strings.Contains(data, "TorrentPathName") || strings.Contains(data, "TorrentDataRawBytes")) {
 		if err := release.DownloadTorrentFileCtx(ctx); err != nil {
-			return 0, errors.Wrap(err, "webhook: could not download torrent file for release: %v", release.TorrentName)
+			return 0, errors.Wrap(err, "webhook: could not download torrent file for release: %s", release.TorrentName)
 		}
 	}
 
@@ -581,7 +583,7 @@ func (s *service) webhook(ctx context.Context, release *domain.Release, url stri
 	if len(release.TorrentDataRawBytes) == 0 && strings.Contains(data, "TorrentDataRawBytes") {
 		t, err := os.ReadFile(release.TorrentTmpFile)
 		if err != nil {
-			return 0, errors.Wrap(err, "could not read torrent file: %v", release.TorrentTmpFile)
+			return 0, errors.Wrap(err, "could not read torrent file: %s", release.TorrentTmpFile)
 		}
 
 		release.TorrentDataRawBytes = t
@@ -592,16 +594,18 @@ func (s *service) webhook(ctx context.Context, release *domain.Release, url stri
 	// parse and replace values in argument string before continuing
 	dataArgs, err := m.Parse(data)
 	if err != nil {
-		return 0, errors.Wrap(err, "could not parse webhook data macro: %v", data)
+		return 0, errors.Wrap(err, "could not parse webhook data macro: %s", data)
 	}
 
+	s.log.Debug().Msgf("sending POST to external webhook filter: (%s) payload: (%s)", url, data)
+
 	t := &http.Transport{
 		TLSClientConfig: &tls.Config{
 			InsecureSkipVerify: true,
 		},
 	}
 
-	client := http.Client{Transport: t, Timeout: 15 * time.Second}
+	client := http.Client{Transport: t, Timeout: 120 * time.Second}
 
 	req, err := http.NewRequestWithContext(ctx, http.MethodPost, url, bytes.NewBufferString(dataArgs))
 	if err != nil {
@@ -611,6 +615,8 @@ func (s *service) webhook(ctx context.Context, release *domain.Release, url stri
 	req.Header.Set("Content-Type", "application/json")
 	req.Header.Set("User-Agent", "autobrr")
 
+	start := time.Now()
+
 	res, err := client.Do(req)
 	if err != nil {
 		return 0, errors.Wrap(err, "could not make request for webhook")
@@ -622,7 +628,7 @@ func (s *service) webhook(ctx context.Context, release *domain.Release, url stri
 		return res.StatusCode, nil
 	}
 
-	s.log.Debug().Msgf("successfully ran external webhook filter to: (%v) payload: (%v)", url, dataArgs)
+	s.log.Debug().Msgf("successfully ran external webhook filter to: (%s) payload: (%s) finished in %s", url, dataArgs, time.Since(start))
 
 	return res.StatusCode, nil
 }

test/mockindexer/main.go

@@ -9,6 +9,7 @@ import (
 	"log"
 	"net/http"
 	"os"
+	"time"
 
 	"github.com/autobrr/autobrr/test/mockindexer/irc"
 	"github.com/go-chi/chi/v5"
@@ -32,6 +33,11 @@ func main() {
 	r := chi.NewRouter()
 	r.Use(middleware.Logger)
 
+	r.Post("/webhook", func(w http.ResponseWriter, r *http.Request) {
+		time.Sleep(30 * time.Second)
+		w.WriteHeader(http.StatusOK)
+	})
+
 	r.Get("/", func(w http.ResponseWriter, r *http.Request) {
 		w.Write([]byte("<html><form method=\"POST\" action=\"/send\">Send an announce line to the channel<br><input style=\"width: 100%; margin-top: 5px; margin-bottom: 5px;\" name=\"line\" type=\"text\"><br><button type=\"submit\">Send to channel</button></form></html>"))
 	})