Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

chore(processor): improve logging with more context #95

Merged
merged 11 commits into from
Apr 10, 2024
84 changes: 45 additions & 39 deletions internal/http/processor.go
Original file line number Diff line number Diff line change
Expand Up @@ -91,7 +91,7 @@ func newProcessor(log logger.Logger, config *config.AppConfig) *processor {
}
}

func (p processor) getClient(client *domain.Client) error {
func (p *processor) getClient(client *domain.Client) error {
s := qbittorrent.Config{
Host: fmt.Sprintf("http://%s:%d", client.Host, client.Port),
Username: client.Username,
Expand All @@ -113,7 +113,7 @@ func (p processor) getClient(client *domain.Client) error {
return nil
}

func (p processor) getAllTorrents(client *domain.Client) entryTime {
func (p *processor) getAllTorrents(client *domain.Client) entryTime {
set := qbittorrent.Config{
Host: fmt.Sprintf("http://%s:%d", client.Host, client.Port),
Username: client.Username,
Expand Down Expand Up @@ -145,15 +145,15 @@ func (p processor) getAllTorrents(client *domain.Client) entryTime {
return *res
}

torrents, err := p.req.Client.GetTorrents(qbittorrent.TorrentFilterOptions{})
ts, err := p.req.Client.GetTorrents(qbittorrent.TorrentFilterOptions{})
if err != nil {
return entryTime{err: err}
}

nt := time.Now()
res = &entryTime{e: make(map[string][]domain.Entry), t: nt.Add(nt.Sub(cur)), d: res.d}

for _, t := range torrents {
for _, t := range ts {
r, ok := res.d[t.Name]
if !ok {
r = rls.ParseString(t.Name)
Expand All @@ -168,10 +168,11 @@ func (p processor) getAllTorrents(client *domain.Client) entryTime {
return *res
}

func (p processor) getFiles(hash string) (*qbittorrent.TorrentFiles, error) {
func (p *processor) getFiles(hash string) (*qbittorrent.TorrentFiles, error) {
return p.req.Client.GetFilesInformation(hash)
}
func (p processor) ProcessSeasonPackHandler(w netHTTP.ResponseWriter, r *netHTTP.Request) {

func (p *processor) ProcessSeasonPackHandler(w netHTTP.ResponseWriter, r *netHTTP.Request) {
p.log.Info().Msg("starting to process season pack request")

if err := json.NewDecoder(r.Body).Decode(&p.req); err != nil {
Expand All @@ -180,56 +181,59 @@ func (p processor) ProcessSeasonPackHandler(w netHTTP.ResponseWriter, r *netHTTP
return
}

code, err := p.processSeasonPack()
p.log = p.log.With().Str("release", p.req.Name).Logger()

code, logMsg, err := p.processSeasonPack()
if err != nil {
p.log.Error().Err(err).Msgf("error processing season pack: %q; code: %d", p.req.Name, code)
p.log.Error().Err(err).Msgf("error processing season pack: %d", code)
netHTTP.Error(w, err.Error(), code)
return
}

p.log.Info().Msgf("successfully matched season pack to episodes in client: %q", p.req.ClientName)
p.log.Info().Msg(logMsg)
w.WriteHeader(code)
}

func (p processor) processSeasonPack() (int, error) {
func (p *processor) processSeasonPack() (int, string, error) {
clientName := p.req.ClientName

if len(clientName) == 0 {
clientName = "default"
p.req.ClientName = clientName
p.log.Info().Msgf("no clientname defined. trying to use %q client", clientName)
}

client, ok := p.cfg.Config.Clients[clientName]
if !ok {
return StatusClientNotFound, fmt.Errorf("client not found in config: %q", clientName)
return StatusClientNotFound, "", fmt.Errorf("client not found in config: %q", clientName)
}
p.log.Info().Msgf("using %q client serving at %s:%d", clientName, client.Host, client.Port)

if len(p.req.Name) == 0 {
return StatusAnnounceNameError, fmt.Errorf("couldn't get announce name")
return StatusAnnounceNameError, "", fmt.Errorf("couldn't get announce name")
}

if err := p.getClient(client); err != nil {
return StatusGetClientError, err
return StatusGetClientError, "", err
}

mp := p.getAllTorrents(client)
if mp.err != nil {
return StatusGetTorrentsError, mp.err
return StatusGetTorrentsError, "", mp.err
}

requestrls := domain.Entry{R: rls.ParseString(p.req.Name)}
v, ok := mp.e[utils.GetFormattedTitle(requestrls.R)]
if !ok {
return StatusNoMatches, fmt.Errorf("no matching releases in client %q", clientName)
return StatusNoMatches, fmt.Sprintf("no matching releases in client %q", clientName), nil
}

packNameAnnounce := utils.FormatSeasonPackTitle(p.req.Name)
p.log.Debug().Msgf("formatted season pack name: %q", packNameAnnounce)

for _, child := range v {
if release.CheckCandidates(&requestrls, &child, p.cfg.Config.FuzzyMatching) == StatusAlreadyInClient {
return StatusAlreadyInClient, fmt.Errorf("release already in client %q", clientName)
return StatusAlreadyInClient, fmt.Sprintf("release already in client %q", clientName), nil
}
}

Expand Down Expand Up @@ -287,10 +291,10 @@ func (p processor) processSeasonPack() (int, error) {
continue

case StatusAlreadyInClient:
return StatusAlreadyInClient, fmt.Errorf("release already in client %q", clientName)
return StatusAlreadyInClient, fmt.Sprintf("release already in client %q", clientName), nil

case StatusNotASeasonPack:
return StatusNotASeasonPack, fmt.Errorf("release is not a season pack")
return StatusNotASeasonPack, fmt.Sprintf("release is not a season pack"), nil

case StatusSuccessfulMatch:
m, err := p.getFiles(child.T.Hash)
Expand Down Expand Up @@ -333,15 +337,15 @@ func (p processor) processSeasonPack() (int, error) {

matchesSlice, ok := matchesMap.Load(p.req.Name)
if !slices.Contains(respCodes, StatusSuccessfulMatch) || !ok {
return StatusNoMatches, fmt.Errorf("no matching releases in client %q", clientName)
return StatusNoMatches, fmt.Sprintf("no matching releases in client %q", clientName), nil
}

if p.cfg.Config.SmartMode {
reqRls := rls.ParseString(p.req.Name)

totalEps, err := utils.GetEpisodesPerSeason(reqRls.Title, reqRls.Series)
if err != nil {
return StatusEpisodeCountError, err
return StatusEpisodeCountError, "", err
}
matchedEps = utils.DedupeSlice(matchedEps)

Expand All @@ -351,13 +355,13 @@ func (p processor) processSeasonPack() (int, error) {
// delete match from matchesMap if threshold is not met
matchesMap.Delete(p.req.Name)

return StatusBelowThreshold, fmt.Errorf("found %d/%d (%.2f%%) episodes in client, below configured smart mode threshold",
len(matchedEps), totalEps, percentEps*100)
return StatusBelowThreshold, fmt.Sprintf("found %d/%d (%.2f%%) episodes in client, below configured smart mode threshold",
len(matchedEps), totalEps, percentEps*100), nil
}
}

if p.cfg.Config.ParseTorrentFile {
return StatusSuccessfulMatch, nil
return StatusSuccessfulMatch, fmt.Sprintf("successfully matched season pack to episodes in client: %q", clientName), nil
}

matches := utils.DedupeSlice(matchesSlice.([]matchPaths))
Expand All @@ -374,12 +378,12 @@ func (p processor) processSeasonPack() (int, error) {
}

if !slices.Contains(hardlinkRespCodes, StatusSuccessfulHardlink) {
return StatusFailedHardlink, fmt.Errorf("couldn't create hardlinks")
return StatusFailedHardlink, "", fmt.Errorf("couldn't create hardlinks")
}
return StatusSuccessfulHardlink, nil
return StatusSuccessfulHardlink, fmt.Sprintf("successfully created hardlinks for matched episodes in client: %q", clientName), nil
}

func (p processor) ParseTorrentHandler(w netHTTP.ResponseWriter, r *netHTTP.Request) {
func (p *processor) ParseTorrentHandler(w netHTTP.ResponseWriter, r *netHTTP.Request) {
p.log.Info().Msg("starting to parse season pack torrent")

if err := json.NewDecoder(r.Body).Decode(&p.req); err != nil {
Expand All @@ -388,50 +392,52 @@ func (p processor) ParseTorrentHandler(w netHTTP.ResponseWriter, r *netHTTP.Requ
return
}

code, err := p.parseTorrent()
p.log = p.log.With().Str("release", p.req.Name).Logger()

code, logMsg, err := p.parseTorrent()
if err != nil {
p.log.Error().Err(err).Msgf("error parsing torrent: %q; code: %d", p.req.Name, code)
p.log.Error().Err(err).Msgf("error parsing torrent: %d", code)
netHTTP.Error(w, err.Error(), code)
return
}

p.log.Info().Msg("successfully parsed torrent and hardlinked episodes")
p.log.Info().Msg(logMsg)
w.WriteHeader(code)
}

func (p processor) parseTorrent() (int, error) {
func (p *processor) parseTorrent() (int, string, error) {
if len(p.req.Name) == 0 {
return StatusAnnounceNameError, fmt.Errorf("couldn't get announce name")
return StatusAnnounceNameError, "", fmt.Errorf("couldn't get announce name")
}

if len(p.req.Torrent) == 0 {
return StatusTorrentBytesError, fmt.Errorf("couldn't get torrent bytes")
return StatusTorrentBytesError, "", fmt.Errorf("couldn't get torrent bytes")
}

torrentBytes, err := torrents.DecodeTorrentDataRawBytes(p.req.Torrent)
if err != nil {
return StatusDecodeTorrentBytesError, err
return StatusDecodeTorrentBytesError, "", err
}
p.req.Torrent = torrentBytes

torrentInfo, err := torrents.ParseTorrentInfoFromTorrentBytes(p.req.Torrent)
if err != nil {
return StatusParseTorrentInfoError, err
return StatusParseTorrentInfoError, "", err
}
packNameParsed := torrentInfo.BestName()
p.log.Debug().Msgf("parsed season pack name: %q", packNameParsed)

torrentEps, err := torrents.GetEpisodesFromTorrentInfo(torrentInfo)
if err != nil {
return StatusGetEpisodesError, err
return StatusGetEpisodesError, "", err
}
for _, torrentEp := range torrentEps {
p.log.Debug().Msgf("found episode: %q", torrentEp)
p.log.Debug().Msgf("found episode in pack: %q", torrentEp)
}

matchesSlice, ok := matchesMap.Load(p.req.Name)
if !ok {
return StatusNoMatches, fmt.Errorf("no matching releases in client")
return StatusNoMatches, fmt.Sprintf("no matching releases in client"), nil
}

matches := utils.DedupeSlice(matchesSlice.([]matchPaths))
Expand All @@ -454,7 +460,7 @@ func (p processor) parseTorrent() (int, error) {
}

if !slices.Contains(hardlinkRespCodes, StatusSuccessfulHardlink) {
return StatusFailedHardlink, fmt.Errorf("couldn't create hardlinks")
return StatusFailedHardlink, "", fmt.Errorf("couldn't create hardlinks")
}
return StatusSuccessfulHardlink, nil
return StatusSuccessfulHardlink, "successfully parsed torrent and hardlinked episodes", nil
}