From 402596523dffb5e404bef8d86ea61e89670e71ef Mon Sep 17 00:00:00 2001 From: Ludvig Lundgren Date: Thu, 7 Jul 2022 16:28:14 +0200 Subject: [PATCH] feat(actions): improve errors and logs (#340) --- internal/action/deluge.go | 264 +++++++++++-------------- internal/action/exec.go | 28 +-- internal/action/exec_test.go | 2 +- internal/action/lidarr.go | 5 +- internal/action/macros.go | 5 +- internal/action/macros_test.go | 1 + internal/action/qbittorrent.go | 178 ++++++++++------- internal/action/radarr.go | 11 +- internal/action/run.go | 185 ++++------------- internal/action/service.go | 18 +- internal/action/sonarr.go | 6 +- internal/action/whisparr.go | 11 +- internal/domain/release.go | 8 +- internal/download_client/connection.go | 9 +- internal/download_client/service.go | 2 +- 15 files changed, 315 insertions(+), 418 deletions(-) diff --git a/internal/action/deluge.go b/internal/action/deluge.go index df02905..3ef8bdb 100644 --- a/internal/action/deluge.go +++ b/internal/action/deluge.go @@ -3,16 +3,16 @@ package action import ( "context" "encoding/base64" - "errors" "io/ioutil" "time" "github.com/autobrr/autobrr/internal/domain" + "github.com/autobrr/autobrr/pkg/errors" delugeClient "github.com/gdm85/go-libdeluge" ) -func (s *service) deluge(action domain.Action, release domain.Release) error { +func (s *service) deluge(action domain.Action, release domain.Release) ([]string, error) { s.log.Debug().Msgf("action Deluge: %v", action.Name) var err error @@ -21,84 +21,34 @@ func (s *service) deluge(action domain.Action, release domain.Release) error { client, err := s.clientSvc.FindByID(context.TODO(), action.ClientID) if err != nil { s.log.Error().Stack().Err(err).Msgf("error finding client: %v", action.ClientID) - return err + return nil, err } if client == nil { - return errors.New("no client found") + return nil, errors.New("could not find client by id: %v", action.ClientID) } - settings := delugeClient.Settings{ - Hostname: client.Host, - Port: uint(client.Port), - Login: client.Username, - Password: client.Password, - DebugServerResponses: true, - ReadWriteTimeout: time.Second * 20, - } + var rejections []string switch client.Type { case "DELUGE_V1": - if err = s.delugeV1(client, settings, action, release); err != nil { - return err - } + rejections, err = s.delugeV1(client, action, release) case "DELUGE_V2": - if err = s.delugeV2(client, settings, action, release); err != nil { - return err - } + rejections, err = s.delugeV2(client, action, release) } - return nil + return rejections, err } -func (s *service) delugeCheckRulesCanDownload(action domain.Action) (bool, error) { +func (s *service) delugeCheckRulesCanDownload(deluge delugeClient.DelugeClient, client *domain.DownloadClient, action domain.Action) ([]string, error) { s.log.Trace().Msgf("action Deluge: %v check rules", action.Name) - // get client for action - client, err := s.clientSvc.FindByID(context.TODO(), action.ClientID) - if err != nil { - s.log.Error().Stack().Err(err).Msgf("error finding client: %v ID %v", action.Name, action.ClientID) - return false, err - } - - if client == nil { - return false, errors.New("no client found") - } - - settings := delugeClient.Settings{ - Hostname: client.Host, - Port: uint(client.Port), - Login: client.Username, - Password: client.Password, - DebugServerResponses: true, - ReadWriteTimeout: time.Second * 20, - } - var deluge delugeClient.DelugeClient - - switch client.Type { - case "DELUGE_V1": - deluge = delugeClient.NewV1(settings) - - case "DELUGE_V2": - deluge = delugeClient.NewV2(settings) - } - - // perform connection to Deluge server - err = deluge.Connect() - if err != nil { - s.log.Error().Stack().Err(err).Msgf("error logging into client: %v %v", client.Name, client.Host) - return false, err - } - - defer deluge.Close() - // check for active downloads and other rules if client.Settings.Rules.Enabled && !action.IgnoreRules { activeDownloads, err := deluge.TorrentsStatus(delugeClient.StateDownloading, nil) if err != nil { - s.log.Error().Stack().Err(err).Msg("Deluge - could not fetch downloading torrents") - return false, err + return nil, errors.Wrap(err, "could not fetch downloading torrents") } // make sure it's not set to 0 by default @@ -107,7 +57,9 @@ func (s *service) delugeCheckRulesCanDownload(action domain.Action) (bool, error // if max active downloads reached, check speed and if lower than threshold add anyways if len(activeDownloads) >= client.Settings.Rules.MaxActiveDownloads { s.log.Debug().Msg("max active downloads reached, skipping") - return false, nil + + rejections := []string{"max active downloads reached, skipping"} + return rejections, nil // // TODO handle ignore slow torrents //if client.Settings.Rules.IgnoreSlowTorrents { @@ -131,132 +83,177 @@ func (s *service) delugeCheckRulesCanDownload(action domain.Action) (bool, error } } - return true, nil + return nil, nil } -func (s *service) delugeV1(client *domain.DownloadClient, settings delugeClient.Settings, action domain.Action, release domain.Release) error { +func (s *service) delugeV1(client *domain.DownloadClient, action domain.Action, release domain.Release) ([]string, error) { + settings := delugeClient.Settings{ + Hostname: client.Host, + Port: uint(client.Port), + Login: client.Username, + Password: client.Password, + DebugServerResponses: true, + ReadWriteTimeout: time.Second * 20, + } deluge := delugeClient.NewV1(settings) // perform connection to Deluge server err := deluge.Connect() if err != nil { - s.log.Error().Stack().Err(err).Msgf("error logging into client: %v %v", client.Name, client.Host) - return err + return nil, errors.Wrap(err, "could not connect to client %v at %v", client.Name, client.Host) } defer deluge.Close() + // perform connection to Deluge server + rejections, err := s.delugeCheckRulesCanDownload(deluge, client, action) + if err != nil { + s.log.Error().Err(err).Msgf("error checking client rules: %v", action.Name) + return nil, err + } + if rejections != nil { + return rejections, nil + } + + if release.TorrentTmpFile == "" { + err = release.DownloadTorrentFile() + if err != nil { + s.log.Error().Err(err).Msgf("could not download torrent file for release: %v", release.TorrentName) + return nil, err + } + } + t, err := ioutil.ReadFile(release.TorrentTmpFile) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not read torrent file: %v", release.TorrentTmpFile) - return err + return nil, errors.Wrap(err, "could not read torrent file: %v", release.TorrentTmpFile) } // encode file to base64 before sending to deluge encodedFile := base64.StdEncoding.EncodeToString(t) if encodedFile == "" { - s.log.Error().Stack().Err(err).Msgf("could not encode torrent file: %v", release.TorrentTmpFile) - return err + return nil, errors.Wrap(err, "could not encode torrent file: %v", release.TorrentTmpFile) } - // set options - options := delugeClient.Options{} - // macros handle args and replace vars m := NewMacro(release) - if action.Paused { - options.AddPaused = &action.Paused - } - if action.SavePath != "" { - // parse and replace values in argument string before continuing - savePathArgs, err := m.Parse(action.SavePath) - if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not parse macro: %v", action.SavePath) - return err - } - - options.DownloadLocation = &savePathArgs - } - if action.LimitDownloadSpeed > 0 { - maxDL := int(action.LimitDownloadSpeed) - options.MaxDownloadSpeed = &maxDL - } - if action.LimitUploadSpeed > 0 { - maxUL := int(action.LimitUploadSpeed) - options.MaxUploadSpeed = &maxUL + options, err := s.prepareDelugeOptions(action, m) + if err != nil { + return nil, errors.Wrap(err, "could not prepare options") } s.log.Trace().Msgf("action Deluge options: %+v", options) torrentHash, err := deluge.AddTorrentFile(release.TorrentTmpFile, encodedFile, &options) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not add torrent %v to client: %v", release.TorrentTmpFile, client.Name) - return err + return nil, errors.Wrap(err, "could not add torrent %v to client: %v", release.TorrentTmpFile, client.Name) } if action.Label != "" { - p, err := deluge.LabelPlugin() + labelPluginActive, err := deluge.LabelPlugin() if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not load label plugin: %v", client.Name) - return err + return nil, errors.Wrap(err, "could not load label plugin for client: %v", client.Name) } // parse and replace values in argument string before continuing labelArgs, err := m.Parse(action.Label) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not parse macro: %v", action.Label) - return err + return nil, errors.Wrap(err, "could not parse macro label: %v", action.Label) } - if p != nil { + if labelPluginActive != nil { // TODO first check if label exists, if not, add it, otherwise set - err = p.SetTorrentLabel(torrentHash, labelArgs) + err = labelPluginActive.SetTorrentLabel(torrentHash, labelArgs) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not set label: %v on client: %v", action.Label, client.Name) - return err + return nil, errors.Wrap(err, "could not set label: %v on client: %v", action.Label, client.Name) } } } s.log.Info().Msgf("torrent with hash %v successfully added to client: '%v'", torrentHash, client.Name) - return nil + return nil, nil } -func (s *service) delugeV2(client *domain.DownloadClient, settings delugeClient.Settings, action domain.Action, release domain.Release) error { +func (s *service) delugeV2(client *domain.DownloadClient, action domain.Action, release domain.Release) ([]string, error) { + settings := delugeClient.Settings{ + Hostname: client.Host, + Port: uint(client.Port), + Login: client.Username, + Password: client.Password, + DebugServerResponses: true, + ReadWriteTimeout: time.Second * 20, + } deluge := delugeClient.NewV2(settings) // perform connection to Deluge server err := deluge.Connect() if err != nil { - s.log.Error().Stack().Err(err).Msgf("error logging into client: %v %v", client.Name, client.Host) - return err + return nil, errors.Wrap(err, "could not connect to client %v at %v", client.Name, client.Host) } defer deluge.Close() t, err := ioutil.ReadFile(release.TorrentTmpFile) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not read torrent file: %v", release.TorrentTmpFile) - return err + return nil, errors.Wrap(err, "could not read torrent file: %v", release.TorrentTmpFile) } // encode file to base64 before sending to deluge encodedFile := base64.StdEncoding.EncodeToString(t) if encodedFile == "" { - s.log.Error().Stack().Err(err).Msgf("could not encode torrent file: %v", release.TorrentTmpFile) - return err + return nil, errors.Wrap(err, "could not encode torrent file: %v", release.TorrentTmpFile) } - // set options - options := delugeClient.Options{} - // macros handle args and replace vars m := NewMacro(release) + // set options + options, err := s.prepareDelugeOptions(action, m) + if err != nil { + return nil, errors.Wrap(err, "could not prepare options") + } + + s.log.Trace().Msgf("action Deluge options: %+v", options) + + torrentHash, err := deluge.AddTorrentFile(release.TorrentTmpFile, encodedFile, &options) + if err != nil { + return nil, errors.Wrap(err, "could not add torrent %v to client: %v", release.TorrentTmpFile, client.Name) + } + + if action.Label != "" { + labelPluginActive, err := deluge.LabelPlugin() + if err != nil { + return nil, errors.Wrap(err, "could not load label plugin for client: %v", client.Name) + } + + // parse and replace values in argument string before continuing + labelArgs, err := m.Parse(action.Label) + if err != nil { + return nil, errors.Wrap(err, "could not parse macro label: %v", action.Label) + } + + if labelPluginActive != nil { + // TODO first check if label exists, if not, add it, otherwise set + err = labelPluginActive.SetTorrentLabel(torrentHash, labelArgs) + if err != nil { + return nil, errors.Wrap(err, "could not set label: %v on client: %v", action.Label, client.Name) + } + } + } + + s.log.Info().Msgf("torrent with hash %v successfully added to client: '%v'", torrentHash, client.Name) + + return nil, nil +} + +func (s *service) prepareDelugeOptions(action domain.Action, m Macro) (delugeClient.Options, error) { + + // set options + options := delugeClient.Options{} + if action.Paused { options.AddPaused = &action.Paused } @@ -264,8 +261,7 @@ func (s *service) delugeV2(client *domain.DownloadClient, settings delugeClient. // parse and replace values in argument string before continuing savePathArgs, err := m.Parse(action.SavePath) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not parse macro: %v", action.SavePath) - return err + return options, errors.Wrap(err, "could not parse save path macro: %v", action.SavePath) } options.DownloadLocation = &savePathArgs @@ -279,39 +275,5 @@ func (s *service) delugeV2(client *domain.DownloadClient, settings delugeClient. options.MaxUploadSpeed = &maxUL } - s.log.Trace().Msgf("action Deluge options: %+v", options) - - torrentHash, err := deluge.AddTorrentFile(release.TorrentTmpFile, encodedFile, &options) - if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not add torrent %v to client: %v", release.TorrentTmpFile, client.Name) - return err - } - - if action.Label != "" { - p, err := deluge.LabelPlugin() - if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not load label plugin: %v", client.Name) - return err - } - - // parse and replace values in argument string before continuing - labelArgs, err := m.Parse(action.Label) - if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not parse macro: %v", action.Label) - return err - } - - if p != nil { - // TODO first check if label exists, if not, add it, otherwise set - err = p.SetTorrentLabel(torrentHash, labelArgs) - if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not set label: %v on client: %v", action.Label, client.Name) - return err - } - } - } - - s.log.Info().Msgf("torrent with hash %v successfully added to client: '%v'", torrentHash, client.Name) - - return nil + return options, nil } diff --git a/internal/action/exec.go b/internal/action/exec.go index 93f648b..4a13c6e 100644 --- a/internal/action/exec.go +++ b/internal/action/exec.go @@ -4,25 +4,30 @@ import ( "os/exec" "time" - "github.com/mattn/go-shellwords" - "github.com/autobrr/autobrr/internal/domain" + "github.com/autobrr/autobrr/pkg/errors" + + "github.com/mattn/go-shellwords" ) -func (s *service) execCmd(release domain.Release, action domain.Action) { +func (s *service) execCmd(action domain.Action, release domain.Release) error { s.log.Debug().Msgf("action exec: %v release: %v", action.Name, release.TorrentName) + if release.TorrentTmpFile == "" { + if err := release.DownloadTorrentFile(); err != nil { + return errors.Wrap(err, "error downloading torrent file for release: %v", release.TorrentName) + } + } + // check if program exists cmd, err := exec.LookPath(action.ExecCmd) if err != nil { - s.log.Error().Stack().Err(err).Msgf("exec failed, could not find program: %v", action.ExecCmd) - return + return errors.Wrap(err, "exec failed, could not find program: %v", action.ExecCmd) } args, err := s.parseExecArgs(release, action.ExecArgs) if err != nil { - s.log.Error().Stack().Err(err).Msgf("parsing args failed: command: %v args: %v torrent: %v", cmd, action.ExecArgs, release.TorrentTmpFile) - return + return errors.Wrap(err, "could not parse exec args: %v", action.ExecArgs) } // we need to split on space into a string slice, so we can spread the args into exec @@ -36,8 +41,7 @@ func (s *service) execCmd(release domain.Release, action domain.Action) { output, err := command.CombinedOutput() if err != nil { // everything other than exit 0 is considered an error - s.log.Error().Stack().Err(err).Msgf("command: %v args: %v failed, torrent: %v", cmd, args, release.TorrentTmpFile) - return + return errors.Wrap(err, "error executing command: %v args: %v", cmd, args) } s.log.Trace().Msgf("executed command: '%v'", string(output)) @@ -45,6 +49,8 @@ func (s *service) execCmd(release domain.Release, action domain.Action) { duration := time.Since(start) s.log.Info().Msgf("executed command: '%v', args: '%v' %v,%v, total time %v", cmd, args, release.TorrentName, release.Indexer, duration) + + return nil } func (s *service) parseExecArgs(release domain.Release, execArgs string) ([]string, error) { @@ -54,14 +60,14 @@ func (s *service) parseExecArgs(release domain.Release, execArgs string) ([]stri // parse and replace values in argument string before continuing parsedArgs, err := m.Parse(execArgs) if err != nil { - return nil, err + return nil, errors.Wrap(err, "could not parse macro") } p := shellwords.NewParser() p.ParseBacktick = true args, err := p.Parse(parsedArgs) if err != nil { - return nil, err + return nil, errors.Wrap(err, "could not parse into shell-words") } return args, nil diff --git a/internal/action/exec_test.go b/internal/action/exec_test.go index 32f1641..1b384e1 100644 --- a/internal/action/exec_test.go +++ b/internal/action/exec_test.go @@ -108,7 +108,7 @@ func Test_service_execCmd(t *testing.T) { clientSvc: nil, bus: nil, } - s.execCmd(tt.args.release, tt.args.action) + s.execCmd(tt.args.action, tt.args.release) }) } } diff --git a/internal/action/lidarr.go b/internal/action/lidarr.go index 0d9f20c..e07c9e3 100644 --- a/internal/action/lidarr.go +++ b/internal/action/lidarr.go @@ -6,10 +6,11 @@ import ( "time" "github.com/autobrr/autobrr/internal/domain" + "github.com/autobrr/autobrr/pkg/errors" "github.com/autobrr/autobrr/pkg/lidarr" ) -func (s *service) lidarr(release domain.Release, action domain.Action) ([]string, error) { +func (s *service) lidarr(action domain.Action, release domain.Release) ([]string, error) { s.log.Trace().Msg("action LIDARR") // TODO validate data @@ -23,7 +24,7 @@ func (s *service) lidarr(release domain.Release, action domain.Action) ([]string // return early if no client found if client == nil { - return nil, err + return nil, errors.New("could not find client by id: %v", action.ClientID) } // initial config diff --git a/internal/action/macros.go b/internal/action/macros.go index 1edfe7b..3de5df6 100644 --- a/internal/action/macros.go +++ b/internal/action/macros.go @@ -7,6 +7,7 @@ import ( "time" "github.com/autobrr/autobrr/internal/domain" + "github.com/autobrr/autobrr/pkg/errors" ) type Macro struct { @@ -65,13 +66,13 @@ func (m Macro) Parse(text string) (string, error) { // setup template tmpl, err := template.New("macro").Parse(text) if err != nil { - return "", err + return "", errors.Wrap(err, "could parse macro template") } var tpl bytes.Buffer err = tmpl.Execute(&tpl, m) if err != nil { - return "", err + return "", errors.Wrap(err, "could not parse macro") } return tpl.String(), nil diff --git a/internal/action/macros_test.go b/internal/action/macros_test.go index e22bab4..038a5a6 100644 --- a/internal/action/macros_test.go +++ b/internal/action/macros_test.go @@ -6,6 +6,7 @@ import ( "time" "github.com/autobrr/autobrr/internal/domain" + "github.com/stretchr/testify/assert" ) diff --git a/internal/action/qbittorrent.go b/internal/action/qbittorrent.go index 6de637d..86588da 100644 --- a/internal/action/qbittorrent.go +++ b/internal/action/qbittorrent.go @@ -7,18 +7,102 @@ import ( "time" "github.com/autobrr/autobrr/internal/domain" + "github.com/autobrr/autobrr/pkg/errors" "github.com/autobrr/autobrr/pkg/qbittorrent" ) const ReannounceMaxAttempts = 50 const ReannounceInterval = 7000 -func (s *service) qbittorrent(qbt *qbittorrent.Client, action domain.Action, release domain.Release) error { +func (s *service) qbittorrent(action domain.Action, release domain.Release) ([]string, error) { s.log.Debug().Msgf("action qBittorrent: %v", action.Name) + // get client for action + client, err := s.clientSvc.FindByID(context.TODO(), action.ClientID) + if err != nil { + return nil, errors.Wrap(err, "error finding client: %v", action.ClientID) + } + + if client == nil { + return nil, errors.New("could not find client by id: %v", action.ClientID) + } + + qbt, exists := s.qbitClients[qbitKey{client.ID, client.Name}] + if !exists { + qbtSettings := qbittorrent.Settings{ + Hostname: client.Host, + Port: uint(client.Port), + Username: client.Username, + Password: client.Password, + TLS: client.TLS, + TLSSkipVerify: client.TLSSkipVerify, + Log: s.subLogger, + } + + // only set basic auth if enabled + if client.Settings.Basic.Auth { + qbtSettings.BasicAuth = client.Settings.Basic.Auth + qbtSettings.Basic.Username = client.Settings.Basic.Username + qbtSettings.Basic.Password = client.Settings.Basic.Password + } + + qbt = qbittorrent.NewClient(qbtSettings) + qbt.Name = client.Name + + s.qbitClients[qbitKey{client.ID, client.Name}] = qbt + + if err = qbt.Login(); err != nil { + return nil, errors.Wrap(err, "could not log into client: %v at %v", client.Name, client.Host) + } + } + + if qbt == nil { + return nil, errors.New("qbit client does not exist") + } + + rejections, err := s.qbittorrentCheckRulesCanDownload(action, client, qbt) + if err != nil { + return nil, errors.Wrap(err, "error checking client rules: %v", action.Name) + } + + if rejections != nil { + return rejections, nil + } + + if release.TorrentTmpFile == "" { + err = release.DownloadTorrentFile() + if err != nil { + return nil, errors.Wrap(err, "error downloading torrent file for release: %v", release.TorrentName) + } + } + // macros handle args and replace vars m := NewMacro(release) + options, err := s.prepareQbitOptions(action, m) + if err != nil { + return nil, errors.Wrap(err, "could not prepare options") + } + + s.log.Trace().Msgf("action qBittorrent options: %+v", options) + + if err = qbt.AddTorrentFromFile(release.TorrentTmpFile, options); err != nil { + return nil, errors.Wrap(err, "could not add torrent %v to client: %v", release.TorrentTmpFile, qbt.Name) + } + + if !action.Paused && !action.ReAnnounceSkip && release.TorrentHash != "" { + if err := s.reannounceTorrent(qbt, action, release.TorrentHash); err != nil { + return nil, errors.Wrap(err, "could not reannounce torrent: %v", release.TorrentHash) + } + } + + s.log.Info().Msgf("torrent with hash %v successfully added to client: '%v'", release.TorrentHash, qbt.Name) + + return nil, nil +} + +func (s *service) prepareQbitOptions(action domain.Action, m Macro) (map[string]string, error) { + options := map[string]string{} if action.Paused { @@ -28,8 +112,7 @@ func (s *service) qbittorrent(qbt *qbittorrent.Client, action domain.Action, rel // parse and replace values in argument string before continuing actionArgs, err := m.Parse(action.SavePath) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not parse macro: %v", action.SavePath) - return err + return nil, errors.Wrap(err, "could not parse savepath macro: %v", action.SavePath) } options["savepath"] = actionArgs @@ -39,8 +122,7 @@ func (s *service) qbittorrent(qbt *qbittorrent.Client, action domain.Action, rel // parse and replace values in argument string before continuing categoryArgs, err := m.Parse(action.Category) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not parse macro: %v", action.Category) - return err + return nil, errors.Wrap(err, "could not parse category macro: %v", action.Category) } options["category"] = categoryArgs @@ -49,8 +131,7 @@ func (s *service) qbittorrent(qbt *qbittorrent.Client, action domain.Action, rel // parse and replace values in argument string before continuing tagsArgs, err := m.Parse(action.Tags) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not parse macro: %v", action.Tags) - return err + return nil, errors.Wrap(err, "could not parse tags macro: %v", action.Tags) } options["tags"] = tagsArgs @@ -68,72 +149,17 @@ func (s *service) qbittorrent(qbt *qbittorrent.Client, action domain.Action, rel options["seedingTimeLimit"] = strconv.FormatInt(action.LimitSeedTime, 10) } - s.log.Trace().Msgf("action qBittorrent options: %+v", options) - - err := qbt.AddTorrentFromFile(release.TorrentTmpFile, options) - if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not add torrent %v to client: %v", release.TorrentTmpFile, qbt.Name) - return err - } - - if !action.Paused && !action.ReAnnounceSkip && release.TorrentHash != "" { - if err := s.reannounceTorrent(qbt, action, release.TorrentHash); err != nil { - s.log.Error().Stack().Err(err).Msgf("could not reannounce torrent: %v", release.TorrentHash) - return err - } - } - - s.log.Info().Msgf("torrent with hash %v successfully added to client: '%v'", release.TorrentHash, qbt.Name) - - return nil + return options, nil } -func (s *service) qbittorrentCheckRulesCanDownload(action domain.Action) (bool, *qbittorrent.Client, error) { +func (s *service) qbittorrentCheckRulesCanDownload(action domain.Action, client *domain.DownloadClient, qbt *qbittorrent.Client) ([]string, error) { s.log.Trace().Msgf("action qBittorrent: %v check rules", action.Name) - // get client for action - client, err := s.clientSvc.FindByID(context.TODO(), action.ClientID) - if err != nil { - s.log.Error().Stack().Err(err).Msgf("error finding client: %v", action.ClientID) - return false, nil, err - } - - if client == nil { - return false, nil, err - } - - qbtSettings := qbittorrent.Settings{ - Hostname: client.Host, - Port: uint(client.Port), - Username: client.Username, - Password: client.Password, - TLS: client.TLS, - TLSSkipVerify: client.TLSSkipVerify, - Log: s.subLogger, - } - - // only set basic auth if enabled - if client.Settings.Basic.Auth { - qbtSettings.BasicAuth = client.Settings.Basic.Auth - qbtSettings.Basic.Username = client.Settings.Basic.Username - qbtSettings.Basic.Password = client.Settings.Basic.Password - } - - qbt := qbittorrent.NewClient(qbtSettings) - qbt.Name = client.Name - // save cookies? - err = qbt.Login() - if err != nil { - s.log.Error().Stack().Err(err).Msgf("error logging into client: %v", client.Host) - return false, nil, err - } - // check for active downloads and other rules if client.Settings.Rules.Enabled && !action.IgnoreRules { activeDownloads, err := qbt.GetTorrentsActiveDownloads() if err != nil { - s.log.Error().Stack().Err(err).Msg("could not fetch downloading torrents") - return false, nil, err + return nil, errors.Wrap(err, "could not fetch active downloads") } // make sure it's not set to 0 by default @@ -145,27 +171,30 @@ func (s *service) qbittorrentCheckRulesCanDownload(action domain.Action) (bool, // check speeds of downloads info, err := qbt.GetTransferInfo() if err != nil { - s.log.Error().Err(err).Msg("could not get transfer info") - return false, nil, err + return nil, errors.Wrap(err, "could not get transfer info") } // if current transfer speed is more than threshold return out and skip // DlInfoSpeed is in bytes so lets convert to KB to match DownloadSpeedThreshold if info.DlInfoSpeed/1024 >= client.Settings.Rules.DownloadSpeedThreshold { s.log.Debug().Msg("max active downloads reached, skipping") - return false, nil, nil + + rejections := []string{"max active downloads reached, skipping"} + return rejections, nil } s.log.Debug().Msg("active downloads are slower than set limit, lets add it") } else { s.log.Debug().Msg("max active downloads reached, skipping") - return false, nil, nil + + rejections := []string{"max active downloads reached, skipping"} + return rejections, nil } } } } - return true, qbt, nil + return nil, nil } func (s *service) reannounceTorrent(qb *qbittorrent.Client, action domain.Action, hash string) error { @@ -190,8 +219,7 @@ func (s *service) reannounceTorrent(qb *qbittorrent.Client, action domain.Action trackers, err := qb.GetTorrentTrackers(hash) if err != nil { - s.log.Error().Err(err).Msgf("qBittorrent - could not get trackers for torrent: %v", hash) - return err + return errors.Wrap(err, "could not get trackers for torrent with hash: %v", hash) } if trackers == nil { @@ -215,8 +243,7 @@ func (s *service) reannounceTorrent(qb *qbittorrent.Client, action domain.Action s.log.Trace().Msgf("qBittorrent - not working yet, lets re-announce %v attempt: %v", hash, attempts) err = qb.ReAnnounceTorrents([]string{hash}) if err != nil { - s.log.Error().Err(err).Msgf("qBittorrent - could not get re-announce torrent: %v", hash) - return err + return errors.Wrap(err, "could not re-announce torrent with hash: %v", hash) } attempts++ @@ -228,8 +255,7 @@ func (s *service) reannounceTorrent(qb *qbittorrent.Client, action domain.Action err := qb.DeleteTorrents([]string{hash}, false) if err != nil { - s.log.Error().Stack().Err(err).Msgf("qBittorrent - could not delete torrent: %v", hash) - return err + return errors.Wrap(err, "could not delete torrent with hash: %v", hash) } } diff --git a/internal/action/radarr.go b/internal/action/radarr.go index b7b6acb..b2a38c8 100644 --- a/internal/action/radarr.go +++ b/internal/action/radarr.go @@ -5,10 +5,11 @@ import ( "time" "github.com/autobrr/autobrr/internal/domain" + "github.com/autobrr/autobrr/pkg/errors" "github.com/autobrr/autobrr/pkg/radarr" ) -func (s *service) radarr(release domain.Release, action domain.Action) ([]string, error) { +func (s *service) radarr(action domain.Action, release domain.Release) ([]string, error) { s.log.Trace().Msg("action RADARR") // TODO validate data @@ -16,13 +17,12 @@ func (s *service) radarr(release domain.Release, action domain.Action) ([]string // get client for action client, err := s.clientSvc.FindByID(context.TODO(), action.ClientID) if err != nil { - s.log.Error().Err(err).Msgf("radarr: error finding client: %v", action.ClientID) - return nil, err + return nil, errors.Wrap(err, "error finding client: %v", action.ClientID) } // return early if no client found if client == nil { - return nil, err + return nil, errors.New("could not find client by id: %v", action.ClientID) } // initial config @@ -53,8 +53,7 @@ func (s *service) radarr(release domain.Release, action domain.Action) ([]string rejections, err := arr.Push(r) if err != nil { - s.log.Error().Stack().Err(err).Msgf("radarr: failed to push release: %v", r) - return nil, err + return nil, errors.Wrap(err, "radarr failed to push release: %v", r) } if rejections != nil { diff --git a/internal/action/run.go b/internal/action/run.go index 83b6434..65d25ca 100644 --- a/internal/action/run.go +++ b/internal/action/run.go @@ -10,122 +10,46 @@ import ( "time" "github.com/autobrr/autobrr/internal/domain" + "github.com/autobrr/autobrr/pkg/errors" ) func (s *service) RunAction(action *domain.Action, release domain.Release) ([]string, error) { - var err error - var rejections []string + var ( + err error + rejections []string + ) switch action.Type { case domain.ActionTypeTest: s.test(action.Name) case domain.ActionTypeExec: - if release.TorrentTmpFile == "" { - if err := release.DownloadTorrentFile(); err != nil { - s.log.Error().Stack().Err(err) - break - } - } - - s.execCmd(release, *action) + err = s.execCmd(*action, release) case domain.ActionTypeWatchFolder: - if release.TorrentTmpFile == "" { - if err := release.DownloadTorrentFile(); err != nil { - s.log.Error().Stack().Err(err) - break - } - } - - s.watchFolder(*action, release) + err = s.watchFolder(*action, release) case domain.ActionTypeWebhook: - if release.TorrentTmpFile == "" { - if err := release.DownloadTorrentFile(); err != nil { - s.log.Error().Stack().Err(err) - break - } - } - - s.webhook(*action, release) + err = s.webhook(*action, release) case domain.ActionTypeDelugeV1, domain.ActionTypeDelugeV2: - canDownload, err := s.delugeCheckRulesCanDownload(*action) - if err != nil { - s.log.Error().Stack().Err(err).Msgf("error checking client rules: %v", action.Name) - break - } - if !canDownload { - rejections = []string{"max active downloads reached, skipping"} - break - } - - if release.TorrentTmpFile == "" { - if err := release.DownloadTorrentFile(); err != nil { - s.log.Error().Stack().Err(err) - break - } - } - - err = s.deluge(*action, release) - if err != nil { - s.log.Error().Stack().Err(err).Msg("error sending torrent to Deluge") - break - } + rejections, err = s.deluge(*action, release) case domain.ActionTypeQbittorrent: - canDownload, client, err := s.qbittorrentCheckRulesCanDownload(*action) - if err != nil { - s.log.Error().Stack().Err(err).Msgf("error checking client rules: %v", action.Name) - break - } - if !canDownload { - rejections = []string{"max active downloads reached, skipping"} - break - } - - if release.TorrentTmpFile == "" { - if err := release.DownloadTorrentFile(); err != nil { - s.log.Error().Stack().Err(err) - break - } - } - - err = s.qbittorrent(client, *action, release) - if err != nil { - s.log.Error().Stack().Err(err).Msg("error sending torrent to qBittorrent") - break - } + rejections, err = s.qbittorrent(*action, release) case domain.ActionTypeRadarr: - rejections, err = s.radarr(release, *action) - if err != nil { - s.log.Error().Stack().Err(err).Msg("error sending torrent to radarr") - break - } + rejections, err = s.radarr(*action, release) case domain.ActionTypeSonarr: - rejections, err = s.sonarr(release, *action) - if err != nil { - s.log.Error().Stack().Err(err).Msg("error sending torrent to sonarr") - break - } + rejections, err = s.sonarr(*action, release) case domain.ActionTypeLidarr: - rejections, err = s.lidarr(release, *action) - if err != nil { - s.log.Error().Stack().Err(err).Msg("error sending torrent to lidarr") - break - } + rejections, err = s.lidarr(*action, release) case domain.ActionTypeWhisparr: - rejections, err = s.whisparr(release, *action) - if err != nil { - s.log.Error().Stack().Err(err).Msg("error sending torrent to whisparr") - break - } + rejections, err = s.whisparr(*action, release) default: s.log.Warn().Msgf("unsupported action type: %v", action.Type) @@ -161,7 +85,7 @@ func (s *service) RunAction(action *domain.Action, release domain.Release) ([]st } if err != nil { - s.log.Err(err).Stack().Msgf("process action failed: %v for '%v'", action.Name, release.TorrentName) + s.log.Error().Err(err).Msgf("process action failed: %v for '%v'", action.Name, release.TorrentName) rlsActionStatus.Status = domain.ReleasePushStatusErr rlsActionStatus.Rejections = []string{err.Error()} @@ -189,56 +113,23 @@ func (s *service) RunAction(action *domain.Action, release domain.Release) ([]st return rejections, err } -func (s *service) CheckCanDownload(actions []domain.Action) bool { - for _, action := range actions { - if !action.Enabled { - // only run active actions - continue - } - - s.log.Debug().Msgf("action-service: check can download action: %v", action.Name) - - switch action.Type { - case domain.ActionTypeDelugeV1, domain.ActionTypeDelugeV2: - canDownload, err := s.delugeCheckRulesCanDownload(action) - if err != nil { - s.log.Error().Stack().Err(err).Msgf("error checking client rules: %v", action.Name) - continue - } - if !canDownload { - continue - } - - return true - - case domain.ActionTypeQbittorrent: - canDownload, _, err := s.qbittorrentCheckRulesCanDownload(action) - if err != nil { - s.log.Error().Stack().Err(err).Msgf("error checking client rules: %v", action.Name) - continue - } - if !canDownload { - continue - } - - return true - } - } - - return false -} - func (s *service) test(name string) { s.log.Info().Msgf("action TEST: %v", name) } -func (s *service) watchFolder(action domain.Action, release domain.Release) { +func (s *service) watchFolder(action domain.Action, release domain.Release) error { + if release.TorrentTmpFile == "" { + if err := release.DownloadTorrentFile(); err != nil { + return errors.Wrap(err, "watch folder: could not download torrent file for release: %v", release.TorrentName) + } + } + m := NewMacro(release) // parse and replace values in argument string before continuing watchFolderArgs, err := m.Parse(action.WatchFolder) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not parse macro: %v", action.WatchFolder) + return errors.Wrap(err, "could not parse watch folder macro: %v", action.WatchFolder) } s.log.Trace().Msgf("action WATCH_FOLDER: %v file: %v", watchFolderArgs, release.TorrentTmpFile) @@ -246,8 +137,7 @@ func (s *service) watchFolder(action domain.Action, release domain.Release) { // Open original file original, err := os.Open(release.TorrentTmpFile) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not open temp file '%v'", release.TorrentTmpFile) - return + return errors.Wrap(err, "could not open temp file: %v", release.TorrentTmpFile) } defer original.Close() @@ -257,29 +147,34 @@ func (s *service) watchFolder(action domain.Action, release domain.Release) { // Create new file newFile, err := os.Create(fullFileName) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not create new temp file '%v'", fullFileName) - return + return errors.Wrap(err, "could not create new file %v", fullFileName) } defer newFile.Close() // Copy file _, err = io.Copy(newFile, original) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not copy file %v to watch folder", fullFileName) - return + return errors.Wrap(err, "could not copy file %v to watch folder", fullFileName) } s.log.Info().Msgf("saved file to watch folder: %v", fullFileName) + + return nil } -func (s *service) webhook(action domain.Action, release domain.Release) { +func (s *service) webhook(action domain.Action, release domain.Release) error { + if release.TorrentTmpFile == "" { + if err := release.DownloadTorrentFile(); err != nil { + return errors.Wrap(err, "webhook: could not download torrent file for release: %v", release.TorrentName) + } + } + m := NewMacro(release) // parse and replace values in argument string before continuing dataArgs, err := m.Parse(action.WebhookData) if err != nil { - s.log.Error().Stack().Err(err).Msgf("could not parse macro: %v", action.WebhookData) - return + return errors.Wrap(err, "could not parse webhook data macro: %v", action.WebhookData) } s.log.Trace().Msgf("action WEBHOOK: '%v' file: %v", action.Name, release.TorrentName) @@ -295,8 +190,7 @@ func (s *service) webhook(action domain.Action, release domain.Release) { req, err := http.NewRequest(http.MethodPost, action.WebhookHost, bytes.NewBufferString(dataArgs)) if err != nil { - s.log.Error().Err(err).Msgf("webhook client request error: %v", action.WebhookHost) - return + return errors.Wrap(err, "could not build request for webhook") } req.Header.Set("Content-Type", "application/json") @@ -304,13 +198,12 @@ func (s *service) webhook(action domain.Action, release domain.Release) { res, err := client.Do(req) if err != nil { - s.log.Error().Err(err).Msgf("webhook client request error: %v", action.WebhookHost) - return + return errors.Wrap(err, "could not make request for webhook") } defer res.Body.Close() s.log.Info().Msgf("successfully ran webhook action: '%v' to: %v payload: %v", action.Name, action.WebhookHost, dataArgs) - return + return nil } diff --git a/internal/action/service.go b/internal/action/service.go index cade767..dd8d966 100644 --- a/internal/action/service.go +++ b/internal/action/service.go @@ -7,6 +7,7 @@ import ( "github.com/autobrr/autobrr/internal/domain" "github.com/autobrr/autobrr/internal/download_client" "github.com/autobrr/autobrr/internal/logger" + "github.com/autobrr/autobrr/pkg/qbittorrent" "github.com/asaskevich/EventBus" "github.com/dcarbone/zadapters/zstdlog" @@ -21,7 +22,11 @@ type Service interface { ToggleEnabled(actionID int) error RunAction(action *domain.Action, release domain.Release) ([]string, error) - CheckCanDownload(actions []domain.Action) bool +} + +type qbitKey struct { + I int // type + N string // name } type service struct { @@ -30,14 +35,17 @@ type service struct { repo domain.ActionRepo clientSvc download_client.Service bus EventBus.Bus + + qbitClients map[qbitKey]*qbittorrent.Client } func NewService(log logger.Logger, repo domain.ActionRepo, clientSvc download_client.Service, bus EventBus.Bus) Service { s := &service{ - log: log.With().Str("module", "action").Logger(), - repo: repo, - clientSvc: clientSvc, - bus: bus, + log: log.With().Str("module", "action").Logger(), + repo: repo, + clientSvc: clientSvc, + bus: bus, + qbitClients: map[qbitKey]*qbittorrent.Client{}, } s.subLogger = zstdlog.NewStdLoggerWithLevel(s.log.With().Logger(), zerolog.TraceLevel) diff --git a/internal/action/sonarr.go b/internal/action/sonarr.go index 9c45a56..398fb15 100644 --- a/internal/action/sonarr.go +++ b/internal/action/sonarr.go @@ -9,7 +9,7 @@ import ( "github.com/autobrr/autobrr/pkg/sonarr" ) -func (s *service) sonarr(release domain.Release, action domain.Action) ([]string, error) { +func (s *service) sonarr(action domain.Action, release domain.Release) ([]string, error) { s.log.Trace().Msg("action SONARR") // TODO validate data @@ -17,7 +17,6 @@ func (s *service) sonarr(release domain.Release, action domain.Action) ([]string // get client for action client, err := s.clientSvc.FindByID(context.TODO(), action.ClientID) if err != nil { - s.log.Error().Err(err).Msgf("sonarr: error finding client: %v", action.ClientID) return nil, errors.Wrap(err, "sonarr could not find client: %v", action.ClientID) } @@ -54,8 +53,7 @@ func (s *service) sonarr(release domain.Release, action domain.Action) ([]string rejections, err := arr.Push(r) if err != nil { - s.log.Error().Stack().Err(err).Msgf("sonarr: failed to push release: %v", r) - return nil, err + return nil, errors.Wrap(err, "sonarr: failed to push release: %v", r) } if rejections != nil { diff --git a/internal/action/whisparr.go b/internal/action/whisparr.go index 7380095..3b5232d 100644 --- a/internal/action/whisparr.go +++ b/internal/action/whisparr.go @@ -5,10 +5,11 @@ import ( "time" "github.com/autobrr/autobrr/internal/domain" + "github.com/autobrr/autobrr/pkg/errors" "github.com/autobrr/autobrr/pkg/whisparr" ) -func (s *service) whisparr(release domain.Release, action domain.Action) ([]string, error) { +func (s *service) whisparr(action domain.Action, release domain.Release) ([]string, error) { s.log.Trace().Msg("action WHISPARR") // TODO validate data @@ -16,13 +17,12 @@ func (s *service) whisparr(release domain.Release, action domain.Action) ([]stri // get client for action client, err := s.clientSvc.FindByID(context.TODO(), action.ClientID) if err != nil { - s.log.Error().Err(err).Msgf("whisparr: error finding client: %v", action.ClientID) - return nil, err + return nil, errors.Wrap(err, "sonarr could not find client: %v", action.ClientID) } // return early if no client found if client == nil { - return nil, err + return nil, errors.New("could not find client by id: %v", action.ClientID) } // initial config @@ -53,8 +53,7 @@ func (s *service) whisparr(release domain.Release, action domain.Action) ([]stri rejections, err := arr.Push(r) if err != nil { - s.log.Error().Stack().Err(err).Msgf("whisparr: failed to push release: %v", r) - return nil, err + return nil, errors.Wrap(err, "whisparr: failed to push release: %v", r) } if rejections != nil { diff --git a/internal/domain/release.go b/internal/domain/release.go index a3b7e8d..a84147a 100644 --- a/internal/domain/release.go +++ b/internal/domain/release.go @@ -318,17 +318,17 @@ func (r *Release) DownloadTorrentFile() error { // Write the body to file _, err = io.Copy(tmpFile, resp.Body) if err != nil { - return errors.Wrap(err, fmt.Sprintf("error writing downloaded file: %v", tmpFile.Name())) + return errors.Wrap(err, "error writing downloaded file: %v", tmpFile.Name()) } meta, err := metainfo.LoadFromFile(tmpFile.Name()) if err != nil { - return errors.Wrap(err, fmt.Sprintf("metainfo could not load file contents: %v", tmpFile.Name())) + return errors.Wrap(err, "metainfo could not load file contents: %v", tmpFile.Name()) } torrentMetaInfo, err := meta.UnmarshalInfo() if err != nil { - return errors.Wrap(err, fmt.Sprintf("metainfo could not unmarshal info from torrent: %v", tmpFile.Name())) + return errors.Wrap(err, "metainfo could not unmarshal info from torrent: %v", tmpFile.Name()) } r.TorrentTmpFile = tmpFile.Name() @@ -337,8 +337,6 @@ func (r *Release) DownloadTorrentFile() error { // remove file if fail - //log.Debug().Msgf("successfully downloaded file: %v", tmpFile.Name()) - return nil } diff --git a/internal/download_client/connection.go b/internal/download_client/connection.go index 98a787b..14f4d94 100644 --- a/internal/download_client/connection.go +++ b/internal/download_client/connection.go @@ -57,11 +57,16 @@ func (s *service) testQbittorrentConnection(client domain.DownloadClient) error } qbt := qbittorrent.NewClient(qbtSettings) - err := qbt.Login() - if err != nil { + + if err := qbt.Login(); err != nil { return errors.Wrap(err, "error logging into client: %v", client.Host) } + _, err := qbt.GetTorrents() + if err != nil { + return errors.Wrap(err, "error getting torrents: %v", client.Host) + } + s.log.Debug().Msgf("test client connection for qBittorrent: success") return nil diff --git a/internal/download_client/service.go b/internal/download_client/service.go index bd93402..96d64a2 100644 --- a/internal/download_client/service.go +++ b/internal/download_client/service.go @@ -113,7 +113,7 @@ func (s *service) Test(client domain.DownloadClient) error { // test if err := s.testConnection(client); err != nil { - s.log.Err(err).Msg("client connection test error") + s.log.Error().Err(err).Msg("client connection test error") return err }