From fa328396230d34843192f2952193b478d1f382cc Mon Sep 17 00:00:00 2001 From: Jimmy Zelinskie Date: Mon, 5 Sep 2016 12:10:42 -0400 Subject: [PATCH 1/6] replace std log w/ logrus There still needs to be much more logged with the debug level. --- cmd/chihaya/main.go | 22 ++++++++++++---------- middleware/jwt/jwt.go | 8 ++++---- middleware/middleware.go | 6 +++--- storage/memory/peer_store.go | 6 +++--- 4 files changed, 22 insertions(+), 20 deletions(-) diff --git a/cmd/chihaya/main.go b/cmd/chihaya/main.go index 3473717..0cc265d 100644 --- a/cmd/chihaya/main.go +++ b/cmd/chihaya/main.go @@ -2,13 +2,13 @@ package main import ( "errors" - "log" "net/http" "os" "os/signal" "runtime/pprof" "syscall" + log "github.com/Sirupsen/logrus" "github.com/prometheus/client_golang/prometheus" "github.com/spf13/cobra" @@ -21,7 +21,7 @@ import ( func rootCmdRun(cmd *cobra.Command, args []string) error { cpuProfilePath, _ := cmd.Flags().GetString("cpuprofile") if cpuProfilePath != "" { - log.Println("enabled CPU profiling to " + cpuProfilePath) + log.Infoln("enabled CPU profiling to", cpuProfilePath) f, err := os.Create(cpuProfilePath) if err != nil { return err @@ -42,26 +42,26 @@ func rootCmdRun(cmd *cobra.Command, args []string) error { Addr: cfg.PrometheusAddr, Handler: prometheus.Handler(), } - log.Println("started serving prometheus stats on", cfg.PrometheusAddr) + log.Infoln("started serving prometheus stats on", cfg.PrometheusAddr) if err := promServer.ListenAndServe(); err != nil { - log.Fatal(err) + log.Fatalln("failed to start prometheus server:", err.Error()) } }() // Force the compiler to enforce memory against the storage interface. peerStore, err := memory.New(cfg.Storage) if err != nil { - return err + return errors.New("failed to create memory storage: " + err.Error()) } preHooks, postHooks, err := configFile.CreateHooks() if err != nil { - return err + return errors.New("failed to create hooks: " + err.Error()) } logic := middleware.NewLogic(cfg.Config, peerStore, preHooks, postHooks) if err != nil { - return err + return errors.New("failed to create TrackerLogic: " + err.Error()) } shutdown := make(chan struct{}) @@ -74,7 +74,7 @@ func rootCmdRun(cmd *cobra.Command, args []string) error { httpFrontend = httpfrontend.NewFrontend(logic, cfg.HTTPConfig) go func() { - log.Println("started serving HTTP on", cfg.HTTPConfig.Addr) + log.Infoln("started serving HTTP on", cfg.HTTPConfig.Addr) if err := httpFrontend.ListenAndServe(); err != nil { errChan <- errors.New("failed to cleanly shutdown HTTP frontend: " + err.Error()) } @@ -85,7 +85,7 @@ func rootCmdRun(cmd *cobra.Command, args []string) error { udpFrontend = udpfrontend.NewFrontend(logic, cfg.UDPConfig) go func() { - log.Println("started serving UDP on", cfg.UDPConfig.Addr) + log.Infoln("started serving UDP on", cfg.UDPConfig.Addr) if err := udpFrontend.ListenAndServe(); err != nil { errChan <- errors.New("failed to cleanly shutdown UDP frontend: " + err.Error()) } @@ -114,6 +114,8 @@ func rootCmdRun(cmd *cobra.Command, args []string) error { } } + // TODO(jzelinskie): stop hooks here + close(errChan) }() @@ -125,7 +127,7 @@ func rootCmdRun(cmd *cobra.Command, args []string) error { close(shutdown) closed = true } else { - log.Println(bufErr) + log.Infoln(bufErr) } bufErr = err } diff --git a/middleware/jwt/jwt.go b/middleware/jwt/jwt.go index 1743c1f..8b9c937 100644 --- a/middleware/jwt/jwt.go +++ b/middleware/jwt/jwt.go @@ -11,7 +11,6 @@ import ( "crypto" "encoding/json" "errors" - "log" "net/http" "net/url" "time" @@ -19,6 +18,7 @@ import ( jc "github.com/SermoDigital/jose/crypto" "github.com/SermoDigital/jose/jws" "github.com/SermoDigital/jose/jwt" + log "github.com/Sirupsen/logrus" "github.com/mendsley/gojwk" "github.com/chihaya/chihaya/bittorrent" @@ -64,7 +64,7 @@ func NewHook(cfg Config) middleware.Hook { case <-time.After(cfg.JWKUpdateInterval): resp, err := http.Get(cfg.JWKSetURL) if err != nil { - log.Println("failed to fetch JWK Set: " + err.Error()) + log.Errorln("failed to fetch JWK Set: " + err.Error()) continue } @@ -72,7 +72,7 @@ func NewHook(cfg Config) middleware.Hook { err = json.NewDecoder(resp.Body).Decode(&parsedJWKs) if err != nil { resp.Body.Close() - log.Println("failed to decode JWK JSON: " + err.Error()) + log.Errorln("failed to decode JWK JSON: " + err.Error()) continue } resp.Body.Close() @@ -81,7 +81,7 @@ func NewHook(cfg Config) middleware.Hook { for kid, parsedJWK := range parsedJWKs { publicKey, err := parsedJWK.DecodePublicKey() if err != nil { - log.Println("failed to decode JWK into public key: " + err.Error()) + log.Errorln("failed to decode JWK into public key: " + err.Error()) continue } keys[kid] = publicKey diff --git a/middleware/middleware.go b/middleware/middleware.go index 0778ce0..0c9b86b 100644 --- a/middleware/middleware.go +++ b/middleware/middleware.go @@ -4,9 +4,9 @@ package middleware import ( "context" - "log" "time" + log "github.com/Sirupsen/logrus" "github.com/chihaya/chihaya/bittorrent" "github.com/chihaya/chihaya/frontend" "github.com/chihaya/chihaya/storage" @@ -65,7 +65,7 @@ func (l *Logic) HandleAnnounce(ctx context.Context, req *bittorrent.AnnounceRequ func (l *Logic) AfterAnnounce(ctx context.Context, req *bittorrent.AnnounceRequest, resp *bittorrent.AnnounceResponse) { for _, h := range l.postHooks { if err := h.HandleAnnounce(ctx, req, resp); err != nil { - log.Println("chihaya: post-announce hooks failed:", err.Error()) + log.Errorln("chihaya: post-announce hooks failed:", err.Error()) return } } @@ -90,7 +90,7 @@ func (l *Logic) HandleScrape(ctx context.Context, req *bittorrent.ScrapeRequest) func (l *Logic) AfterScrape(ctx context.Context, req *bittorrent.ScrapeRequest, resp *bittorrent.ScrapeResponse) { for _, h := range l.postHooks { if err := h.HandleScrape(ctx, req, resp); err != nil { - log.Println("chihaya: post-scrape hooks failed:", err.Error()) + log.Errorln("chihaya: post-scrape hooks failed:", err.Error()) return } } diff --git a/storage/memory/peer_store.go b/storage/memory/peer_store.go index 02211a1..1947d48 100644 --- a/storage/memory/peer_store.go +++ b/storage/memory/peer_store.go @@ -3,12 +3,13 @@ package memory import ( "encoding/binary" "errors" - "log" "net" "runtime" "sync" "time" + log "github.com/Sirupsen/logrus" + "github.com/chihaya/chihaya/bittorrent" "github.com/chihaya/chihaya/storage" ) @@ -53,7 +54,7 @@ func New(cfg Config) (storage.PeerStore, error) { return case <-time.After(cfg.GarbageCollectionInterval): before := time.Now().Add(-cfg.PeerLifetime) - log.Println("memory: purging peers with no announces since ", before) + log.Debugln("memory: purging peers with no announces since", before) ps.collectGarbage(before) } } @@ -327,7 +328,6 @@ func (s *peerStore) collectGarbage(cutoff time.Time) error { default: } - log.Printf("memory: collecting garbage. Cutoff time: %s", cutoff.String()) cutoffUnix := cutoff.UnixNano() for _, shard := range s.shards { shard.RLock() From 486e898ce944822c262a6fbd7217ad0b4eb0257f Mon Sep 17 00:00:00 2001 From: Jimmy Zelinskie Date: Mon, 5 Sep 2016 12:19:54 -0400 Subject: [PATCH 2/6] cmd: add --debug for debug logging --- cmd/chihaya/main.go | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/cmd/chihaya/main.go b/cmd/chihaya/main.go index 0cc265d..2ff789a 100644 --- a/cmd/chihaya/main.go +++ b/cmd/chihaya/main.go @@ -19,6 +19,11 @@ import ( ) func rootCmdRun(cmd *cobra.Command, args []string) error { + debugLog, _ := cmd.Flags().GetBool("debug") + if debugLog { + log.SetLevel(log.DebugLevel) + log.Debugln("debug logging enabled") + } cpuProfilePath, _ := cmd.Flags().GetString("cpuprofile") if cpuProfilePath != "" { log.Infoln("enabled CPU profiling to", cpuProfilePath) @@ -149,6 +154,7 @@ func main() { } rootCmd.Flags().String("config", "/etc/chihaya.yaml", "location of configuration file") rootCmd.Flags().String("cpuprofile", "", "location to save a CPU profile") + rootCmd.Flags().Bool("debug", false, "enable debug logging") if err := rootCmd.Execute(); err != nil { log.Fatal(err) From 6cd505269ee7bc33a087c97822e7e82d1e017812 Mon Sep 17 00:00:00 2001 From: Jimmy Zelinskie Date: Mon, 5 Sep 2016 12:22:49 -0400 Subject: [PATCH 3/6] bt: remove unused Tracker interface --- bittorrent/bittorrent.go | 6 ------ 1 file changed, 6 deletions(-) diff --git a/bittorrent/bittorrent.go b/bittorrent/bittorrent.go index eb18451..5f650df 100644 --- a/bittorrent/bittorrent.go +++ b/bittorrent/bittorrent.go @@ -135,9 +135,3 @@ type ClientError string // Error implements the error interface for ClientError. func (c ClientError) Error() string { return string(c) } - -// Tracker represents an implementation of the BitTorrent tracker protocol. -type Tracker interface { - ListenAndServe() error - Stop() -} From 093a748457037ed29d3685ecd03e85c86365dbfb Mon Sep 17 00:00:00 2001 From: Jimmy Zelinskie Date: Mon, 5 Sep 2016 12:25:11 -0400 Subject: [PATCH 4/6] frontend: s/ctx.TODO/ctx.Background --- frontend/http/frontend.go | 8 ++++---- frontend/udp/frontend.go | 8 ++++---- 2 files changed, 8 insertions(+), 8 deletions(-) diff --git a/frontend/http/frontend.go b/frontend/http/frontend.go index 48cedf9..6f976cf 100644 --- a/frontend/http/frontend.go +++ b/frontend/http/frontend.go @@ -136,7 +136,7 @@ func (t *Frontend) announceRoute(w http.ResponseWriter, r *http.Request, _ httpr return } - resp, err := t.logic.HandleAnnounce(context.TODO(), req) + resp, err := t.logic.HandleAnnounce(context.Background(), req) if err != nil { WriteError(w, err) return @@ -148,7 +148,7 @@ func (t *Frontend) announceRoute(w http.ResponseWriter, r *http.Request, _ httpr return } - go t.logic.AfterAnnounce(context.TODO(), req, resp) + go t.logic.AfterAnnounce(context.Background(), req, resp) } // scrapeRoute parses and responds to a Scrape by using t.TrackerLogic. @@ -163,7 +163,7 @@ func (t *Frontend) scrapeRoute(w http.ResponseWriter, r *http.Request, _ httprou return } - resp, err := t.logic.HandleScrape(context.TODO(), req) + resp, err := t.logic.HandleScrape(context.Background(), req) if err != nil { WriteError(w, err) return @@ -175,5 +175,5 @@ func (t *Frontend) scrapeRoute(w http.ResponseWriter, r *http.Request, _ httprou return } - go t.logic.AfterScrape(context.TODO(), req, resp) + go t.logic.AfterScrape(context.Background(), req, resp) } diff --git a/frontend/udp/frontend.go b/frontend/udp/frontend.go index 1cf3d03..757ec13 100644 --- a/frontend/udp/frontend.go +++ b/frontend/udp/frontend.go @@ -203,7 +203,7 @@ func (t *Frontend) handleRequest(r Request, w ResponseWriter) (actionName string } var resp *bittorrent.AnnounceResponse - resp, err = t.logic.HandleAnnounce(context.TODO(), req) + resp, err = t.logic.HandleAnnounce(context.Background(), req) if err != nil { WriteError(w, txID, err) return @@ -211,7 +211,7 @@ func (t *Frontend) handleRequest(r Request, w ResponseWriter) (actionName string WriteAnnounce(w, txID, resp) - go t.logic.AfterAnnounce(context.TODO(), req, resp) + go t.logic.AfterAnnounce(context.Background(), req, resp) return @@ -226,7 +226,7 @@ func (t *Frontend) handleRequest(r Request, w ResponseWriter) (actionName string } var resp *bittorrent.ScrapeResponse - resp, err = t.logic.HandleScrape(context.TODO(), req) + resp, err = t.logic.HandleScrape(context.Background(), req) if err != nil { WriteError(w, txID, err) return @@ -234,7 +234,7 @@ func (t *Frontend) handleRequest(r Request, w ResponseWriter) (actionName string WriteScrape(w, txID, resp) - go t.logic.AfterScrape(context.TODO(), req, resp) + go t.logic.AfterScrape(context.Background(), req, resp) return From c4706022d7d38ed8292ee0036aeeb1e055381fea Mon Sep 17 00:00:00 2001 From: Jimmy Zelinskie Date: Mon, 5 Sep 2016 12:27:00 -0400 Subject: [PATCH 5/6] udp: remove unnecessary returns in switch stmt --- frontend/udp/frontend.go | 8 ++------ 1 file changed, 2 insertions(+), 6 deletions(-) diff --git a/frontend/udp/frontend.go b/frontend/udp/frontend.go index 757ec13..4d0ef58 100644 --- a/frontend/udp/frontend.go +++ b/frontend/udp/frontend.go @@ -190,7 +190,6 @@ func (t *Frontend) handleRequest(r Request, w ResponseWriter) (actionName string } WriteConnectionID(w, txID, NewConnectionID(r.IP, time.Now(), t.PrivateKey)) - return case announceActionID: actionName = "announce" @@ -213,8 +212,6 @@ func (t *Frontend) handleRequest(r Request, w ResponseWriter) (actionName string go t.logic.AfterAnnounce(context.Background(), req, resp) - return - case scrapeActionID: actionName = "scrape" @@ -236,11 +233,10 @@ func (t *Frontend) handleRequest(r Request, w ResponseWriter) (actionName string go t.logic.AfterScrape(context.Background(), req, resp) - return - default: err = errUnknownAction WriteError(w, txID, err) - return } + + return } From 57ee2d0c9030e2f28ef939bf83c9bb1acc5fb501 Mon Sep 17 00:00:00 2001 From: Jimmy Zelinskie Date: Mon, 5 Sep 2016 12:30:03 -0400 Subject: [PATCH 6/6] bytepool: enforce equal length and cap --- frontend/udp/bytepool/bytepool.go | 6 +++--- frontend/udp/frontend.go | 2 +- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/frontend/udp/bytepool/bytepool.go b/frontend/udp/bytepool/bytepool.go index f4ec893..93507a9 100644 --- a/frontend/udp/bytepool/bytepool.go +++ b/frontend/udp/bytepool/bytepool.go @@ -7,11 +7,11 @@ type BytePool struct { sync.Pool } -// New allocates a new BytePool with slices of the provided capacity. -func New(length, capacity int) *BytePool { +// New allocates a new BytePool with slices of equal length and capacity. +func New(length int) *BytePool { var bp BytePool bp.Pool.New = func() interface{} { - return make([]byte, length, capacity) + return make([]byte, length, length) } return &bp } diff --git a/frontend/udp/frontend.go b/frontend/udp/frontend.go index 4d0ef58..2be9a3e 100644 --- a/frontend/udp/frontend.go +++ b/frontend/udp/frontend.go @@ -93,7 +93,7 @@ func (t *Frontend) ListenAndServe() error { } defer t.socket.Close() - pool := bytepool.New(2048, 2048) + pool := bytepool.New(2048) for { // Check to see if we need to shutdown.