feat(logging); improve messages and errors (#336)

* feat(logger): add module context

* feat(logger): change errors package

* feat(logger): update tests
This commit is contained in:
Ludvig Lundgren 2022-07-05 13:31:44 +02:00 committed by GitHub
parent 95471a4cf7
commit 0e88117702
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
69 changed files with 1172 additions and 957 deletions

View file

@ -5,6 +5,7 @@ import (
"crypto/tls"
"fmt"
"io"
"log"
"mime/multipart"
"net/http"
"net/http/cookiejar"
@ -14,8 +15,9 @@ import (
"strings"
"time"
"github.com/rs/zerolog/log"
"golang.org/x/net/publicsuffix"
"github.com/autobrr/autobrr/pkg/errors"
publicsuffix "golang.org/x/net/publicsuffix"
)
var (
@ -31,6 +33,8 @@ type Client struct {
Name string
settings Settings
http *http.Client
Log *log.Logger
}
type Settings struct {
@ -43,6 +47,7 @@ type Settings struct {
protocol string
BasicAuth bool
Basic Basic
Log *log.Logger
}
type Basic struct {
@ -51,20 +56,24 @@ type Basic struct {
}
func NewClient(s Settings) *Client {
jarOptions := &cookiejar.Options{PublicSuffixList: publicsuffix.List}
//store cookies in jar
jar, err := cookiejar.New(jarOptions)
if err != nil {
log.Error().Err(err).Msg("new client cookie error")
}
httpClient := &http.Client{
Timeout: timeout,
Jar: jar,
}
c := &Client{
settings: s,
http: httpClient,
}
if s.Log == nil {
c.Log = log.New(io.Discard, "qbittorrent", log.LstdFlags)
}
//store cookies in jar
jarOptions := &cookiejar.Options{PublicSuffixList: publicsuffix.List}
jar, err := cookiejar.New(jarOptions)
if err != nil {
c.Log.Println("new client cookie error")
}
c.http = &http.Client{
Timeout: timeout,
Jar: jar,
}
c.settings.protocol = "http"
@ -92,8 +101,7 @@ func (c *Client) get(endpoint string, opts map[string]string) (*http.Response, e
req, err := http.NewRequest("GET", reqUrl, nil)
if err != nil {
log.Error().Err(err).Msgf("GET: error %v", reqUrl)
return nil, err
return nil, errors.Wrap(err, "could not build request")
}
if c.settings.BasicAuth {
@ -109,14 +117,13 @@ func (c *Client) get(endpoint string, opts map[string]string) (*http.Response, e
break
}
log.Debug().Msgf("qbit GET failed: retrying attempt %d - %v", i, reqUrl)
c.Log.Printf("qbit GET failed: retrying attempt %d - %v\n", i, reqUrl)
time.Sleep(backoff)
}
if err != nil {
log.Error().Err(err).Msgf("GET: do %v", reqUrl)
return nil, err
return nil, errors.Wrap(err, "error making get request: %v", reqUrl)
}
return resp, nil
@ -138,8 +145,7 @@ func (c *Client) post(endpoint string, opts map[string]string) (*http.Response,
req, err := http.NewRequest("POST", reqUrl, strings.NewReader(form.Encode()))
if err != nil {
log.Error().Err(err).Msgf("POST: req %v", reqUrl)
return nil, err
return nil, errors.Wrap(err, "could not build request")
}
if c.settings.BasicAuth {
@ -158,14 +164,13 @@ func (c *Client) post(endpoint string, opts map[string]string) (*http.Response,
break
}
log.Debug().Msgf("qbit POST failed: retrying attempt %d - %v", i, reqUrl)
c.Log.Printf("qbit POST failed: retrying attempt %d - %v\n", i, reqUrl)
time.Sleep(backoff)
}
if err != nil {
log.Error().Err(err).Msgf("POST: do %v", reqUrl)
return nil, err
return nil, errors.Wrap(err, "error making post request: %v", reqUrl)
}
return resp, nil
@ -187,8 +192,7 @@ func (c *Client) postBasic(endpoint string, opts map[string]string) (*http.Respo
req, err := http.NewRequest("POST", reqUrl, strings.NewReader(form.Encode()))
if err != nil {
log.Error().Err(err).Msgf("POST: req %v", reqUrl)
return nil, err
return nil, errors.Wrap(err, "could not build request")
}
if c.settings.BasicAuth {
@ -200,8 +204,7 @@ func (c *Client) postBasic(endpoint string, opts map[string]string) (*http.Respo
resp, err = c.http.Do(req)
if err != nil {
log.Error().Err(err).Msgf("POST: do %v", reqUrl)
return nil, err
return nil, errors.Wrap(err, "error making post request: %v", reqUrl)
}
return resp, nil
@ -213,8 +216,7 @@ func (c *Client) postFile(endpoint string, fileName string, opts map[string]stri
file, err := os.Open(fileName)
if err != nil {
log.Error().Err(err).Msgf("POST file: opening file %v", fileName)
return nil, err
return nil, errors.Wrap(err, "error opening file %v", fileName)
}
// Close the file later
defer file.Close()
@ -228,15 +230,13 @@ func (c *Client) postFile(endpoint string, fileName string, opts map[string]stri
// Initialize file field
fileWriter, err := multiPartWriter.CreateFormFile("torrents", fileName)
if err != nil {
log.Error().Err(err).Msgf("POST file: initializing file field %v", fileName)
return nil, err
return nil, errors.Wrap(err, "error initializing file field %v", fileName)
}
// Copy the actual file content to the fields writer
_, err = io.Copy(fileWriter, file)
if err != nil {
log.Error().Err(err).Msgf("POST file: could not copy file to writer %v", fileName)
return nil, err
return nil, errors.Wrap(err, "error copy file contents to writer %v", fileName)
}
// Populate other fields
@ -244,14 +244,12 @@ func (c *Client) postFile(endpoint string, fileName string, opts map[string]stri
for key, val := range opts {
fieldWriter, err := multiPartWriter.CreateFormField(key)
if err != nil {
log.Error().Err(err).Msgf("POST file: could not add other fields %v", fileName)
return nil, err
return nil, errors.Wrap(err, "error creating form field %v with value %v", key, val)
}
_, err = fieldWriter.Write([]byte(val))
if err != nil {
log.Error().Err(err).Msgf("POST file: could not write field %v", fileName)
return nil, err
return nil, errors.Wrap(err, "error writing field %v with value %v", key, val)
}
}
}
@ -262,8 +260,7 @@ func (c *Client) postFile(endpoint string, fileName string, opts map[string]stri
reqUrl := buildUrl(c.settings, endpoint)
req, err := http.NewRequest("POST", reqUrl, &requestBody)
if err != nil {
log.Error().Err(err).Msgf("POST file: could not create request object %v", fileName)
return nil, err
return nil, errors.Wrap(err, "error creating request %v", fileName)
}
if c.settings.BasicAuth {
@ -282,14 +279,13 @@ func (c *Client) postFile(endpoint string, fileName string, opts map[string]stri
break
}
log.Debug().Msgf("qbit POST file failed: retrying attempt %d - %v", i, reqUrl)
c.Log.Printf("qbit POST file failed: retrying attempt %d - %v\n", i, reqUrl)
time.Sleep(backoff)
}
if err != nil {
log.Error().Err(err).Msgf("POST file: could not perform request %v", fileName)
return nil, err
return nil, errors.Wrap(err, "error making post file request %v", fileName)
}
return resp, nil

View file

@ -2,14 +2,13 @@ package qbittorrent
import (
"encoding/json"
"errors"
"io/ioutil"
"net/http"
"net/http/httputil"
"strconv"
"strings"
"github.com/rs/zerolog/log"
"github.com/autobrr/autobrr/pkg/errors"
)
// Login https://github.com/qbittorrent/qBittorrent/wiki/WebUI-API-(qBittorrent-4.1)#authentication
@ -21,15 +20,12 @@ func (c *Client) Login() error {
resp, err := c.postBasic("auth/login", opts)
if err != nil {
log.Error().Err(err).Msg("login error")
return err
return errors.Wrap(err, "login error")
} else if resp.StatusCode == http.StatusForbidden {
log.Error().Err(err).Msg("User's IP is banned for too many failed login attempts")
return err
return errors.New("User's IP is banned for too many failed login attempts")
} else if resp.StatusCode != http.StatusOK { // check for correct status code
log.Error().Err(err).Msgf("login bad status %v error", resp.StatusCode)
return errors.New("qbittorrent login bad status")
return errors.New("qbittorrent login bad status %v", resp.StatusCode)
}
defer resp.Body.Close()
@ -61,23 +57,20 @@ func (c *Client) GetTorrents() ([]Torrent, error) {
resp, err := c.get("torrents/info", nil)
if err != nil {
log.Error().Err(err).Msg("get torrents error")
return nil, err
return nil, errors.Wrap(err, "get torrents error")
}
defer resp.Body.Close()
body, readErr := ioutil.ReadAll(resp.Body)
if readErr != nil {
log.Error().Err(err).Msg("get torrents read error")
return nil, readErr
return nil, errors.Wrap(readErr, "could not read body")
}
var torrents []Torrent
err = json.Unmarshal(body, &torrents)
if err != nil {
log.Error().Err(err).Msg("get torrents unmarshal error")
return nil, err
return nil, errors.Wrap(err, "could not unmarshal body")
}
return torrents, nil
@ -90,23 +83,20 @@ func (c *Client) GetTorrentsFilter(filter TorrentFilter) ([]Torrent, error) {
resp, err := c.get("torrents/info", opts)
if err != nil {
log.Error().Err(err).Msgf("get filtered torrents error: %v", filter)
return nil, err
return nil, errors.Wrap(err, "could not get filtered torrents with filter: %v", filter)
}
defer resp.Body.Close()
body, readErr := ioutil.ReadAll(resp.Body)
if readErr != nil {
log.Error().Err(err).Msgf("get filtered torrents read error: %v", filter)
return nil, readErr
return nil, errors.Wrap(readErr, "could not read body")
}
var torrents []Torrent
err = json.Unmarshal(body, &torrents)
if err != nil {
log.Error().Err(err).Msgf("get filtered torrents unmarshal error: %v", filter)
return nil, err
return nil, errors.Wrap(err, "could not unmarshal body")
}
return torrents, nil
@ -121,23 +111,20 @@ func (c *Client) GetTorrentsActiveDownloads() ([]Torrent, error) {
resp, err := c.get("torrents/info", opts)
if err != nil {
log.Error().Err(err).Msgf("get filtered torrents error: %v", filter)
return nil, err
return nil, errors.Wrap(err, "could not get active torrents")
}
defer resp.Body.Close()
body, readErr := ioutil.ReadAll(resp.Body)
if readErr != nil {
log.Error().Err(err).Msgf("get filtered torrents read error: %v", filter)
return nil, readErr
return nil, errors.Wrap(readErr, "could not read body")
}
var torrents []Torrent
err = json.Unmarshal(body, &torrents)
if err != nil {
log.Error().Err(err).Msgf("get filtered torrents unmarshal error: %v", filter)
return nil, err
return nil, errors.Wrap(readErr, "could not unmarshal body")
}
res := make([]Torrent, 0)
@ -155,13 +142,15 @@ func (c *Client) GetTorrentsActiveDownloads() ([]Torrent, error) {
func (c *Client) GetTorrentsRaw() (string, error) {
resp, err := c.get("torrents/info", nil)
if err != nil {
log.Error().Err(err).Msg("get torrent trackers raw error")
return "", err
return "", errors.Wrap(err, "could not get torrents raw")
}
defer resp.Body.Close()
data, _ := ioutil.ReadAll(resp.Body)
data, err := ioutil.ReadAll(resp.Body)
if err != nil {
return "", errors.Wrap(err, "could not get read body torrents raw")
}
return string(data), nil
}
@ -173,40 +162,35 @@ func (c *Client) GetTorrentTrackers(hash string) ([]TorrentTracker, error) {
resp, err := c.get("torrents/trackers", opts)
if err != nil {
log.Error().Err(err).Msgf("get torrent trackers error: %v", hash)
return nil, err
return nil, errors.Wrap(err, "could not get torrent trackers for hash: %v", hash)
}
defer resp.Body.Close()
dump, err := httputil.DumpResponse(resp, true)
if err != nil {
log.Error().Err(err).Msgf("get torrent trackers dump response error: %v", err)
c.Log.Printf("get torrent trackers error dump response: %v\n", string(dump))
}
log.Trace().Msgf("get torrent trackers response dump: %v", string(dump))
c.Log.Printf("get torrent trackers response dump: %v\n", string(dump))
if resp.StatusCode == http.StatusNotFound {
//return nil, fmt.Errorf("torrent not found: %v", hash)
return nil, nil
} else if resp.StatusCode == http.StatusForbidden {
//return nil, fmt.Errorf("torrent not found: %v", hash)
return nil, nil
}
body, readErr := ioutil.ReadAll(resp.Body)
if readErr != nil {
log.Error().Err(err).Msgf("get torrent trackers read error: %v", hash)
return nil, readErr
return nil, errors.Wrap(err, "could not read body")
}
log.Trace().Msgf("get torrent trackers body: %v", string(body))
c.Log.Printf("get torrent trackers body: %v\n", string(body))
var trackers []TorrentTracker
err = json.Unmarshal(body, &trackers)
if err != nil {
log.Error().Err(err).Msgf("get torrent trackers: %v", hash)
return nil, err
return nil, errors.Wrap(err, "could not unmarshal body")
}
return trackers, nil
@ -217,11 +201,9 @@ func (c *Client) AddTorrentFromFile(file string, options map[string]string) erro
res, err := c.postFile("torrents/add", file, options)
if err != nil {
log.Error().Err(err).Msgf("add torrents error: %v", file)
return err
return errors.Wrap(err, "could not add torrent %v", file)
} else if res.StatusCode != http.StatusOK {
log.Error().Err(err).Msgf("add torrents bad status: %v", file)
return err
return errors.Wrap(err, "could not add torrent %v unexpected status: %v", file, res.StatusCode)
}
defer res.Body.Close()
@ -240,11 +222,9 @@ func (c *Client) DeleteTorrents(hashes []string, deleteFiles bool) error {
resp, err := c.get("torrents/delete", opts)
if err != nil {
log.Error().Err(err).Msgf("delete torrents error: %v", hashes)
return err
return errors.Wrap(err, "could not delete torrents: %+v", hashes)
} else if resp.StatusCode != http.StatusOK {
log.Error().Err(err).Msgf("delete torrents bad code: %v", hashes)
return err
return errors.Wrap(err, "could not delete torrents %v unexpected status: %v", hashes, resp.StatusCode)
}
defer resp.Body.Close()
@ -261,11 +241,9 @@ func (c *Client) ReAnnounceTorrents(hashes []string) error {
resp, err := c.get("torrents/reannounce", opts)
if err != nil {
log.Error().Err(err).Msgf("re-announce error: %v", hashes)
return err
return errors.Wrap(err, "could not re-announce torrents: %v", hashes)
} else if resp.StatusCode != http.StatusOK {
log.Error().Err(err).Msgf("re-announce error bad status: %v", hashes)
return err
return errors.Wrap(err, "could not re-announce torrents: %v unexpected status: %v", hashes, resp.StatusCode)
}
defer resp.Body.Close()
@ -276,23 +254,20 @@ func (c *Client) ReAnnounceTorrents(hashes []string) error {
func (c *Client) GetTransferInfo() (*TransferInfo, error) {
resp, err := c.get("transfer/info", nil)
if err != nil {
log.Error().Err(err).Msg("get torrents error")
return nil, err
return nil, errors.Wrap(err, "could not get transfer info")
}
defer resp.Body.Close()
body, readErr := ioutil.ReadAll(resp.Body)
if readErr != nil {
log.Error().Err(err).Msg("get torrents read error")
return nil, readErr
return nil, errors.Wrap(readErr, "could not read body")
}
var info TransferInfo
err = json.Unmarshal(body, &info)
if err != nil {
log.Error().Err(err).Msg("get torrents unmarshal error")
return nil, err
return nil, errors.Wrap(readErr, "could not unmarshal body")
}
return &info, nil